Ender 3 v2 struggles to connect via USB to octoprint

r3ticuli · November 23, 2020, 5:44pm

What is the problem?

My octoprint was working fine for months, but randomly started to struggle connecting to my printer (Ender 3 v2) via USB. The UI stays stuck like so :

What did you already try to solve it?

I have tried various usb cables (some of which i know worked in the past), i have replaced the motherboard (4.2.2 to 4.2.7), I have replaced raspberry pi (tried v4, v3), i have tried using octoprint 0.18.0, and I have placed tape over the power pin on the usb. I can see that the usb cable is visible by the pi.

I have noticed that after unplugging and replugging the pi in repeatedly, the issue seems to eventually solve itself. It is hard to say what exactly solves it, but hard resetting it (turning off octoprint, and unplugging the pi from the power source) seems to fix it eventually.

Have you tried running in safe mode and if so did it solve the issue?

Safe mode has not helped.

Complete Logs

lsusb output:

Bus 001 Device 004: ID 1a86:7523 QinHeng Electronics HL-340 USB-Serial adapter
Bus 001 Device 005: ID 0424:7800 Standard Microsystems Corp. 
Bus 001 Device 003: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 001 Device 002: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

dmesg | grep usb output:

[    0.306705] usbcore: registered new interface driver usbfs
[    0.306816] usbcore: registered new interface driver hub
[    0.307007] usbcore: registered new device driver usb
[    1.599984] usbcore: registered new interface driver r8152
[    1.602640] usbcore: registered new interface driver lan78xx
[    1.605227] usbcore: registered new interface driver smsc95xx
[    2.603302] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.605586] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    2.607985] dwc_otg 3f980000.usb: irq 9, io mem 0x00000000
[    2.615484] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    2.620225] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.622785] usb usb1: Product: DWC OTG Controller
[    2.625289] usb usb1: Manufacturer: Linux 5.4.51-v8+ dwc_otg_hcd
[    2.627779] usb usb1: SerialNumber: 3f980000.usb
[    2.637644] usbcore: registered new interface driver uas
[    2.640062] usbcore: registered new interface driver usb-storage
[    2.681005] usbcore: registered new interface driver usbhid
[    2.683155] usbhid: USB HID core driver
[    3.053199] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.265651] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    3.269640] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.565198] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.669675] usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    3.674585] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.969206] usb 1-1.1.3: new full-speed USB device number 4 using dwc_otg
[    4.074813] usb 1-1.1.3: New USB device found, idVendor=1a86, idProduct=7523, bcdDevice= 2.64
[    4.079590] usb 1-1.1.3: New USB device strings: Mfr=0, Product=2, SerialNumber=0
[    4.084446] usb 1-1.1.3: Product: USB Serial
[    4.309204] usb 1-1.1.1: new high-speed USB device number 5 using dwc_otg
[    4.409948] usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800, bcdDevice= 3.00
[    4.414951] usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    7.423982] usbcore: registered new interface driver usbserial_generic
[    7.424071] usbserial: USB Serial support registered for generic
[    7.449922] usbcore: registered new interface driver ch341
[    7.450030] usbserial: USB Serial support registered for ch341-uart
[    7.453119] usb 1-1.1.3: ch341-uart converter now attached to ttyUSB0
[    7.459173] usbcore: registered new interface driver brcmfmac

serial.log:

2020-11-23 17:34:03,008 - Changing monitoring state from "Offline" to "Opening serial connection"
2020-11-23 17:34:03,027 - Connecting to port /dev/ttyUSB0, baudrate 115200
2020-11-23 17:34:03,090 - Changing monitoring state from "Opening serial connection" to "Connecting"
2020-11-23 17:34:03,116 - Connected to: Serial<id=0x7f9c132f98, open=True>(port='/dev/ttyUSB0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=1.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
2020-11-23 17:34:03,131 - Send: N0 M110 N0*125
2020-11-23 17:34:03,157 - Recv: ok
2020-11-23 17:34:03,192 - Changing monitoring state from "Connecting" to "Operational"
2020-11-23 17:34:03,194 - Send: N0 M110 N0*125
2020-11-23 17:34:03,245 - Recv: ok
2020-11-23 17:34:03,280 - Send: N0 M110 N0*125
2020-11-23 17:34:03,313 - Recv: ok
2020-11-23 17:34:03,325 - Send: N1 M115*39
2020-11-23 17:34:03,385 - Recv: FIRMWARE_NAME:Marlin bugfix-2.0.x (Nov 18 2020 18:52:35) SOURCE_CODE_URL:https://github.com/MarlinFirmware/Marlin PROTOCOL_VERSION:1.0 MACHINE_TYPE:Ender-3 V2 EXTRUDER_COUNT:1 UUID:cede2a2f-41a2-4748-9b12-c55c62f367ff
2020-11-23 17:34:03,398 - Recv: Cap:SERIAL_XON_XOFF:0
2020-11-23 17:34:03,402 - Recv: Cap:BINARY_FILE_TRANSFER:0
2020-11-23 17:34:03,403 - Recv: Cap:EEPROM:1
2020-11-23 17:34:03,405 - Recv: Cap:VOLUMETRIC:1
2020-11-23 17:34:03,406 - Recv: Cap:AUTOREPORT_TEMP:1
2020-11-23 17:34:03,414 - Recv: Cap:PROGRESS:0
2020-11-23 17:34:03,426 - Recv: Cap:PRINT_JOB:1
2020-11-23 17:34:03,432 - Recv: Cap:AUTOLEVEL:1
2020-11-23 17:34:03,433 - Recv: Cap:RUNOUT:1
2020-11-23 17:34:03,434 - Recv: Cap:Z_PROBE:1
2020-11-23 17:34:03,436 - Recv: Cap:LEVELING_DATA:1
2020-11-23 17:34:03,449 - Recv: Cap:BUILD_PERCENT:0
2020-11-23 17:34:03,471 - Recv: Cap:SOFTWARE_POWER:0
2020-11-23 17:34:03,498 - Recv: Cap:TOGGLE_LIGHTS:0
2020-11-23 17:34:03,522 - Recv: Cap:CASE_LIGHT_BRIGHTNESS:0
2020-11-23 17:34:03,570 - Recv: Cap:EMERGENCY_PARSER:0
2020-11-23 17:34:03,583 - Recv: Cap:PROMPT_SUPPORT:0
2020-11-23 17:34:03,628 - Recv: Cap:SDCARD:1
2020-11-23 17:34:03,661 - Recv: Cap:AUTOREPORT_SD_STATUS:0
2020-11-23 17:34:03,754 - Recv: Cap:LONG_FILENAME:0
2020-11-23 17:34:03,840 - Recv: Cap:THERMAL_PROTECTION:1
2020-11-23 17:34:03,856 - Recv: Cap:MOTION_MODES:0
2020-11-23 17:34:03,911 - Recv: Cap:ARCS:1
2020-11-23 17:34:03,945 - Recv: Cap:BABYSTEPPING:1
2020-11-23 17:34:03,973 - Recv: Cap:CHAMBER_TEMPERATURE:0
2020-11-23 17:34:04,039 - Recv: ok
2020-11-23 17:34:04,058 - Send: M21
2020-11-23 17:34:04,088 - Recv: echo:SD card ok
2020-11-23 17:34:04,091 - Recv: ok
2020-11-23 17:34:04,093 - Send: M155 S0
2020-11-23 17:34:04,122 - Recv: ok
2020-11-23 17:34:04,125 - Send: M20
2020-11-23 17:34:04,210 - Recv: Begin file list
2020-11-23 17:34:04,285 - Recv: FIRSTL~1.GCO 24813
2020-11-23 17:34:04,377 - Recv: /TRASHE~1/501/CAT-35~1.GCO 8522491
2020-11-23 17:34:04,379 - Recv: /TRASHE~1/501/CE3_3D~1.GCO 3746861
2020-11-23 17:34:04,382 - Recv: /TRASHE~1/501/CE3_BA~1.GCO 2256274
2020-11-23 17:34:04,384 - Recv: /TRASHE~1/501/CE3_CL~1.GCO 4302833
2020-11-23 17:34:04,386 - Recv: /TRASHE~1/501/CE3_SC~1.GCO 7427434
2020-11-23 17:34:04,389 - Recv: /TRASHE~1/501/CE3_SU~1.GCO 8762633
2020-11-23 17:34:04,390 - Recv: /TRASHE~1/501/DOG-2~1.GCO 2934972
2020-11-23 17:34:04,409 - Recv: /TRASHE~1/501/PIG-4~1.GCO 15191323
2020-11-23 17:34:04,416 - Recv: /TRASHE~1/501/CE3_I6~1.GCO 3014622
2020-11-23 17:34:04,425 - Recv: /TRASHE~1/501/CE3_I6~2.GCO 1407974
2020-11-23 17:34:04,427 - Recv: /TRASHE~1/501/CE3_LI~1.GCO 1795378
2020-11-23 17:34:04,428 - Recv: /TRASHE~1/501/CE3_T-~1.GCO 484230
2020-11-23 17:34:04,430 - Recv: /TRASHE~1/501/CE3_CA~1.GCO 8310182
2020-11-23 17:34:04,432 - Recv: /TRASHE~1/501/CE3_3-~1.GCO 9842482
2020-11-23 17:34:04,434 - Recv: /TRASHE~1/501/CE3_TN~1.GCO 258417
2020-11-23 17:34:04,447 - Recv: End file list
2020-11-23 17:34:04,449 - Recv: ok
2020-11-23 17:34:04,458 - Send: M105
2020-11-23 17:34:04,505 - Recv: ok T:26.16 /0.00 B:25.82 /0.00 @:0 B@:0
2020-11-23 17:34:05,239 - Send: M105
2020-11-23 17:34:05,264 - Recv: ok T:26.16 /0.00 B:25.91 /0.00 @:0 B@:0
2020-11-23 17:34:06,188 - Send: M105
2020-11-23 17:34:06,230 - Recv: ok T:26.16 /0.00 B:25.91 /0.00 @:0 B@:0
2020-11-23 17:34:07,194 - Send: M105
2020-11-23 17:34:07,214 - Recv: ok T:26.14 /0.00 B:25.91 /0.00 @:0 B@:0
2020-11-23 17:34:08,196 - Send: M105
2020-11-23 17:34:08,207 - Recv: ok T:26.31 /0.00 B:25.91 /0.00 @:0 B@:0
2020-11-23 17:34:09,196 - Send: M105
2020-11-23 17:34:09,206 - Recv: ok T:26.25 /0.00 B:25.91 /0.00 @:0 B@:0
2020-11-23 17:34:10,197 - Send: M105

octoprint.log

2020-11-23 17:33:55,065 - octoprint.startup - INFO - ******************************************************************************
2020-11-23 17:33:55,068 - octoprint.startup - INFO - Starting OctoPrint 1.4.2
2020-11-23 17:33:55,070 - octoprint.startup - INFO - ******************************************************************************
2020-11-23 17:33:55,518 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2020-11-23 17:33:55,615 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: online
2020-11-23 17:33:55,615 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is working
2020-11-23 17:33:55,615 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is working
2020-11-23 17:33:55,635 - octoprint.startup - INFO - Blacklist processing done, adding 10 blacklisted plugin versions: roomtemp (any), GcodeEditor (0.1.1), GcodeEditor (0.2.0), GcodeEditor (0.2.1), GcodeEditor (0.2.2), GcodeEditor (0.2.3), GcodeEditor (0.2.4), GcodeEditor (0.2.5), GcodeEditor (0.2.6), GcodeEditor (0.2.8)
2020-11-23 17:33:55,692 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2020-11-23 17:33:57,328 - octoprint.plugins.octoprint.plugins.discovery - INFO - pybonjour is not installed, Zeroconf Discovery won't be available
2020-11-23 17:33:57,360 - octoprint.plugin.core - INFO - Found 19 plugin(s) providing 19 mixin implementations, 36 hook handlers
2020-11-23 17:33:57,578 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2020-11-23 17:33:57,588 - octoprint.server - INFO - Intermediary server started
2020-11-23 17:33:57,589 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2020-11-23 17:33:57,659 - octoprint.plugin.core - INFO - Found 19 plugin(s) providing 19 mixin implementations, 36 hook handlers
2020-11-23 17:33:57,692 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2020-11-23 17:33:58,131 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2020-11-23 17:33:58,135 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: "Need(method='role', value='plugin_action_command_notification_show')")
2020-11-23 17:33:58,136 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: "Need(method='role', value='plugin_action_command_notification_clear')")
2020-11-23 17:33:58,136 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: "Need(method='role', value='plugin_action_command_prompt_interact')")
2020-11-23 17:33:58,137 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2020-11-23 17:33:58,137 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: "Need(method='role', value='plugin_announcements_manage'), Need(method='role', value='plugin_announcements_read')")
2020-11-23 17:33:58,138 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2020-11-23 17:33:58,138 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2020-11-23 17:33:58,139 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2020-11-23 17:33:58,139 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2020-11-23 17:33:58,139 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2020-11-23 17:33:58,140 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2020-11-23 17:33:58,141 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: "Need(method='role', value='plugin_pluginmanager_install'), Need(method='role', value='plugin_pluginmanager_manage')")
2020-11-23 17:33:58,143 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2020-11-23 17:33:58,144 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2020-11-23 17:33:59,207 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2020-11-23 17:34:00,240 - octoprint.util.pip - INFO - Version of pip is 20.2.4
2020-11-23 17:34:00,242 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2020-11-23 17:34:00,253 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-11-23 17:34:00,332 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2020-11-23 17:34:00,341 - octoprint.plugin.core - INFO - Initialized 19 plugin implementation(s)
2020-11-23 17:34:00,354 - octoprint.plugin.core - INFO - 19 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
|  Bed Visualizer (1.0.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_bedlevelvisualizer
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  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 (2020.8.7) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2020.9.23) (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
|  Login UI (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/loginui
|  Pi Support Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/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
2020-11-23 17:34:00,370 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|      cores: 4
|      freq: 1400.0
|      ram: 903024640
|  os:
|      id: linux
|      platform: linux
|  plugins:
|      pi_support:
|          model: Raspberry Pi 3 Model B Plus Rev 1.3
|          octopi_version: 0.18.0
|  python:
|      pip: 20.2.4
|      version: 3.7.3
|      virtualenv: /home/pi/oprint
2020-11-23 17:34:00,387 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2020-11-23 17:34:00,419 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2020-11-23 17:34:01,264 - octoprint.server - INFO - Shutting down intermediary server...
2020-11-23 17:34:01,277 - octoprint.server - INFO - Intermediary server shut down
2020-11-23 17:34:01,281 - octoprint.events - INFO - Processing startup event, this is our first event
2020-11-23 17:34:01,281 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2020-11-23 17:34:01,282 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2020-11-23 17:34:01,285 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2020-11-23 17:34:01,310 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2020-11-23 17:34:01,349 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2020-11-23 17:34:02,862 - octoprint.server - INFO - Trying to connect to configured serial port /dev/ttyUSB0
2020-11-23 17:34:03,024 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2020-11-23 17:34:03,026 - octoprint.util.comm - INFO - Connecting to port /dev/ttyUSB0, baudrate 115200
2020-11-23 17:34:03,078 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2020-11-23 17:34:03,088 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2020-11-23 17:34:03,114 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2020-11-23 17:34:03,130 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-23 17:34:03,158 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2020-11-23 17:34:03,191 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-23 17:34:03,205 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2020-11-23 17:34:03,279 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-23 17:34:03,386 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin bugfix-2.0.x (Nov 18 2020"
2020-11-23 17:34:03,391 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2020-11-23 17:34:03,406 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2020-11-23 17:34:03,426 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2020-11-23 17:34:03,585 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2020-11-23 17:34:04,577 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:04,823 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2020-11-23 17:34:04,831 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2020-11-23 17:34:04,838 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-11-23 17:34:04,924 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 25.8GB. That is considered sufficient for updating.
2020-11-23 17:34:05,106 - octoprint.plugins.bedlevelvisualizer - INFO - OctoPrint-BedLevelVisualizer loaded!
2020-11-23 17:34:05,839 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://octopi.local/', 'path': '/', 'query_string': 'l10n=en'}
2020-11-23 17:34:06,380 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2020-11-23 17:34:08,180 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:10,488 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:10,609 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:13,075 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:13,178 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:15,672 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:15,852 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:17,232 - octoprint.server.preemptive_cache - INFO - ... done in 11.39s
2020-11-23 17:34:17,235 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://192.168.1.46/', 'path': '/', 'query_string': 'l10n=en'}
2020-11-23 17:34:17,623 - octoprint.server.preemptive_cache - INFO - ... done in 0.39s
2020-11-23 17:34:17,624 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://192.168.1.86/', 'path': '/', 'query_string': 'l10n=en'}
2020-11-23 17:34:17,722 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:17,788 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:18,070 - octoprint.server.preemptive_cache - INFO - ... done in 0.45s
2020-11-23 17:34:19,720 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:19,789 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:22,732 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:22,802 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22
2020-11-23 17:34:25,576 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.22
2020-11-23 17:34:25,648 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.22

Additional information about your setup

OctoPrint version: 1.4.2

OctoPi version: 0.18.0 and 0.17.0

printer: Ender 3 v2

firmware: Marlin bugfix-2.0.x

browser: chrome 86.0.4240.198

operating system: mac os 10.15.7

Charlie_Powell · November 23, 2020, 5:49pm

I'm going to assume that by 'the UI stays stuck' you mean that the disconnect button does not work - since that panel looks like it is connected to me.

The serial logs also indicate that it is connecting just fine.

If you are reporting a UI issue, it helps to look in the browser error console. On Chrome/Windows, this can be accessed with ctrl - shift - i on the keyboard, or right click, press 'inspect' and switch to the console.

Everything seems normal from the picture & provided logs (and can I say thank you for including them straight away, properly formatted. Beautiful), maybe the issue is that the messages are not making their way to the UI on the websocket.

r3ticuli · November 23, 2020, 9:16pm

Thanks for the reply Charlie. I dont see any errors in the console :

Starting dependency resolution...
packed_core.js?3fb354c1:860 ... dependency resolution done
packed_core.js?3fb354c1:883 Initial application setup done, connecting to server...
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:883 Finalizing application startup
packed_core.js?3fb354c1:866 Going to bind 38 view models...
packed_core.js?3fb354c1:876 Did not bind view model BackupViewModel to target #wizard_plugin_backup since it does not exist
packed_core.js?3fb354c1:876 Did not bind view model UsageViewModel to target #wizard_plugin_tracking since it does not exist
packed_core.js?3fb354c1:876 Did not bind view model SoftwareUpdateViewModel to target #softwareupdate_confirmation_dialog since it does not exist
packed_core.js?3fb354c1:876 Did not bind view model SoftwareUpdateViewModel to target #wizard_plugin_softwareupdate since it does not exist
packed_core.js?3fb354c1:876 Did not bind view model bedlevelvisualizerViewModel to target #wizard_plugin_bedlevelvisualizer since it does not exist
packed_core.js?3fb354c1:158 User logged in
packed_core.js?3fb354c1:881 ... binding done
packed_core.js?3fb354c1:881 Application startup complete
packed_plugins.js?86c24c7e:6089 Array(4)
packed_plugins.js?86c24c7e:6224 Back [um]:-30
packed_plugins.js?86c24c7e:6225 Front [um]:74
packed_plugins.js?86c24c7e:6226 Left [um]:-3
packed_plugins.js?86c24c7e:6227 Right [um]:45
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server

And you are correct - the disconnect button doesnt work and I am unable to queue anything for printing, i.e. this panel never changes when I click a STL to print :

This is very confusing, because as you mentioned the logs reflect everything is working as expected. . .

Charlie_Powell · November 23, 2020, 9:23pm

There may not be any errors, but what that log does tell me is that the connection drops frequently - some kind of network issue. I would see if you can get a more stable connection to the Pi - maybe using a wired connection at one end (typically the Pi is worse off, although I appreciate this may be a little impractical)

The only tree I can find to bark up is the network one, since everything else seems to be reporting no issues.

r3ticuli · November 24, 2020, 6:24pm

Interesting. Can you note where in the logs the connection is struggling? I will look at my network and see if I can debug anything there.

r3ticuli · November 24, 2020, 8:21pm

I got a new error today :

2020-11-24 20:19:13,823 - Recv: echo:busy: processing
2020-11-24 20:19:14,821 - Recv:  T:27.61 /0.00 B:48.47 /50.00 @:0 B@:127 W:?
2020-11-24 20:19:15,819 - Recv:  T:27.50 /0.00 B:48.68 /50.00 @:0 B@:127 W:?
2020-11-24 20:19:15,822 - Recv: echo:busy: processing
2020-11-24 20:19:16,819 - Recv:  T:27.61 /0.00 B:48.95 /50.00 @:0 B@:127 W:?
2020-11-24 20:19:17,084 - Unexpected error while reading serial port, please consult octoprint.log for details: SerialException: 'read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:2916
2020-11-24 20:19:17,086 - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2020-11-24 20:19:17,110 - Changing monitoring state from "Cancelling" to "Offline (Error: SerialException: 'read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:2916)"

I am investigating this link to see what i can do.

EDIT : I investiaged the link, and bullets 1-5 were not relevant to me. I have ordered a cable and will see if that makes a difference. It could be the case that all of my usb cables are busted for some reason...

foosel · November 25, 2020, 9:19am

packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server
packed_core.js?3fb354c1:707 Triggering connect on all view models
packed_core.js?3fb354c1:709 Server (re)connect processed
packed_core.js?3fb354c1:702 Connected to the server

This indicates the browser is constantly losing connection to the server, regaining it, losing it again, regaining it, ...

r3ticuli · November 25, 2020, 3:55pm

Ohhh!! Hmmm. Is this something you've seen before? I have tried various browsers and the issue persists. It must be something at the network level.

I'm using a unifi AP, and I don't see any issues. Should I try connecting a ethernet cable to my pi?

foosel · November 25, 2020, 4:02pm

Would be worth a shot. I run unifi gear here myself (AC-Lite, USG, various switches) and never had issues.

r3ticuli · November 26, 2020, 5:35pm

Thanks for your help everyone - I found that the webclient works beautifully on a windows pc. The connectivity issues we were seeing were experienced on a macbook pro. I am not sure why that is the case, but it seems the issue turned out to be the client computer all along!

Esmith289 · November 28, 2020, 6:09am

So here is a thought. The raspi is powering main board thru the USB cable which maybe causing an under voltage condition which could affect the USB port. One else on the forum had previously pointed this out. The fixed as pointed is cover the 5v pin on the USB cable. Doing this significantly improved the reliability of my connection. Just a thought.

r3ticuli · November 28, 2020, 6:53am

Thanks for the insight Esmith289. I mentioned above that I did try that, and it did not help. Thank you nonetheless.