OctoPrint-MeatPack icon indicating copy to clipboard operation
OctoPrint-MeatPack copied to clipboard

OctoPrint unable to connect to printer when plug-in is enabled

Open Taomyn opened this issue 3 years ago • 92 comments

I have an Ender 3 Pro with SKR BTT Mini E3 v1.2, OctoPi v0.18 (RPi-4) fully up to date, MeatPack plug-in v 1.5.21. My fork of Marlin can be found here https://github.com/Taomyn/Marlin

Compiled latest bugfix as I found tonight including enabling MeatPack.

When enabled OctoPrint will not connect to the printer, disable it and OctoPrint is working fine. Some log data below, let me know if I can provide anything else.

Excerpt from OctoPrint log:

2021-01-28 20:03:25,462 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-01-28 20:03:25,482 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 2 port/baudrate candidates: /dev/ttyACM0@250000, /dev/ttyS0@250000
2021-01-28 20:03:25,482 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000
2021-01-28 20:03:25,483 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:03:25,484 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:03:25,507 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-01-28 20:03:25,511 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:03:27,721 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #2 with timeout 2.0s
2021-01-28 20:03:27,726 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:03:29,753 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #3 with timeout 2.0s
2021-01-28 20:03:29,757 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:03:32,753 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyS0, baudrate 250000
2021-01-28 20:03:32,763 - octoprint.util.comm - ERROR - Unexpected error while connecting to serial port /dev/ttyS0, baudrate 250000 from hook meatpack: SerialException: 'Could not configure port: (5, 'Input/output error')' @ comm.py:_open_serial:3670
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 398, in _reconfigure_port
    orig_attr = termios.tcgetattr(self.fd)
termios.error: (5, 'Input/output error')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 3670, in _open_serial
    settings().getFloat(["serial", "timeout", "connection"]),
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/__init__.py", line 1890, in wrapper
    return f(*args, **kwargs)
  File "/home/pi/oprint/lib/python3.7/site-packages/OctoPrint_MeatPack/__init__.py", line 52, in serial_factory_hook
    self._serial_obj.port = str(port)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialutil.py", line 276, in port
    self.open()
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 332, in open
    self._reconfigure_port(force_update=True)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 401, in _reconfigure_port
    raise SerialException("Could not configure port: {}".format(msg))
serial.serialutil.SerialException: Could not configure port: (5, 'Input/output error')
2021-01-28 20:03:32,802 - octoprint.util.comm - INFO - Serial detection: Could not open port /dev/ttyS0, baudrate 250000, skipping
2021-01-28 20:03:32,802 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Error: No more candidates to test, and no working port/baudrate combination detected."
2021-01-28 20:03:32,804 - octoprint.util.comm - INFO - Changing monitoring state from "Error: No more candidates to test, and no working port/baudrate combination detected." to "Offline (Error: No more candidates to test, and no working port/baudrate combination detected.)"
2021-01-28 20:03:32,811 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-error' with value Error: No more candidates to test, and no working port/baudrate combination detected. (mydomain)
2021-01-28 20:03:33,180 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-error' with value Error: No more candidates to test, and no working port/baudrate combination detected. (mydomain)

Serial.log - failing

2021-01-28 20:02:47,456 - serial.log is currently not enabled, you can enable it via Settings > Serial Connection > Log communication to serial.log
2021-01-28 20:03:25,445 - serial.log is currently not enabled, you can enable it via Settings > Serial Connection > Log communication to serial.log
2021-01-28 20:08:08,102 - serial.log is currently not enabled, you can enable it via Settings > Serial Connection > Log communication to serial.log
2021-01-28 20:10:42,155 - Enabling serial logging
2021-01-28 20:10:52,495 - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-01-28 20:10:52,531 - Performing autodetection with 2 port/baudrate candidates: /dev/ttyACM0@250000, /dev/ttyS0@250000
2021-01-28 20:10:52,531 - Trying port /dev/ttyACM0, baudrate 250000
2021-01-28 20:10:52,549 - Handshake attempt #1 with timeout 2.0s
2021-01-28 20:10:52,552 - Connected to: PackingSerial<id=0xa8c07a70, open=True>(port='/dev/ttyACM0', baudrate=250000, bytesize=8, parity='N', stopbits=1, timeout=2.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
2021-01-28 20:10:52,554 - Send: N0 M110 N0*125
2021-01-28 20:10:53,141 - Recv: Not SD printing
2021-01-28 20:10:54,132 - Recv:  T:21.87 /0.00 B:34.17 /0.00 @:0 B@:0
2021-01-28 20:10:54,142 - Recv: Not SD printing
2021-01-28 20:10:55,143 - Recv: Not SD printing
2021-01-28 20:10:55,144 - Handshake attempt #2 with timeout 2.0s
2021-01-28 20:10:55,157 - Send: N0 M110 N0*125
2021-01-28 20:10:56,131 - Recv:  T:20.94 /0.00 B:34.17 /0.00 @:0 B@:0
2021-01-28 20:10:56,142 - Recv: Not SD printing
2021-01-28 20:10:57,142 - Recv: Not SD printing
2021-01-28 20:10:58,131 - Recv:  T:21.25 /0.00 B:34.14 /0.00 @:0 B@:0
2021-01-28 20:10:58,139 - Handshake attempt #3 with timeout 2.0s
2021-01-28 20:10:58,147 - Send: N0 M110 N0*125
2021-01-28 20:10:58,150 - Recv: Not SD printing
2021-01-28 20:10:59,143 - Recv: Not SD printing
2021-01-28 20:11:00,131 - Recv:  T:21.41 /0.00 B:34.17 /0.00 @:0 B@:0
2021-01-28 20:11:00,143 - Recv: Not SD printing
2021-01-28 20:11:00,145 - Trying port /dev/ttyS0, baudrate 250000
2021-01-28 20:11:00,156 - Unexpected error while connecting to serial port /dev/ttyS0, baudrate 250000 from hook meatpack: SerialException: 'Could not configure port: (5, 'Input/output error')' @ comm.py:_open_serial:3670
2021-01-28 20:11:00,192 - Could not open port /dev/ttyS0, baudrate 250000, skipping
2021-01-28 20:11:00,193 - Changing monitoring state from "Detecting serial connection" to "Error: No more candidates to test, and no working port/baudrate combination detected."
2021-01-28 20:11:00,194 - Changing monitoring state from "Error: No more candidates to test, and no working port/baudrate combination detected." to "Offline (Error: No more candidates to test, and no working port/baudrate combination detected.)"
2021-01-28 20:11:00,195 - Connection closed, closing down monitor
2021-01-28 20:11:07,075 - Disabling serial logging

Serial.log - working

2021-01-28 20:22:37,140 - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-01-28 20:22:37,760 - Performing autodetection with 2 port/baudrate candidates: /dev/ttyACM0@250000, /dev/ttyS0@250000
2021-01-28 20:22:37,761 - Trying port /dev/ttyACM0, baudrate 250000
2021-01-28 20:22:37,762 - Connecting to port /dev/ttyACM0, baudrate 250000
2021-01-28 20:22:37,868 - Handshake attempt #1 with timeout 2.0s
2021-01-28 20:22:37,893 - Connected to: Serial<id=0xa8b76910, open=True>(port='/dev/ttyACM0', baudrate=250000, bytesize=8, parity='N', stopbits=1, timeout=2.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
2021-01-28 20:22:37,895 - Send: N0 M110 N0*125
2021-01-28 20:22:37,931 - Recv: ok WNÂ…0g P31 B31
2021-01-28 20:22:37,978 - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-01-28 20:22:38,036 - Send: N0 M110 N0*125
2021-01-28 20:22:38,116 - Recv: ok WNÂ…0g P31 B31
2021-01-28 20:22:38,118 - Send: N1 M115*39
2021-01-28 20:22:38,155 - Recv: FIRMWARE_NAME:Marlin v2.0.x (Jan 28 2021 19:53:47) SOURCE_CODE_URL:github.com/MarlinFirmware/Marlin PROTOCOL_VERSION:1.0 MACHINE_TYPE:Ender-3 Pro EXTRUDER_COUNT:1 UUID:

Taomyn avatar Jan 28 '21 19:01 Taomyn

Looks like it's trying to access a port that isn't available (/dev/ttyS0), and the exception isn't being caught in the python module.

I have implemented a wrapper around the standard Serial object. I'm guessing OctoPrint typically just discards these exceptions if the port isn't available, but my implementation does not.

You can try disabling or removing the /dev/ttyS0 port, since it looks like you are using /dev/ttyACM0. In the meanwhile, I will try/except the exception and discard it, since it's only telling us the port can't be opened.

scottmudge avatar Jan 28 '21 19:01 scottmudge

Actually, you should really specify the correct port. The failing MeatPack log shows a different port being used than the one logged in the "working" log. Does MeatPack fail with /dev/ttyACM0?

scottmudge avatar Jan 28 '21 19:01 scottmudge

Actually, you should really specify the correct port. The failing MeatPack log shows a different port being used than the one logged in the "working" log. Does MeatPack fail with /dev/ttyACM0?

Nope just sits there "Connecting"......

image

Taomyn avatar Jan 28 '21 19:01 Taomyn

Alright you can try installing this branch which catches that exception. It might just be trying ttyS0 and then it can't recover.

You can install by activating your OctoPrint virtualenv and then running:

pip install git+https://github.com/scottmudge/OctoPrint-MeatPack.git@bugfix_serialconnfail.

You can also try installing it via the plugin manager, but it might not load git addresses correctly.

If that doesn't work, I'll need the rest of the octoprint.log file, since the excerpt is missing info about the ttyACM0 connection attempt.

scottmudge avatar Jan 28 '21 19:01 scottmudge

If that doesn't work, I'll need the rest of the octoprint.log file, since the excerpt is missing info about the ttyACM0 connection attempt.

No joy I'm afraid:

2021-01-28 20:46:59,600 - octoprint.events.fire - DEBUG - Firing event: SettingsUpdated (Payload: {'config_hash': '906e544d04923db7633c7ef4ffed074a', 'effective_hash': '58fbf453d6222da9ad45fc7d733c5a7d'})
2021-01-28 20:46:59,600 - octoprint.events - DEBUG - Sending action to <function Server.run.<locals>.on_settings_update at 0xaf947b70>
2021-01-28 20:46:59,601 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:46:59,602 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:46:59,603 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:46:59,604 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:46:59,605 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:46:59,607 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:46:59,608 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:46:59,609 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:46:59,610 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:01,637 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:01,637 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:01,637 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:01,638 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:01,639 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:01,639 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:01,639 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:01,640 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:01,640 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:01,640 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:05,899 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 6.87ms
2021-01-28 20:47:05,910 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 7.51ms
2021-01-28 20:47:06,111 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 8.15ms
2021-01-28 20:47:06,123 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 8.75ms
2021-01-28 20:47:06,297 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 7.39ms
2021-01-28 20:47:06,521 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 5.32ms
2021-01-28 20:47:06,702 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 4.90ms
2021-01-28 20:47:08,575 - octoprint.events.fire - DEBUG - Firing event: Connecting (Payload: None)
2021-01-28 20:47:08,576 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:08,577 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:08,578 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:08,579 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:08,579 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:08,580 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:08,580 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:08,581 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:08,581 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:08,581 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:08,581 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:08,582 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:08,583 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:08,583 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:08,622 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2021-01-28 20:47:08,626 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:47:08,632 - octoprint.events.fire - DEBUG - Firing event: PrinterStateChanged (Payload: {'state_id': 'OPEN_SERIAL', 'state_string': 'Opening serial connection'})
2021-01-28 20:47:08,634 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:47:08,634 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:08,640 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:08,641 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:08,646 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:08,648 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:08,649 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:08,649 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:08,650 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:08,651 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:08,651 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:08,652 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:08,653 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:08,654 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:08,654 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:08,655 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:08,656 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:08,657 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:08,657 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:08,659 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:08,665 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2021-01-28 20:47:08,670 - octoprint.events.fire - DEBUG - Firing event: PrinterStateChanged (Payload: {'state_id': 'CONNECTING', 'state_string': 'Connecting'})
2021-01-28 20:47:08,674 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:08,672 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:47:08,676 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:08,680 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:08,681 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:08,683 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:08,685 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:08,686 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:08,688 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:08,689 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:08,690 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:08,691 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:08,693 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:08,694 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:08,695 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:08,696 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:08,697 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:08,698 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:08,700 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:08,703 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:14,386 - octoprint.events.fire - DEBUG - Firing event: UserLoggedIn (Payload: {'username': None})
2021-01-28 20:47:14,387 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:14,389 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:14,389 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:14,390 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:14,390 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:14,390 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:14,391 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:14,391 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:14,391 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:14,411 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:14,411 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:14,412 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:14,412 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:14,412 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:14,413 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:14,413 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:14,413 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:14,414 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:14,414 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:14,612 - octoprint.events.fire - DEBUG - Firing event: UserLoggedIn (Payload: {'username': None})
2021-01-28 20:47:14,612 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:14,618 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:14,618 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:14,619 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:14,619 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:14,619 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:14,619 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:14,620 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:14,620 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:14,622 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:14,622 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:14,623 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:14,629 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:14,630 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:14,630 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:14,630 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:14,630 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:14,631 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:14,631 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:35,893 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 9.86ms
2021-01-28 20:47:35,909 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 10.95ms
2021-01-28 20:47:36,018 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 6.34ms
2021-01-28 20:47:36,105 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 5.58ms
2021-01-28 20:47:36,324 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 5.64ms
2021-01-28 20:47:36,561 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 4.70ms
2021-01-28 20:47:36,708 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 7.73ms
2021-01-28 20:47:36,970 - octoprint.events.fire - DEBUG - Firing event: Disconnecting (Payload: None)
2021-01-28 20:47:36,971 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:36,973 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:36,974 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:36,974 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:36,974 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:36,974 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:36,974 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:36,975 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:36,975 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:36,976 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:36,976 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:36,976 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:36,976 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:36,977 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:36,981 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Offline"
2021-01-28 20:47:36,981 - octoprint.events.fire - DEBUG - Firing event: UpdatedFiles (Payload: {'type': 'printables'})
2021-01-28 20:47:36,986 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:36,992 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:36,994 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:36,998 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:36,999 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:37,001 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:37,002 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:37,003 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:37,004 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:37,005 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:37,006 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:37,007 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:37,007 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:37,008 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:37,008 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:37,009 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:37,009 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:37,010 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:37,011 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:37,011 - octoprint.events.fire - DEBUG - Firing event: Disconnected (Payload: None)
2021-01-28 20:47:37,012 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:37,014 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:37,015 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-01-28 20:47:37,016 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:37,017 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:37,017 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:37,019 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:37,021 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:37,022 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:37,024 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:37,024 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:37,025 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:37,026 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:37,026 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:37,027 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:37,028 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:37,029 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:37,029 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:37,031 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:37,032 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:37,033 - octoprint.events.fire - DEBUG - Firing event: PrinterStateChanged (Payload: {'state_id': 'OFFLINE', 'state_string': 'Offline'})
2021-01-28 20:47:37,034 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:37,036 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:37,038 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:37,038 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:37,039 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:37,040 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:37,040 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:37,041 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:37,042 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:37,042 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:37,043 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:37,044 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:37,044 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:37,045 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:37,045 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:37,046 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:37,046 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:37,047 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:37,049 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:45,668 - octoprint.events.fire - DEBUG - Firing event: Connecting (Payload: None)
2021-01-28 20:47:45,668 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:45,670 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:45,670 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:45,670 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:45,671 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:45,671 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:45,671 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:45,671 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:45,672 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:45,672 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:45,672 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:45,673 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:45,673 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:45,673 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:45,674 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:45,688 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:45,705 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:45,712 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:45,708 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-01-28 20:47:45,722 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:45,728 - octoprint.events.fire - DEBUG - Firing event: PrinterStateChanged (Payload: {'state_id': 'DETECT_SERIAL', 'state_string': 'Detecting serial connection'})
2021-01-28 20:47:45,730 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:45,732 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:45,735 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:45,736 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:45,737 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:45,738 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:45,739 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:45,740 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:45,741 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:45,741 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:45,742 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:45,743 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:45,744 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:45,745 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:45,747 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:45,748 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:45,749 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:45,751 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:45,753 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:45,762 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 2 port/baudrate candidates: /dev/ttyACM0@250000, /dev/ttyS0@250000
2021-01-28 20:47:45,763 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000
2021-01-28 20:47:45,765 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:47:45,766 - octoprint.plugins.meatpack - INFO - [Serial]: Cannot query packing state -- port not open.
2021-01-28 20:47:45,777 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-01-28 20:47:45,784 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:47:47,903 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #2 with timeout 2.0s
2021-01-28 20:47:47,909 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:47:49,903 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #3 with timeout 2.0s
2021-01-28 20:47:49,910 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:47:51,904 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyS0, baudrate 250000
2021-01-28 20:47:51,914 - octoprint.plugins.meatpack - WARNING - failed to establish connection with serial port /dev/ttyS0 at baud rate 250000
	Exception: SerialException("Could not configure port: (5, 'Input/output error')")
2021-01-28 20:47:51,915 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-01-28 20:47:51,918 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 3831, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/lib/python3.7/site-packages/OctoPrint_MeatPack/packing_serial.py", line 182, in readline
    read = super(PackingSerial, self).readline(**kwargs)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 560, in read
    raise PortNotOpenError()
serial.serialutil.PortNotOpenError: Attempting to use a port that is not open
2021-01-28 20:47:51,919 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-01-28 20:47:51,949 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-01-28 20:47:51,963 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Offline (Error: PortNotOpenError: 'Attempting to use a port that is not open' @ comm.py:_readline:3831)"
2021-01-28 20:47:51,964 - octoprint.events.fire - DEBUG - Firing event: UpdatedFiles (Payload: {'type': 'printables'})
2021-01-28 20:47:51,965 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:51,968 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:51,969 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:51,969 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:51,969 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:51,969 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:51,970 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:51,970 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:51,970 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:51,970 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:51,970 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:51,971 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:51,971 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:51,972 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:51,972 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:51,972 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:51,972 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:51,972 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:51,973 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:51,973 - octoprint.events.fire - DEBUG - Firing event: Disconnected (Payload: None)
2021-01-28 20:47:51,973 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:51,976 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:51,980 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-01-28 20:47:51,983 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:51,984 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:51,985 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:51,986 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:51,993 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:51,995 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:51,996 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:51,997 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:51,999 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:52,000 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:52,001 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:52,002 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:52,003 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:52,004 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:52,004 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:52,005 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:52,006 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:47:52,008 - octoprint.events.fire - DEBUG - Firing event: PrinterStateChanged (Payload: {'state_id': 'OFFLINE', 'state_string': 'Offline'})
2021-01-28 20:47:52,008 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:47:52,012 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:47:52,012 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:47:52,014 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:47:52,015 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:47:52,016 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:47:52,016 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:47:52,017 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:47:52,018 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:47:52,019 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:47:52,020 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:47:52,022 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:47:52,022 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:47:52,023 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:47:52,025 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:47:52,025 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:47:52,026 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:47:52,027 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:47:52,030 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:48:05,945 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 7.33ms
2021-01-28 20:48:05,959 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 8.39ms
2021-01-28 20:48:06,090 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 8.29ms
2021-01-28 20:48:06,097 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 4.56ms
2021-01-28 20:48:06,316 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 6.49ms
2021-01-28 20:48:06,563 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 4.63ms
2021-01-28 20:48:06,767 - tornado.access - WARNING - 409 GET /api/printer (::ffff:192.168.1.1) 8.68ms
2021-01-28 20:48:14,140 - octoprint.events.fire - DEBUG - Firing event: UserLoggedIn (Payload: {'username': None})
2021-01-28 20:48:14,141 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:48:14,151 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:48:14,152 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:48:14,154 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:48:14,155 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:48:14,157 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:48:14,159 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:48:14,159 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:48:14,160 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:48:14,160 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:48:14,161 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:48:14,162 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:48:14,163 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:48:14,163 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:48:14,164 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:48:14,164 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:48:14,165 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:48:14,166 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:48:14,166 - octoprint.plugin - DEBUG - Calling on_event on tasmota
2021-01-28 20:48:14,326 - octoprint.events.fire - DEBUG - Firing event: UserLoggedIn (Payload: {'username': None})
2021-01-28 20:48:14,326 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0xa98505f0>>
2021-01-28 20:48:14,327 - octoprint.plugin - DEBUG - Calling on_event on action_command_notification
2021-01-28 20:48:14,330 - octoprint.plugin - DEBUG - Calling on_event on action_command_prompt
2021-01-28 20:48:14,331 - octoprint.plugin - DEBUG - Calling on_event on announcements
2021-01-28 20:48:14,332 - octoprint.plugin - DEBUG - Calling on_event on file_check
2021-01-28 20:48:14,333 - octoprint.plugin - DEBUG - Calling on_event on firmware_check
2021-01-28 20:48:14,334 - octoprint.plugin - DEBUG - Calling on_event on pluginmanager
2021-01-28 20:48:14,335 - octoprint.plugin - DEBUG - Calling on_event on softwareupdate
2021-01-28 20:48:14,336 - octoprint.plugin - DEBUG - Calling on_event on DisplayLayerProgress
2021-01-28 20:48:14,338 - octoprint.plugin - DEBUG - Calling on_event on DryRun
2021-01-28 20:48:14,355 - octoprint.plugin - DEBUG - Calling on_event on FriendlyBeeper
2021-01-28 20:48:14,381 - octoprint.plugin - DEBUG - Calling on_event on PrintTimeGenius
2021-01-28 20:48:14,407 - octoprint.plugin - DEBUG - Calling on_event on backupscheduler
2021-01-28 20:48:14,407 - octoprint.plugin - DEBUG - Calling on_event on bedlevelvisualizer
2021-01-28 20:48:14,408 - octoprint.plugin - DEBUG - Calling on_event on dashboard
2021-01-28 20:48:14,434 - octoprint.plugin - DEBUG - Calling on_event on eeprom_marlin
2021-01-28 20:48:14,446 - octoprint.plugin - DEBUG - Calling on_event on m73progress
2021-01-28 20:48:14,472 - octoprint.plugin - DEBUG - Calling on_event on printoid
2021-01-28 20:48:14,498 - octoprint.plugin - DEBUG - Calling on_event on tasmota

Taomyn avatar Jan 28 '21 19:01 Taomyn

Looks like it's still trying to read from ttyS0 in that excerpt. The PackingSerial() class doesn't decide which port to open. OctoPrint tells it what port to open.

I'm guessing there's still more to the log. Can you upload the whole thing to pastebin or attach it?

Also, I see your branch has a lot of configuration differences from the default, but does the build from here work?:

https://marlin.crc.id.au/

If there's a compatible build, anyway. I've confirmed it works the other night with the guy who runs the site and creates those builds, so it would narrow down if it's something in your build or not.

scottmudge avatar Jan 28 '21 19:01 scottmudge

And a final note, when Marlin merged my file they did some refactoring which may not have been tested. The builds that were tested were built from a patch without this refactoring.

If you're able to use the crc.id.au builds and they work (or if you can't and it still doesn't work on your branch), try replacing "meatpack.cpp" on your branch with the one I've attached here, and do a clean rebuild.

meatpack_cpp.zip

scottmudge avatar Jan 28 '21 20:01 scottmudge

Looks like it's still trying to read from ttyS0 in that excerpt. The PackingSerial() class doesn't decide which port to open. OctoPrint tells it what port to open.

I'm guessing there's still more to the log. Can you upload the whole thing to pastebin or attach it?

Nope that was everything for the time I was testing

Also, I see your branch has a lot of configuration differences from the default, but does the build from here work?:

https://marlin.crc.id.au/

If there's a compatible build, anyway. I've confirmed it works the other night with the guy who runs the site and creates those builds, so it would narrow down if it's something in your build or not.

Unfortunately I'm not going to be able to try that until the weekend, probably Sunday, and then it will take time as I'd need to be 100% it was going to work with my hardware set-up - it's hardly stock but not anything non-standard e.g. it's a genuine BL-Touch not a clone.

Taomyn avatar Jan 28 '21 20:01 Taomyn

And a final note, when Marlin merged my file they did some refactoring which may not have been tested. The builds that were tested were built from a patch without this refactoring.

If you're able to use the crc.id.au builds and they work (or if you can't and it still doesn't work on your branch), try replacing "meatpack.cpp" on your branch with the one I've attached here, and do a clean rebuild.

meatpack_cpp.zip

Sure, I can try that tomorrow and let you know.

Taomyn avatar Jan 28 '21 20:01 Taomyn

No problem, then for the time being try replacing meatpack.cpp with the file I linked above, and then rebuild.

And if you wouldn't mind, after it's done compiling, rename the .elf file produced to .elf.txt and attach it to the response, so I can check the disassembly.

Thanks for helping in the debug process!

scottmudge avatar Jan 28 '21 20:01 scottmudge

No problem, then for the time being try replacing meatpack.cpp with the file I linked above, and then rebuild.

It would not compile

image

I did have issues trying to compile just the latest bugfix changes from today, but after I reverted it was ok again and then I copied over your file and the above is what I got.

Taomyn avatar Jan 29 '21 17:01 Taomyn

Indeed, the toggle command was removed in the header. Here's a fix, removed that case statement. meatpack_cor.zip

scottmudge avatar Jan 29 '21 17:01 scottmudge

Indeed, the toggle command was removed in the header. Here's a fix, removed that case statement. meatpack_cor.zip

image

Taomyn avatar Jan 29 '21 17:01 Taomyn

Geez they refactored a lot, that additional serial iface index might have something to do with why it doesn't work?

Here, I made a branch of the commit that was tested and confirmed working on my fork. See if you can merge your fork with it and build. It's pretty much the same as bugfix-2.0.x, just without the refactoring they did to MeatPack after they merged my PR.

https://github.com/scottmudge/Marlin/tree/bugfix-2.0.x_meatpack_test

scottmudge avatar Jan 29 '21 18:01 scottmudge

Geez they refactored a lot, that additional serial iface index might have something to do with why it doesn't work?

Here, I made a branch of the commit that was tested and confirmed working on my fork. See if you can merge your fork with it and build. It's pretty much the same as bugfix-2.0.x, just without the refactoring they did to MeatPack after they merged my PR.

https://github.com/scottmudge/Marlin/tree/bugfix-2.0.x_meatpack_test

Sorry, I have no clue how to merge my branch with yours, I've only been using Github for my own fork for the last 6 months - I use Github Desktop on Windows, and even on the site I can't figure it out and none of the drop downs ever shows your fork, e.g.

image

It's also annoying that even after months hitting the "Compare" button any fork including the main Marlin one just brings up this

image

I reported it and they still haven't done anything about it.

Taomyn avatar Jan 29 '21 18:01 Taomyn

No problem, I can do it for you. Just give me a moment.

scottmudge avatar Jan 29 '21 18:01 scottmudge

Alright, so create a directory to store the repo, open a terminal inside of it, then run the following:

git clone https://github.com/scottmudge/Marlin.git
cd Marlin
git checkout Taomyn_Ender3Pro_Branch_MPMerge

That should get you a nice merged branch, with all your changes from your fork.

scottmudge avatar Jan 29 '21 18:01 scottmudge

That should get you a nice merged branch, with all your changes from your fork.

Thanks, that was successfully compiled - I just need to wait about an hour for a test print to finish then I can flash it. Here's the .elf file in the meantime.

firmware.elf.zip

Taomyn avatar Jan 29 '21 19:01 Taomyn

I am having the same issue with my printer not connecting. I first merged the bugfix-2.0.0 branch from Marlin. It didn't connect.

Then I tried to automatically merge from the branch: bugfix-2.0.x_meatpack_test

Didn't compile.

Then I manually copy and pasted the meatpack files and got compile errors:

In file included from Marlin\src\gcode\queue.cpp:52: Marlin\src\gcode../feature/meatpack.h:117:55: warning: ISO C++17 does not allow 'register' storage class specifier [-Wregister] 117 | static uint8_t unpacked_char(register const uint8_t in); | ^~ Marlin\src\gcode\queue.cpp: In static member function 'static void GCodeQueue::get_serial_commands()': Marlin\src\gcode\queue.cpp:482:46: error: no matching function for call to 'MeatPack::handle_rx_char(uint8_t, uint8_t&)' 482 | meatpack.handle_rx_char(uint8_t(c), p); | ^ In file included from Marlin\src\gcode\queue.cpp:52: Marlin\src\gcode../feature/meatpack.h:105:15: note: candidate: 'static void MeatPack::handle_rx_char(uint8_t)' 105 | static void handle_rx_char(const uint8_t c); | ^~~~~~~~~~~~~~ Marlin\src\gcode../feature/meatpack.h:105:15: note: candidate expects 1 argument, 2 provided *** [.pio\build\LPC1768\src\src\gcode\queue.cpp.o] Error 1

I then copy and pasted the files from your initial commit (meatpack.h, .c and queue)

It compiled but still doesn't connect.

I am now reverting back so I can continue printing.

My last configuration can be found on my github.

https://github.com/Di3mex/Marlin-P802/tree/bugfix-2.0.x

Di3mex avatar Jan 29 '21 19:01 Di3mex

I then copy and pasted the files from your initial commit (meatpack.h, .c and queue)

@Di3mex Which commit did you copy from? Looking at your fork, it looks like it still has the refactored and potentially broken code from Marlin.

I need to bring it up with Marlin. It doesn't seem like they effectively tested all of the code they refactored when they pulled my changes, which is unfortunate.

I will prepare you a branch from your fork with the tested, working revision.

scottmudge avatar Jan 29 '21 19:01 scottmudge

@Di3mex

Try this branch, I copied your config:

https://github.com/scottmudge/Marlin/tree/Dimex_Branch_testing

git clone https://github.com/scottmudge/Marlin.git
cd Marlin
git checkout Dimex_Branch_testing

scottmudge avatar Jan 29 '21 19:01 scottmudge

@scottmudge I'm afraid the version compiled from your code is doing the same thing - when I set it to the port manually it just sits there forever connecting.

Taomyn avatar Jan 29 '21 19:01 Taomyn

Okay, well at least that's been narrowed down. If the only difference is the Configuration.h and Configuration_adv.h changes, then something in there must be causing a problem.

scottmudge avatar Jan 29 '21 19:01 scottmudge

@Di3mex

Try this branch, I copied your config:

https://github.com/scottmudge/Marlin/tree/Dimex_Branch_testing

git clone https://github.com/scottmudge/Marlin.git
cd Marlin
git checkout Dimex_Branch_testing

Thanks, but also doesn't connect.

Di3mex avatar Jan 29 '21 19:01 Di3mex

Alright so there is some configuration difference between the builds produced on https://marlin.crc.id.au/ and those you're producing.

Can you produce a standard set of Configuration.h and Configuration_adv.h for your respective printer(s), or detail how yours is changed from the default? The existing one on the repo just looks like a template.

scottmudge avatar Jan 29 '21 20:01 scottmudge

Alright so there is some configuration difference between the builds produced on https://marlin.crc.id.au/ and those you're producing.

Can you produce a standard set of Configuration.h and Configuration_adv.h for your respective printer(s), or detail how yours is changed from the default? The existing one on the repo just looks like a template.

Got a bit confused by your now deleted message as I was sure mine was 32 image

My readme.md lists all the changes I make to a default Marlin config files, I have not used any of the vendor files.

Taomyn avatar Jan 29 '21 20:01 Taomyn

@scottmudge The config in my repo is not the default config. Not much changed. Just ABL and the options to enable Host command support (in config.adv), Lin advance, 32 microsteps, bigger buffers and stuff to "improve" the serial connection via USB.

Di3mex avatar Jan 29 '21 20:01 Di3mex

@Taomyn yes I was looking at the wrong side of my diff view, the other (Marlin default) was set to 0. Does setting it to 0 have any effect though?

And on that note, @Di3mex , did you do the same modification to TX_BUFFER_SIZE?

That's the only difference I can think of that would have a potential cause in the Firmware.

The only other potential cause would be on the host side. @Di3mex, can you link/attach your complete octoprint.log file? Perhaps OctoPrint + MeatPack doesn't like it when there's a separate, unused serial interface (e.g., /dev/ttyS0).

scottmudge avatar Jan 29 '21 20:01 scottmudge

Ok - just to fix some confusion here - Meatpack won't work with USB Emulated serial - ie /dev/ttyACM0 - that is because it isn't real serial. There's no such thing as a baud rate in USB Emulated Serial - hence your max speeds are about 12Mbit - not 115200.

As such, it doesn't really make sense to use MeatPack in this scenario - as your printer can't print at a 12Mbit data rate.

As such, Marlin will only allow MeatPack on real serial ports (0-7) - whereas USB is serial port -1.

As further info, you can connect to a different serial port on the same board and use Meatpack - but that also wouldn't make sense as it'd still be slower than the emulated usb serial.

CRCinAU avatar Jan 30 '21 02:01 CRCinAU

Thank you for clarifying, should have noticed it was ACM0, not AMA0.

On that note, I should pass-through control in the plugin w/o MP enabled if it is USB emulated. @CRCinAU - Is this type of serial device always enumerated with the ttyACM* device ID?

scottmudge avatar Jan 30 '21 03:01 scottmudge