On startup, Octoprint (safe mode) immediately disconnects from Prusa i3 MK3S

What is the problem?

When I either start up OctoPrint or press its "Connect" button, the state transitions as follows.
Offline
Detecting serial connection
Operational
Offline

What did you already try to solve it?

Restart, power cycle.
Updated RPi4.
In Protocol fine tuning, set Wait for start on connect.

Have you tried running in safe mode?

Yes.

Did running in safe mode solve the problem?

No.

Complete Logs

Octoprint and serial logs follow.

2021-03-06 17:10:37,528 - octoprint.startup - INFO - ******************************************************************************
2021-03-06 17:10:37,529 - octoprint.startup - INFO - Starting OctoPrint 1.5.3
2021-03-06 17:10:37,530 - octoprint.startup - INFO - Starting in SAFE MODE. Third party plugins will be disabled!
2021-03-06 17:10:37,530 - octoprint.startup - INFO - Reason for safe mode: setting in config.yaml
2021-03-06 17:10:37,530 - octoprint.startup - INFO - ******************************************************************************
2021-03-06 17:10:37,882 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2021-03-06 17:10:37,983 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: online
2021-03-06 17:10:37,983 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is working
2021-03-06 17:10:37,983 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is working
2021-03-06 17:10:38,591 - octoprint.startup - INFO - Blacklist processing done, adding 12 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), gcodeleveling (0.1.0), gcodeleveling (0.1.1)
2021-03-06 17:10:38,630 - 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...
2021-03-06 17:10:39,228 - octoprint.plugin.core - INFO - Plugin Anonymous Usage Tracking is disabled.
2021-03-06 17:10:39,234 - octoprint.plugin.core - INFO - Plugin Error Tracking is disabled.
2021-03-06 17:10:39,638 - octoprint.plugin.core - WARNING - Plugin BetterHeaterTimeout (1.2.0) is not compatible to Python 3.7.3 (compatibility string: >=2.7,<3).
2021-03-06 17:10:39,719 - octoprint.startup - INFO - Added settings overlay from plugin firmware_check
2021-03-06 17:10:39,720 - octoprint.plugin.core - INFO - Found 33 plugin(s) providing 15 mixin implementations, 34 hook handlers
2021-03-06 17:10:40,067 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2021-03-06 17:10:40,074 - octoprint.server - INFO - Intermediary server started
2021-03-06 17:10:40,096 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2021-03-06 17:10:40,512 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2021-03-06 17:10:40,514 - 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')")
2021-03-06 17:10:40,515 - 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')")
2021-03-06 17:10:40,515 - 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')")
2021-03-06 17:10:40,515 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2021-03-06 17:10:40,516 - 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')")
2021-03-06 17:10:40,516 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2021-03-06 17:10:40,516 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2021-03-06 17:10:40,517 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2021-03-06 17:10:40,517 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2021-03-06 17:10:40,517 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2021-03-06 17:10:40,518 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2021-03-06 17:10:40,519 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: "Need(method='role', value='plugin_pluginmanager_manage'), Need(method='role', value='plugin_pluginmanager_install')")
2021-03-06 17:10:40,519 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2021-03-06 17:10:40,519 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2021-03-06 17:10:40,521 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CONFIGURE (needs: "Need(method='role', value='plugin_softwareupdate_configure')")
2021-03-06 17:10:41,216 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2021-03-06 17:10:41,825 - octoprint.util.pip - INFO - Version of pip is 20.2.3
2021-03-06 17:10:41,827 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2021-03-06 17:10:41,827 - octoprint.util.pip - INFO - ==> pip ok -> yes
2021-03-06 17:10:41,986 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2021-03-06 17:10:41,997 - octoprint.plugin.core - INFO - Initialized 15 plugin implementation(s)
2021-03-06 17:10:42,007 - octoprint.plugin.core - INFO - 33 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
| !Autoselect Plugin (0.3.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_autoselect
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
| !Bed Visualizer (1.0.1) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_bedlevelvisualizer
| *BetterHeaterTimeout (1.2.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_BetterHeaterTimeout
|  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
| !DisplayZ (0.2.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_displayz
| !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.2.4) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
| !Firmware Updater (1.9.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
| !Fullscreen Plugin (0.0.6) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_fullscreen
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
| !ipOnConnect (0.2.4) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_ipOnConnect
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
| !M73 Progress Plugin (0.2.1) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_m73progress
| !Navbar Temperature Plugin (0.14) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_navbartemp
|  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
| !Preheat Button (0.6.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_preheat
| !Prusa Leveling Guide (1.0.17) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_PrusaLevelingGuide
| !Simple Emergency Stop (1.0.4) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_simpleemergencystop
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
| !Tab Order (0.5.12) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_taborder
| !Terminal Commands Extended (0.1.6) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_terminalcommandsextended
| !Themeify (1.2.2) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_themeify
| !TP-Link Smartplug (0.9.26) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_tplinksmartplug
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2021-03-06 17:10:42,031 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|      cores: 4
|      freq: 1500.0
|      ram: 3925282816
|  os:
|      bits: 64
|      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.2.3
|      version: 3.7.3
|      virtualenv: /home/pi/oprint
2021-03-06 17:10:42,046 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2021-03-06 17:10:42,074 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2021-03-06 17:10:42,535 - octoprint.server - INFO - Shutting down intermediary server...
2021-03-06 17:10:42,985 - octoprint.server - INFO - Intermediary server shut down
2021-03-06 17:10:42,986 - octoprint.events - INFO - Processing startup event, this is our first event
2021-03-06 17:10:42,987 - octoprint.events - INFO - Adding 2 events to queue that were held back before startup event
2021-03-06 17:10:42,987 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2021-03-06 17:10:42,992 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2021-03-06 17:10:43,002 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2021-03-06 17:10:43,030 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2021-03-06 17:10:43,039 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2021-03-06 17:10:44,089 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2021-03-06 17:10:44,112 - octoprint.server - INFO - Trying to connect to configured serial port None
2021-03-06 17:10:44,171 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-03-06 17:10:44,178 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2021-03-06 17:10:44,182 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2021-03-06 17:10:44,200 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@115200
2021-03-06 17:10:44,201 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 115200
2021-03-06 17:10:44,201 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 115200
2021-03-06 17:10:44,218 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-03-06 17:10:44,220 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-03-06 17:10:44,999 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "Octoprint"._http._tcp.local.' for _http._tcp.local.
2021-03-06 17:10:45,263 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-03-06 17:10:45,276 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-03-06 17:10:45,809 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "Octoprint"._octoprint._tcp.local.' for _octoprint._tcp.local.
2021-03-06 17:10:45,812 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "Octoprint" for SSDP
2021-03-06 17:10:45,832 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2021-03-06 17:10:45,833 - octoprint.server - INFO - Server started successfully in safe mode as requested from config, removing flag
2021-03-06 17:10:46,190 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.7
2021-03-06 17:10:46,263 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2021-03-06 17:10:46,581 - octoprint.server.util.flask - INFO - Passively logging in user Adam from ::ffff:192.168.0.7
2021-03-06 17:10:46,582 - octoprint.access.users - INFO - Logged in user: Adam
2021-03-06 17:10:46,906 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2021-03-06 17:10:46,907 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2021-03-06 17:10:46,907 - octoprint.util.pip - INFO - ==> pip ok -> yes
2021-03-06 17:10:46,958 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 16.6GB. That is considered sufficient for updating.
2021-03-06 17:10:47,285 - octoprint.util.comm - INFO - Communication timeout while idle, trying to trigger response from printer.
2021-03-06 17:10:47,751 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2021-03-06 17:10:47,900 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://192.168.0.19/', 'path': '/', 'query_string': 'l10n=en'}
2021-03-06 17:10:49,296 - octoprint.util.comm - INFO - Communication timeout while idle, trying to trigger response from printer.
2021-03-06 17:10:51,309 - octoprint.util.comm - INFO - No response from printer after 3 consecutive communication timeouts, considering it dead.
2021-03-06 17:10:51,324 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2021-03-06 17:10:51,327 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2021-03-06 17:10:51,399 - octoprint.server.util.flask - INFO - Passively logging in user Adam from ::ffff:192.168.0.7
2021-03-06 17:10:51,400 - octoprint.access.users - INFO - Logged in user: Adam
2021-03-06 17:10:59,165 - octoprint.server.preemptive_cache - INFO - ... done in 11.27s
2021-03-06 17:10:59,184 - octoprint.server.util.sockjs - INFO - User Adam logged in on the socket from client ::ffff:192.168.0.7
2021-03-06 17:10:59,197 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.7
2021-03-06 17:10:59,468 - octoprint.server.util.flask - INFO - Passively logging in user Adam from ::ffff:192.168.0.7
2021-03-06 17:10:59,468 - octoprint.access.users - INFO - Logged in user: Adam
2021-03-06 17:10:59,994 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.7
2021-03-06 17:11:00,115 - octoprint.server.util.flask - INFO - Passively logging in user Adam from ::ffff:192.168.0.7
2021-03-06 17:11:00,115 - octoprint.access.users - INFO - Logged in user: Adam
2021-03-06 17:11:01,945 - octoprint.server.util.sockjs - INFO - User Adam logged in on the socket from client ::ffff:192.168.0.7
2021-03-06 17:11:24,583 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.7




2021-03-06 17:10:44,168 - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-03-06 17:10:44,200 - Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@115200
2021-03-06 17:10:44,201 - Trying port /dev/ttyACM0, baudrate 115200
2021-03-06 17:10:44,201 - Connecting to port /dev/ttyACM0, baudrate 115200
2021-03-06 17:10:44,218 - Handshake attempt #1 with timeout 2.0s
2021-03-06 17:10:44,219 - Connected to: Serial<id=0x7f7c1f65c0, open=True>(port='/dev/ttyACM0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=2.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
2021-03-06 17:10:44,221 - Send: N0 M110 N0*125
2021-03-06 17:10:45,261 - Recv: start
2021-03-06 17:10:45,263 - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-03-06 17:10:45,276 - Send: N0 M110 N0*125
2021-03-06 17:10:47,286 - Communication timeout while idle, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2021-03-06 17:10:47,287 - Send: N1 M115*39
2021-03-06 17:10:49,297 - Communication timeout while idle, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2021-03-06 17:10:49,305 - Send: N2 M21*18
2021-03-06 17:10:51,310 - No response from printer after 3 consecutive communication timeouts, considering it dead. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2021-03-06 17:10:51,324 - Changing monitoring state from "Operational" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2021-03-06 17:10:51,325 - Connection closed, closing down monitor

Additional information about your setup

OctoPrint 1.5.3 Python 3.7.3 OctoPi 0.18.0 Prusa i3 MK3S (3.9.3-3556)

Hello @AdamLD !

In this case, the serial.log comes in quite handy. You may have to enable this logging before.
And please attach logs as files.

To your issue: Use a USB cable as short and as best quality as possible.

You may check the SD card in the printer. It may be faulty.

2 Likes

Isn't there an option that can be changed from the Prusa LCD panel about which serial port to use (or something like that)? It looks to me like the serial hardware is connecting but the firmware in the Prusa is ignoring it.

1 Like

That would be this one:

1 Like

You are correct, and thank you for posting! I'm tagging Charlie Powell's response as the "solution" only because it links to the full explanation.
Thanks for helping make the forum great.
Adam

Thank you Charlie; I had searched the FAQ but not thoroughly enough. I'm going to look into adding some keywords to help others.
Adam

1 Like