Skip to content

Instantly share code, notes, and snippets.

@kazibole
Created April 9, 2019 03:30
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save kazibole/faf49b88ed881bd7889fcaf590ea18a4 to your computer and use it in GitHub Desktop.
Save kazibole/faf49b88ed881bd7889fcaf590ea18a4 to your computer and use it in GitHub Desktop.
octoprint_1.3.11rc2_02.log
2019-04-08 22:38:29,687 - 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-04-08 22:38:31,951 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 15 mixin implementations, 17 hook handlers
2019-04-08 22:38:32,097 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 22:38:32,170 - octoprint.server - INFO - Intermediary server started
2019-04-08 22:38:32,171 - 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-04-08 22:38:32,696 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 15 mixin implementations, 17 hook handlers
2019-04-08 22:38:32,698 - octoprint.printer.profile - ERROR - Profile _default does not exist, creating _default again and setting it as default
2019-04-08 22:38:32,827 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 22:38:32,829 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 22:38:34,568 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 22:38:35,956 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 22:38:35,958 - 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-04-08 22:38:35,958 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 22:38:35,963 - octoprint.plugin.core - INFO - Initialized 15 plugin implementation(s)
2019-04-08 22:38:36,065 - octoprint.plugin.core - INFO - 15 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
| CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 22:38:36,083 - 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-04-08 22:38:36,091 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 22:38:36,092 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 22:38:36,436 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 22:38:36,696 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 22:38:36,699 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 22:38:36,700 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 22:38:36,702 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 22:38:36,707 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 22:38:36,722 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 22:38:36,733 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 22:38:36,743 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 22:38:36,784 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 22:38:37,543 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.69s
2019-04-08 22:38:37,833 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2019-04-08 22:38:38,323 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 22:38:38,324 - 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-04-08 22:38:38,325 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 22:38:38,549 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.73s
2019-04-08 22:38:38,923 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2019-04-08 22:38:39,204 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.58s
2019-04-08 22:38:39,860 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.58s
2019-04-08 22:38:40,416 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 22:38:40,560 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.57s
2019-04-08 22:38:46,825 - 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-04-08 22:38:46,825 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 22:38:46,842 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 16:47:47,977 - octoprint.server - INFO - Shutting down...
2019-04-08 16:47:48,907 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 16:47:48,907 - octoprint.events - INFO - Event loop shut down
2019-04-08 16:47:48,917 - octoprint.server - INFO - Goodbye!
2019-04-08 16:47:53,794 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 16:47:53,796 - octoprint.startup - INFO - Starting OctoPrint 1.3.10
2019-04-08 16:47:53,798 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 16:47:54,950 - 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-04-08 16:47:57,297 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 15 mixin implementations, 17 hook handlers
2019-04-08 16:47:57,415 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 16:47:57,461 - octoprint.server - INFO - Intermediary server started
2019-04-08 16:47:57,462 - 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-04-08 16:47:58,033 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 15 mixin implementations, 17 hook handlers
2019-04-08 16:47:58,071 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 16:47:58,072 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 16:47:58,116 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 16:48:00,024 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 16:48:01,399 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 16:48:01,400 - 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-04-08 16:48:01,401 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 16:48:01,405 - octoprint.plugin.core - INFO - Initialized 15 plugin implementation(s)
2019-04-08 16:48:01,414 - octoprint.plugin.core - INFO - 15 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
| CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 16:48:01,432 - 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-04-08 16:48:01,441 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 16:48:01,443 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 16:48:01,804 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 16:48:01,976 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 16:48:01,978 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 16:48:01,979 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 16:48:01,980 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 16:48:01,987 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 16:48:02,001 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 16:48:02,011 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 16:48:02,022 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 16:48:02,037 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 16:48:02,100 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 16:48:02,439 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 16:48:03,666 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 16:48:03,668 - 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-04-08 16:48:03,669 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 16:48:12,223 - octoprint.server.util.flask.PreemptiveCache - INFO - Adding entry for / and {'query_string': 'l10n=en', 'path': u'/', '_count': 1, '_timestamp': 1554760092.223473, 'base_url': 'https://172.16.12.81/'}
2019-04-08 16:48:31,088 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 16:48:40,067 - octoprint.server.api - INFO - Actively logging in user admin from ::ffff:172.16.12.20
2019-04-08 16:48:41,672 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 16:48:43,831 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking
2019-04-08 16:48:45,093 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.10', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 16:49:57,649 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 16:49:57,653 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 16:49:57,657 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:49:58,772 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:50:00,384 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 16:50:00,393 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 16:50:00,404 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:50:00,444 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 16:50:01,060 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': 'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 16:52:26,638 - octoprint.plugins.tracking - INFO - Sent tracking event disable_plugin, payload: {'plugin_version': None, 'plugin': 'cura'}
2019-04-08 16:52:35,501 - octoprint.plugins.tracking - INFO - Sent tracking event disable_plugin, payload: {'plugin_version': None, 'plugin': 'virtual_printer'}
2019-04-08 16:52:41,302 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2019-04-08 16:52:41,492 - octoprint.server - INFO - Shutting down...
2019-04-08 16:52:42,217 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 16:52:42,224 - octoprint.events - INFO - Event loop shut down
2019-04-08 16:52:42,244 - octoprint.server - INFO - Goodbye!
2019-04-08 16:52:44,409 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 16:52:44,411 - octoprint.startup - INFO - Starting OctoPrint 1.3.10
2019-04-08 16:52:44,412 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 16:52:45,381 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 16:52:46,003 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 16:52:46,039 - 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-04-08 16:52:46,784 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 16:52:47,039 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 16:52:47,808 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 16:52:47,904 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 16:52:47,929 - octoprint.server - INFO - Intermediary server started
2019-04-08 16:52:47,929 - 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-04-08 16:52:48,445 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 16:52:48,486 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 16:52:48,488 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 16:52:48,504 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking
2019-04-08 16:52:48,533 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 16:52:49,908 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 16:52:51,279 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 16:52:51,281 - 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-04-08 16:52:51,281 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 16:52:51,286 - octoprint.plugin.core - INFO - Initialized 13 plugin implementation(s)
2019-04-08 16:52:51,294 - octoprint.plugin.core - INFO - 15 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
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 16:52:51,312 - 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-04-08 16:52:51,321 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 16:52:51,337 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 16:52:51,646 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 16:52:52,122 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 16:52:52,127 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 16:52:52,143 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 16:52:52,152 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 16:52:52,204 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 16:52:52,257 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 16:52:52,298 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 16:52:52,385 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 16:52:52,563 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 16:52:52,686 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 16:52:52,686 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 16:52:52,817 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 16:52:53,458 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 16:52:54,103 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 16:52:54,173 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 16:52:54,185 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 16:52:54,302 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 16:52:54,303 - 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-04-08 16:52:54,304 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 16:52:54,416 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 16:52:55,047 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.10', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 16:53:04,072 - octoprint.server.preemptive_cache - INFO - ... done in 9.66s
2019-04-08 16:55:17,176 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 16:55:17,286 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 16:55:18,129 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 16:55:18,197 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 16:55:19,892 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 16:55:59,715 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 16:55:59,719 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 16:55:59,736 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:57:00,909 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Offline"
2019-04-08 16:58:07,633 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 16:58:07,645 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 16:58:07,655 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:58:08,762 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:58:10,409 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 16:58:10,423 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 16:58:10,433 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 16:58:10,480 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 16:58:11,431 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': 'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 16:59:22,123 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing from SD"
2019-04-08 16:59:22,779 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 16:59:24,505 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 16:59:39,275 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:06:14,593 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:06:14,600 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s
2019-04-08 17:06:15,056 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1346, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1356, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1282, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 793, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 17:07:47,905 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-04-08 17:07:48,954 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:07:49,084 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:07:49,924 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:07:50,011 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:07:51,836 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:07:51,838 - octoprint.printer.standard - ERROR - Error while trying to send initial state update
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 919, in _sendInitialStateUpdate
data = self._stateMonitor.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1356, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1282, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 793, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 17:07:54,970 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {}
2019-04-08 17:12:40,089 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 17:12:40,745 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 797}
2019-04-08 17:12:40,801 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 17:15:09,280 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now
2019-04-08 17:15:09,456 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:15:09,702 - octoprint.server - INFO - Shutting down...
2019-04-08 17:15:09,773 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:15:09,774 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:15:09,801 - octoprint.server - INFO - Goodbye!
2019-04-08 17:15:15,137 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:15:15,139 - octoprint.startup - INFO - Starting OctoPrint 1.3.10
2019-04-08 17:15:15,141 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:15:16,265 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 17:15:16,337 - 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-04-08 17:15:17,571 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:15:17,932 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 17:15:18,770 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:15:18,892 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:15:18,940 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:15:18,941 - 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-04-08 17:15:19,511 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:15:19,557 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:15:19,559 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:15:19,576 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking
2019-04-08 17:15:19,608 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 17:15:21,964 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:15:23,428 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:15:23,430 - 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-04-08 17:15:23,430 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:15:23,435 - octoprint.plugin.core - INFO - Initialized 13 plugin implementation(s)
2019-04-08 17:15:23,443 - octoprint.plugin.core - INFO - 15 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
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:15:23,462 - 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-04-08 17:15:23,471 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:15:23,487 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:15:23,912 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:15:23,981 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:15:23,984 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:15:23,985 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 17:15:23,986 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:15:23,990 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:15:24,003 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:15:24,014 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:15:24,025 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:15:24,040 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:15:24,148 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:15:24,578 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:15:25,534 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:15:25,588 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:15:25,598 - 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-04-08 17:15:25,598 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:15:25,624 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:15:25,635 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:15:25,639 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:15:25,745 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:15:26,417 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:15:26,497 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:15:26,607 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.10', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:15:36,756 - octoprint.server.preemptive_cache - INFO - ... done in 10.34s
2019-04-08 17:15:53,089 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:15:53,194 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:15:54,051 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:15:54,175 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:15:55,912 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:15:59,593 - octoprint.server.api.system - INFO - Performing command for core:restart_safe: sudo service octoprint restart
2019-04-08 17:15:59,934 - octoprint.server - INFO - Shutting down...
2019-04-08 17:15:59,972 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:15:59,975 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:15:59,990 - octoprint.server - INFO - Goodbye!
2019-04-08 17:16:02,106 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:16:02,108 - octoprint.startup - INFO - Starting OctoPrint 1.3.10
2019-04-08 17:16:02,109 - octoprint.startup - INFO - Starting in SAFE MODE. Third party plugins will be disabled!
2019-04-08 17:16:02,110 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:16:03,086 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:16:03,710 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 17:16:03,773 - 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-04-08 17:16:04,471 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:16:04,726 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 17:16:05,495 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:16:05,591 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:16:05,616 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:16:05,616 - 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-04-08 17:16:06,135 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:16:06,176 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:16:06,178 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:16:06,194 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking
2019-04-08 17:16:06,223 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 17:16:07,606 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:16:08,979 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:16:08,981 - 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-04-08 17:16:08,981 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:16:08,990 - octoprint.plugin.core - INFO - Initialized 13 plugin implementation(s)
2019-04-08 17:16:08,999 - octoprint.plugin.core - INFO - 15 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
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:16:09,016 - 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-04-08 17:16:09,026 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:16:09,039 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:16:09,344 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:16:09,371 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:16:09,373 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:16:09,373 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 17:16:09,376 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:16:09,403 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:16:09,704 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:16:09,708 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:16:09,719 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:16:09,837 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:16:09,852 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:16:09,923 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:16:09,934 - octoprint.server - INFO - Server started successfully in safe mode as requested from config, removing flag
2019-04-08 17:16:10,306 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:16:10,703 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:16:11,744 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:16:11,746 - 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-04-08 17:16:11,747 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:16:11,817 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:16:11,998 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:16:12,080 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:16:12,092 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:16:12,468 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.10', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:16:21,770 - octoprint.server.preemptive_cache - INFO - ... done in 9.95s
2019-04-08 17:16:48,496 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 17:16:48,502 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 17:16:48,515 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:16:49,629 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:16:51,134 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 17:16:51,153 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 17:16:51,164 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:16:51,213 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 17:16:51,836 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': 'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 17:17:04,248 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 17:17:04,255 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 17:17:39,078 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:21:41,068 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:22:21,258 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing from SD"
2019-04-08 17:22:21,933 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 17:22:31,313 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 17:22:42,676 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 17:22:53,104 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1346, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1356, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1282, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 793, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 17:23:21,881 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 17:23:41,883 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 17:27:31,459 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 17:28:07,088 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 17:28:07,751 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 345}
2019-04-08 17:28:20,605 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 17:30:17,932 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now
2019-04-08 17:30:18,067 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:30:18,352 - octoprint.server - INFO - Shutting down...
2019-04-08 17:30:19,039 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:30:19,040 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:30:19,227 - octoprint.server - INFO - Goodbye!
2019-04-08 17:30:24,920 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:30:24,924 - octoprint.startup - INFO - Starting OctoPrint 1.3.10
2019-04-08 17:30:24,925 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:30:26,282 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 17:30:26,351 - 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-04-08 17:30:27,504 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:30:27,858 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 17:30:28,702 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:30:28,823 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:30:28,910 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:30:28,911 - 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-04-08 17:30:29,457 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 13 mixin implementations, 16 hook handlers
2019-04-08 17:30:29,499 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:30:29,501 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:30:29,518 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking
2019-04-08 17:30:29,550 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 17:30:31,704 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:30:33,132 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:30:33,133 - 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-04-08 17:30:33,133 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:30:33,139 - octoprint.plugin.core - INFO - Initialized 13 plugin implementation(s)
2019-04-08 17:30:33,147 - octoprint.plugin.core - INFO - 15 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
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:30:33,165 - 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-04-08 17:30:33,175 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:30:33,191 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:30:33,555 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:30:33,576 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:30:33,578 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:30:33,579 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 17:30:33,581 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:30:33,587 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:30:33,598 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:30:33,609 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:30:33,620 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:30:33,643 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:30:33,701 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:30:34,532 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:30:34,538 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:30:34,614 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:30:34,632 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:30:35,189 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:30:35,190 - 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-04-08 17:30:35,192 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:30:35,232 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:30:35,257 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:30:35,602 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:30:36,171 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:30:36,532 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.10', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:30:46,950 - octoprint.server.preemptive_cache - INFO - ... done in 10.78s
2019-04-08 17:34:41,879 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:34:43,369 - octoprint - ERROR - Exception on / [GET]
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
response = self.full_dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
rv = self.handle_user_exception(e)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
rv = self.dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
return self.view_functions[rule.endpoint](**req.view_args)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 412, in index
response = default_view()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 384, in default_view
return preemptively_cached()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 913, in decorated_function
for e in entries:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 967, in decorated_function
if not self._validate_entry(entry):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 700, in decorated_function
with self._mutex:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 669, in f_with_duration
def calculate_timeout(self, timeout=None):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 922, in decorated_function
cache_data = self.get_all_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 938, in decorated_function
import copy
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 371, in make_default_ui
r = make_response(render_template("index.jinja2", **render_kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 128, in render_template
context, ctx.app)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 110, in _render
rv = template.render(context)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 989, in render
return self.environment.handle_exception(exc_info, True)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 754, in handle_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/index.jinja2", line 16, in top-level template code
{% include 'initscript.jinja2' %}
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/initscript.jinja2", line 33, in top-level template code
var SUPPORTED_FILETYPES = {{ supportedFiletypes|tojson }};
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 243, in tojson_filter
return Markup(htmlsafe_dumps(obj, **kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 186, in htmlsafe_dumps
rv = dumps(obj, **kwargs) \
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 126, in dumps
rv = _json.dumps(obj, **kwargs)
File "/usr/lib/python2.7/json/__init__.py", line 251, in dumps
sort_keys=sort_keys, **kw).encode(obj)
File "/usr/lib/python2.7/json/encoder.py", line 209, in encode
chunks = list(chunks)
File "/usr/lib/python2.7/json/encoder.py", line 442, in _iterencode
o = _default(o)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 1492, in default
"js/app/client/browser.js",
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 83, in default
return _json.JSONEncoder.default(self, o)
File "/usr/lib/python2.7/json/encoder.py", line 184, in default
raise TypeError(repr(o) + " is not JSON serializable")
TypeError: Undefined is not JSON serializable
2019-04-08 17:34:43,372 - tornado.access - ERROR - 500 GET / (::ffff:172.16.12.20) 1512.00ms
2019-04-08 17:34:43,381 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:34:43,683 - tornado.access - WARNING - 404 GET /favicon.ico (::ffff:172.16.12.20) 9.95ms
2019-04-08 17:34:53,847 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:34:54,624 - octoprint - ERROR - Exception on / [GET]
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
response = self.full_dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
rv = self.handle_user_exception(e)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
rv = self.dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
return self.view_functions[rule.endpoint](**req.view_args)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 412, in index
response = default_view()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 384, in default_view
return preemptively_cached()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 913, in decorated_function
for e in entries:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 967, in decorated_function
if not self._validate_entry(entry):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 700, in decorated_function
with self._mutex:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 669, in f_with_duration
def calculate_timeout(self, timeout=None):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 922, in decorated_function
cache_data = self.get_all_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 938, in decorated_function
import copy
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 371, in make_default_ui
r = make_response(render_template("index.jinja2", **render_kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 128, in render_template
context, ctx.app)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 110, in _render
rv = template.render(context)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 989, in render
return self.environment.handle_exception(exc_info, True)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 754, in handle_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/index.jinja2", line 16, in top-level template code
{% include 'initscript.jinja2' %}
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/initscript.jinja2", line 33, in top-level template code
var SUPPORTED_FILETYPES = {{ supportedFiletypes|tojson }};
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 243, in tojson_filter
return Markup(htmlsafe_dumps(obj, **kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 186, in htmlsafe_dumps
rv = dumps(obj, **kwargs) \
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 126, in dumps
rv = _json.dumps(obj, **kwargs)
File "/usr/lib/python2.7/json/__init__.py", line 251, in dumps
sort_keys=sort_keys, **kw).encode(obj)
File "/usr/lib/python2.7/json/encoder.py", line 209, in encode
chunks = list(chunks)
File "/usr/lib/python2.7/json/encoder.py", line 442, in _iterencode
o = _default(o)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 1492, in default
"js/app/client/browser.js",
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 83, in default
return _json.JSONEncoder.default(self, o)
File "/usr/lib/python2.7/json/encoder.py", line 184, in default
raise TypeError(repr(o) + " is not JSON serializable")
TypeError: Undefined is not JSON serializable
2019-04-08 17:34:54,626 - tornado.access - ERROR - 500 GET / (::ffff:172.16.12.20) 797.01ms
2019-04-08 17:35:06,879 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:35:07,708 - octoprint - ERROR - Exception on / [GET]
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
response = self.full_dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
rv = self.handle_user_exception(e)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
rv = self.dispatch_request()
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
return self.view_functions[rule.endpoint](**req.view_args)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 412, in index
response = default_view()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 384, in default_view
return preemptively_cached()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 913, in decorated_function
for e in entries:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 967, in decorated_function
if not self._validate_entry(entry):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 700, in decorated_function
with self._mutex:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 669, in f_with_duration
def calculate_timeout(self, timeout=None):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 922, in decorated_function
cache_data = self.get_all_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 938, in decorated_function
import copy
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/views.py", line 371, in make_default_ui
r = make_response(render_template("index.jinja2", **render_kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 128, in render_template
context, ctx.app)
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/templating.py", line 110, in _render
rv = template.render(context)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 989, in render
return self.environment.handle_exception(exc_info, True)
File "/home/pi/oprint/local/lib/python2.7/site-packages/jinja2/environment.py", line 754, in handle_exception
reraise(exc_type, exc_value, tb)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/index.jinja2", line 16, in top-level template code
{% include 'initscript.jinja2' %}
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/templates/initscript.jinja2", line 33, in top-level template code
var SUPPORTED_FILETYPES = {{ supportedFiletypes|tojson }};
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 243, in tojson_filter
return Markup(htmlsafe_dumps(obj, **kwargs))
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 186, in htmlsafe_dumps
rv = dumps(obj, **kwargs) \
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 126, in dumps
rv = _json.dumps(obj, **kwargs)
File "/usr/lib/python2.7/json/__init__.py", line 251, in dumps
sort_keys=sort_keys, **kw).encode(obj)
File "/usr/lib/python2.7/json/encoder.py", line 209, in encode
chunks = list(chunks)
File "/usr/lib/python2.7/json/encoder.py", line 442, in _iterencode
o = _default(o)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 1492, in default
"js/app/client/browser.js",
File "/home/pi/oprint/local/lib/python2.7/site-packages/flask/json.py", line 83, in default
return _json.JSONEncoder.default(self, o)
File "/usr/lib/python2.7/json/encoder.py", line 184, in default
raise TypeError(repr(o) + " is not JSON serializable")
TypeError: Undefined is not JSON serializable
2019-04-08 17:35:07,711 - tornado.access - ERROR - 500 GET / (::ffff:172.16.12.20) 850.00ms
2019-04-08 17:35:13,668 - octoprint.server - INFO - Shutting down...
2019-04-08 17:35:13,932 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:35:13,934 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:35:14,168 - octoprint.server - INFO - Goodbye!
2019-04-08 17:35:20,205 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:35:20,207 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc1
2019-04-08 17:35:20,209 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:35:21,441 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 17:35:21,508 - 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-04-08 17:35:22,766 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:35:24,150 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:35:24,404 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:35:24,448 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:35:24,450 - 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-04-08 17:35:25,116 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:35:25,208 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:35:25,210 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:35:25,298 - octoprint.plugins.softwareupdate - INFO - Version cache was created for another version of OctoPrint, not using it
2019-04-08 17:35:27,260 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:35:28,699 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:35:28,701 - 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-04-08 17:35:28,702 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:35:28,706 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 17:35:28,717 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:35:28,735 - 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-04-08 17:35:28,746 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:35:28,761 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:35:29,218 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:35:29,454 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:35:29,457 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:35:29,457 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 17:35:29,460 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:35:29,464 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 17:35:29,465 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:35:29,468 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 17:35:29,480 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:35:29,491 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:35:29,503 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:35:29,518 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:35:29,599 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:35:29,983 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:35:31,118 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:35:31,120 - 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-04-08 17:35:31,121 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:35:31,160 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:35:31,192 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:35:31,676 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:35:33,398 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:35:37,544 - 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-04-08 17:35:37,544 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:35:37,584 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 17:35:37,764 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:35:38,161 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc1', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:35:38,998 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 14}
2019-04-08 17:35:39,401 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:36:06,068 - octoprint.server.preemptive_cache - INFO - ... done in 20.58s
2019-04-08 17:36:06,923 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:36:07,038 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:36:08,713 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:36:54,795 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 17:36:54,802 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 17:36:54,820 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:36:55,929 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:36:57,554 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 17:36:57,567 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 17:36:57,579 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:36:57,630 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 17:36:58,252 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': 'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 17:37:09,962 - octoprint.plugin.errortracking - INFO - Initialized error tracking
2019-04-08 17:37:42,281 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:37:42,388 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:37:43,259 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:37:43,375 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:37:44,855 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:38:42,729 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: TEST_P~1.GCO, owner: None, user: None
2019-04-08 17:38:43,881 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 17:38:46,060 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 17:38:46,068 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 17:38:56,091 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:44:08,784 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 17:45:00,035 - octoprint.util.comm - INFO - Timeout while in an active heatup, considering heatup to be over.
2019-04-08 17:45:29,200 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting print from SD"
2019-04-08 17:45:29,214 - octoprint.printer.standard.job - INFO - Print job started - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 17:45:29,267 - octoprint.util.comm - INFO - Changing monitoring state from "Starting print from SD" to "Printing from SD"
2019-04-08 17:45:30,225 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 17:45:58,924 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1469, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1479, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1405, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 860, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 17:50:24,406 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-04-08 17:50:34,926 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 17:50:34,936 - octoprint.printer.standard.job - INFO - Print job done - origin: sdcard, path: test_p~1.gco, owner: None
2019-04-08 17:50:35,857 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 305}
2019-04-08 17:50:38,216 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 906}
2019-04-08 17:50:48,445 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 17:52:53,429 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 17:53:02,537 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2019-04-08 17:53:02,728 - octoprint.server - INFO - Shutting down...
2019-04-08 17:53:02,981 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:53:02,986 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:53:03,000 - octoprint.server - INFO - Goodbye!
2019-04-08 17:53:05,377 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:53:05,379 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc1
2019-04-08 17:53:05,380 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:53:06,367 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:53:07,227 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 17:53:07,263 - 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-04-08 17:53:08,086 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:53:09,153 - octoprint.plugin.errortracking - INFO - Initialized error tracking
2019-04-08 17:53:09,157 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:53:09,423 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:53:09,449 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:53:09,450 - 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-04-08 17:53:10,099 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:53:10,144 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:53:10,146 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:53:10,192 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 17:53:11,598 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:53:12,998 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:53:13,000 - 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-04-08 17:53:13,001 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:53:13,006 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 17:53:13,017 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:53:13,036 - 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-04-08 17:53:13,047 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:53:13,063 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:53:13,467 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:53:13,546 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:53:13,549 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:53:13,550 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 17:53:13,554 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:53:13,557 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:53:13,560 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 17:53:13,585 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:53:13,586 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 17:53:13,775 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:53:13,794 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:53:13,914 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:53:13,932 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:53:14,072 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:53:14,250 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:53:14,587 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:53:15,625 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:53:15,627 - 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-04-08 17:53:15,628 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:53:15,879 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:53:16,091 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:53:16,179 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:53:16,192 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:53:16,282 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc1', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:53:17,269 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7}
2019-04-08 17:53:24,760 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:53:31,810 - octoprint.server.preemptive_cache - INFO - ... done in 15.93s
2019-04-08 17:53:31,835 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:53:32,754 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:53:32,854 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:53:34,343 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:53:43,583 - octoprint.plugins.softwareupdate - INFO - Starting update of octoprint to 1.3.11rc2...
2019-04-08 17:53:45,036 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:53:48,742 - 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-04-08 17:53:48,744 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:54:07,083 - octoprint.plugins.softwareupdate - INFO - Update of octoprint to 1.3.11rc2 successful!
2019-04-08 17:54:07,202 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 17:54:07,206 - octoprint.plugins.softwareupdate - INFO - Restarting...
2019-04-08 17:54:07,322 - octoprint.server - INFO - Shutting down...
2019-04-08 17:54:07,606 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:54:07,609 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:54:07,622 - octoprint.server - INFO - Goodbye!
2019-04-08 17:54:11,791 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:54:11,793 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 17:54:11,794 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:54:11,869 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:54:11,873 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 17:54:11,909 - 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-04-08 17:54:12,688 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:54:13,784 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 17:54:13,787 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:54:14,138 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:54:14,165 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:54:14,166 - 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-04-08 17:54:14,737 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:54:14,783 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:54:14,785 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:54:14,815 - octoprint.plugins.softwareupdate - INFO - Version cache was created for another version of OctoPrint, not using it
2019-04-08 17:54:16,211 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:54:17,605 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:54:17,607 - 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-04-08 17:54:17,608 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:54:17,613 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 17:54:17,625 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:54:17,643 - 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-04-08 17:54:17,656 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:54:17,672 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:54:18,070 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:54:18,154 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:54:18,157 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:54:18,158 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 17:54:18,168 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:54:18,184 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:54:18,199 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:54:18,200 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 17:54:18,523 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:54:18,524 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 17:54:18,540 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:54:18,597 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:54:18,613 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:54:18,691 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:54:18,806 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:54:19,239 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:54:20,279 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:54:20,281 - 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-04-08 17:54:20,282 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:54:20,699 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:54:20,791 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:54:20,877 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:54:21,046 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:54:23,029 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:54:25,036 - 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-04-08 17:54:25,037 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:54:25,059 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 17:54:25,277 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:54:25,795 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:54:26,524 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 12}
2019-04-08 17:54:40,479 - octoprint.server.preemptive_cache - INFO - ... done in 15.20s
2019-04-08 17:54:40,560 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:54:41,426 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:54:41,525 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:54:42,984 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:54:56,007 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now
2019-04-08 17:54:56,175 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 17:54:56,445 - octoprint.server - INFO - Shutting down...
2019-04-08 17:54:57,139 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 17:54:57,141 - octoprint.events - INFO - Event loop shut down
2019-04-08 17:54:57,151 - octoprint.server - INFO - Goodbye!
2019-04-08 17:55:05,121 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:55:05,123 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 17:55:05,125 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 17:55:05,201 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 17:55:05,268 - 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-04-08 17:55:06,544 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 17:55:07,852 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 17:55:07,857 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:55:08,224 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 17:55:08,269 - octoprint.server - INFO - Intermediary server started
2019-04-08 17:55:08,270 - 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-04-08 17:55:08,830 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 17:55:08,889 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 17:55:08,891 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 17:55:08,942 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 17:55:10,847 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:55:12,310 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 17:55:12,312 - 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-04-08 17:55:12,313 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:55:12,321 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 17:55:12,332 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 17:55:12,351 - 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-04-08 17:55:12,361 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 17:55:12,376 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 17:55:12,830 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 17:55:13,276 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 17:55:13,283 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 17:55:13,284 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 17:55:13,289 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 17:55:13,297 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 17:55:13,305 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 17:55:13,312 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 17:55:13,341 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 17:55:13,366 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 17:55:13,389 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 17:55:13,426 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 17:55:13,548 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:55:14,044 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:55:14,978 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 17:55:14,979 - 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-04-08 17:55:14,980 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 17:55:15,022 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 17:55:15,049 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 17:55:15,558 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 17:55:15,752 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 17:55:15,837 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 17:55:15,862 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 17:55:15,874 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 17:55:16,271 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 17:55:17,145 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 8}
2019-04-08 17:55:27,083 - octoprint.server.preemptive_cache - INFO - ... done in 11.25s
2019-04-08 17:56:12,305 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 17:56:12,310 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 17:56:12,316 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:56:13,437 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:56:15,053 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 17:56:15,067 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 17:56:15,081 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 17:56:15,132 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 17:56:15,758 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': u'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 17:58:03,677 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: TEST_P~1.GCO, owner: None, user: None
2019-04-08 17:58:04,833 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 17:58:07,163 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 17:58:07,170 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 17:58:17,096 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 18:02:43,226 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 18:03:23,037 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting print from SD"
2019-04-08 18:03:23,046 - octoprint.printer.standard.job - INFO - Print job started - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 18:03:23,097 - octoprint.util.comm - INFO - Changing monitoring state from "Starting print from SD" to "Printing from SD"
2019-04-08 18:03:23,722 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 18:03:46,091 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1471, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1481, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1407, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 862, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 18:09:08,654 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 18:09:08,665 - octoprint.printer.standard.job - INFO - Print job done - origin: sdcard, path: test_p~1.gco, owner: None
2019-04-08 18:09:09,285 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 345}
2019-04-08 18:09:22,461 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 18:10:03,703 - octoprint.server.api.system - INFO - Performing command for core:restart_safe: sudo service octoprint restart
2019-04-08 18:10:04,058 - octoprint.server - INFO - Shutting down...
2019-04-08 18:10:04,580 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 18:10:04,595 - octoprint.events - INFO - Event loop shut down
2019-04-08 18:10:04,620 - octoprint.server - INFO - Goodbye!
2019-04-08 18:10:08,689 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:10:08,691 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 18:10:08,692 - octoprint.startup - INFO - Starting in SAFE MODE. Third party plugins will be disabled!
2019-04-08 18:10:08,693 - octoprint.startup - INFO - Reason for safe mode: setting in config.yaml
2019-04-08 18:10:08,694 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:10:08,763 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 18:10:09,381 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 18:10:09,446 - 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-04-08 18:10:10,220 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 18:10:11,309 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 18:10:11,313 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 18:10:11,666 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 18:10:11,692 - octoprint.server - INFO - Intermediary server started
2019-04-08 18:10:11,693 - 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-04-08 18:10:12,258 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 18:10:12,303 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 18:10:12,305 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 18:10:12,354 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 18:10:13,767 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:10:15,169 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 18:10:15,171 - 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-04-08 18:10:15,172 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:10:15,177 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 18:10:15,188 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 18:10:15,207 - 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-04-08 18:10:15,217 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 18:10:15,232 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 18:10:15,631 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 18:10:16,110 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 18:10:16,113 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 18:10:16,114 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 18:10:16,119 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 18:10:16,126 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 18:10:16,130 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 18:10:16,158 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:10:16,330 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 18:10:16,469 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:10:16,535 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 18:10:16,567 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 18:10:16,678 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 18:10:16,697 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 18:10:16,698 - octoprint.server - INFO - Server started successfully in safe mode as requested from config, removing flag
2019-04-08 18:10:16,965 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:10:17,337 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:10:18,402 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:10:18,404 - 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-04-08 18:10:18,405 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:10:18,668 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:10:18,737 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 18:10:18,766 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 18:10:18,779 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 18:10:19,151 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 18:10:20,103 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7}
2019-04-08 18:10:22,676 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 18:10:22,719 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 18:10:22,745 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:10:30,220 - octoprint.server.preemptive_cache - INFO - ... done in 11.48s
2019-04-08 18:10:34,961 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:10:36,582 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 18:10:36,596 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 18:10:36,606 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:10:36,661 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 18:10:37,249 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': u'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 18:11:07,433 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: TEST_P~1.GCO, owner: None, user: None
2019-04-08 18:11:08,584 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 18:11:10,761 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 18:11:10,767 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 18:12:40,829 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 18:16:39,370 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 18:17:19,571 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting print from SD"
2019-04-08 18:17:19,577 - octoprint.printer.standard.job - INFO - Print job started - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 18:17:19,622 - octoprint.util.comm - INFO - Changing monitoring state from "Starting print from SD" to "Printing from SD"
2019-04-08 18:17:20,272 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 18:17:40,966 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1471, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1481, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1407, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 862, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 18:23:05,182 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 18:23:05,192 - octoprint.printer.standard.job - INFO - Print job done - origin: sdcard, path: test_p~1.gco, owner: None
2019-04-08 18:23:05,880 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 345}
2019-04-08 18:23:18,993 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 18:25:11,668 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-04-08 18:25:19,070 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 907}
2019-04-08 18:25:41,825 - tornado.access - WARNING - 409 POST /api/job (::ffff:172.16.12.20) 36.86ms
2019-04-08 18:25:51,506 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2019-04-08 18:25:51,652 - octoprint.server - INFO - Shutting down...
2019-04-08 18:25:52,413 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 18:25:52,424 - octoprint.events - INFO - Event loop shut down
2019-04-08 18:25:52,446 - octoprint.server - INFO - Goodbye!
2019-04-08 18:25:56,477 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:25:56,479 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 18:25:56,480 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:25:56,544 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 18:25:57,145 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 18:25:57,180 - 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-04-08 18:25:58,015 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 18:25:59,099 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 18:25:59,103 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 18:25:59,453 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 18:25:59,479 - octoprint.server - INFO - Intermediary server started
2019-04-08 18:25:59,480 - 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-04-08 18:26:00,043 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 18:26:00,088 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 18:26:00,090 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 18:26:00,140 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 18:26:01,531 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:26:02,916 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 18:26:02,918 - 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-04-08 18:26:02,920 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:26:02,924 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 18:26:02,938 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 18:26:02,957 - 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-04-08 18:26:02,967 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 18:26:02,983 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 18:26:03,381 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 18:26:03,390 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 18:26:03,393 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 18:26:03,394 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 18:26:03,399 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 18:26:03,433 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:26:03,554 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 18:26:03,680 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 18:26:03,681 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 18:26:03,748 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:26:03,825 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 18:26:03,898 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 18:26:03,921 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 18:26:03,966 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 18:26:04,155 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:26:04,525 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:26:05,492 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:26:05,493 - 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-04-08 18:26:05,494 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:26:05,733 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 18:26:06,175 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 18:26:06,865 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:26:06,948 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7}
2019-04-08 18:26:06,995 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 18:26:07,252 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 18:26:16,670 - octoprint.server.preemptive_cache - INFO - ... done in 10.94s
2019-04-08 18:27:54,604 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 18:27:54,848 - octoprint.server - INFO - Shutting down...
2019-04-08 18:27:54,976 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 18:27:54,978 - octoprint.events - INFO - Event loop shut down
2019-04-08 18:27:54,993 - octoprint.server - INFO - Goodbye!
2019-04-08 18:28:01,086 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:28:01,088 - octoprint.startup - INFO - Starting OctoPrint 1.3.9
2019-04-08 18:28:01,089 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:28:02,280 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 18:28:02,389 - 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-04-08 18:28:03,601 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 18:28:03,920 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 18:28:04,734 - octoprint.plugin.core - INFO - Found 11 plugin(s) providing 9 mixin implementations, 7 hook handlers
2019-04-08 18:28:04,891 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 18:28:04,941 - octoprint.server - INFO - Intermediary server started
2019-04-08 18:28:04,942 - 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-04-08 18:28:05,468 - octoprint.plugin.core - INFO - Found 11 plugin(s) providing 9 mixin implementations, 7 hook handlers
2019-04-08 18:28:05,512 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 18:28:05,514 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 18:28:05,559 - octoprint.plugins.softwareupdate - INFO - Version cache was created for another version of OctoPrint, not using it
2019-04-08 18:28:07,904 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:28:09,304 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 18:28:09,306 - 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-04-08 18:28:09,306 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:28:09,310 - octoprint.plugin.core - INFO - Initialized 9 plugin implementation(s)
2019-04-08 18:28:09,317 - octoprint.plugin.core - INFO - 11 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
| Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
| OctoPi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/octopi_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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 18:28:09,335 - 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:
| octopi_support:
| model: unknown
| revision: a020d3
| version: 0.16.0
| python:
| pip: 19.0.1
| version: 2.7.13
| virtualenv: /home/pi/oprint
2019-04-08 18:28:09,345 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 18:28:09,360 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 18:28:09,561 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 18:28:09,712 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 18:28:09,714 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 18:28:09,715 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 18:28:09,717 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 18:28:09,721 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 18:28:09,734 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _http._tcp
2019-04-08 18:28:09,745 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _octoprint._tcp
2019-04-08 18:28:09,749 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 18:28:09,750 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 18:28:09,852 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:28:10,062 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 18:28:10,375 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:28:10,378 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:28:10,506 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 18:28:10,752 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:28:10,958 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:28:11,051 - tornado.access - WARNING - 403 POST /api/login (::ffff:172.16.12.20) 13.63ms
2019-04-08 18:28:13,096 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:28:19,886 - 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-04-08 18:28:19,887 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:28:20,089 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 18:28:22,338 - octoprint.server.preemptive_cache - INFO - ... done in 11.83s
2019-04-08 18:31:37,245 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 18:31:37,415 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:31:37,513 - tornado.access - WARNING - 403 POST /api/login (::ffff:172.16.12.20) 24.51ms
2019-04-08 18:31:57,494 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 18:31:58,444 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:32:03,297 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 18:32:03,301 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 18:32:03,307 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:32:04,431 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:32:05,820 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 18:32:05,832 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 18:32:05,843 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:32:05,876 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 18:32:16,723 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, telling it to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 18:32:25,641 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing from SD"
2019-04-08 18:32:26,644 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 18:37:46,233 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1328, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1338, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1264, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 783, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 18:38:08,206 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 18:38:56,810 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 18:42:56,184 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2019-04-08 18:43:04,894 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-04-08 18:43:31,619 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 18:43:45,140 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2019-04-08 18:57:22,225 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 18:57:22,412 - octoprint.server - INFO - Shutting down...
2019-04-08 18:57:23,002 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 18:57:23,003 - octoprint.events - INFO - Event loop shut down
2019-04-08 18:57:23,013 - octoprint.server - INFO - Goodbye!
2019-04-08 18:57:28,002 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:57:28,005 - octoprint.startup - INFO - Starting OctoPrint 1.3.8
2019-04-08 18:57:28,005 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 18:57:29,257 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 18:57:29,321 - 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-04-08 18:57:29,332 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 18:57:30,753 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2019-04-08 18:57:31,512 - octoprint.plugin.core - INFO - Found 10 plugin(s) providing 8 mixin implementations, 3 hook handlers
2019-04-08 18:57:31,626 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 18:57:31,680 - octoprint.server - INFO - Intermediary server started
2019-04-08 18:57:31,681 - 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-04-08 18:57:32,251 - octoprint.plugin.core - INFO - Found 10 plugin(s) providing 8 mixin implementations, 3 hook handlers
2019-04-08 18:57:32,295 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 18:57:32,296 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 18:57:32,346 - octoprint.plugins.softwareupdate - INFO - Version cache was created for another version of OctoPrint, not using it
2019-04-08 18:57:34,559 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:57:35,964 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 18:57:35,966 - 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-04-08 18:57:35,966 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:57:35,968 - octoprint.plugin.core - INFO - Initialized 8 plugin implementation(s)
2019-04-08 18:57:35,974 - octoprint.plugin.core - INFO - 10 plugin(s) registered with the system:
| Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements
| Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
| Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
| Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
| OctoPi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/octopi_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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 18:57:35,992 - 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:
| octopi_support:
| model: unknown
| revision: a020d3
| version: 0.16.0
| python:
| pip: 19.0.1
| version: 2.7.13
| virtualenv: /home/pi/oprint
2019-04-08 18:57:36,001 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 18:57:36,019 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 18:57:36,219 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 18:57:36,700 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 18:57:36,726 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 18:57:36,728 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 18:57:36,733 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 18:57:36,742 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 18:57:36,766 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _http._tcp
2019-04-08 18:57:36,789 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _octoprint._tcp
2019-04-08 18:57:36,794 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 18:57:36,799 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 18:57:36,867 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:57:37,138 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 18:57:37,308 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:57:37,332 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 18:57:37,355 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 18:57:37,823 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 18:57:39,002 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:57:39,852 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 18:57:46,527 - 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-04-08 18:57:46,543 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 18:57:46,757 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 18:57:48,807 - octoprint.server.preemptive_cache - INFO - ... done in 11.47s
2019-04-08 18:57:50,717 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 18:57:51,779 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 18:58:36,435 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 18:58:36,439 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 18:58:36,443 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:58:37,566 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:58:39,201 - octoprint.util.comm - INFO - Ignoring resend request for line 1 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2019-04-08 18:58:39,208 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 18:58:39,217 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 18:58:39,251 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 18:59:11,115 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, telling it to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 18:59:20,030 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing from SD"
2019-04-08 18:59:21,036 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 19:10:44,739 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Operational"
2019-04-08 19:12:31,628 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2019-04-08 19:12:37,079 - octoprint.plugins.softwareupdate - INFO - Starting update of octoprint to 1.3.11rc2...
2019-04-08 19:13:24,494 - octoprint.plugins.softwareupdate - INFO - Update of octoprint to 1.3.11rc2 successful!
2019-04-08 19:13:24,609 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 19:13:24,610 - octoprint.plugins.softwareupdate - INFO - Restarting...
2019-04-08 19:13:28,114 - octoprint.server - INFO - Shutting down...
2019-04-08 19:13:28,380 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 19:13:28,381 - octoprint.events - INFO - Event loop shut down
2019-04-08 19:13:28,391 - octoprint.server - INFO - Goodbye!
2019-04-08 19:13:30,193 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 19:13:30,195 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 19:13:30,196 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 19:13:31,209 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 19:13:32,145 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-04-08 19:13:32,221 - 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-04-08 19:13:33,030 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 19:13:34,127 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 19:13:34,131 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 19:13:34,399 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 19:13:34,426 - octoprint.server - INFO - Intermediary server started
2019-04-08 19:13:34,427 - 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-04-08 19:13:35,080 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 19:13:35,125 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 19:13:35,127 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 19:13:35,162 - octoprint.plugins.softwareupdate - INFO - Version cache was created for another version of OctoPrint, not using it
2019-04-08 19:13:36,614 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 19:13:38,034 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 19:13:38,036 - 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-04-08 19:13:38,037 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 19:13:38,043 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 19:13:38,054 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 19:13:38,071 - 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-04-08 19:13:38,081 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 19:13:38,095 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 19:13:38,497 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 19:13:38,728 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 19:13:38,731 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 19:13:38,732 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2019-04-08 19:13:38,737 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 19:13:38,745 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 19:13:38,765 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 19:13:38,773 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 19:13:39,025 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 19:13:39,091 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 19:13:39,099 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 19:13:39,110 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 19:13:39,181 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 19:13:39,269 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 19:13:39,440 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 19:13:39,809 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 19:13:40,770 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 19:13:40,880 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:13:40,919 - tornado.access - WARNING - 404 GET /api/plugin/octopi_support (::ffff:172.16.12.20) 18.90ms
2019-04-08 19:13:41,008 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 19:13:41,010 - 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-04-08 19:13:41,013 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 19:13:41,406 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 19:13:45,167 - 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-04-08 19:13:45,168 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 19:13:45,187 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2019-04-08 19:13:45,386 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 19:13:46,017 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 11}
2019-04-08 19:13:47,120 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 19:13:55,991 - octoprint.server.preemptive_cache - INFO - ... done in 10.60s
2019-04-08 19:14:55,799 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:14:55,929 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 19:14:56,932 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 19:14:57,057 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:14:58,661 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 19:15:42,532 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:15:42,665 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 19:15:43,608 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 19:15:43,702 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:15:45,300 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 19:16:09,689 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 19:16:09,913 - octoprint.server - INFO - Shutting down...
2019-04-08 19:16:10,082 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2019-04-08 19:16:10,163 - octoprint.events - INFO - Event loop shut down
2019-04-08 19:16:10,208 - octoprint.server - INFO - Goodbye!
2019-04-08 19:16:16,217 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 19:16:16,219 - octoprint.startup - INFO - Starting OctoPrint 1.3.11rc2
2019-04-08 19:16:16,222 - octoprint.startup - INFO - ******************************************************************************
2019-04-08 19:16:17,496 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2019-04-08 19:16:17,562 - 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-04-08 19:16:18,836 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2019-04-08 19:16:20,151 - octoprint.plugins.errortracking - INFO - Initialized error tracking
2019-04-08 19:16:20,155 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 19:16:20,456 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2019-04-08 19:16:20,502 - octoprint.server - INFO - Intermediary server started
2019-04-08 19:16:20,503 - 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-04-08 19:16:21,159 - octoprint.plugin.core - INFO - Found 15 plugin(s) providing 14 mixin implementations, 22 hook handlers
2019-04-08 19:16:21,205 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2019-04-08 19:16:21,207 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2019-04-08 19:16:21,258 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2019-04-08 19:16:23,267 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 19:16:24,735 - octoprint.util.pip - INFO - Version of pip is 19.0.1
2019-04-08 19:16:24,736 - 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-04-08 19:16:24,737 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 19:16:24,743 - octoprint.plugin.core - INFO - Initialized 14 plugin implementation(s)
2019-04-08 19:16:24,755 - octoprint.plugin.core - INFO - 15 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
| Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
| 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
| 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
| Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2019-04-08 19:16:24,774 - 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-04-08 19:16:24,784 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2019-04-08 19:16:24,799 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2019-04-08 19:16:25,256 - octoprint.server - INFO - Shutting down intermediary server...
2019-04-08 19:16:25,284 - octoprint.server - INFO - Intermediary server shut down
2019-04-08 19:16:25,288 - octoprint.events - INFO - Processing startup event, this is our first event
2019-04-08 19:16:25,289 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2019-04-08 19:16:25,292 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2019-04-08 19:16:25,295 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2019-04-08 19:16:25,299 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2019-04-08 19:16:25,301 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2019-04-08 19:16:25,314 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2019-04-08 19:16:25,324 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2019-04-08 19:16:25,335 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2019-04-08 19:16:25,351 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2019-04-08 19:16:25,417 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 19:16:25,878 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 19:16:26,870 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2019-04-08 19:16:26,871 - 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-04-08 19:16:26,872 - octoprint.util.pip - INFO - ==> pip ok -> yes
2019-04-08 19:16:26,911 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2019-04-08 19:16:26,938 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2019-04-08 19:16:27,322 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2019-04-08 19:16:27,594 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://172.16.12.81/'}
2019-04-08 19:16:27,962 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.16.0', 'version': u'1.3.11rc2', 'pip': '19.0.1', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'}
2019-04-08 19:16:28,819 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7}
2019-04-08 19:16:30,613 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 19:16:31,033 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:16:31,643 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 19:16:39,528 - octoprint.server.preemptive_cache - INFO - ... done in 11.93s
2019-04-08 19:17:09,305 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:17:09,438 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:172.16.12.20
2019-04-08 19:17:10,646 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:172.16.12.20
2019-04-08 19:17:10,765 - octoprint.server.util.flask - INFO - Passively logging in user admin from ::ffff:172.16.12.20
2019-04-08 19:17:12,321 - octoprint.server.util.sockjs - INFO - User admin logged in on the socket from client ::ffff:172.16.12.20
2019-04-08 19:17:20,459 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2019-04-08 19:17:20,468 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2019-04-08 19:17:20,482 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 19:17:21,585 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 19:17:23,174 - octoprint.util.comm - INFO - Got a resend request for line 1 which is also our current line. It looks like we just handled a reset and this is a left over of this
2019-04-08 19:17:23,188 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2019-04-08 19:17:23,196 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2019-04-08 19:17:23,253 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.7.0 based on Marlin"
2019-04-08 19:17:23,877 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': u'/dev/ttyACM0', 'firmware_name': u'Prusa-Firmware 3.7.0 based on Marlin'}
2019-04-08 19:17:33,273 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: TEST_P~1.GCO, owner: None, user: None
2019-04-08 19:17:34,427 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 19:17:36,756 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2019-04-08 19:17:36,763 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 9s
2019-04-08 19:17:46,688 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 19:21:53,763 - octoprint.util.comm - INFO - Externally triggered heatup detected
2019-04-08 19:22:33,763 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting print from SD"
2019-04-08 19:22:33,770 - octoprint.printer.standard.job - INFO - Print job started - origin: sdcard, path: test_p~1.gco, owner: None, user: None
2019-04-08 19:22:34,441 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17'}
2019-04-08 19:22:34,669 - octoprint.util.comm - INFO - Changing monitoring state from "Starting print from SD" to "Printing from SD"
2019-04-08 19:22:56,367 - octoprint.printer.standard - ERROR - Looks like something crashed inside the state update worker. Please report this on the OctoPrint issue tracker (make sure to include logs!)
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1471, in _work
data = self.get_current_data()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1481, in get_current_data
self._progress = self._get_current_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 1407, in _get_current_progress
return self._on_get_progress()
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/standard.py", line 862, in _updateProgressDataCallback
statisticalTotalPrintTimeType)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 106, in estimate
estimatedTotalPrintTime = self.estimate_total(progress, cleanedPrintTime)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 166, in estimate_total
return self._data.update(printTime / progress)
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 207, in update
if -1.0 * self._threshold < self.average_distance < self._threshold:
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/printer/estimation.py", line 239, in average_distance
return sum(self._distances) / len(self._distances)
ZeroDivisionError: division by zero
2019-04-08 19:28:19,419 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Finishing"
2019-04-08 19:28:19,429 - octoprint.printer.standard.job - INFO - Print job done - origin: sdcard, path: test_p~1.gco, owner: None
2019-04-08 19:28:20,098 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'sdcard', 'file': '61b53313e9fb83b1d2bd8320047c14d3068cfd17', 'elapsed': 345}
2019-04-08 19:28:33,108 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment