intermitant gpio buttons #335

Open
opened 2020-08-02 17:20:06 +01:00 by tonywright · 4 comments
tonywright commented 2020-08-02 17:20:06 +01:00 (Migrated from github.com)

Hi, I have the Enclosure plug in all set up on a Raspberry Pi 4, 4Gb. Pressing a button (Connected between +3.3 and gpio pi via a resistor, on pin 17 BCM) only works on "rare" occasions. I can see the gpio input is changing every time I press the button by using "GPIO readall" on the command line, but octoprint does not respond very often.

Obviously the connections are correct because it does occasionally work if I sit there constantly pressing the button.
On the rare times it does work, it then sometimes works multiple times for one click.

I am running the latest version of the plugin, 4.13.1, the raspberry pi is only running octoprint. The command the button is sending is a g-code for "Home" (I have 4 other buttons set up and they all behave with the same indifference to me pressing them)

I have turned on the debugging mode but nothing seems to appear in the logs except the command (when it does pickup the gpio change)

Any ideas if there is anything else required to get this to work correctly?

Thanks,

Tony

Hi, I have the Enclosure plug in all set up on a Raspberry Pi 4, 4Gb. Pressing a button (Connected between +3.3 and gpio pi via a resistor, on pin 17 BCM) only works on "rare" occasions. I can see the gpio input is changing every time I press the button by using "GPIO readall" on the command line, but octoprint does not respond very often. Obviously the connections are correct because it does occasionally work if I sit there constantly pressing the button. On the rare times it does work, it then sometimes works multiple times for one click. I am running the latest version of the plugin, 4.13.1, the raspberry pi is only running octoprint. The command the button is sending is a g-code for "Home" (I have 4 other buttons set up and they all behave with the same indifference to me pressing them) I have turned on the debugging mode but nothing seems to appear in the logs except the command (when it does pickup the gpio change) Any ideas if there is anything else required to get this to work correctly? Thanks, Tony
vitormhenrique commented 2020-10-19 20:41:59 +01:00 (Migrated from github.com)

I must say that this is probably because of wiring as I never seen this issue....
are you using pull up / down resistors?
have pictures of your wiring?

I must say that this is probably because of wiring as I never seen this issue.... are you using pull up / down resistors? have pictures of your wiring?
thestephenmarshall commented 2020-11-20 20:13:17 +00:00 (Migrated from github.com)

This is not likely a wiring issue. Looks like there were some errors related to threading:

2020-11-20 15:45:41,543 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 15:45:41,551 - octoprint.server - INFO - --- Log roll over detected ---------------------------------------------------
2020-11-20 15:45:41,552 - octoprint.server - INFO - OctoPrint 1.4.2
2020-11-20 15:45:41,558 - octoprint.plugin.core - INFO - 26 plugin(s) registered with the system:
| !Access Anywhere - The Spaghetti Detective (1.3.3) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_notification
|  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
|  Arc-Welder (1.0.0+u.bb71e8f) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_arc_welder
|  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
| !Detailed Progress (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  Enclosure Plugin (4.13.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure
|  Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
|  File Check (2020.8.7) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_file_check
|  Firmware Check (2020.9.23) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.7.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmwareupdater
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Login UI (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/loginui
|  Macro (0.3.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_macro
|  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
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_themeify
|  TouchUI (0.3.16) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2020-11-20 15:45:41,581 - octoprint.environment - INFO - Detected environment is Python 2.7.16 under Linux (linux2). Details:
|  hardware:
|      cores: 4
|      freq: 1200.0
|      ram: 917016576
|  os:
|      id: linux
|      platform: linux2
|  plugins:
|      pi_support:
|          model: Raspberry Pi 3 Model B Rev 1.2
|          octopi_version: 0.17.0
|  python:
|      pip: 19.3.1
|      version: 2.7.16
|      virtualenv: /home/pi/oprint
2020-11-20 15:45:41,581 - octoprint.server - INFO - ------------------------------------------------------------------------------
2020-11-20 15:47:05,390 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 15:47:05,393 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen
2020-11-20 15:47:05,396 - octoprint.access.users - INFO - Logged out user: stephen
2020-11-20 15:47:05,399 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 15:47:06,261 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 15:47:06,264 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen
2020-11-20 15:47:06,267 - octoprint.access.users - INFO - Logged out user: stephen
2020-11-20 15:47:06,269 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 15:47:06,959 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 15:47:07,005 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 15:47:07,006 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen
2020-11-20 15:47:07,007 - octoprint.access.users - INFO - Logged out user: stephen
2020-11-20 15:47:07,009 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 15:47:09,234 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 15:47:13,658 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 16:00:41,546 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 16:01:40,058 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration.gcode
2020-11-20 16:01:40,063 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration.gcode
2020-11-20 16:01:41,097 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration.gcode, owner: stephen, user: stephen
2020-11-20 16:01:43,157 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration.gcode finished, needed 3.10s
2020-11-20 16:05:38,674 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 16:05:38,682 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration.gcode, owner: stephen, user: stephen
2020-11-20 16:05:38,694 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 16:06:18,757 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 16:15:41,549 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 16:30:41,551 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 16:45:41,553 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 17:00:41,555 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 17:09:06,848 - octoprint.util.comm - INFO - Finished in 3808.174 s.
2020-11-20 17:09:06,852 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing"
2020-11-20 17:09:06,868 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: acceleration.gcode, owner: stephen
2020-11-20 17:09:06,895 - octoprint.plugin - ERROR - Error while calling plugin enclosure
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin
    result = getattr(plugin, method)(*args, **kwargs)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event
    file_name = os.path.basename(payload["file"])
KeyError: 'file'
2020-11-20 17:09:09,835 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2020-11-20 17:13:11,383 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 17:13:14,868 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration_(1).gcode
2020-11-20 17:13:14,881 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration_(1).gcode
2020-11-20 17:13:16,291 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration_(1).gcode, owner: stephen, user: stephen
2020-11-20 17:13:17,995 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration_(1).gcode finished, needed 3.13s
2020-11-20 17:14:30,434 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 17:14:33,144 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration_(2).gcode
2020-11-20 17:14:33,152 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration_(2).gcode
2020-11-20 17:14:36,367 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration_(2).gcode finished, needed 3.22s
2020-11-20 17:14:38,533 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen
2020-11-20 17:14:40,360 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 17:14:40,374 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen
2020-11-20 17:14:40,405 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 17:15:10,337 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 17:15:41,557 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 17:16:38,739 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling"
2020-11-20 17:16:38,782 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen
2020-11-20 17:16:38,813 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational"
2020-11-20 17:17:11,103 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 17:17:11,117 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen
2020-11-20 17:17:11,146 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 17:17:40,927 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 17:30:41,558 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 17:45:41,560 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 17:46:27,176 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 18:00:41,563 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 18:15:41,566 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 18:18:38,245 - octoprint.util.comm - INFO - Finished in 3687.152 s.
2020-11-20 18:18:38,249 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing"
2020-11-20 18:18:38,266 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: acceleration_(2).gcode, owner: stephen
2020-11-20 18:18:38,283 - octoprint.plugin - ERROR - Error while calling plugin enclosure
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin
    result = getattr(plugin, method)(*args, **kwargs)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event
    file_name = os.path.basename(payload["file"])
KeyError: 'file'
2020-11-20 18:18:41,234 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2020-11-20 18:18:58,546 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.248
2020-11-20 18:18:58,614 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.248
2020-11-20 18:18:58,618 - octoprint.access.users - INFO - Cleaning up user session 173036782D4149CE80AD6B8872082F96 for user stephen
2020-11-20 18:18:58,619 - octoprint.access.users - INFO - Logged out user: stephen
2020-11-20 18:18:58,620 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen
2020-11-20 18:18:58,622 - octoprint.access.users - INFO - Logged out user: stephen
2020-11-20 18:18:58,623 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:18:58,703 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.248
2020-11-20 18:20:11,096 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.248
2020-11-20 18:22:14,453 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:22:14,457 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:22:15,531 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:22:15,533 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:22:16,299 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 18:22:16,362 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:22:16,367 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:22:19,208 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 18:22:25,561 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 18:30:33,196 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:30:33,205 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:30:37,185 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:30:41,569 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 18:30:45,450 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.26s
2020-11-20 18:31:34,574 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 18:33:02,770 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:33:02,771 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:33:04,513 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:33:04,515 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:33:05,221 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 18:33:05,255 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 18:33:05,257 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:33:07,077 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.56s
2020-11-20 18:33:07,924 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.59s
2020-11-20 18:33:08,609 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.55s
2020-11-20 18:33:09,420 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.74s
2020-11-20 18:33:10,098 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.56s
2020-11-20 18:33:11,206 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2020-11-20 18:33:11,657 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 18:33:17,482 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 18:33:22,101 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:33:22,104 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:33:23,376 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:33:24,565 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 18:33:24,574 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:33:24,595 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 18:33:34,585 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.48s
2020-11-20 18:33:54,554 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 18:34:32,324 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling"
2020-11-20 18:34:32,352 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:34:48,985 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational"
2020-11-20 18:35:17,118 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 18:35:17,144 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:35:17,174 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 18:35:21,470 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Cancelling"
2020-11-20 18:35:21,508 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:35:27,196 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/util/comm.py", line 2916, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/util/comm.py", line 5069, in readline
    c = self.read(1)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/serial/serialposix.py", line 501, in read
    'device reports readiness to read but returned no data '
SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2020-11-20 18:35:27,200 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2020-11-20 18:35:27,224 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:2916)"
2020-11-20 18:35:27,235 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2020-11-20 18:35:40,839 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2020-11-20 18:35:40,906 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@250000
2020-11-20 18:35:40,907 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000
2020-11-20 18:35:40,910 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000
2020-11-20 18:35:40,918 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2020-11-20 18:35:40,924 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 18:35:40,932 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2020-11-20 18:35:40,941 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 18:35:40,955 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2020-11-20 18:35:40,957 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2020-11-20 18:35:41,032 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020"
2020-11-20 18:35:41,096 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2020-11-20 18:35:49,223 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:35:51,011 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 18:36:23,494 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:36:23,498 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode
2020-11-20 18:36:30,510 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2020-11-20 18:36:35,595 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s
2020-11-20 18:36:35,768 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.27s
2020-11-20 18:36:50,530 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:36:51,584 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 18:36:51,598 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen
2020-11-20 18:36:51,613 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 18:37:27,137 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 18:39:18,262 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 18:40:10,573 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.248
2020-11-20 18:40:10,636 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.248
2020-11-20 18:40:10,639 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 18:40:10,701 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.248
2020-11-20 18:40:57,121 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.248
2020-11-20 18:45:41,572 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 18:57:55,867 - octoprint.util.comm - INFO - Finished in 1264.284 s.
2020-11-20 18:57:55,869 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing"
2020-11-20 18:57:55,884 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen
2020-11-20 18:57:55,897 - octoprint.plugin - ERROR - Error while calling plugin enclosure
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin
    result = getattr(plugin, method)(*args, **kwargs)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event
    file_name = os.path.basename(payload["file"])
KeyError: 'file'
2020-11-20 18:58:03,547 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2020-11-20 19:00:12,623 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:00:12,625 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:00:13,943 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:00:13,945 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:00:14,585 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:00:14,617 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:00:14,618 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:00:17,528 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 19:00:41,573 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 19:05:14,936 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 19:06:57,877 - octoprint.plugins.enclosure - INFO - Setting GPIO pin 12 as PWM
2020-11-20 19:06:57,878 - octoprint.plugins.enclosure - WARNING - An exception of type RuntimeError occurred on log_error. Arguments:
('A PWM object already exists for this GPIO channel',)
2020-11-20 19:07:51,432 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode
2020-11-20 19:07:51,442 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --g90-extruder /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode
2020-11-20 19:07:58,550 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen
2020-11-20 19:07:59,588 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.aw.gcode
2020-11-20 19:07:59,592 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --g90-extruder /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.aw.gcode
2020-11-20 19:08:10,520 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.aw.gcode finished, needed 10.93s
2020-11-20 19:11:51,828 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 19:11:51,843 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen
2020-11-20 19:11:51,865 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:11:52,204 - tornado.access - WARNING - 409 POST /api/job (::ffff:192.168.1.212) 21.46ms
2020-11-20 19:12:23,763 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 19:13:19,375 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling"
2020-11-20 19:13:19,415 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen
2020-11-20 19:13:20,409 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational"
2020-11-20 19:13:54,450 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2020-11-20 19:13:54,464 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen
2020-11-20 19:13:54,486 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:14:28,258 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2020-11-20 19:15:41,575 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 19:28:00,201 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:28:00,203 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:28:00,367 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 19:28:00,877 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:28:00,927 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:28:00,929 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:28:03,291 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 19:29:21,652 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:29:21,653 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:29:21,879 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 19:29:22,383 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:29:22,431 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:29:22,433 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:29:24,879 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 19:30:41,580 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-11-20 19:35:08,887 - octoprint.util.comm - INFO - Finished in 1274.439 s.
2020-11-20 19:35:08,889 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing"
2020-11-20 19:35:08,899 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen
2020-11-20 19:35:08,904 - octoprint.plugin - ERROR - Error while calling plugin enclosure
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin
    result = getattr(plugin, method)(*args, **kwargs)
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1551, in on_event
    self.run_tasks()
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1582, in run_tasks
    task['thread'].start()
  File "/usr/lib/python2.7/threading.py", line 730, in start
    raise RuntimeError("threads can only be started once")
RuntimeError: threads can only be started once
2020-11-20 19:35:16,656 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2020-11-20 19:35:34,383 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a
2020-11-20 19:35:38,205 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline"
2020-11-20 19:35:38,227 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2020-11-20 19:35:44,067 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2020-11-20 19:35:44,086 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000
2020-11-20 19:35:44,112 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2020-11-20 19:35:44,121 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:35:44,125 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:35:44,133 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2020-11-20 19:35:44,142 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:35:44,156 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2020-11-20 19:35:44,157 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2020-11-20 19:35:44,165 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020"
2020-11-20 19:35:44,178 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2020-11-20 19:36:14,102 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:36:14,104 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:36:15,489 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:36:15,491 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:36:16,096 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 19:36:16,776 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:36:16,808 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:36:16,809 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:36:19,124 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 19:36:33,662 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now
2020-11-20 19:36:33,958 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 19:36:34,230 - octoprint.server - INFO - Shutting down...
2020-11-20 19:36:35,123 - octoprint.server - INFO - Calling on_shutdown on plugins
2020-11-20 19:36:35,124 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2020-11-20 19:36:35,128 - octoprint.events - INFO - Event loop shut down
2020-11-20 19:36:35,503 - octoprint.server - INFO - Goodbye!
2020-11-20 19:36:43,874 - octoprint.startup - INFO - ******************************************************************************
2020-11-20 19:36:43,877 - octoprint.startup - INFO - Starting OctoPrint 1.4.2
2020-11-20 19:36:43,877 - octoprint.startup - INFO - ******************************************************************************
2020-11-20 19:36:44,892 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: offline
2020-11-20 19:36:44,893 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is not working
2020-11-20 19:36:44,894 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is not working
2020-11-20 19:36:44,900 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2020-11-20 19:36:44,973 - 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...
2020-11-20 19:36:47,376 - octoprint.plugin.core - INFO - Plugin Access Anywhere - The Spaghetti Detective (1.3.3) is disabled.
2020-11-20 19:36:47,436 - octoprint.plugin.core - INFO - Plugin Remove /dev/ttyS* ports (0.1.0) did not pass check, not loading.
2020-11-20 19:36:47,817 - octoprint.plugin.core - INFO - Plugin Detailed Progress (0.2.5) is disabled.
2020-11-20 19:36:48,071 - octoprint.plugin.core - INFO - Found 26 plugin(s) providing 24 mixin implementations, 42 hook handlers
2020-11-20 19:36:48,575 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2020-11-20 19:36:48,634 - octoprint.server - INFO - Intermediary server started
2020-11-20 19:36:48,636 - 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...
2020-11-20 19:36:48,803 - octoprint.plugin.core - INFO - Plugin Remove /dev/ttyS* ports (0.1.0) did not pass check, not loading.
2020-11-20 19:36:48,818 - octoprint.plugin.core - INFO - Found 26 plugin(s) providing 24 mixin implementations, 42 hook handlers
2020-11-20 19:36:48,856 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2020-11-20 19:36:48,860 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2020-11-20 19:36:48,864 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: u"Need(method='role', value=u'plugin_action_command_notification_show')")
2020-11-20 19:36:48,865 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: u"Need(method='role', value=u'plugin_action_command_notification_clear')")
2020-11-20 19:36:48,866 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: u"Need(method='role', value=u'plugin_action_command_prompt_interact')")
2020-11-20 19:36:48,868 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: u"Need(method='role', value=u'plugin_announcements_read')")
2020-11-20 19:36:48,870 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: u"Need(method='role', value=u'plugin_announcements_manage'), Need(method='role', value=u'plugin_announcements_read')")
2020-11-20 19:36:48,871 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: u"Need(method='role', value=u'plugin_appkeys_admin')")
2020-11-20 19:36:48,872 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: u"Need(method='role', value=u'plugin_backup_access')")
2020-11-20 19:36:48,874 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: u"Need(method='role', value=u'plugin_firmware_check_display')")
2020-11-20 19:36:48,876 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: u"Need(method='role', value=u'plugin_logging_manage')")
2020-11-20 19:36:48,877 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: u"Need(method='role', value=u'plugin_pi_support_check')")
2020-11-20 19:36:48,877 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: u"Need(method='role', value=u'plugin_pluginmanager_manage')")
2020-11-20 19:36:48,879 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: u"Need(method='role', value=u'plugin_pluginmanager_install'), Need(method='role', value=u'plugin_pluginmanager_manage')")
2020-11-20 19:36:48,882 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: u"Need(method='role', value=u'plugin_softwareupdate_check')")
2020-11-20 19:36:48,884 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: u"Need(method='role', value=u'plugin_softwareupdate_update')")
2020-11-20 19:36:49,177 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2020-11-20 19:36:50,501 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-11-20 19:36:51,627 - octoprint.util.pip - INFO - Version of pip is 19.3.1
2020-11-20 19:36:51,630 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2020-11-20 19:36:51,630 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-11-20 19:36:51,634 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s)
2020-11-20 19:36:51,659 - octoprint.plugin.core - INFO - 26 plugin(s) registered with the system:
| !Access Anywhere - The Spaghetti Detective (1.3.3) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_notification
|  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
|  Arc-Welder (1.0.0+u.bb71e8f) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_arc_welder
|  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
| !Detailed Progress (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  Enclosure Plugin (4.13.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure
|  Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking
|  File Check (2020.8.7) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_file_check
|  Firmware Check (2020.9.23) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.7.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmwareupdater
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Login UI (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/loginui
|  Macro (0.3.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_macro
|  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
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_themeify
|  TouchUI (0.3.16) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2020-11-20 19:36:51,678 - octoprint.environment - INFO - Detected environment is Python 2.7.16 under Linux (linux2). Details:
|  hardware:
|      cores: 4
|      freq: 1200.0
|      ram: 917016576
|  os:
|      id: linux
|      platform: linux2
|  plugins:
|      pi_support:
|          model: Raspberry Pi 3 Model B Rev 1.2
|          octopi_version: 0.17.0
|  python:
|      pip: 19.3.1
|      version: 2.7.16
|      virtualenv: /home/pi/oprint
2020-11-20 19:36:51,705 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2020-11-20 19:36:51,735 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2020-11-20 19:36:53,481 - octoprint.server - INFO - Shutting down intermediary server...
2020-11-20 19:36:53,806 - octoprint.server - INFO - Intermediary server shut down
2020-11-20 19:36:53,809 - octoprint.events - INFO - Processing startup event, this is our first event
2020-11-20 19:36:53,810 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2020-11-20 19:36:53,814 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2020-11-20 19:36:53,814 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2020-11-20 19:36:53,851 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2020-11-20 19:36:53,873 - octoprint.server - INFO - Trying to connect to configured serial port None
2020-11-20 19:36:53,928 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2020-11-20 19:36:53,936 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2020-11-20 19:36:53,937 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2020-11-20 19:36:53,964 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@250000
2020-11-20 19:36:53,967 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp
2020-11-20 19:36:53,976 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000
2020-11-20 19:36:53,982 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000
2020-11-20 19:36:53,996 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp
2020-11-20 19:36:54,012 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2020-11-20 19:36:54,036 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2020-11-20 19:36:54,053 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:36:54,073 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2020-11-20 19:36:54,074 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2020-11-20 19:36:54,082 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-11-20 19:36:54,088 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2020-11-20 19:36:54,091 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2020-11-20 19:36:54,108 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020"
2020-11-20 19:36:54,171 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2020-11-20 19:36:54,254 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2020-11-20 19:36:56,230 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-11-20 19:36:56,232 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2020-11-20 19:36:56,247 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2020-11-20 19:36:56,251 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-11-20 19:36:56,262 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 22.5GB. That is considered sufficient for updating.
2020-11-20 19:36:56,483 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2020-11-20 19:36:56,632 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2020-11-20 19:36:57,286 - octoprint.plugins.enclosure - INFO - Setting GPIO mode to BCM
2020-11-20 19:36:57,289 - octoprint.plugins.enclosure - INFO - Setting GPIO pin 12 as PWM
2020-11-20 19:36:57,304 - octoprint.plugins.enclosure - INFO - starting PWM on pin 12
2020-11-20 19:36:57,356 - octoprint.plugins.themeify - INFO - Themeify initialized.
2020-11-20 19:36:58,841 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://192.168.1.235/'}
2020-11-20 19:36:59,719 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:36:59,720 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2020-11-20 19:36:59,963 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:36:59,965 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:36:59,996 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
2020-11-20 19:37:21,276 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:37:21,278 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:37:22,228 - octoprint.server.preemptive_cache - INFO - ... done in 14.68s
2020-11-20 19:37:22,230 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://192.168.1.69/'}
2020-11-20 19:37:22,590 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212
2020-11-20 19:37:22,888 - octoprint.server.preemptive_cache - INFO - ... done in 0.66s
2020-11-20 19:37:22,943 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212
2020-11-20 19:37:22,983 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212
2020-11-20 19:37:22,984 - octoprint.access.users - INFO - Logged in user: stephen
2020-11-20 19:37:25,095 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212
This is not likely a wiring issue. Looks like there were some errors related to threading: ``` 2020-11-20 15:45:41,543 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 15:45:41,551 - octoprint.server - INFO - --- Log roll over detected --------------------------------------------------- 2020-11-20 15:45:41,552 - octoprint.server - INFO - OctoPrint 1.4.2 2020-11-20 15:45:41,558 - octoprint.plugin.core - INFO - 26 plugin(s) registered with the system: | !Access Anywhere - The Spaghetti Detective (1.3.3) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective | Action Command Notification Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_notification | 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 | Arc-Welder (1.0.0+u.bb71e8f) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_arc_welder | 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 | !Detailed Progress (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress | Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery | Enclosure Plugin (4.13.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure | Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking | File Check (2020.8.7) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_file_check | Firmware Check (2020.9.23) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmware_check | Firmware Updater (1.7.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmwareupdater | GCode Viewer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/gcodeviewer | Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging | Login UI (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/loginui | Macro (0.3.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_macro | 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 | Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate | Themeify (1.2.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_themeify | TouchUI (0.3.16) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui | Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer Prefix legend: ! = disabled, # = blacklisted, * = incompatible 2020-11-20 15:45:41,581 - octoprint.environment - INFO - Detected environment is Python 2.7.16 under Linux (linux2). Details: | hardware: | cores: 4 | freq: 1200.0 | ram: 917016576 | os: | id: linux | platform: linux2 | plugins: | pi_support: | model: Raspberry Pi 3 Model B Rev 1.2 | octopi_version: 0.17.0 | python: | pip: 19.3.1 | version: 2.7.16 | virtualenv: /home/pi/oprint 2020-11-20 15:45:41,581 - octoprint.server - INFO - ------------------------------------------------------------------------------ 2020-11-20 15:47:05,390 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 15:47:05,393 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen 2020-11-20 15:47:05,396 - octoprint.access.users - INFO - Logged out user: stephen 2020-11-20 15:47:05,399 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 15:47:06,261 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 15:47:06,264 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen 2020-11-20 15:47:06,267 - octoprint.access.users - INFO - Logged out user: stephen 2020-11-20 15:47:06,269 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 15:47:06,959 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 15:47:07,005 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 15:47:07,006 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen 2020-11-20 15:47:07,007 - octoprint.access.users - INFO - Logged out user: stephen 2020-11-20 15:47:07,009 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 15:47:09,234 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 15:47:13,658 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 16:00:41,546 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 16:01:40,058 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration.gcode 2020-11-20 16:01:40,063 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration.gcode 2020-11-20 16:01:41,097 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration.gcode, owner: stephen, user: stephen 2020-11-20 16:01:43,157 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration.gcode finished, needed 3.10s 2020-11-20 16:05:38,674 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 16:05:38,682 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration.gcode, owner: stephen, user: stephen 2020-11-20 16:05:38,694 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 16:06:18,757 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 16:15:41,549 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 16:30:41,551 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 16:45:41,553 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 17:00:41,555 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 17:09:06,848 - octoprint.util.comm - INFO - Finished in 3808.174 s. 2020-11-20 17:09:06,852 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2020-11-20 17:09:06,868 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: acceleration.gcode, owner: stephen 2020-11-20 17:09:06,895 - octoprint.plugin - ERROR - Error while calling plugin enclosure Traceback (most recent call last): File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event file_name = os.path.basename(payload["file"]) KeyError: 'file' 2020-11-20 17:09:09,835 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2020-11-20 17:13:11,383 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 17:13:14,868 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration_(1).gcode 2020-11-20 17:13:14,881 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration_(1).gcode 2020-11-20 17:13:16,291 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration_(1).gcode, owner: stephen, user: stephen 2020-11-20 17:13:17,995 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration_(1).gcode finished, needed 3.13s 2020-11-20 17:14:30,434 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 17:14:33,144 - octoprint.filemanager.analysis - INFO - Starting analysis of local:acceleration_(2).gcode 2020-11-20 17:14:33,152 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/acceleration_(2).gcode 2020-11-20 17:14:36,367 - octoprint.filemanager.analysis - INFO - Analysis of entry local:acceleration_(2).gcode finished, needed 3.22s 2020-11-20 17:14:38,533 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen 2020-11-20 17:14:40,360 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 17:14:40,374 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen 2020-11-20 17:14:40,405 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 17:15:10,337 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 17:15:41,557 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 17:16:38,739 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2020-11-20 17:16:38,782 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen 2020-11-20 17:16:38,813 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2020-11-20 17:17:11,103 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 17:17:11,117 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: acceleration_(2).gcode, owner: stephen, user: stephen 2020-11-20 17:17:11,146 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 17:17:40,927 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 17:30:41,558 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 17:45:41,560 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 17:46:27,176 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 18:00:41,563 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 18:15:41,566 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 18:18:38,245 - octoprint.util.comm - INFO - Finished in 3687.152 s. 2020-11-20 18:18:38,249 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2020-11-20 18:18:38,266 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: acceleration_(2).gcode, owner: stephen 2020-11-20 18:18:38,283 - octoprint.plugin - ERROR - Error while calling plugin enclosure Traceback (most recent call last): File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event file_name = os.path.basename(payload["file"]) KeyError: 'file' 2020-11-20 18:18:41,234 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2020-11-20 18:18:58,546 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.248 2020-11-20 18:18:58,614 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.248 2020-11-20 18:18:58,618 - octoprint.access.users - INFO - Cleaning up user session 173036782D4149CE80AD6B8872082F96 for user stephen 2020-11-20 18:18:58,619 - octoprint.access.users - INFO - Logged out user: stephen 2020-11-20 18:18:58,620 - octoprint.access.users - INFO - Cleaning up user session A065206215B64858ACE8A30580234B86 for user stephen 2020-11-20 18:18:58,622 - octoprint.access.users - INFO - Logged out user: stephen 2020-11-20 18:18:58,623 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:18:58,703 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.248 2020-11-20 18:20:11,096 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.248 2020-11-20 18:22:14,453 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:22:14,457 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:22:15,531 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:22:15,533 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:22:16,299 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 18:22:16,362 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:22:16,367 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:22:19,208 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 18:22:25,561 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 18:30:33,196 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:30:33,205 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:30:37,185 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:30:41,569 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 18:30:45,450 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.26s 2020-11-20 18:31:34,574 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 18:33:02,770 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:33:02,771 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:33:04,513 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:33:04,515 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:33:05,221 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 18:33:05,255 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 18:33:05,257 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:33:07,077 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.56s 2020-11-20 18:33:07,924 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.59s 2020-11-20 18:33:08,609 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.55s 2020-11-20 18:33:09,420 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.74s 2020-11-20 18:33:10,098 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.56s 2020-11-20 18:33:11,206 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json 2020-11-20 18:33:11,657 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 18:33:17,482 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 18:33:22,101 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:33:22,104 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:33:23,376 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:33:24,565 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 18:33:24,574 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:33:24,595 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 18:33:34,585 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.48s 2020-11-20 18:33:54,554 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 18:34:32,324 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2020-11-20 18:34:32,352 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:34:48,985 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2020-11-20 18:35:17,118 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 18:35:17,144 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:35:17,174 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 18:35:21,470 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Cancelling" 2020-11-20 18:35:21,508 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:35:27,196 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port Traceback (most recent call last): File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/util/comm.py", line 2916, in _readline ret = self._serial.readline() File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/util/comm.py", line 5069, in readline c = self.read(1) File "/home/pi/oprint/local/lib/python2.7/site-packages/serial/serialposix.py", line 501, in read 'device reports readiness to read but returned no data ' SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?) 2020-11-20 18:35:27,200 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this. 2020-11-20 18:35:27,224 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:2916)" 2020-11-20 18:35:27,235 - octoprint.plugins.action_command_notification - INFO - Notifications cleared 2020-11-20 18:35:40,839 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection" 2020-11-20 18:35:40,906 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@250000 2020-11-20 18:35:40,907 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000 2020-11-20 18:35:40,910 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000 2020-11-20 18:35:40,918 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s 2020-11-20 18:35:40,924 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 18:35:40,932 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational" 2020-11-20 18:35:40,941 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 18:35:40,955 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event 2020-11-20 18:35:40,957 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set 2020-11-20 18:35:41,032 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020" 2020-11-20 18:35:41,096 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting 2020-11-20 18:35:49,223 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:35:51,011 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 18:36:23,494 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:36:23,498 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode 2020-11-20 18:36:30,510 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly 2020-11-20 18:36:35,595 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s 2020-11-20 18:36:35,768 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.gcode finished, needed 12.27s 2020-11-20 18:36:50,530 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:36:51,584 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 18:36:51,598 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen, user: stephen 2020-11-20 18:36:51,613 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 18:37:27,137 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 18:39:18,262 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 18:40:10,573 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.248 2020-11-20 18:40:10,636 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.248 2020-11-20 18:40:10,639 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 18:40:10,701 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.248 2020-11-20 18:40:57,121 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.248 2020-11-20 18:45:41,572 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 18:57:55,867 - octoprint.util.comm - INFO - Finished in 1264.284 s. 2020-11-20 18:57:55,869 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2020-11-20 18:57:55,884 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: CE5_test-cylinder-Cylinder.gcode, owner: stephen 2020-11-20 18:57:55,897 - octoprint.plugin - ERROR - Error while calling plugin enclosure Traceback (most recent call last): File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1573, in on_event file_name = os.path.basename(payload["file"]) KeyError: 'file' 2020-11-20 18:58:03,547 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2020-11-20 19:00:12,623 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:00:12,625 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:00:13,943 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:00:13,945 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:00:14,585 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:00:14,617 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:00:14,618 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:00:17,528 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 19:00:41,573 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 19:05:14,936 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 19:06:57,877 - octoprint.plugins.enclosure - INFO - Setting GPIO pin 12 as PWM 2020-11-20 19:06:57,878 - octoprint.plugins.enclosure - WARNING - An exception of type RuntimeError occurred on log_error. Arguments: ('A PWM object already exists for this GPIO channel',) 2020-11-20 19:07:51,432 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.gcode 2020-11-20 19:07:51,442 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --g90-extruder /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.gcode 2020-11-20 19:07:58,550 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen 2020-11-20 19:07:59,588 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE5_test-cylinder-Cylinder.aw.gcode 2020-11-20 19:07:59,592 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --g90-extruder /home/pi/.octoprint/uploads/CE5_test-cylinder-Cylinder.aw.gcode 2020-11-20 19:08:10,520 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE5_test-cylinder-Cylinder.aw.gcode finished, needed 10.93s 2020-11-20 19:11:51,828 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 19:11:51,843 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen 2020-11-20 19:11:51,865 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:11:52,204 - tornado.access - WARNING - 409 POST /api/job (::ffff:192.168.1.212) 21.46ms 2020-11-20 19:12:23,763 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 19:13:19,375 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2020-11-20 19:13:19,415 - octoprint.printer.standard.job - INFO - Print job cancelled - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen 2020-11-20 19:13:20,409 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2020-11-20 19:13:54,450 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting" 2020-11-20 19:13:54,464 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen, user: stephen 2020-11-20 19:13:54,486 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:14:28,258 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing" 2020-11-20 19:15:41,575 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 19:28:00,201 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:28:00,203 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:28:00,367 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 19:28:00,877 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:28:00,927 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:28:00,929 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:28:03,291 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 19:29:21,652 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:29:21,653 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:29:21,879 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 19:29:22,383 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:29:22,431 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:29:22,433 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:29:24,879 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 19:30:41,580 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2020-11-20 19:35:08,887 - octoprint.util.comm - INFO - Finished in 1274.439 s. 2020-11-20 19:35:08,889 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2020-11-20 19:35:08,899 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: CE5_test-cylinder-Cylinder.aw.gcode, owner: stephen 2020-11-20 19:35:08,904 - octoprint.plugin - ERROR - Error while calling plugin enclosure Traceback (most recent call last): File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/plugin/__init__.py", line 230, in call_plugin result = getattr(plugin, method)(*args, **kwargs) File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1551, in on_event self.run_tasks() File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure/__init__.py", line 1582, in run_tasks task['thread'].start() File "/usr/lib/python2.7/threading.py", line 730, in start raise RuntimeError("threads can only be started once") RuntimeError: threads can only be started once 2020-11-20 19:35:16,656 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2020-11-20 19:35:34,383 - octoprint.printer.standard.job - INFO - Print job deselected - user: n/a 2020-11-20 19:35:38,205 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline" 2020-11-20 19:35:38,227 - octoprint.plugins.action_command_notification - INFO - Notifications cleared 2020-11-20 19:35:44,067 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection" 2020-11-20 19:35:44,086 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000 2020-11-20 19:35:44,112 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting" 2020-11-20 19:35:44,121 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:35:44,125 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:35:44,133 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational" 2020-11-20 19:35:44,142 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:35:44,156 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event 2020-11-20 19:35:44,157 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set 2020-11-20 19:35:44,165 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020" 2020-11-20 19:35:44,178 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting 2020-11-20 19:36:14,102 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:36:14,104 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:36:15,489 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:36:15,491 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:36:16,096 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 19:36:16,776 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:36:16,808 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:36:16,809 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:36:19,124 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 19:36:33,662 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now 2020-11-20 19:36:33,958 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 19:36:34,230 - octoprint.server - INFO - Shutting down... 2020-11-20 19:36:35,123 - octoprint.server - INFO - Calling on_shutdown on plugins 2020-11-20 19:36:35,124 - octoprint.events - INFO - Processing shutdown event, this will be our last event 2020-11-20 19:36:35,128 - octoprint.events - INFO - Event loop shut down 2020-11-20 19:36:35,503 - octoprint.server - INFO - Goodbye! 2020-11-20 19:36:43,874 - octoprint.startup - INFO - ****************************************************************************** 2020-11-20 19:36:43,877 - octoprint.startup - INFO - Starting OctoPrint 1.4.2 2020-11-20 19:36:43,877 - octoprint.startup - INFO - ****************************************************************************** 2020-11-20 19:36:44,892 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: offline 2020-11-20 19:36:44,893 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is not working 2020-11-20 19:36:44,894 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is not working 2020-11-20 19:36:44,900 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist 2020-11-20 19:36:44,973 - 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... 2020-11-20 19:36:47,376 - octoprint.plugin.core - INFO - Plugin Access Anywhere - The Spaghetti Detective (1.3.3) is disabled. 2020-11-20 19:36:47,436 - octoprint.plugin.core - INFO - Plugin Remove /dev/ttyS* ports (0.1.0) did not pass check, not loading. 2020-11-20 19:36:47,817 - octoprint.plugin.core - INFO - Plugin Detailed Progress (0.2.5) is disabled. 2020-11-20 19:36:48,071 - octoprint.plugin.core - INFO - Found 26 plugin(s) providing 24 mixin implementations, 42 hook handlers 2020-11-20 19:36:48,575 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval 2020-11-20 19:36:48,634 - octoprint.server - INFO - Intermediary server started 2020-11-20 19:36:48,636 - 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... 2020-11-20 19:36:48,803 - octoprint.plugin.core - INFO - Plugin Remove /dev/ttyS* ports (0.1.0) did not pass check, not loading. 2020-11-20 19:36:48,818 - octoprint.plugin.core - INFO - Found 26 plugin(s) providing 24 mixin implementations, 42 hook handlers 2020-11-20 19:36:48,856 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads... 2020-11-20 19:36:48,860 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully. 2020-11-20 19:36:48,864 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: u"Need(method='role', value=u'plugin_action_command_notification_show')") 2020-11-20 19:36:48,865 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: u"Need(method='role', value=u'plugin_action_command_notification_clear')") 2020-11-20 19:36:48,866 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: u"Need(method='role', value=u'plugin_action_command_prompt_interact')") 2020-11-20 19:36:48,868 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: u"Need(method='role', value=u'plugin_announcements_read')") 2020-11-20 19:36:48,870 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: u"Need(method='role', value=u'plugin_announcements_manage'), Need(method='role', value=u'plugin_announcements_read')") 2020-11-20 19:36:48,871 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: u"Need(method='role', value=u'plugin_appkeys_admin')") 2020-11-20 19:36:48,872 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: u"Need(method='role', value=u'plugin_backup_access')") 2020-11-20 19:36:48,874 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: u"Need(method='role', value=u'plugin_firmware_check_display')") 2020-11-20 19:36:48,876 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: u"Need(method='role', value=u'plugin_logging_manage')") 2020-11-20 19:36:48,877 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: u"Need(method='role', value=u'plugin_pi_support_check')") 2020-11-20 19:36:48,877 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: u"Need(method='role', value=u'plugin_pluginmanager_manage')") 2020-11-20 19:36:48,879 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: u"Need(method='role', value=u'plugin_pluginmanager_install'), Need(method='role', value=u'plugin_pluginmanager_manage')") 2020-11-20 19:36:48,882 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: u"Need(method='role', value=u'plugin_softwareupdate_check')") 2020-11-20 19:36:48,884 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: u"Need(method='role', value=u'plugin_softwareupdate_update')") 2020-11-20 19:36:49,177 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk 2020-11-20 19:36:50,501 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2020-11-20 19:36:51,627 - octoprint.util.pip - INFO - Version of pip is 19.3.1 2020-11-20 19:36:51,630 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2020-11-20 19:36:51,630 - octoprint.util.pip - INFO - ==> pip ok -> yes 2020-11-20 19:36:51,634 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s) 2020-11-20 19:36:51,659 - octoprint.plugin.core - INFO - 26 plugin(s) registered with the system: | !Access Anywhere - The Spaghetti Detective (1.3.3) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_thespaghettidetective | Action Command Notification Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_notification | 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 | Arc-Welder (1.0.0+u.bb71e8f) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_arc_welder | 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 | !Detailed Progress (0.2.5) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress | Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery | Enclosure Plugin (4.13.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_enclosure | Error Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/errortracking | File Check (2020.8.7) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_file_check | Firmware Check (2020.9.23) (bundled) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmware_check | Firmware Updater (1.7.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmwareupdater | GCode Viewer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/gcodeviewer | Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging | Login UI (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/loginui | Macro (0.3.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_macro | 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 | Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate | Themeify (1.2.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_themeify | TouchUI (0.3.16) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui | Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer Prefix legend: ! = disabled, # = blacklisted, * = incompatible 2020-11-20 19:36:51,678 - octoprint.environment - INFO - Detected environment is Python 2.7.16 under Linux (linux2). Details: | hardware: | cores: 4 | freq: 1200.0 | ram: 917016576 | os: | id: linux | platform: linux2 | plugins: | pi_support: | model: Raspberry Pi 3 Model B Rev 1.2 | octopi_version: 0.17.0 | python: | pip: 19.3.1 | version: 2.7.16 | virtualenv: /home/pi/oprint 2020-11-20 19:36:51,705 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets... 2020-11-20 19:36:51,735 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache... 2020-11-20 19:36:53,481 - octoprint.server - INFO - Shutting down intermediary server... 2020-11-20 19:36:53,806 - octoprint.server - INFO - Intermediary server shut down 2020-11-20 19:36:53,809 - octoprint.events - INFO - Processing startup event, this is our first event 2020-11-20 19:36:53,810 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event 2020-11-20 19:36:53,814 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue... 2020-11-20 19:36:53,814 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer... 2020-11-20 19:36:53,851 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue 2020-11-20 19:36:53,873 - octoprint.server - INFO - Trying to connect to configured serial port None 2020-11-20 19:36:53,928 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection" 2020-11-20 19:36:53,936 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder... 2020-11-20 19:36:53,937 - octoprint.server.util.watchdog - INFO - ... initial scan done. 2020-11-20 19:36:53,964 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 1 port/baudrate candidates: /dev/ttyACM0@250000 2020-11-20 19:36:53,967 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _http._tcp 2020-11-20 19:36:53,976 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyACM0, baudrate 250000 2020-11-20 19:36:53,982 - octoprint.util.comm - INFO - Connecting to port /dev/ttyACM0, baudrate 250000 2020-11-20 19:36:53,996 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi' for _octoprint._tcp 2020-11-20 19:36:54,012 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP 2020-11-20 19:36:54,036 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s 2020-11-20 19:36:54,053 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:36:54,073 - octoprint.server - INFO - Listening on http://127.0.0.1:5000 2020-11-20 19:36:54,074 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational" 2020-11-20 19:36:54,082 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2020-11-20 19:36:54,088 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event 2020-11-20 19:36:54,091 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set 2020-11-20 19:36:54,108 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Nov 20 2020" 2020-11-20 19:36:54,171 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting 2020-11-20 19:36:54,254 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid 2020-11-20 19:36:56,230 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2020-11-20 19:36:56,232 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid 2020-11-20 19:36:56,247 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2020-11-20 19:36:56,251 - octoprint.util.pip - INFO - ==> pip ok -> yes 2020-11-20 19:36:56,262 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 22.5GB. That is considered sufficient for updating. 2020-11-20 19:36:56,483 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online 2020-11-20 19:36:56,632 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid 2020-11-20 19:36:57,286 - octoprint.plugins.enclosure - INFO - Setting GPIO mode to BCM 2020-11-20 19:36:57,289 - octoprint.plugins.enclosure - INFO - Setting GPIO pin 12 as PWM 2020-11-20 19:36:57,304 - octoprint.plugins.enclosure - INFO - starting PWM on pin 12 2020-11-20 19:36:57,356 - octoprint.plugins.themeify - INFO - Themeify initialized. 2020-11-20 19:36:58,841 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://192.168.1.235/'} 2020-11-20 19:36:59,719 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:36:59,720 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid 2020-11-20 19:36:59,963 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:36:59,965 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:36:59,996 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 2020-11-20 19:37:21,276 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:37:21,278 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:37:22,228 - octoprint.server.preemptive_cache - INFO - ... done in 14.68s 2020-11-20 19:37:22,230 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://192.168.1.69/'} 2020-11-20 19:37:22,590 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.212 2020-11-20 19:37:22,888 - octoprint.server.preemptive_cache - INFO - ... done in 0.66s 2020-11-20 19:37:22,943 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.212 2020-11-20 19:37:22,983 - octoprint.server.util.flask - INFO - Passively logging in user stephen from ::ffff:192.168.1.212 2020-11-20 19:37:22,984 - octoprint.access.users - INFO - Logged in user: stephen 2020-11-20 19:37:25,095 - octoprint.server.util.sockjs - INFO - User stephen logged in on the socket from client ::ffff:192.168.1.212 ```
thestephenmarshall commented 2020-11-20 20:14:12 +00:00 (Migrated from github.com)

Restarting Octoprint resolves the issue.

Restarting Octoprint resolves the issue.
jacopotediosi commented 2025-05-01 17:50:44 +01:00 (Migrated from github.com)

Hi everyone, the recently merged PR #504 should have fixed this issue. Could you please reinstall the plugin and, if confirmed, close the issue?

Hi everyone, the recently merged PR #504 should have fixed this issue. Could you please reinstall the plugin and, if confirmed, close the issue?
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: Gandalf/OctoPrint-Enclosure#335