Error SerialException in printing

flof · March 30, 2021, 7:43pm

What is the problem?

Hi,

I have a problem with my printer Tronxy x5s and Octoprint:
My printing stop about 5-10min of process. Octoprint write this error:

Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831)

Octoprint run on Debian 10 on server HP Prolian ML350 G6.
Have you got any idea? I have already tried several solutions ...

What did you already try to solve it?

Yes I try this:
-New USB cable
-Mask pin1 of USB cable
-Print with disconnected LCD and button panel

I print ABS at 250°C and bed at 105°C.
I have custom powersupply for bed in 24v.
My motherboard is at 12v and hotend is activate by mosfet.

Thanks.

Complete Logs

Ocotprint log:

2021-03-30 21:10:37,817 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port
Traceback (most recent call last):
File "/opt/octoprint/venv/lib/python3.7/site-packages/octoprint/util/comm.py", line 3831, in _readline
ret = self._serial.readline()
File "/opt/octoprint/venv/lib/python3.7/site-packages/octoprint/util/comm.py", line 6455, in readline
c = self.read(1)
File "/opt/octoprint/venv/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2021-03-30 21:10:37,819 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-03-30 21:10:37,823 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831)"
2021-03-30 21:10:37,846 - octoprint.plugins.action_command_notification - INFO - Notifications cleared

Serial logs:

2021-03-30 19:27:57,903 - Recv: T:250.00 /250.00 B:105.27 /105.00 @:96 B@:127
2021-03-30 19:27:57,998 - Recv: echo:busy: processing
2021-03-30 19:27:58,637 - Recv: ok
2021-03-30 19:27:58,638 - Send: N164 G1 X202.525 Y113.865 E226.93784108
2021-03-30 19:27:58,805 - Recv: ok
2021-03-30 19:27:58,806 - Send: N165 G1 X202.525 Y137.673 E229.23233111
2021-03-30 19:27:59,477 - Recv: ok
2021-03-30 19:27:59,478 - Send: N166 G1 X202.307 Y137.891 E229.26203110
2021-03-30 19:27:59,645 - Recv: ok
2021-03-30 19:27:59,646 - Send: N167 G1 X52.001 Y137.891 E243.7476583
2021-03-30 19:27:59,902 - Recv: T:250.00 /250.00 B:105.41 /105.00 @:97 B@:0
2021-03-30 19:28:01,655 - Recv: echo:busy: processing
2021-03-30 19:28:01,902 - Recv: T:249.92 /250.00 B:105.54 /105.00 @:100 B@:0
2021-03-30 19:28:03,654 - Recv: echo:busy: processing
2021-03-30 19:28:03,902 - Recv: T:250.00 /250.00 B:105.41 /105.00 @:98 B@:0
2021-03-30 19:28:04,531 - Recv: ok
2021-03-30 19:28:04,532 - Send: N168 G1 X51.783 Y137.673 E243.7773586
2021-03-30 19:28:04,698 - Recv: ok
2021-03-30 19:28:04,699 - Send: N169 G1 X51.783 Y113.865 E246.0718587
2021-03-30 19:28:05,371 - Recv: ok
2021-03-30 19:28:05,372 - Send: N170 G1 X51.959 Y113.690 E246.0957684
2021-03-30 19:28:05,539 - Recv: ok
2021-03-30 19:28:05,540 - Send: N171 G1 E244.09576 F2400.0000021
2021-03-30 19:28:05,706 - Recv: ok
2021-03-30 19:28:05,707 - Send: N172 G92 E067
2021-03-30 19:28:05,884 - Recv: X:51.96 Y:113.69 Z:0.35 E:0.00 Count A:17973 B:-4089 Z:78
2021-03-30 19:28:05,884 - Recv: ok
2021-03-30 19:28:05,885 - Send: N173 G1 X52.505 Y137.169 F7800.000103
2021-03-30 19:28:05,907 - Recv: T:249.84 /250.00 B:105.14 /105.00 @:103 B@:0
2021-03-30 19:28:06,674 - Unexpected error while reading serial port, please consult octoprint.log for details: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831
2021-03-30 19:28:06,676 - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-03-30 19:28:06,680 - Changing monitoring state from "Printing" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831)"
2021-03-30 19:28:06,683 - Connection closed, closing down monitor
2021-03-30 19:29:18,346 - Disabling serial logging

WRITE HERE

Additional information about your setup

OctoPrint version printer: Tronxy x5s firmware Marlin 2.0.5 operating system: Debian 10

flof · April 1, 2021, 5:42am

Hi,

I test to upgrade Marlin firmware 2.0.5 to the lastest 2.0.7 but the problem is the same.

For the moments I print with SD card.
I will try Klipper...

Regards.

Simon_Pamplin · April 20, 2021, 10:29am

No resolution for you but I have just had the same error mid-print. Only change recently was getting multi cam support working and running a USB camera and the Pi Camera from the onboard ribbon connector. I am looking for a supported powered hub as I suspect the USB power being the culprit but there dont appear to be any available recommended powered hubs.... I was printing ABS at similar temps as you at the time.

Neil_Fox · June 8, 2021, 8:17am

I'm having same issue with Ender 3 V2.
Have not been able to print from Octopi at all.
I removed the camera, changed all cables and no luck.
Any new ideas???

Ewald_Ikemann · June 8, 2021, 9:14am

Hello @Neil_Fox !

Do you even get the printer connected to OctoPrint?

Neil_Fox · June 14, 2021, 10:16am

Hello Ewald. Yes. Octoprint connects to the printer just fine but when I send the print command, I get the same error of "SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)"
Here is the log file.

2021-06-08 20:38:19,734 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 20:38:19,742 - octoprint.server - INFO - --- Log roll over detected ---------------------------------------------------
2021-06-08 20:38:19,742 - octoprint.server - INFO - OctoPrint 1.6.1
2021-06-08 20:38:19,745 - octoprint.plugin.core - INFO - 18 plugin(s) registered with the system:
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Creality-2x-temperature-reporting-fix (0.0.4) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_ender3v2tempfix
|  Discovery (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/discovery
|  Error Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  File Check (2021.2.23) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2021.5.31) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
|  Pi Support Plugin (2021.3.26.post2) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2021-06-08 20:38:19,758 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|    cores: 4
|    freq: 1500.0
|    ram: 3959984128
|  os:
|    bits: 32
|    id: linux
|    platform: linux
|  plugins:
|    pi_support:
|      model: Raspberry Pi 4 Model B Rev 1.2
|      octopi_version: 0.18.0
|      throttle_state: '0x0'
|  python:
|    pip: 20.3.3
|    version: 3.7.3
|    virtualenv: /home/pi/oprint
2021-06-08 20:38:19,758 - octoprint.server - INFO - ------------------------------------------------------------------------------
2021-06-08 20:38:20,389 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 36920, 'printer_state': 'OFFLINE'}
2021-06-08 20:53:19,736 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 20:53:20,406 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 37820, 'printer_state': 'OFFLINE'}
2021-06-08 21:08:19,737 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 21:08:20,613 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 38720, 'printer_state': 'OFFLINE'}
2021-06-08 21:23:19,739 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 21:23:20,535 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 39620, 'printer_state': 'OFFLINE'}
2021-06-08 21:38:19,740 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 21:38:20,270 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 40520, 'printer_state': 'OFFLINE'}
2021-06-08 21:53:19,742 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 21:53:20,669 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 41420, 'printer_state': 'OFFLINE'}
2021-06-08 22:08:19,743 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 22:08:20,282 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 42320, 'printer_state': 'OFFLINE'}
2021-06-08 22:23:19,744 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 22:23:20,631 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 43220, 'printer_state': 'OFFLINE'}
2021-06-08 22:38:19,746 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 22:38:20,232 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 44120, 'printer_state': 'OFFLINE'}
2021-06-08 22:53:19,747 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 22:53:20,500 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 45020, 'printer_state': 'OFFLINE'}
2021-06-08 23:08:19,749 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 23:08:20,408 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 45920, 'printer_state': 'OFFLINE'}
2021-06-08 23:23:19,750 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 23:23:20,498 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 46820, 'printer_state': 'OFFLINE'}
2021-06-08 23:38:19,751 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 23:38:20,266 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 47720, 'printer_state': 'OFFLINE'}
2021-06-08 23:53:19,753 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-08 23:53:20,470 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 48620, 'printer_state': 'OFFLINE'}
2021-06-09 00:08:19,754 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 00:08:20,315 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 49520, 'printer_state': 'OFFLINE'}
2021-06-09 00:23:19,756 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 00:23:20,470 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 50420, 'printer_state': 'OFFLINE'}
2021-06-09 00:38:19,757 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 00:38:20,282 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 51320, 'printer_state': 'OFFLINE'}
2021-06-09 00:53:19,759 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 00:53:20,602 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 52220, 'printer_state': 'OFFLINE'}
2021-06-09 01:08:19,760 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 01:08:20,526 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 53120, 'printer_state': 'OFFLINE'}
2021-06-09 01:23:19,761 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 01:23:20,368 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 54020, 'printer_state': 'OFFLINE'}
2021-06-09 01:38:19,763 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 01:38:20,285 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 54920, 'printer_state': 'OFFLINE'}
2021-06-09 01:53:19,764 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 01:53:20,279 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 55820, 'printer_state': 'OFFLINE'}
2021-06-09 02:08:19,765 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 02:08:20,243 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 56720, 'printer_state': 'OFFLINE'}
2021-06-09 02:23:19,767 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 02:23:20,313 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 57620, 'printer_state': 'OFFLINE'}
2021-06-09 02:38:19,768 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 02:38:20,251 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 58520, 'printer_state': 'OFFLINE'}
2021-06-09 02:53:19,770 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 02:53:20,328 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 59420, 'printer_state': 'OFFLINE'}
2021-06-09 03:08:19,771 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 03:08:20,447 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 60320, 'printer_state': 'OFFLINE'}
2021-06-09 03:23:19,772 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 03:23:20,361 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 61220, 'printer_state': 'OFFLINE'}
2021-06-09 03:38:19,774 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 03:38:20,249 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 62120, 'printer_state': 'OFFLINE'}
2021-06-09 03:53:19,775 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 03:53:20,455 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 63020, 'printer_state': 'OFFLINE'}
2021-06-09 04:08:19,777 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 04:08:20,354 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 63920, 'printer_state': 'OFFLINE'}
2021-06-09 04:23:19,778 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 04:23:20,360 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 64820, 'printer_state': 'OFFLINE'}
2021-06-09 04:38:19,779 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 04:38:20,526 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 65720, 'printer_state': 'OFFLINE'}
2021-06-09 04:53:19,781 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 04:53:20,282 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 66620, 'printer_state': 'OFFLINE'}
2021-06-09 05:08:19,782 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 05:08:20,487 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 67520, 'printer_state': 'OFFLINE'}
2021-06-09 05:23:19,784 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 05:23:20,396 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 68420, 'printer_state': 'OFFLINE'}
2021-06-09 05:38:19,785 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 05:38:20,387 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 69320, 'printer_state': 'OFFLINE'}
2021-06-09 05:53:19,787 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 05:53:20,405 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 70220, 'printer_state': 'OFFLINE'}
2021-06-09 06:08:19,788 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 06:08:20,275 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 71120, 'printer_state': 'OFFLINE'}
2021-06-09 06:23:19,790 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 06:23:20,297 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 72020, 'printer_state': 'OFFLINE'}
2021-06-09 06:38:19,791 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 06:38:20,286 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 72920, 'printer_state': 'OFFLINE'}
2021-06-09 06:53:19,792 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 06:53:20,383 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 73820, 'printer_state': 'OFFLINE'}
2021-06-09 07:08:19,794 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 07:08:20,386 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 74720, 'printer_state': 'OFFLINE'}
2021-06-09 07:23:19,795 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 07:23:20,368 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 75620, 'printer_state': 'OFFLINE'}
2021-06-09 07:38:19,797 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 07:38:20,401 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 76520, 'printer_state': 'OFFLINE'}
2021-06-09 07:53:19,798 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 07:53:20,583 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 77420, 'printer_state': 'OFFLINE'}
2021-06-09 08:08:19,800 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 08:08:20,369 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 78320, 'printer_state': 'OFFLINE'}
2021-06-09 08:23:19,801 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 08:23:20,426 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 79220, 'printer_state': 'OFFLINE'}
2021-06-09 08:38:19,803 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 08:38:20,524 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 80120, 'printer_state': 'OFFLINE'}
2021-06-09 08:53:19,804 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 08:53:20,366 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 81020, 'printer_state': 'OFFLINE'}
2021-06-09 09:08:19,805 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 09:08:20,287 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 81920, 'printer_state': 'OFFLINE'}
2021-06-09 09:23:19,807 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 09:23:20,460 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 82820, 'printer_state': 'OFFLINE'}
2021-06-09 09:38:19,808 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 09:38:20,316 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 83720, 'printer_state': 'OFFLINE'}
2021-06-09 09:53:19,809 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 09:53:20,367 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 84620, 'printer_state': 'OFFLINE'}
2021-06-09 10:08:19,811 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 10:08:20,391 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 85520, 'printer_state': 'OFFLINE'}
2021-06-09 10:23:19,812 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 10:23:20,392 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 86420, 'printer_state': 'OFFLINE'}
2021-06-09 10:38:19,814 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 10:38:20,363 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 87320, 'printer_state': 'OFFLINE'}
2021-06-09 10:53:19,815 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 10:53:20,310 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 88220, 'printer_state': 'OFFLINE'}
2021-06-09 11:08:19,816 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 11:08:20,310 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 89120, 'printer_state': 'OFFLINE'}
2021-06-09 11:23:19,818 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 11:23:20,559 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 90020, 'printer_state': 'OFFLINE'}
2021-06-09 11:38:19,819 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 11:38:20,584 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 90920, 'printer_state': 'OFFLINE'}
2021-06-09 11:53:19,821 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 11:53:20,530 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 91820, 'printer_state': 'OFFLINE'}
2021-06-09 12:08:19,822 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-06-09 12:08:20,420 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 92720, 'printer_state': 'OFFLINE'}
2021-06-09 12:10:06,609 - octoprint.server.util.flask - INFO - Passively logging in user oakley from 2600:1700:850:6210::5e3
2021-06-09 12:10:06,610 - octoprint.access.users - INFO - Cleaning up user session 3E04621048EB4125817F06E04AD8F502 for user oakley
2021-06-09 12:10:06,610 - octoprint.access.users - INFO - Logged out user: oakley
2021-06-09 12:10:06,610 - octoprint.access.users - INFO - Logged in user: oakley
2021-06-09 12:10:06,810 - octoprint.server.util.sockjs - INFO - Client connection closed: 2600:1700:850:6210::5e3
2021-06-09 12:10:07,234 - octoprint.server.util.sockjs - INFO - New connection from client: 2600:1700:850:6210::5e3
2021-06-09 12:10:07,345 - octoprint.server.util.flask - INFO - Passively logging in user oakley from 2600:1700:850:6210::5e3
2021-06-09 12:10:07,345 - octoprint.access.users - INFO - Logged in user: oakley
2021-06-09 12:10:07,414 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2021-06-09 12:10:09,405 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2021-06-09 12:10:10,538 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2021-06-09 12:10:10,589 - octoprint.server.util.sockjs - INFO - User oakley logged in on the socket from client 2600:1700:850:6210::5e3
2021-06-09 12:10:25,131 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-06-09 12:10:25,152 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 7 port/baudrate candidates: /dev/ttyUSB0@115200, /dev/ttyUSB0@250000, /dev/ttyUSB0@230400, /dev/ttyUSB0@57600, /dev/ttyUSB0@38400, /dev/ttyUSB0@19200, /dev/ttyUSB0@9600
2021-06-09 12:10:25,152 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:10:25,153 - octoprint.util.comm - INFO - Connecting to port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:10:25,169 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-06-09 12:10:25,171 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:10:25,202 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-06-09 12:10:25,214 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:10:25,276 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin Ver 1.0.2"
2021-06-09 12:10:25,287 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2021-06-09 12:10:25,712 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {'firmware_name': 'Marlin Ver 1.0.2', 'printer_port': 'AUTO', 'printer_baudrate': 0}
2021-06-09 12:10:37,566 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:10:50,724 - octoprint.util.comm - INFO - Starting job on behalf of user oakley
2021-06-09 12:10:50,731 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2021-06-09 12:10:50,738 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:10:50,767 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:10:50,786 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2021-06-09 12:10:51,566 - 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 3860, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 6488, in readline
    c = self.read(1)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2021-06-09 12:10:51,571 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-06-09 12:10:51,588 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline after error"
2021-06-09 12:10:51,606 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-06-09 12:10:52,237 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5'}
2021-06-09 12:10:52,700 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5', 'reason': 'error', 'commerror_text': 'SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)'}
2021-06-09 12:11:07,118 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-06-09 12:11:07,155 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 7 port/baudrate candidates: /dev/ttyUSB0@115200, /dev/ttyUSB0@250000, /dev/ttyUSB0@230400, /dev/ttyUSB0@57600, /dev/ttyUSB0@38400, /dev/ttyUSB0@19200, /dev/ttyUSB0@9600
2021-06-09 12:11:07,155 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:11:07,156 - octoprint.util.comm - INFO - Connecting to port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:11:07,228 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-06-09 12:11:07,234 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:11:07,239 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-06-09 12:11:07,246 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:11:07,276 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin Ver 1.0.2"
2021-06-09 12:11:07,289 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2021-06-09 12:11:07,742 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {'firmware_name': 'Marlin Ver 1.0.2', 'printer_port': 'AUTO', 'printer_baudrate': 0}
2021-06-09 12:11:11,549 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:11:13,422 - octoprint.util.comm - INFO - Starting job on behalf of user oakley
2021-06-09 12:11:13,424 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2021-06-09 12:11:13,430 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:11:13,451 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:11:13,477 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2021-06-09 12:11:14,356 - 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 3860, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 6488, in readline
    c = self.read(1)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2021-06-09 12:11:14,359 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-06-09 12:11:14,384 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline after error"
2021-06-09 12:11:14,394 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-06-09 12:11:15,116 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5'}
2021-06-09 12:11:15,572 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5', 'reason': 'error', 'commerror_text': 'SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)'}
2021-06-09 12:11:46,488 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-06-09 12:11:46,514 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyUSB0@115200
2021-06-09 12:11:46,514 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:11:46,515 - octoprint.util.comm - INFO - Connecting to port /dev/ttyUSB0, baudrate 115200
2021-06-09 12:11:46,567 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-06-09 12:11:46,590 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:11:46,608 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-06-09 12:11:46,614 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:11:46,650 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin Ver 1.0.2"
2021-06-09 12:11:46,663 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2021-06-09 12:11:47,180 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {'firmware_name': 'Marlin Ver 1.0.2', 'printer_port': 'AUTO', 'printer_baudrate': 115200}
2021-06-09 12:13:29,990 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:13:46,065 - octoprint.util.comm - INFO - Starting job on behalf of user oakley
2021-06-09 12:13:46,071 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2021-06-09 12:13:46,078 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE3_Heimi1.gcode, owner: oakley, user: oakley
2021-06-09 12:13:46,125 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-06-09 12:13:46,141 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2021-06-09 12:13:46,600 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5'}
2021-06-09 12:13:46,956 - 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 3860, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 6488, in readline
    c = self.read(1)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2021-06-09 12:13:46,958 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-06-09 12:13:46,985 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline after error"
2021-06-09 12:13:46,995 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-06-09 12:13:47,448 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'file': 'dcdc387ac3d0f2db6628efddd8ac800d6b6519d5', 'reason': 'error', 'commerror_text': 'SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)'}

Neil_Fox · July 9, 2021, 3:32pm

I finally solved my issue. Turns out I had firmware for 4.2.7 board installed when I actually have a 4.2.2 board. I changed to the 4.2.2 firmware and all is working well now.
Thanks for the insight.

rfryar · July 22, 2022, 8:53pm

I have been running into the same error..

Things I have tried:

New USB Cable
USB Power block adapter to ensure no power is sent down USB cable
Updated the cmdline.txt to set slow USB as only the printer is connected to the Pi through the USB

Pi does not report any undervoltage problems, it is running with a decent power supply.

From the PI dmesg command I see this line about the USB disconnecting, not sure if this is the octoprint doing the disconnect, or something else doing the disconnect.

[ 4415.328776] usb 1-1.4: USB disconnect, device number 15

Logs with serial logging: octoprint-logs (2).zip (1.8 MB)

Is there any other tracing I can do? Anything via the marlin firmware to determine if it is doing the USB disconnect for some reason?

Ewald_Ikemann · July 23, 2022, 6:14am

Hello @rfryar !

Does this issue always appear at the same spot in the print?

BTW: What printer do you use?

rfryar · July 23, 2022, 3:47pm

No it occurs at a random time. Even prints that I know worked in the past fail through the USB connection. SD card printing work fine.

This is an Anycubic Mega X on the latest Marlin firmware 2.0 - 1.44.

I am going to try printing from a computer next to eliminate any issues with the ras pi, the then moving the USB cable to a different spot in case the printer is causing interference, etc. But at a loss as it worked fine for 2+ years and suddenly this issue has started.

rfryar · July 24, 2022, 3:29am

Testing from a laptop and directly printing from Cura worked perfectly. So that rules out the printer and the cable. So down to the pi and octoprint. My next guess is the pi overheating and causing usb to disconnect.

Does anyone have any recommendations on good thermal management for the Pi? Is there any octoprint plug ins to track the pi's temperature?

Ewald_Ikemann · July 24, 2022, 6:44am

You need at least heatsinks on the chips and a decent fan.

For the plugins, there are for example these:

rfryar · July 25, 2022, 1:37pm

Stumped.. Not temp based, the Pi never got about 50 degrees. Not power based as there was no power fluctuation or power warnings on the Pi either. I wonder if I have a faulty pi board that causes the USB disconnect.

This is the message from dmesg:

[85322.808796] usb 1-1-port4: disabled by hub (EMI?), re-enabling...

May try a new pi if I can find another one in my junk drawer

rfryar · July 27, 2022, 1:48am

Switched from Raspberry pi3 to pi4. Rebuilt octoprint.. Same disconnect, different error:

usb_serial_generic_read_bulk_callback - urb stopped: -32

Based on some comments in other threads on this error I am removing my power blocking adapter. One more try, hopefully it no longer disconnects from the USB.