Printer disconnects at same spot in gcode file

What is the problem?

When trying to print a particular gcode file the printer will disconnect every time at the same spot. I've done longer prints without issue (this failure occurs relatively early) and the same file is now currently printing fine from a usb stick (past the part where it will cause the printer to disconnect from OctoPrint if I try to print via OctoPrint).

What did you already try to solve it?

Upped the timeout,
Updated the raspberry pi's firmware (it's a 3B+),
Lowered the baud rate,

Logs (octoprint.log, serial.log or output on terminal tab at a minimum, browser error console if UI issue ... no logs, no support!)

Here is the tail end of serial.log

2019-11-13 15:44:34,060 - Recv: ok
2019-11-13 15:44:34,067 - Send: N810 G1 X221.962 Y118.192 E108.3839*93
2019-11-13 15:44:34,322 - Recv: ok
2019-11-13 15:44:34,329 - Send: N811 G1 X222.192 Y117.857 E108.3961*91
2019-11-13 15:44:34,517 - Recv: ok
2019-11-13 15:44:34,524 - Send: N812 G1 X221.355 Y117.020 E108.4316*87
2019-11-13 15:44:34,817 - Recv: ok
2019-11-13 15:44:34,825 - Send: N813 G92 E0.0000*99
2019-11-13 15:44:34,983 - Recv: ok
2019-11-13 15:44:35,040 - Send: N814 G1 E-1.0000 F2400*18
2019-11-13 15:44:35,342 - Recv: ok
2019-11-13 15:44:35,393 - Send: N815 M106 S255*105
2019-11-13 15:45:05,364 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:45:05,379 - Send: N816 M105*40
2019-11-13 15:45:35,398 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:45:35,405 - Send: N817 M105*41
2019-11-13 15:46:05,433 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:46:05,444 - Send: N818 M105*38
2019-11-13 15:46:35,467 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:46:35,478 - Send: N819 M105*39
2019-11-13 15:47:05,526 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:47:05,533 - Send: N820 M105*45
2019-11-13 15:47:35,565 - No response from printer after 6 consecutive communication timeouts, considering it dead. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2019-11-13 15:47:39,518 - Changing monitoring state from "Printing" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2019-11-13 15:47:39,544 - Connection closed, closing down monitor

Here is the tail octoprint.log

2019-11-13 15:42:54,163 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 15:42:54,171 - octoprint.plugins.DisplayLayerProgress - INFO - File selected. Determining number of layers.
2019-11-13 15:43:02,206 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2019-11-13 15:43:02,263 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 15:43:02,277 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 15:43:02,329 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2019-11-13 15:43:02,755 - octoprint.plugins.DisplayLayerProgress - INFO - Printing started. Detailed progress started.{'origin': 'local', 'name': u'flintvasea.gcode', 'file': u'/home/pi/.octoprint/uploads/flintvasea.gcode', 'owner': 'barrett', 'path': u'flintvasea.gcode', 'user': 'barrett', 'size': 2962393L, 'filename': u'flintvasea.gcode'}
2019-11-13 15:43:03,468 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '2cbc52d6a4cca403c94bc14fe87d216e24c333bb'}
2019-11-13 15:43:03,772 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:03] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:11,092 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:15,478 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:15] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:18,917 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:18] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:27,521 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:27] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:31,199 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:32,509 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:32] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:39,440 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:39] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:51,491 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:51,543 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:02,942 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:02] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:11,254 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:14,776 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:14] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:26,723 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:26] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:31,316 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:38,207 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:38] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:50,029 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:44:51,351 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:44:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:01,861 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:01] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:05,361 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:45:11,387 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:13,705 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:13] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:25,779 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:31,414 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:35,396 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:45:37,615 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:37] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:49,476 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:49] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:45:51,443 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:45:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:01,318 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:01] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:05,430 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:46:11,463 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:12,755 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:12] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:24,564 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:24] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:31,504 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:35,465 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:46:36,534 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:36] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:48,277 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:51,564 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:46:59,649 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:46:59] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:05,517 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:47:11,476 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:11,609 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:23,352 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:23] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:31,631 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:34,822 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:34] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:35,564 - octoprint.util.comm - INFO - No response from printer after 6 consecutive communication timeouts, considering it dead.
2019-11-13 15:47:35,871 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:35] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:36,296 - octoprint.plugins.tracking - INFO - Sent tracking event commerror_timeout, payload: {'commerror_text': 'Too many consecutive timeouts, printer still connected and alive?'}
2019-11-13 15:47:39,519 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2019-11-13 15:47:40,267 - octoprint.plugins.DisplayLayerProgress - INFO - Printing stopped. Detailed progress stopped.
2019-11-13 15:47:40,449 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:40] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:41,106 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'error', 'commerror_text': 'Too many consecutive timeouts, printer still connected and alive?', 'file': '2cbc52d6a4cca403c94bc14fe87d216e24c333bb', 'elapsed': 277}
2019-11-13 15:47:41,179 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:41] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:47:51,693 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:47:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:48:11,738 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:48:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:48:31,790 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:48:31] "GET /?action=snapshot HTTP/1.1" 200 -

I can attach full logs if need be, but I didn't see much and the one log is over 10mb

Additional information about your setup (OctoPrint version, OctoPi version, printer, firmware, browser, operating system, ... as much data as possible)

OctoPrint 1.3.12 running on OctoPi 0.16.0 on a pi 3B+ (from a CanaKit with the included power adapter)

CraftBot 3 Printer

I'm VERY new to 3d printing, sorry if excluding something useful and thank you in advance.

2019-11-13 15:44:35,393 - Send: N815 M106 S255*105

A wild guess: the (part cooling) fan lowers the bed or nozzle temperature that much, that the firmware tries to recover it but can't and the communication timeout triggers before the thermal runaway protection.

1 Like

Does that mean my timeout just needs to be set longer in OctoPrint? It's currently printing that same exact file (that failed in that same spot a dozen times when sent via OctoPrint) via a USB stick in the printer.

Like is the issue that it cooled it too much, and is taking longer than the timeout to heat back up so OctoPrint is giving up?

I'm VERY new to 3D printing, and this is the second gcode I've made that errors in only OctoPrint (previous one I fixed by rotating the model in the slicer and that fixed the issue, I didn't try that this time as I've become a bit more familiar with the system)

I would rather don't set the fan to maximum speed. Try 75% or 50% in the slicer settings.
It would be a bit more easy if you would have sent the full log, because at the start the first settings for the print are made.

2 Likes

Here's more of the log (should be starting in the middle of the night during a successful print). The snapshots are really spamming the log, so I tried to trim some out.

2019-11-13 14:45:46,745 - octoprint.plugins.pluginmanager - INFO - Installing plugin from https://github.com/FormerLurker/Octolapse/archive/v0.3.4.zip
2019-11-13 14:45:55,957 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:45:55] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:46:03,808 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 14:46:05,159 - octoprint.plugin.core - INFO - Found 25 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 14:46:05,167 - octoprint.plugin.core - INFO - 25 plugin(s) registered with the system:
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  DisplayLayerProgress Plugin (1.14.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_DisplayLayerProgress
|  Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
|  Floating Navbar (0.3.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_floatingnavbar
|  Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Navbar Temperature Plugin (0.11) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_navbartemp
| !Octolapse (0.3.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_octolapse
|  OctoPrint Anywhere (1.0.20) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere
|  Octoslack (1.9.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_Octoslack
|  Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager
|  Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check
|  Simple Emergency Stop (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_simpleemergencystop
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  The Spaghetti Detective (1.0.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective
|  TouchUI (0.3.13) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
|  Webcam Tab (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_webcamtab
2019-11-13 14:46:05,169 - octoprint.plugins.pluginmanager - INFO - The plugin was installed successfully: Octolapse, version 0.3.4
2019-11-13 14:46:05,889 - octoprint.plugins.tracking - INFO - Sent tracking event install_plugin, payload: {'plugin_version': '0.3.4', 'plugin': 'octolapse'}
2019-11-13 14:46:16,036 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 14:46:16,092 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:46:16] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:46:16,993 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 14:46:17,684 - octoprint.plugins.tracking - INFO - Sent tracking event uninstall_plugin, payload: {'plugin_version': '0.3.4', 'plugin': 'octolapse'}
2019-11-13 14:46:22,427 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2019-11-13 14:46:22,611 - octoprint.server - INFO - Shutting down...
2019-11-13 14:46:23,540 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-11-13 14:46:23,601 - octoprint.events - INFO - Event loop shut down
2019-11-13 14:46:23,663 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:46:23] "POST /shutdown HTTP/1.1" 404 -
2019-11-13 14:46:23,677 - octoprint.server - INFO - Goodbye!
2019-11-13 14:46:28,889 - octoprint.startup - INFO - ******************************************************************************
2019-11-13 14:46:28,892 - octoprint.startup - INFO - Starting OctoPrint 1.3.12
2019-11-13 14:46:28,893 - octoprint.startup - INFO - ******************************************************************************
2019-11-13 14:46:29,041 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-11-13 14:46:29,759 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-11-13 14:46:29,839 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 14:46:32,596 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 14:46:33,207 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-11-13 14:46:33,221 - octoprint.server - INFO - Intermediary server started
2019-11-13 14:46:33,222 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 14:46:34,015 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 14:46:34,059 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-11-13 14:46:34,805 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-11-13 14:46:35,077 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-11-13 14:46:36,920 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-11-13 14:46:38,722 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-11-13 14:46:38,724 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2019-11-13 14:46:38,724 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-11-13 14:46:38,729 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s)
2019-11-13 14:46:38,764 - octoprint.plugin.core - INFO - 24 plugin(s) registered with the system:
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  DisplayLayerProgress Plugin (1.14.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_DisplayLayerProgress
|  Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
|  Floating Navbar (0.3.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_floatingnavbar
|  Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Navbar Temperature Plugin (0.11) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_navbartemp
|  OctoPrint Anywhere (1.0.20) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere
|  Octoslack (1.9.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_Octoslack
|  Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager
|  Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check
|  Simple Emergency Stop (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_simpleemergencystop
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  The Spaghetti Detective (1.0.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective
|  TouchUI (0.3.13) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
|  Webcam Tab (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_webcamtab
2019-11-13 14:46:38,784 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details:
|  hardware:
|    cores: 4
|    freq: 1400.0
|    ram: 918188032
|  os:
|    id: linux
|    platform: linux2
|  plugins:
|    pi_support:
|      model: Raspberry Pi 3 Model B Plus Rev 1.3
|      octopi_version: 0.16.0
|  python:
|    pip: 19.0.1
|    version: 2.7.13
|    virtualenv: /home/pi/oprint
2019-11-13 14:46:38,799 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-11-13 14:46:38,819 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-11-13 14:46:40,015 - octoprint.server - INFO - Shutting down intermediary server...
2019-11-13 14:46:40,343 - octoprint.server - INFO - Intermediary server shut down
2019-11-13 14:46:40,346 - octoprint.events - INFO - Processing startup event, this is our first event
2019-11-13 14:46:40,371 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-11-13 14:46:40,373 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-11-13 14:46:40,460 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-11-13 14:46:40,513 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-11-13 14:46:41,368 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-11-13 14:46:41,404 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-11-13 14:46:41,409 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-11-13 14:46:41,425 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-11-13 14:46:41,439 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-11-13 14:46:41,447 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-11-13 14:46:41,484 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-11-13 14:46:41,548 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-11-13 14:46:42,016 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-11-13 14:46:43,006 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.163
2019-11-13 14:46:43,238 - octoprint.server.util.flask - INFO - Passively logging in user barrett from ::ffff:192.168.1.163
2019-11-13 14:46:43,254 - octoprint.server.util.sockjs - INFO - User barrett logged in on the socket from client ::ffff:192.168.1.163
2019-11-13 14:46:43,548 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-11-13 14:46:43,550 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2019-11-13 14:46:43,551 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-11-13 14:46:43,847 - py.warnings - WARNING - /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere/config.py:53: YAMLLoadWarning: calling yaml.load() without Loader=... is deprecated, as the default Loader is unsafe. Please read https://msg.pyyaml.org/load for full details.
  self.__items__ = yaml.load(config_str)

2019-11-13 14:46:43,951 - octoprint.plugins.navbartemp - INFO - Broadcom detected
2019-11-13 14:46:44,124 - octoprint.plugins.anywhere - WARNING - {u'mjpeg_stream_tier': 1, u'UserId': 36910, u'camResolution': u'medium', u'name': u'Craftbot 3', u'premium_video': True, u'flipV': True, u'octolapseOptedIn': True, u'recordTimelapse': True, u'rotate90N': False, u'token': u'T93HCQLETZN1NPZMBFFIL6KQYNPIOFWQ', u'lastSeen': u'2019-11-13T14:46:10.329Z', u'flipH': False, u'updatedAt': u'2019-11-13T14:46:10.329Z', u'deletedAt': None, u'rotate90': False, u'id': 47248, u'createdAt': u'2019-11-09T21:13:04.157Z', u'subscription': u'pro'}
2019-11-13 14:46:44,125 - octoprint.plugins.anywhere - WARNING - Printer is eligible for premium video streaming.
2019-11-13 14:46:44,326 - backoff - INFO - Backing off capture_mjpeg(...) for 0.7s (URLError: <urlopen error [Errno 111] Connection refused>)
2019-11-13 14:46:44,456 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 12}
2019-11-13 14:46:45,194 - backoff - INFO - Backing off capture_mjpeg(...) for 0.1s (URLError: <urlopen error [Errno 111] Connection refused>)
2019-11-13 14:46:45,408 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'plugins': u'displaylayerprogress:1.14.2,webcamtab:0.1.2,octoslack:1.9.1,touchui:0.3.13,simpleemergencystop:0.2.5,thespaghettidetective:1.0.0,navbartemp:0.11,anywhere:1.0.20,floatingnavbar:0.3.1'}
2019-11-13 14:46:45,420 - backoff - INFO - Backing off capture_mjpeg(...) for 1.9s (URLError: <urlopen error [Errno 111] Connection refused>)
2019-11-13 14:46:45,842 - werkzeug - INFO -  * Running on http://0.0.0.0:8080/ (Press CTRL+C to quit)
2019-11-13 14:46:45,941 - octoprint.plugins.anywhere - WARNING - Launching: /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere/bin/ffmpeg -re -i pipe:0 -y -an -vcodec copy -f hls -hls_time 2 -hls_list_size 10 -hls_delete_threshold 10 -hls_flags split_by_time+delete_segments+second_level_segment_index -strftime 1 -hls_segment_filename /tmp/octoprintanywhere-ts/%s-%%d.ts -hls_segment_type mpegts -
2019-11-13 14:46:46,056 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.12', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-11-13 14:46:47,517 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:46:47] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:46:54,481 - octoprint.plugins.thespaghettidetective - WARNING - Conceding pi camera exclusive use
2019-11-13 14:47:04,533 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:47:04] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:47:24,615 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:47:24] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:47:44,762 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:47:44] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:48:04,822 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:48:04] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:48:05,723 - octoprint.server.util.flask - INFO - Passively logging in user barrett from ::ffff:192.168.1.163
2019-11-13 14:48:25,392 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:48:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:48:25,475 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.163
2019-11-13 14:48:26,024 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.163
2019-11-13 14:48:26,272 - octoprint.server.util.flask - INFO - Passively logging in user barrett from ::ffff:192.168.1.163
2019-11-13 14:48:28,325 - octoprint.server.util.sockjs - INFO - User barrett logged in on the socket from client ::ffff:192.168.1.163
2019-11-13 14:48:44,839 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:48:44] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:49:04,991 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:49:04] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:49:24,979 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:49:24] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:49:45,060 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:49:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:50:05,038 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:50:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:50:25,157 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:50:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:50:45,096 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:50:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:51:05,091 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:51:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:51:25,115 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:51:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:51:45,186 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:51:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:52:05,294 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:52:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:52:25,300 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:52:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:52:45,288 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:52:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:53:05,345 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:53:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:53:25,414 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:53:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:53:45,458 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:53:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:54:05,512 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:54:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:54:25,501 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:54:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:54:45,653 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:54:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:55:05,640 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:55:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:55:25,789 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:55:25] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:55:45,865 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:55:45] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:56:05,892 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:56:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:56:26,017 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:56:26] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:56:46,108 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:56:46] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:57:06,099 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:57:06] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:57:26,127 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:57:26] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:57:46,286 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:57:46] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:58:06,347 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:58:06] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:58:26,298 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:58:26] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:58:46,366 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:58:46] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:59:06,406 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:59:06] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:59:26,428 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:59:26] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:59:40,579 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial port"
2019-11-13 14:59:40,981 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial port" to "Opening serial port"
2019-11-13 14:59:40,985 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-11-13 14:59:41,769 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 14:59:41,786 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 14:59:41,792 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-11-13 14:59:41,797 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 14:59:42,185 - octoprint.util.comm - INFO - Printer reports firmware name "pr3Dator"
2019-11-13 14:59:42,865 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'AUTO', 'firmware_name': 'pr3Dator'}
2019-11-13 14:59:46,533 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 14:59:46] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 14:59:51,961 - octoprint.filemanager.analysis - INFO - Starting analysis of local:flintvasea.gcode
2019-11-13 14:59:51,990 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --offset 0.0 0.0 /home/pi/.octoprint/uploads/flintvasea.gcode
2019-11-13 14:59:58,715 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 14:59:58,721 - octoprint.plugins.DisplayLayerProgress - INFO - File selected. Determining number of layers.
2019-11-13 14:59:58,826 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2019-11-13 14:59:58,902 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 14:59:58,920 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 14:59:58,953 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2019-11-13 15:00:00,163 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:00:00] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:00:02,355 - octoprint.plugins.DisplayLayerProgress - INFO - Printing started. Detailed progress started.{'origin': 'local', 'name': u'flintvasea.gcode', 'file': u'/home/pi/.octoprint/uploads/flintvasea.gcode', 'owner': 'barrett', 'path': u'flintvasea.gcode', 'user': 'barrett', 'size': 2962393L, 'filename': u'flintvasea.gcode'}
2019-11-13 15:00:03,377 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '2cbc52d6a4cca403c94bc14fe87d216e24c333bb'}
2019-11-13 15:07:08,627 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:19,656 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:19] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:27,701 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:27] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:31,130 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:41,833 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:07:42,643 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:42] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:47,766 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:47] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:07:53,799 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:07:53] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:05,203 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:05] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:07,845 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:07] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:11,876 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:08:16,674 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:16] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:27,860 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:27] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:28,041 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:28] "GET /?action=snapshot HTTP/1.1" 200 -

2019-11-13 15:08:39,173 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:39] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:41,886 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:08:47,983 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:47] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:08:50,662 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:08:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:02,122 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:02] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:07,959 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:07] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:11,908 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:09:13,602 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:13] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:24,643 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:24] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:27,988 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:27] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:36,078 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:36] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:41,941 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-11-13 15:09:47,547 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:47] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:48,100 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:09:58,650 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:09:58] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:08,175 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:10,103 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:11,970 - octoprint.util.comm - INFO - No response from printer after 6 consecutive communication timeouts, considering it dead.
2019-11-13 15:10:12,279 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:12] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:12,740 - octoprint.plugins.tracking - INFO - Sent tracking event commerror_timeout, payload: {'commerror_text': 'Too many consecutive timeouts, printer still connected and alive?'}
2019-11-13 15:10:15,957 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2019-11-13 15:10:15,969 - octoprint.filemanager.analysis - INFO - Starting analysis of local:flintvasea.gcode
2019-11-13 15:10:15,974 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --offset 0.0 0.0 /home/pi/.octoprint/uploads/flintvasea.gcode
2019-11-13 15:10:17,193 - octoprint.plugins.DisplayLayerProgress - INFO - Printing stopped. Detailed progress stopped.
2019-11-13 15:10:17,659 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:17] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:17,791 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:17] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:18,025 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'error', 'commerror_text': 'Too many consecutive timeouts, printer still connected and alive?', 'file': '2cbc52d6a4cca403c94bc14fe87d216e24c333bb', 'elapsed': 617}
2019-11-13 15:10:28,195 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:28] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:10:36,206 - octoprint.filemanager.analysis - INFO - Analysis of entry local:flintvasea.gcode finished, needed 20.24s
2019-11-13 15:10:48,310 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:10:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:11:08,334 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:11:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:11:28,405 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:11:28] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:11:48,450 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:11:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:12:08,477 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:12:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:12:28,575 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:12:28] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:12:48,654 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:12:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:13:08,679 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:13:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:13:28,661 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:13:28] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:13:48,650 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:13:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:14:08,775 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:14:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:14:28,797 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:14:28] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:14:48,910 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:14:48] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:15:08,930 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:15:08] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:15:29,007 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:15:29] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:15:49,030 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:15:49] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:16:09,099 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:16:09] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:16:29,165 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:16:29] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:16:33,212 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-11-13 15:16:44,478 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 1812}
2019-11-13 15:16:49,279 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:16:49] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:17:09,346 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:17:09] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:17:29,330 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:17:29] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:17:29,787 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:17:29] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:17:49,856 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:17:49] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:18:09,912 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:18:09] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:18:29,999 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:18:29] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:18:50,022 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:18:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:19:10,046 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:19:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:19:30,081 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:19:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:19:50,102 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:19:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:20:10,095 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:20:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:20:30,201 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:20:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:20:50,229 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:20:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:21:10,216 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:21:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:21:30,258 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:21:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:21:50,324 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:21:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:22:10,396 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:22:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:22:30,417 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:22:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:22:50,458 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:22:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:23:10,488 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:23:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:23:30,513 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:23:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:23:50,576 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:23:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:24:10,617 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:24:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:24:30,602 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:24:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:24:50,634 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:24:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:25:10,655 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:25:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:25:30,723 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:25:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:25:50,765 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:25:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:26:10,797 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:26:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:26:30,819 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:26:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:26:50,890 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:26:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:27:10,878 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:27:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:27:30,957 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:27:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:27:51,049 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:27:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:28:11,131 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:28:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:28:31,119 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:28:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:28:51,155 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:28:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:29:11,249 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:29:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:29:31,275 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:29:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:29:51,347 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:29:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:30:11,386 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:30:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:30:31,373 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:30:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:30:51,435 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:30:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:31:11,471 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:31:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:31:31,543 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:31:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:31:33,214 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-11-13 15:31:44,467 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 2712}
2019-11-13 15:31:51,615 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:31:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:32:11,681 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:32:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:32:31,750 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:32:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:32:51,859 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:32:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:33:11,920 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:33:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:33:31,991 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:33:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:33:52,416 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:33:52] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:34:12,098 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:34:12] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:34:32,120 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:34:32] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:34:52,197 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:34:52] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:35:12,179 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:35:12] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:35:32,220 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:35:32] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:37:54,344 - octoprint.startup - INFO - ******************************************************************************
2019-11-13 15:37:54,347 - octoprint.startup - INFO - Starting OctoPrint 1.3.12
2019-11-13 15:37:54,349 - octoprint.startup - INFO - ******************************************************************************
2019-11-13 15:37:54,521 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-11-13 15:37:54,608 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 15:37:58,531 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 15:37:59,158 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-11-13 15:37:59,195 - octoprint.server - INFO - Intermediary server started
2019-11-13 15:37:59,196 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2019-11-13 15:37:59,991 - octoprint.plugin.core - INFO - Found 24 plugin(s) providing 24 mixin implementations, 40 hook handlers
2019-11-13 15:38:00,037 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-11-13 15:38:00,792 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-11-13 15:38:01,055 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-11-13 15:38:03,296 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-11-13 15:38:05,110 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-11-13 15:38:05,112 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2019-11-13 15:38:05,114 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-11-13 15:38:05,131 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s)
2019-11-13 15:38:05,165 - octoprint.plugin.core - INFO - 24 plugin(s) registered with the system:
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  DisplayLayerProgress Plugin (1.14.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_DisplayLayerProgress
|  Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
|  Floating Navbar (0.3.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_floatingnavbar
|  Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Navbar Temperature Plugin (0.11) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_navbartemp
|  OctoPrint Anywhere (1.0.20) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere
|  Octoslack (1.9.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_Octoslack
|  Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager
|  Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check
|  Simple Emergency Stop (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_simpleemergencystop
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  The Spaghetti Detective (1.0.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective
|  TouchUI (0.3.13) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
|  Webcam Tab (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_webcamtab
2019-11-13 15:38:05,187 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details:
|  hardware:
|    cores: 4
|    freq: 1400.0
|    ram: 917008384
|  os:
|    id: linux
|    platform: linux2
|  plugins:
|    pi_support:
|      model: Raspberry Pi 3 Model B Plus Rev 1.3
|      octopi_version: 0.16.0
|  python:
|    pip: 19.0.1
|    version: 2.7.13
|    virtualenv: /home/pi/oprint
2019-11-13 15:38:05,200 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-11-13 15:38:05,222 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-11-13 15:38:06,451 - octoprint.server - INFO - Shutting down intermediary server...
2019-11-13 15:38:06,789 - octoprint.server - INFO - Intermediary server shut down
2019-11-13 15:38:06,793 - octoprint.events - INFO - Processing startup event, this is our first event
2019-11-13 15:38:06,793 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-11-13 15:38:06,817 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-11-13 15:38:06,870 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-11-13 15:38:06,886 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-11-13 15:38:06,890 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-11-13 15:38:06,905 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-11-13 15:38:06,917 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-11-13 15:38:06,931 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-11-13 15:38:06,955 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-11-13 15:38:06,997 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-11-13 15:38:07,637 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-11-13 15:38:08,844 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-11-13 15:38:08,845 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2019-11-13 15:38:08,846 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-11-13 15:38:08,890 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-11-13 15:38:08,919 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-11-13 15:38:09,434 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-11-13 15:38:09,810 - py.warnings - WARNING - /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere/config.py:53: YAMLLoadWarning: calling yaml.load() without Loader=... is deprecated, as the default Loader is unsafe. Please read https://msg.pyyaml.org/load for full details.
  self.__items__ = yaml.load(config_str)

2019-11-13 15:38:09,904 - octoprint.plugins.navbartemp - INFO - Broadcom detected
2019-11-13 15:38:10,074 - octoprint.plugins.anywhere - WARNING - {u'mjpeg_stream_tier': 1, u'UserId': 36910, u'camResolution': u'medium', u'name': u'Craftbot 3', u'premium_video': True, u'flipV': True, u'octolapseOptedIn': True, u'recordTimelapse': True, u'rotate90N': False, u'token': u'T93HCQLETZN1NPZMBFFIL6KQYNPIOFWQ', u'lastSeen': u'2019-11-13T15:34:53.143Z', u'flipH': False, u'updatedAt': u'2019-11-13T15:34:53.143Z', u'deletedAt': None, u'rotate90': False, u'id': 47248, u'createdAt': u'2019-11-09T21:13:04.157Z', u'subscription': u'pro'}
2019-11-13 15:38:10,082 - octoprint.plugins.anywhere - WARNING - Printer is eligible for premium video streaming.
2019-11-13 15:38:10,654 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 13}
2019-11-13 15:38:11,623 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 917008384, 'octopi_version': '0.16.0', 'version': u'1.3.12', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-11-13 15:38:12,362 - werkzeug - INFO -  * Running on http://0.0.0.0:8080/ (Press CTRL+C to quit)
2019-11-13 15:38:12,452 - octoprint.plugins.anywhere - WARNING - Launching: /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_anywhere/bin/ffmpeg -re -i pipe:0 -y -an -vcodec copy -f hls -hls_time 2 -hls_list_size 10 -hls_delete_threshold 10 -hls_flags split_by_time+delete_segments+second_level_segment_index -strftime 1 -hls_segment_filename /tmp/octoprintanywhere-ts/%s-%%d.ts -hls_segment_type mpegts -
2019-11-13 15:38:12,482 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'plugins': u'displaylayerprogress:1.14.2,webcamtab:0.1.2,octoslack:1.9.1,touchui:0.3.13,simpleemergencystop:0.2.5,thespaghettidetective:1.0.0,navbartemp:0.11,anywhere:1.0.20,floatingnavbar:0.3.1'}
2019-11-13 15:38:12,876 - backoff - INFO - Backing off wait_for_janus(...) for 0.5s (error: [Errno 111] Connection refused)
2019-11-13 15:38:14,382 - backoff - INFO - Backing off wait_for_janus(...) for 1.6s (error: [Errno 111] Connection refused)
2019-11-13 15:38:18,110 - backoff - INFO - Backing off start_gst(...) for 1.0s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:38:29,032 - backoff - INFO - Backing off start_gst(...) for 0.1s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:38:30,265 - backoff - INFO - Backing off start_gst(...) for 3.5s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:38:30,401 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:38:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:38:34,828 - backoff - INFO - Backing off start_gst(...) for 3.5s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:38:39,397 - backoff - INFO - Backing off start_gst(...) for 14.4s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:38:50,456 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:38:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:38:54,825 - backoff - INFO - Backing off start_gst(...) for 31.6s (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:39:10,526 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:39:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:39:22,374 - octoprint.server.util.flask - INFO - Passively logging in user barrett from ::ffff:192.168.1.163
2019-11-13 15:39:27,533 - backoff - ERROR - Giving up start_gst(...) after 7 tries (Exception: GST failed. Exit code: 1
STDERR: None)
2019-11-13 15:39:30,930 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:39:30] "POST /shutdown HTTP/1.1" 404 -
2019-11-13 15:39:30,976 - octoprint_thespaghettidetective.utils - ERROR - Backing off 0.209622 seconds: Janus WS connection closed!
2019-11-13 15:39:31,189 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:39:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:39:31,196 - octoprint_thespaghettidetective.utils - ERROR - Backing off 0.493435 seconds: Janus WS connection closed!
2019-11-13 15:39:31,713 - octoprint_thespaghettidetective.utils - ERROR - Backing off 1.271539 seconds: Janus WS connection closed!
2019-11-13 15:39:32,017 - octoprint.plugins.thespaghettidetective - ERROR - GST failed. Exit code: 1
STDERR: None

2019-11-13 15:39:44,561 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.163
2019-11-13 15:39:44,784 - octoprint.server.util.flask - INFO - Passively logging in user barrett from ::ffff:192.168.1.163
2019-11-13 15:39:47,165 - octoprint.server.util.sockjs - INFO - User barrett logged in on the socket from client ::ffff:192.168.1.163
2019-11-13 15:39:50,587 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:39:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:40:10,664 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:40:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:40:30,934 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial port"
2019-11-13 15:40:31,009 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:40:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:40:31,580 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial port" to "Opening serial port"
2019-11-13 15:40:31,933 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Detecting baudrate"
2019-11-13 15:40:32,948 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 15:40:32,957 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting baudrate" to "Operational"
2019-11-13 15:40:32,986 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 15:40:33,392 - octoprint.util.comm - INFO - Printer reports firmware name "pr3Dator"
2019-11-13 15:40:34,068 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 0, u'printer_port': u'AUTO', 'firmware_name': 'pr3Dator'}
2019-11-13 15:40:50,762 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:40:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:41:10,781 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:41:10] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:41:30,859 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:41:30] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:41:50,932 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:41:50] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:42:11,032 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:42:11] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:42:31,022 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:42:31] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:42:51,064 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:42:51] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:42:54,163 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 15:42:54,171 - octoprint.plugins.DisplayLayerProgress - INFO - File selected. Determining number of layers.
2019-11-13 15:43:02,206 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2019-11-13 15:43:02,263 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: flintvasea.gcode, owner: barrett, user: barrett
2019-11-13 15:43:02,277 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-11-13 15:43:02,329 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2019-11-13 15:43:02,755 - octoprint.plugins.DisplayLayerProgress - INFO - Printing started. Detailed progress started.{'origin': 'local', 'name': u'flintvasea.gcode', 'file': u'/home/pi/.octoprint/uploads/flintvasea.gcode', 'owner': 'barrett', 'path': u'flintvasea.gcode', 'user': 'barrett', 'size': 2962393L, 'filename': u'flintvasea.gcode'}
2019-11-13 15:43:03,468 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '2cbc52d6a4cca403c94bc14fe87d216e24c333bb'}
2019-11-13 15:43:03,772 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:03] "GET /?action=snapshot HTTP/1.1" 200 -
2019-11-13 15:43:11,092 - werkzeug - INFO - 127.0.0.1 - - [13/Nov/2019 15:43:11] "GET /?action=snapshot HTTP/1.1" 200 -

Full logs: https://www.dropbox.com/s/ei7vzpgfgib5cuv/Archive%202.zip?dl=0

So since I got the file to print via USB I didn't bother trying that print again via OctoPrint, but the issue did occur again several prints down the road. This time I just went and tripled every timeout (both busy and not busy communications and connection) from it's initial value. This has gotten me past the part that was failing on that print (which was consistent with the earlier failures).

So if someone comes across this thread in the future (probably me in several months) triple those three timeout settings and it seems to go through without a problem (and assumedly the only consequence would be that it'd take a few more seconds to recognize it lost connection were there to be another problem).

1 Like