Printer Froze - did Pushover Plugin cause this?

Get Help
1

What is the problem?

Printer froze 20 minutes in to print. Temperatures remained on. OP temp graph shows no abnomalies. Steppers remained fixed for more than 30 seconds, and then released.

System been running flawless for over a year.
Upgraded to OP 1.4.2 and Python 3, around 2 weeks ago. No print issues since then.
Around same time installed the Pushover plugin.

This morning our internet connection bandwidth allocation was exhausted, so we suddenly had no internet connection.

The print appears to have stopped 20 minutes in to the print.

Pushover plugin options in OP was set to send a text & pic Pushover notification every 20 minutes.

I this just a coincidence, or is it likely ( or even a known issue ) that the Pushover plugin ( or whatever part of the Pi OS controls the transmission of the Pushover notices out to the internet ), could freeze the Pi if it can not connect to the internet when trying to send a message ?

Purchased more bandwidth, Restarted the print, and already past the point where it previously stopped, so the gCode is good.

What did you already try to solve it?

Reset system. Restarted print.

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

No. did not try safe mode.

Complete Logs

2020-09-30 06:57:28,185 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: online
2020-09-30 06:57:28,200 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is working
2020-09-30 06:57:28,236 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is working
2020-09-30 06:57:33,309 - 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-09-30 06:57:35,488 - 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-09-30 06:58:13,941 - octoprint.plugins.octoprint.plugins.discovery - INFO - pybonjour is not installed, Zeroconf Discovery won't be available
2020-09-30 06:58:14,581 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 41 hook handlers
2020-09-30 06:58:19,411 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2020-09-30 06:58:19,879 - octoprint.server - INFO - Intermediary server started
2020-09-30 06:58:19,882 - 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-09-30 06:58:21,572 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 41 hook handlers
2020-09-30 06:58:22,277 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2020-09-30 06:58:30,971 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2020-09-30 06:58:31,752 - 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-09-30 06:58:31,779 - 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-09-30 06:58:31,810 - 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-09-30 06:58:31,832 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2020-09-30 06:58:31,861 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: "Need(method='role', value='plugin_announcements_read'), Need(method='role', value='plugin_announcements_manage')")
2020-09-30 06:58:31,889 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2020-09-30 06:58:31,921 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2020-09-30 06:58:31,932 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2020-09-30 06:58:31,971 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2020-09-30 06:58:31,996 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2020-09-30 06:58:32,015 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2020-09-30 06:58:32,049 - 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')")
2020-09-30 06:58:32,055 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2020-09-30 06:58:32,077 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2020-09-30 06:58:49,192 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 06:58:56,999 - octoprint.util.pip - INFO - Version of pip is 20.2.3
2020-09-30 06:58:57,054 - 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-09-30 06:58:57,056 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-09-30 06:58:58,718 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2020-09-30 06:58:59,003 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s)
2020-09-30 06:58:59,189 - octoprint.plugin.core - INFO - 24 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
|  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.6.22) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.7.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
|  Floating Navbar (0.3.4) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_floatingnavbar
|  Fullscreen Plugin (0.0.5) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_fullscreen
|  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
|  M117NavBar (0.1.1) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_M117NavBar
|  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
|  Pushover (0.3.8) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pushover
|  Sidebar Temp Graph (0.1.6) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_sidebartempgraph
|  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-09-30 06:58:59,480 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|      cores: 1
|      freq: 700.0
|      ram: 121413632
|  os:
|      id: linux
|      platform: linux
|  plugins:
|      pi_support:
|          model: Raspberry Pi Model B Rev 1
|          octopi_version: 0.17.0
|  python:
|      pip: 20.2.3
|      version: 3.7.3
|      virtualenv: /home/pi/oprint
2020-09-30 06:58:59,702 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2020-09-30 06:58:59,846 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2020-09-30 06:59:08,132 - octoprint.server - INFO - Shutting down intermediary server...
2020-09-30 06:59:08,273 - octoprint.server - INFO - Intermediary server shut down
2020-09-30 06:59:08,331 - octoprint.events - INFO - Processing startup event, this is our first event
2020-09-30 06:59:08,352 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2020-09-30 06:59:08,376 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2020-09-30 06:59:08,455 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2020-09-30 06:59:08,530 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2020-09-30 06:59:08,947 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2020-09-30 06:59:09,588 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2020-09-30 06:59:09,835 - octoprint.filemanager.analysis - INFO - Starting analysis of local:i3_final_body.gcode
2020-09-30 06:59:09,856 - octoprint.filemanager - INFO - Added 1 items from storage type "local" to analysis queue
2020-09-30 06:59:09,888 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.01 --throttle-lines=100 /home/pi/.octoprint/uploads/i3_final_body.gcode
2020-09-30 06:59:16,012 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 5.9s
2020-09-30 06:59:16,561 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2020-09-30 06:59:31,990 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 3.3s
2020-09-30 06:59:38,103 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 3.4s
2020-09-30 06:59:43,676 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 06:59:43,815 - 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-09-30 06:59:43,817 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-09-30 06:59:44,094 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 4.6GB. That is considered sufficient for updating.
2020-09-30 06:59:49,602 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 5.2s
2020-09-30 07:00:14,152 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 1.1e+01s
2020-09-30 07:01:09,193 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 07:01:09,201 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 07:01:09,162 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 07:01:09,156 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 07:01:12,362 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2020-09-30 07:01:27,519 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2020-09-30 07:02:30,511 - 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-09-30 07:02:30,535 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-09-30 07:02:38,654 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2020-09-30 07:02:41,713 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 284}
2020-09-30 07:02:42,868 - octoprint.plugins.pushover - INFO - Connected to Pushover
2020-09-30 07:02:44,000 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'version': '1.4.2', 'os': 'linux', 'python': '3.7.3', 'pip': '20.2.3', 'cores': 1, 'freq': 700.0, 'ram': 121413632, 'pi_model': 'Raspberry Pi Model B Rev 1', 'octopi_version': '0.17.0', 'plugins': 'sidebartempgraph:0.1.6,pushover:0.3.8,m117navbar:0.1.1,fullscreen:0.0.5,floatingnavbar:0.3.4,firmwareupdater:1.7.0'}
2020-09-30 07:02:46,497 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'version': '1.4.2', 'os': 'linux', 'python': '3.7.3', 'pip': '20.2.3', 'cores': 1, 'freq': 700.0, 'ram': 121413632, 'pi_model': 'Raspberry Pi Model B Rev 1', 'octopi_version': '0.17.0'}
2020-09-30 07:02:49,899 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://192.168.1.113/', 'path': '/', 'query_string': 'l10n=en'}
2020-09-30 07:06:54,436 - octoprint.server.preemptive_cache - INFO - ... done in 244.56s
2020-09-30 07:13:19,458 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-09-30 07:17:41,068 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 1184}
2020-09-30 07:28:19,490 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-09-30 07:41:26,420 - octoprint.server.util.flask - INFO - Passively logging in user DaveOB from ::ffff:192.168.1.91
2020-09-30 07:41:26,520 - octoprint.access.users - INFO - Logged in user: DaveOB
2020-09-30 07:41:34,415 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.91
2020-09-30 07:41:36,336 - octoprint.events - INFO - Executing a system command
2020-09-30 07:41:37,009 - octoprint.server.util.flask - INFO - Passively logging in user DaveOB from ::ffff:192.168.1.91
2020-09-30 07:41:37,027 - octoprint.access.users - INFO - Logged in user: DaveOB
2020-09-30 07:42:18,535 - octoprint.server.util.sockjs - INFO - User DaveOB logged in on the socket from client ::ffff:192.168.1.91
2020-09-30 07:42:22,292 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2020-09-30 07:42:22,580 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 115200
2020-09-30 07:42:22,742 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2020-09-30 07:42:23,017 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-09-30 07:42:32,311 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-09-30 07:42:36,315 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-09-30 07:42:36,367 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2020-09-30 07:42:36,545 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-09-30 07:42:36,578 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2020-09-30 07:42:36,676 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2020-09-30 07:42:36,731 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin V1; Sprinter/grbl mashup for gen6"
2020-09-30 07:43:19,502 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-09-30 07:45:18,376 - octoprint.filemanager.analysis - INFO - Starting analysis of local:i3_part_head.gcode
2020-09-30 07:45:18,438 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/i3_part_head.gcode
2020-09-30 07:46:12,404 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: i3_part_head.gcode, owner: DaveOB, user: DaveOB
2020-09-30 07:46:12,694 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-09-30 07:46:12,794 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: i3_part_head.gcode, owner: DaveOB, user: DaveOB
2020-09-30 07:46:12,970 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-09-30 07:46:13,106 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-09-30 07:58:19,522 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-09-30 08:06:15,079 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2020-09-30 08:06:45,134 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2020-09-30 08:07:02,356 - octoprint.util.comm - WARNING - Printer sent 'start' while printing. External reset? Aborting job since printer lost state.
2020-09-30 08:07:02,435 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling"
2020-09-30 08:07:02,454 - octoprint.filemanager.analysis - INFO - Starting analysis of local:i3_part_head.gcode
2020-09-30 08:07:02,479 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/i3_part_head.gcode
2020-09-30 08:07:02,764 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: i3_part_head.gcode, owner: DaveOB, user: None
2020-09-30 08:07:29,182 - octoprint.server.util.flask - INFO - Passively logging in user DaveOB from ::ffff:192.168.1.91
2020-09-30 08:07:29,203 - octoprint.access.users - INFO - Logged in user: DaveOB
2020-09-30 08:07:36,409 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2020-09-30 08:07:36,617 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.91
2020-09-30 08:07:41,255 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.91
2020-09-30 08:07:41,763 - octoprint.server.util.flask - INFO - Passively logging in user DaveOB from ::ffff:192.168.1.91
2020-09-30 08:07:41,796 - octoprint.access.users - INFO - Logged in user: DaveOB
2020-09-30 08:08:06,611 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2020-09-30 08:08:17,360 - octoprint.server.util.sockjs - INFO - User DaveOB logged in on the socket from client ::ffff:192.168.1.91
2020-09-30 08:08:36,731 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2020-09-30 08:08:37,864 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.91

Additional information about your setup

OP 1.4.2 Pi B+ Ethernet connected, printer reprap, Arduino 2560, Marlin

2

just to clarify ( if it makes any difference ).

Pi is connected to ethernet hub via LAN cable.
Network hub and router were working.
The internet connection was blocked at the ISP level.

3

I found this in your log.

So 20 minutes after starting the print the printer does not respond any more to OctoPrint.
Usually OctoPrint checks the connectivity to the printer more than two times every 15 seconds.
Before the 3rd connectivity test the printer initiated a start.
As a result, OctoPrint cancelled the print.

I assume the issue is with the firmware.
What Marlin version are you running?

4

If I think I understand the log ( not 100% certain ) :

07:46:13 print started
07:58:19 heartbeat ( i assume this is a periodic check )
08:06:15 comms could not be established
08:07:02 was when I reset the Arduino on the Printer

Seems odd that the comms failed within 2 seconds of the 20 minute after print started.

I still think that comms on the Pi were 'locked up' by the Pi trying to communicate online with the Pushover service.

5

If there would be communication problems with the internet, they would appear in the log too.

At 08:06:15 and 30 seconds later (I have to correct my 15 seconds from my last post) at 08:06:45 OctoPrint actively tries to connect the printer with no result. The serial.log is more detailed in this case, but I assume the serial logging was not enabled at the time.

If there is a possibility to reproduce this issue with serial logging, it would give more data to find out what is happening.

6

Thanks Ewald

Serial logging was not enabled unfortunately.

Since I have already purchased additional bandwidth from our ISP, I would only be able to recreate these exact circumstances again towards the end of October, when we will likely again run out of bandwidth.

I will get the serial logging enabled before that point.

So either the printer will fail again before that point ( indicating an Arduino hardware comms failure ), or it will fail again at the exact time that the Pushover plugin is trying to send a message out.

7

I don't see how the pusover plugin could be causing your printer to go AWOL. I think you are barking up the wrong tree here. You should rather check your printer's firmware and cabling and make sure your Pi is receiving enough power and not getting throttled too.

If you'd shared complete logs like you were asked to we could rule that out, so it's just guesswork.

8

ok. Yes, I have been known to bark at trees before. It just seemed to much of a coincidence that it happened at the 20 minute time.

When my current print is completed, I will look for all the log files. Do you want previous days' logs also, or only from today ?

9

The more the merrier.

10

i think it is time that I can now bark louder at this tree again.

Since the first / previous time of this problem, I have done the following :

  1. checked all printer cables and CAT5 cable from hub to Pi
  2. replace PiB+ with Pi 3B+

I have had no problems printing almost daily since then.

Todays sequence of events :
8:30 am started new print.
Pushover sends notifications to say temperature reached, etc.
Pushover notification is set for every 30 minutes.
Sometime after 8:30am, we ran out of bandwidth, and the ISP blocked internet access.
The printer was still connected to the hub / router, and the router still had an internet connection, but the ISP blocks all traffic when the bandwidth allocation for the month is used.
At approx. 9am the printer stops. Totally unresponsive. Try to reconnect to Octoprint from my browser, and can not connect.
Reset the printer via the Ramps reset button.
Still can not connect to Octoprint from my browser ( LAN, not wifi ).
Used an alternate device to purchase additional bandwidth from the ISP.
Internet access / traffic re-enabled and working.
Octoprint still not accepting connection.
Used Putty to connect to the Pi and reset.
Once reset, I was able to connect to Octoprint / printer again and start the print again.

It is, imho, impossible that it is a coincidence for this same thing to happen, twice, one month apart, both times at the exact time that the Pushover plugin is trying to send a Pushover notification, when the Pi is connected to the router, and can see the internet connection, but the ISP is blocking traffic.

Octoprint 1.4.2
Python 3.7.3
OctoPi 0.17.0

Attach zip with log files.

octoprint logs.zip (238.2 KB)