OctoPrint / OctoPrint-FirmwareUpdater

OctoPrint plugin for flashing pre-compiled firmware images to a 3D printer.
https://plugins.octoprint.org/plugins/firmwareupdater/
GNU Affero General Public License v3.0
352 stars 76 forks source link

Already Flashing #331

Closed jaymedavis closed 1 year ago

jaymedavis commented 1 year ago

Hello there! Thanks for the tool, very handy.

I started flashing my prusa mk3, forgetting I had a slice engineering mosquito magnum. The flash did not complete succesfully. Trying to flash again gives me the message

Flashing failed
Already flashing.

can you tell me how to cancel this and start over so I can send the correct firmware from slice engineering?

Here is my log:

2023-01-15 16:37:43,510 
2023-01-15 16:37:43,521 /usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmp3tg0ofrz:i
2023-01-15 16:37:44,212 > 
2023-01-15 16:37:44,213 > avrdude: Version 6.3-20171130
2023-01-15 16:37:44,213 >          Copyright (c) 2000-2005 Brian Dean, http://www.bdmicro.com/
2023-01-15 16:37:44,213 >          Copyright (c) 2007-2014 Joerg Wunsch
2023-01-15 16:37:44,213 > 
2023-01-15 16:37:44,214 >          System wide configuration file is "/etc/avrdude.conf"
2023-01-15 16:37:44,214 >          User configuration file is "/home/pi/.avrduderc"
2023-01-15 16:37:44,214 >          User configuration file does not exist or is not a regular file, skipping
2023-01-15 16:37:44,215 > 
2023-01-15 16:37:44,215 >          Using Port                    : /dev/ttyS0
2023-01-15 16:37:44,215 >          Using Programmer              : wiring
2023-01-15 16:37:44,215 > 
2023-01-15 18:39:14,827 
2023-01-15 18:39:14,829 /usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmpaipvo3d2:i
2023-01-15 18:39:15,510 > 
2023-01-15 18:39:15,511 > avrdude: Version 6.3-20171130
2023-01-15 18:39:15,511 >          Copyright (c) 2000-2005 Brian Dean, http://www.bdmicro.com/
2023-01-15 18:39:15,511 >          Copyright (c) 2007-2014 Joerg Wunsch
2023-01-15 18:39:15,512 > 
2023-01-15 18:39:15,512 >          System wide configuration file is "/etc/avrdude.conf"
2023-01-15 18:39:15,512 >          User configuration file is "/home/pi/.avrduderc"
2023-01-15 18:39:15,512 >          User configuration file does not exist or is not a regular file, skipping
2023-01-15 18:39:15,513 > 
2023-01-15 18:39:15,513 >          Using Port                    : /dev/ttyS0
2023-01-15 18:39:15,513 >          Using Programmer              : wiring
2023-01-15 18:39:15,513 > 
2023-01-15 20:56:02,994 
2023-01-15 20:56:02,996 /usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyAMA0 -D -U flash:w:/tmp/tmpvd2fu7ca:i
2023-01-15 20:56:03,641 > 
2023-01-15 20:56:03,642 > avrdude: Version 6.3-20171130
2023-01-15 20:56:03,642 >          Copyright (c) 2000-2005 Brian Dean, http://www.bdmicro.com/
2023-01-15 20:56:03,643 >          Copyright (c) 2007-2014 Joerg Wunsch
2023-01-15 20:56:03,643 > 
2023-01-15 20:56:03,644 >          System wide configuration file is "/etc/avrdude.conf"
2023-01-15 20:56:03,645 >          User configuration file is "/home/pi/.avrduderc"
2023-01-15 20:56:03,645 >          User configuration file does not exist or is not a regular file, skipping
2023-01-15 20:56:03,646 > 
2023-01-15 20:56:03,646 >          Using Port                    : /dev/ttyAMA0
2023-01-15 20:56:03,647 >          Using Programmer              : wiring
2023-01-15 20:56:03,647 > 
2023-01-15 20:56:08,886 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:08,887 > 
2023-01-15 20:56:13,115 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:13,116 > 
2023-01-15 20:56:17,348 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:17,349 > 
2023-01-15 20:56:21,572 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:21,573 > 
2023-01-15 20:56:25,801 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:25,802 > 
2023-01-15 20:56:30,029 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-15 20:56:30,030 > avrdude: stk500v2_getsync(): timeout communicating with programmer
2023-01-15 20:56:30,031 > 
2023-01-15 20:56:30,031 > avrdude done.  Thank you.
2023-01-15 20:56:30,032 > 
2023-01-15 20:56:30,032 > 
2023-01-15 20:59:44,739 
2023-01-15 20:59:44,743 /usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmpicusswm5:i
2023-01-15 20:59:45,329 > 
2023-01-15 20:59:45,330 > avrdude: Version 6.3-20171130
2023-01-15 20:59:45,330 >          Copyright (c) 2000-2005 Brian Dean, http://www.bdmicro.com/
2023-01-15 20:59:45,331 >          Copyright (c) 2007-2014 Joerg Wunsch
2023-01-15 20:59:45,331 > 
2023-01-15 20:59:45,331 >          System wide configuration file is "/etc/avrdude.conf"
2023-01-15 20:59:45,331 >          User configuration file is "/home/pi/.avrduderc"
2023-01-15 20:59:45,332 >          User configuration file does not exist or is not a regular file, skipping
2023-01-15 20:59:45,332 > 
2023-01-15 20:59:45,332 >          Using Port                    : /dev/ttyS0
2023-01-15 20:59:45,333 >          Using Programmer              : wiring
2023-01-15 20:59:45,333 > 
benlye commented 1 year ago

You probably need to restart OctoPrint (or restart your Raspberry Pi) to clear the 'already flashing' error.

jaymedavis commented 1 year ago

Unfortunately, that didn't help. I tried several times.

benlye commented 1 year ago

Can you post the octoprint log as an attachment? The log above is the firmware updater console log but there will be more info in OctoPrint's log.

jaymedavis commented 1 year ago

certainly.

this may be what you are looking for

2023-01-15 20:56:02,717 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 20:56:02,732 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 20:56:02,734 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyAMA0
2023-01-15 20:56:02,759 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 20:56:02,948 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
2023-01-15 20:56:02,993 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyAMA0 -D -U flash:w:/tmp/tmpvd2fu7ca:i' in /usr/bin
2023-01-15 20:56:30,034 - octoprint.plugins.firmwareupdater - ERROR - Flashing failed. Timeout communicating with programmer.

here's the whole thing


2023-01-14 19:42:49,380 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 19:42:49,388 - octoprint.server - INFO - --- Log roll over detected ---------------------------------------------------
2023-01-14 19:42:49,388 - octoprint.server - INFO - OctoPrint 1.8.6
2023-01-14 19:42:49,392 - octoprint.plugin.core - INFO - 23 plugin(s) registered with the system:
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/discovery
|  Error Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  Event Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/eventmanager
|  File Check (2021.2.23) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2021.10.11) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.13.3) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
|  Floating Navbar (0.3.7) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_floatingnavbar
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
|  OctoApp (1.1.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_octoapp
|  Pi Support Plugin (2022.6.13) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Preheat Button (0.8.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_preheat
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_themeify
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2023-01-14 19:42:49,414 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|    cores: 4
|    freq: 1200.0
|    ram: 383967232
|  os:
|    bits: 32
|    id: linux
|    platform: linux
|  plugins:
|    pi_support:
|      model: Raspberry Pi Zero 2 Rev 1.0
|      octopi_version: 0.18.0
|      throttle_check_enabled: true
|      throttle_check_functional: true
|      throttle_state: '0x0'
|  python:
|    pip: 20.3.3
|    version: 3.7.3
|    virtualenv: /home/pi/oprint
2023-01-14 19:42:49,415 - octoprint.server - INFO - ------------------------------------------------------------------------------
2023-01-14 19:43:00,368 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0', 'plugins': 'themeify:1.2.2,preheat:0.8.0,floatingnavbar:0.3.7,firmwareupdater:1.13.3,octoapp:1.1.0'}
2023-01-14 19:43:04,360 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 432016, 'printer_state': 'OPERATIONAL'}
2023-01-14 19:57:49,381 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 19:58:04,398 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 432916, 'printer_state': 'OPERATIONAL'}
2023-01-14 20:12:49,383 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 20:13:04,399 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 433816, 'printer_state': 'OPERATIONAL'}
2023-01-14 20:27:49,384 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 20:28:04,326 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 434716, 'printer_state': 'OPERATIONAL'}
2023-01-14 20:42:49,385 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 20:43:04,421 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 435616, 'printer_state': 'OPERATIONAL'}
2023-01-14 20:57:49,386 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 20:58:04,425 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 436516, 'printer_state': 'OPERATIONAL'}
2023-01-14 21:12:49,388 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 21:13:04,459 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 437416, 'printer_state': 'OPERATIONAL'}
2023-01-14 21:27:49,389 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 21:28:04,482 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 438316, 'printer_state': 'OPERATIONAL'}
2023-01-14 21:42:49,390 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 21:43:04,449 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 439216, 'printer_state': 'OPERATIONAL'}
2023-01-14 21:57:49,392 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 21:58:04,550 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 440116, 'printer_state': 'OPERATIONAL'}
2023-01-14 22:12:49,393 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 22:13:04,415 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 441016, 'printer_state': 'OPERATIONAL'}
2023-01-14 22:27:49,395 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 22:28:04,492 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 441916, 'printer_state': 'OPERATIONAL'}
2023-01-14 22:42:49,396 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 22:43:04,450 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 442816, 'printer_state': 'OPERATIONAL'}
2023-01-14 22:57:49,398 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 22:58:04,457 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 443716, 'printer_state': 'OPERATIONAL'}
2023-01-14 23:12:49,404 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 23:13:04,508 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 444616, 'printer_state': 'OPERATIONAL'}
2023-01-14 23:27:49,405 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 23:28:04,490 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 445516, 'printer_state': 'OPERATIONAL'}
2023-01-14 23:42:49,407 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 23:43:04,489 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 446416, 'printer_state': 'OPERATIONAL'}
2023-01-14 23:57:49,408 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-14 23:58:04,525 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 447316, 'printer_state': 'OPERATIONAL'}
2023-01-15 00:12:49,410 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 00:13:04,548 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 448216, 'printer_state': 'OPERATIONAL'}
2023-01-15 00:27:49,411 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 00:28:04,529 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 449116, 'printer_state': 'OPERATIONAL'}
2023-01-15 00:42:49,412 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 00:43:04,497 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 450016, 'printer_state': 'OPERATIONAL'}
2023-01-15 00:57:49,419 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 00:58:04,523 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 450916, 'printer_state': 'OPERATIONAL'}
2023-01-15 01:12:49,420 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 01:13:04,572 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 451816, 'printer_state': 'OPERATIONAL'}
2023-01-15 01:27:49,422 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 01:28:04,545 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 452716, 'printer_state': 'OPERATIONAL'}
2023-01-15 01:42:49,423 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 01:43:04,566 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 453616, 'printer_state': 'OPERATIONAL'}
2023-01-15 01:57:49,424 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 01:58:04,556 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 454516, 'printer_state': 'OPERATIONAL'}
2023-01-15 02:12:49,425 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 02:13:04,612 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 455416, 'printer_state': 'OPERATIONAL'}
2023-01-15 02:27:49,432 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 02:28:04,591 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 456316, 'printer_state': 'OPERATIONAL'}
2023-01-15 02:42:49,433 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 02:43:04,590 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 457216, 'printer_state': 'OPERATIONAL'}
2023-01-15 02:57:49,435 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 02:58:04,640 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 458116, 'printer_state': 'OPERATIONAL'}
2023-01-15 03:12:49,436 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 03:13:04,660 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 459016, 'printer_state': 'OPERATIONAL'}
2023-01-15 03:27:49,437 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 03:28:04,690 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 459916, 'printer_state': 'OPERATIONAL'}
2023-01-15 03:42:49,439 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 03:43:04,664 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 460816, 'printer_state': 'OPERATIONAL'}
2023-01-15 03:57:49,440 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 03:58:04,650 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 461716, 'printer_state': 'OPERATIONAL'}
2023-01-15 04:12:49,441 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 04:13:04,682 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 462616, 'printer_state': 'OPERATIONAL'}
2023-01-15 04:27:49,443 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 04:28:04,646 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 463516, 'printer_state': 'OPERATIONAL'}
2023-01-15 04:42:49,444 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 04:43:04,710 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 464416, 'printer_state': 'OPERATIONAL'}
2023-01-15 04:57:49,446 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 04:58:04,682 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 465316, 'printer_state': 'OPERATIONAL'}
2023-01-15 05:12:49,447 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 05:13:04,920 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 466216, 'printer_state': 'OPERATIONAL'}
2023-01-15 05:27:49,449 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 05:28:04,738 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 467116, 'printer_state': 'OPERATIONAL'}
2023-01-15 05:42:49,450 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 05:43:04,695 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 468016, 'printer_state': 'OPERATIONAL'}
2023-01-15 05:57:49,451 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 05:58:04,673 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 468916, 'printer_state': 'OPERATIONAL'}
2023-01-15 06:12:49,453 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 06:13:04,795 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 469816, 'printer_state': 'OPERATIONAL'}
2023-01-15 06:27:49,454 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 06:28:04,757 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 470716, 'printer_state': 'OPERATIONAL'}
2023-01-15 06:42:49,455 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 06:43:04,777 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 471617, 'printer_state': 'OPERATIONAL'}
2023-01-15 06:57:49,456 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 06:58:04,793 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 472517, 'printer_state': 'OPERATIONAL'}
2023-01-15 07:12:49,458 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 07:13:04,797 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 473417, 'printer_state': 'OPERATIONAL'}
2023-01-15 07:27:49,459 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 07:28:04,836 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 474317, 'printer_state': 'OPERATIONAL'}
2023-01-15 07:42:49,460 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 07:43:04,838 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 475217, 'printer_state': 'OPERATIONAL'}
2023-01-15 07:57:49,462 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 07:58:04,854 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 476117, 'printer_state': 'OPERATIONAL'}
2023-01-15 08:12:49,463 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 08:13:04,834 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 477017, 'printer_state': 'OPERATIONAL'}
2023-01-15 08:27:49,464 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 08:28:04,804 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 477917, 'printer_state': 'OPERATIONAL'}
2023-01-15 08:42:49,466 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 08:43:04,916 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 478817, 'printer_state': 'OPERATIONAL'}
2023-01-15 08:57:49,467 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 08:58:04,913 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 479717, 'printer_state': 'OPERATIONAL'}
2023-01-15 09:12:49,469 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 09:13:04,883 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 480617, 'printer_state': 'OPERATIONAL'}
2023-01-15 09:27:49,470 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 09:28:04,881 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 481517, 'printer_state': 'OPERATIONAL'}
2023-01-15 09:42:49,471 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 09:43:04,976 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 482417, 'printer_state': 'OPERATIONAL'}
2023-01-15 09:57:49,473 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 09:58:04,881 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 483317, 'printer_state': 'OPERATIONAL'}
2023-01-15 10:12:49,474 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 10:13:04,894 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 484217, 'printer_state': 'OPERATIONAL'}
2023-01-15 10:27:49,476 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 10:28:04,954 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 485117, 'printer_state': 'OPERATIONAL'}
2023-01-15 10:42:49,477 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 10:43:04,953 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 486017, 'printer_state': 'OPERATIONAL'}
2023-01-15 10:57:49,479 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 10:58:04,928 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 486917, 'printer_state': 'OPERATIONAL'}
2023-01-15 11:12:49,480 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 11:13:04,951 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 487817, 'printer_state': 'OPERATIONAL'}
2023-01-15 11:27:49,481 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 11:28:04,904 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 488717, 'printer_state': 'OPERATIONAL'}
2023-01-15 11:42:49,482 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 11:43:04,990 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 489617, 'printer_state': 'OPERATIONAL'}
2023-01-15 11:57:49,484 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 11:58:05,004 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 490517, 'printer_state': 'OPERATIONAL'}
2023-01-15 12:12:49,485 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 12:13:04,979 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 491417, 'printer_state': 'OPERATIONAL'}
2023-01-15 12:27:49,486 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 12:28:05,105 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 492317, 'printer_state': 'OPERATIONAL'}
2023-01-15 12:42:49,488 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 12:43:05,000 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 493217, 'printer_state': 'OPERATIONAL'}
2023-01-15 12:57:49,489 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 12:58:05,002 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 494117, 'printer_state': 'OPERATIONAL'}
2023-01-15 13:12:49,491 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 13:13:04,980 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 495017, 'printer_state': 'OPERATIONAL'}
2023-01-15 13:27:49,492 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 13:28:04,973 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 495917, 'printer_state': 'OPERATIONAL'}
2023-01-15 13:42:49,493 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 13:43:05,057 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 496817, 'printer_state': 'OPERATIONAL'}
2023-01-15 13:57:49,495 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 13:58:05,013 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 497717, 'printer_state': 'OPERATIONAL'}
2023-01-15 14:12:49,496 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 14:13:05,019 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 498617, 'printer_state': 'OPERATIONAL'}
2023-01-15 14:27:49,498 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 14:28:05,036 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 499517, 'printer_state': 'OPERATIONAL'}
2023-01-15 14:42:49,499 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 14:43:05,068 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 500417, 'printer_state': 'OPERATIONAL'}
2023-01-15 14:57:49,500 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 14:58:05,045 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 501317, 'printer_state': 'OPERATIONAL'}
2023-01-15 15:12:49,502 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 15:13:05,044 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 502217, 'printer_state': 'OPERATIONAL'}
2023-01-15 15:27:49,503 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 15:28:05,059 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 503117, 'printer_state': 'OPERATIONAL'}
2023-01-15 15:42:49,505 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 15:43:05,083 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 504017, 'printer_state': 'OPERATIONAL'}
2023-01-15 15:57:49,506 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 15:58:05,079 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 504917, 'printer_state': 'OPERATIONAL'}
2023-01-15 16:12:49,507 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 16:13:05,151 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 505817, 'printer_state': 'OPERATIONAL'}
2023-01-15 16:27:49,509 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 16:28:05,110 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 506717, 'printer_state': 'OPERATIONAL'}
2023-01-15 16:28:59,988 - octoprint.access.users - INFO - Cleaning up user session 2C107D46B87648CAB46947F2FD9CF097 for user pi
2023-01-15 16:28:59,988 - octoprint.access.users - INFO - Logged out user: pi
2023-01-15 16:29:01,115 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2023-01-15 16:36:27,696 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2023-01-15 16:37:43,049 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 16:37:43,062 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 16:37:43,063 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 16:37:43,087 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 16:37:43,293 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
2023-01-15 16:37:43,294 - octoprint.plugins.firmwareupdater - INFO - Disconnecting from printer
2023-01-15 16:37:43,453 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline"
2023-01-15 16:37:43,496 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2023-01-15 16:37:43,509 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmp3tg0ofrz:i' in /usr/bin
2023-01-15 16:42:49,510 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 16:43:05,044 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 507617, 'printer_state': 'OFFLINE'}
2023-01-15 16:57:49,511 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 16:58:05,055 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 508517, 'printer_state': 'OFFLINE'}
2023-01-15 17:12:49,512 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 17:13:05,081 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 509417, 'printer_state': 'OFFLINE'}
2023-01-15 17:27:49,513 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 17:28:05,073 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 510317, 'printer_state': 'OFFLINE'}
2023-01-15 17:42:49,514 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 17:43:05,117 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 511217, 'printer_state': 'OFFLINE'}
2023-01-15 17:54:46,253 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:54:46,253 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:54:47,503 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 17:54:47,603 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:54:47,604 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:54:50,668 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 17:54:51,327 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2023-01-15 17:54:52,321 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2023-01-15 17:54:53,379 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 17:55:04,146 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 17:55:04,157 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 17:55:04,158 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyAMA0
2023-01-15 17:55:04,177 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 17:55:08,900 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 17:55:08,952 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:08,952 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:09,203 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 17:55:09,266 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 17:55:09,426 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:09,427 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:09,652 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 17:55:09,707 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:09,708 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:12,582 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 17:55:13,932 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 17:55:18,346 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 17:55:18,385 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:18,386 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:18,739 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:18,740 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:19,039 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 17:55:19,093 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 17:55:19,093 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 17:55:20,746 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 17:55:21,941 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 17:55:42,461 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 17:55:42,471 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 17:55:42,471 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 17:55:42,489 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 17:52:41,014 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 17:52:41,017 - octoprint.startup - INFO - Starting OctoPrint 1.8.6
2023-01-15 17:52:41,019 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 17:52:45,938 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2023-01-15 17:52:45,939 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: online
2023-01-15 17:52:45,940 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is working
2023-01-15 17:52:45,941 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is working
2023-01-15 17:52:46,528 - octoprint.startup - INFO - Blacklist processing done, adding 3 blacklisted plugin versions: roomtemp (any), GcodeEditor (>=0.1.1,<=0.2.8), gcodeleveling (>=0.1.0,<=0.1.1)
2023-01-15 17:52:46,554 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2023-01-15 17:52:51,135 - octoprint.plugin.core - ERROR - Error loading plugin onedrive_files
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 1274, in _import_plugin
    module = _load_module(module_name, spec)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 52, in _load_module
    return imp.load_module(name, f, filename, details)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 238, in load_module
    return load_package(name, filename)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 212, in load_package
    return _load(spec)
  File "<frozen importlib._bootstrap>", line 696, in _load
  File "<frozen importlib._bootstrap>", line 677, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 728, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_onedrive_files/__init__.py", line 4, in <module>
    import octo_onedrive.onedrive
ModuleNotFoundError: No module named 'octo_onedrive'
2023-01-15 17:52:52,450 - octoprint.plugin.core - INFO - Found 23 plugin(s) providing 23 mixin implementations, 52 hook handlers
2023-01-15 17:52:52,670 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2023-01-15 17:52:52,992 - octoprint.server - INFO - Intermediary server started
2023-01-15 17:52:53,037 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2023-01-15 17:52:53,200 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2023-01-15 17:52:53,208 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: "Need(method='role', value='plugin_action_command_notification_show')")
2023-01-15 17:52:53,209 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: "Need(method='role', value='plugin_action_command_notification_clear')")
2023-01-15 17:52:53,209 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: "Need(method='role', value='plugin_action_command_prompt_interact')")
2023-01-15 17:52:53,210 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2023-01-15 17:52:53,211 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: "Need(method='role', value='plugin_announcements_manage'), Need(method='role', value='plugin_announcements_read')")
2023-01-15 17:52:53,211 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2023-01-15 17:52:53,212 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_GRANT (needs: "Need(method='role', value='plugin_appkeys_user')")
2023-01-15 17:52:53,212 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2023-01-15 17:52:53,213 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2023-01-15 17:52:53,213 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2023-01-15 17:52:53,217 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_RECEIVE_NOTIFICATIONS (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 17:52:53,220 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_GET_DATA (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 17:52:53,224 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2023-01-15 17:52:53,227 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_LIST (needs: "Need(method='role', value='plugin_pluginmanager_list')")
2023-01-15 17:52:53,229 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2023-01-15 17:52:53,231 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: "Need(method='role', value='plugin_pluginmanager_install'), Need(method='role', value='plugin_pluginmanager_manage')")
2023-01-15 17:52:53,235 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2023-01-15 17:52:53,238 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2023-01-15 17:52:53,241 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CONFIGURE (needs: "Need(method='role', value='plugin_softwareupdate_configure')")
2023-01-15 17:52:54,665 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 17:52:55,684 - octoprint.util.pip - INFO - Version of pip is 20.3.3
2023-01-15 17:52:55,711 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 17:52:55,712 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 17:52:55,912 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2023-01-15 17:52:55,943 - octoprint.plugins.softwareupdate - INFO - Loaded update log from disk
2023-01-15 17:52:56,079 - octoprint.plugins.firmwareupdater - INFO - Python binproto2 package installed: False
2023-01-15 17:52:56,095 - octoprint.plugin.core - INFO - Initialized 23 plugin implementation(s)
2023-01-15 17:52:56,134 - octoprint.plugin.core - INFO - 23 plugin(s) registered with the system:
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/discovery
|  Error Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  Event Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/eventmanager
|  File Check (2021.2.23) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2021.10.11) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.13.3) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
|  Floating Navbar (0.3.7) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_floatingnavbar
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
|  OctoApp (1.1.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_octoapp
|  Pi Support Plugin (2022.6.13) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Preheat Button (0.8.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_preheat
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_themeify
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2023-01-15 17:52:56,179 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|    cores: 4
|    freq: 1200.0
|    ram: 383967232
|  os:
|    bits: 32
|    id: linux
|    platform: linux
|  plugins:
|    pi_support:
|      model: Raspberry Pi Zero 2 Rev 1.0
|      octopi_version: 0.18.0
|      throttle_check_enabled: true
|      throttle_check_functional: true
|      throttle_state: '0x0'
|  python:
|    pip: 20.3.3
|    version: 3.7.3
|    virtualenv: /home/pi/oprint
2023-01-15 17:52:56,207 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2023-01-15 17:52:56,209 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2023-01-15 17:52:56,211 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-manifest.json...
2023-01-15 17:52:56,452 - octoprint.plugins.firmwareupdater - WARNING - The Blueprint of this plugin is relying on the default implementation of is_blueprint_csrf_protected (newly added in OctoPrint 1.8.3), which in a future version will be switched from False to True for security reasons. Plugin authors should ensure they explicitly declare the CSRF protection status in their BlueprintPlugin mixin implementation. Recommendation is to enable CSRF protection and exempt views that must not use it with the octoprint.plugin.BlueprintPlugin.csrf_exempt decorator.
2023-01-15 17:52:56,452 - octoprint.server - WARNING - CSRF Protection for Blueprint of plugin firmwareupdater is DISABLED
2023-01-15 17:52:57,139 - octoprint.plugins.firmwareupdater - INFO - Setting maximum upload size for /flash to 5243904
2023-01-15 17:52:57,140 - octoprint.server - INFO - Shutting down intermediary server...
2023-01-15 17:52:57,514 - octoprint.server - INFO - Intermediary server shut down
2023-01-15 17:52:57,519 - octoprint.events - INFO - Processing startup event, this is our first event
2023-01-15 17:52:57,520 - octoprint.events - INFO - Adding 2 events to queue that were held back before startup event
2023-01-15 17:52:57,527 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2023-01-15 17:52:57,536 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2023-01-15 17:52:57,557 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2023-01-15 17:52:57,682 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 17:52:58,092 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2023-01-15 17:52:58,096 - octoprint.server - INFO - Trying to connect to configured serial port /dev/ttyAMA0
2023-01-15 17:52:58,270 - octoprint.plugins.tracking - INFO - Sent tracking event system_unthrottled, payload: {'throttled_now': False, 'throttled_past': False, 'throttled_mask': 0, 'throttled_voltage_now': False, 'throttled_voltage_past': False, 'throttled_overheat_now': False, 'throttled_overheat_past': False}
2023-01-15 17:52:59,193 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2023-01-15 17:52:59,221 - octoprint.util.comm - INFO - Connecting to port /dev/ttyAMA0, baudrate 115200
2023-01-15 17:52:59,246 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2023-01-15 17:52:59,336 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2023-01-15 17:52:59,367 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2023-01-15 17:52:59,410 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 17:52:59,430 - octoprint.util.comm - WARNING - Received line:
2023-01-15 17:52:59,430 - octoprint.util.comm - WARNING - | o\x00k
2023-01-15 17:52:59,431 - octoprint.util.comm - WARNING - The received line contains at least one null byte character at position 1, this hints at some data corruption going on
2023-01-15 17:53:00,443 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.92s
2023-01-15 17:53:00,486 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._http._tcp.local.' for _http._tcp.local.
2023-01-15 17:53:00,965 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 17:53:00,966 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 17:53:00,966 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 17:53:01,336 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.57s
2023-01-15 17:53:01,420 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._octoprint._tcp.local.' for _octoprint._tcp.local.
2023-01-15 17:53:01,474 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2023-01-15 17:53:01,698 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2023-01-15 17:53:01,912 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2023-01-15 17:53:01,979 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 17:53:02,270 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.65s
2023-01-15 17:53:02,612 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.72s
2023-01-15 17:53:03,086 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 17:53:03,087 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 17:53:03,087 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 17:53:03,144 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.57s
2023-01-15 17:53:03,205 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 53.7GB. That is considered sufficient for updating.
2023-01-15 17:53:03,365 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2023-01-15 17:53:03,375 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.55s
2023-01-15 17:53:03,869 - octoprint.plugins.octoapp - INFO - OctoApp started, updating config
2023-01-15 17:53:03,939 - octoprint.plugins.themeify - INFO - Themeify initialized.
2023-01-15 17:53:04,211 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.59s
2023-01-15 17:53:04,355 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.66s
2023-01-15 17:53:04,467 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 12, 'printer_state': 'CONNECTING'}
2023-01-15 17:53:04,895 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'https://192.168.0.100/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 17:53:05,031 - octoprint.plugins.octoapp - INFO - OctoApp loaded config: {'maxUpdateIntervalSecs': 60, 'updatePercentModulus': 5, 'highPrecisionRangeStart': 5, 'highPrecisionRangeEnd': 5, 'sendNotificationUrl': 'https://europe-west1-octoapp-4e438.cloudfunctions.net/sendNotification'}
2023-01-15 17:53:05,165 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0', 'plugins': 'themeify:1.2.2,preheat:0.8.0,floatingnavbar:0.3.7,firmwareupdater:1.13.3,octoapp:1.1.0'}
2023-01-15 17:53:05,557 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2023-01-15 17:53:05,672 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0'}
2023-01-15 17:57:49,717 - octoprint.server.preemptive_cache - INFO - ... done in 13.64s
2023-01-15 17:57:49,718 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://octopi.local/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 17:57:50,615 - octoprint.server.preemptive_cache - INFO - ... done in 0.90s
2023-01-15 17:58:00,648 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 17:58:00,655 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 17:58:00,661 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2023-01-15 17:58:00,690 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2023-01-15 17:58:00,719 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2023-01-15 17:58:00,777 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 17:58:00,802 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.9.1 based on Marlin"
2023-01-15 17:58:00,803 - octoprint.util.comm - INFO - Detected Prusa firmware, enabling relevant features for issue free communication
2023-01-15 17:58:01,332 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {'firmware_name': 'Prusa-Firmware 3.9.1 based on Marlin', 'printer_port': '/dev/ttyAMA0', 'printer_baudrate': 115200}
2023-01-15 17:59:17,329 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2023-01-15 17:59:24,875 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s
2023-01-15 18:06:39,082 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 18:06:39,212 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 18:06:39,213 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 18:06:39,320 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 18:06:54,419 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 18:06:54,498 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 18:06:54,499 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 18:06:55,706 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 18:07:52,673 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 18:08:04,364 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 641, 'printer_state': 'OPERATIONAL'}
2023-01-15 18:22:52,674 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 18:23:04,327 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 1541, 'printer_state': 'OPERATIONAL'}
2023-01-15 18:30:40,906 - octoprint.util.comm - INFO - Communication timeout while idle, trying to trigger response from printer.
2023-01-15 18:37:52,675 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 18:38:04,387 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 2441, 'printer_state': 'OPERATIONAL'}
2023-01-15 18:38:33,641 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 18:38:35,159 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 18:38:35,159 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 18:38:36,113 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 18:38:36,152 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 18:38:37,551 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 18:38:37,552 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 18:38:38,647 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 18:38:38,695 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 18:38:38,696 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 18:38:40,020 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 18:38:41,576 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 18:39:04,511 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 18:39:04,527 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 18:39:04,527 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 18:39:04,547 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 18:39:04,588 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
2023-01-15 18:39:04,589 - octoprint.plugins.firmwareupdater - INFO - Disconnecting from printer
2023-01-15 18:39:14,697 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline"
2023-01-15 18:39:14,744 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2023-01-15 18:39:14,827 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmpaipvo3d2:i' in /usr/bin
2023-01-15 18:52:52,676 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 18:53:04,318 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 3341, 'printer_state': 'OFFLINE'}
2023-01-15 19:07:52,677 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 19:08:04,340 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 4241, 'printer_state': 'OFFLINE'}
2023-01-15 19:22:52,678 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 19:23:04,371 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 5141, 'printer_state': 'OFFLINE'}
2023-01-15 19:37:52,679 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 19:38:04,392 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 6041, 'printer_state': 'OFFLINE'}
2023-01-15 19:52:52,680 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 19:53:04,379 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 6941, 'printer_state': 'OFFLINE'}
2023-01-15 20:07:52,681 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 20:08:04,360 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7841, 'printer_state': 'OFFLINE'}
2023-01-15 20:13:43,074 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:13:43,393 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:13:43,393 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:13:43,887 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:13:43,887 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:13:44,160 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:13:44,269 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:13:44,269 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:13:46,988 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:13:48,762 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:13:55,024 - octoprint.plugins.firmwareupdater - INFO - Flash in progress, preventing connection to printer
2023-01-15 20:13:55,024 - octoprint.printer.standard - INFO - Connect signalled as handled by plugin firmwareupdater
2023-01-15 20:14:03,064 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:14:03,103 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:14:03,104 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:14:03,598 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:14:03,598 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:14:03,868 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:14:03,925 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:14:03,926 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:14:05,480 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:14:06,710 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:14:10,645 - octoprint.plugins.firmwareupdater - INFO - Flash in progress, preventing connection to printer
2023-01-15 20:14:10,645 - octoprint.printer.standard - INFO - Connect signalled as handled by plugin firmwareupdater
2023-01-15 20:14:20,553 - octoprint.plugins.firmwareupdater - INFO - Flash in progress, preventing connection to printer
2023-01-15 20:14:20,554 - octoprint.printer.standard - INFO - Connect signalled as handled by plugin firmwareupdater
2023-01-15 20:14:25,192 - octoprint.server.api.system - INFO - Performing command for core:reboot: sudo shutdown -r now
2023-01-15 20:14:25,459 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:14:25,493 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:14:25,528 - octoprint.server - INFO - Shutting down...
2023-01-15 20:14:25,541 - octoprint.server - INFO - Calling on_shutdown on plugins
2023-01-15 20:14:25,545 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2023-01-15 20:14:25,735 - octoprint.server.api.system - WARNING - Command for core:reboot failed with return code -15:
! 
! STDOUT:
! 
! 
! STDERR:
2023-01-15 20:14:25,886 - octoprint.plugins.firmwareupdater - ERROR - Flashing failed. Avrdude returned code -15.
2023-01-15 20:14:25,893 - octoprint.plugins.firmwareupdater - INFO - Reconnecting to printer: port=/dev/ttyAMA0, baudrate=115200, profile={'axes': {'e': {'inverted': False, 'speed': 300}, 'x': {'inverted': False, 'speed': 6000}, 'y': {'inverted': False, 'speed': 6000}, 'z': {'inverted': False, 'speed': 200}}, 'color': 'default', 'extruder': {'count': 1, 'defaultExtrusionLength': 5, 'nozzleDiameter': 0.4, 'offsets': [(0.0, 0.0)], 'sharedNozzle': False}, 'heatedBed': True, 'heatedChamber': False, 'id': '_default', 'model': 'MK3S', 'name': 'Prusa', 'volume': {'custom_box': False, 'depth': 210.0, 'formFactor': 'rectangular', 'height': 210.0, 'origin': 'lowerleft', 'width': 250.0}}
2023-01-15 20:14:26,110 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2023-01-15 20:14:26,118 - octoprint.util.comm - INFO - Connecting to port /dev/ttyAMA0, baudrate 115200
2023-01-15 20:14:26,128 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2023-01-15 20:14:26,136 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 20:14:27,072 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2023-01-15 20:14:27,224 - octoprint.plugins.octoapp - WARNING - Failed to get webcam snapshot HTTPConnectionPool(host='127.0.0.1', port=8080): Max retries exceeded with url: /?action=snapshot (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x70ee8a30>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-01-15 20:14:32,292 - octoprint.plugins.octoapp - WARNING - Failed to get webcam snapshot HTTPConnectionPool(host='127.0.0.1', port=8080): Max retries exceeded with url: /?action=snapshot (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x70e96830>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-01-15 20:14:35,873 - octoprint.events - INFO - Event loop shut down
2023-01-15 20:14:35,876 - octoprint.server - INFO - Goodbye!
2023-01-15 20:14:43,811 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 20:14:43,814 - octoprint.startup - INFO - Starting OctoPrint 1.8.6
2023-01-15 20:14:43,817 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 20:14:50,547 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: offline
2023-01-15 20:14:50,547 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is not working
2023-01-15 20:14:50,548 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is not working
2023-01-15 20:14:50,566 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist
2023-01-15 20:14:50,583 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2023-01-15 20:14:55,146 - octoprint.plugin.core - ERROR - Error loading plugin onedrive_files
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 1274, in _import_plugin
    module = _load_module(module_name, spec)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 52, in _load_module
    return imp.load_module(name, f, filename, details)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 238, in load_module
    return load_package(name, filename)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 212, in load_package
    return _load(spec)
  File "<frozen importlib._bootstrap>", line 696, in _load
  File "<frozen importlib._bootstrap>", line 677, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 728, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_onedrive_files/__init__.py", line 4, in <module>
    import octo_onedrive.onedrive
ModuleNotFoundError: No module named 'octo_onedrive'
2023-01-15 20:14:56,313 - octoprint.plugin.core - INFO - Found 23 plugin(s) providing 23 mixin implementations, 52 hook handlers
2023-01-15 20:14:56,533 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2023-01-15 20:14:56,730 - octoprint.server - INFO - Intermediary server started
2023-01-15 20:14:56,897 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2023-01-15 20:14:57,065 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2023-01-15 20:14:57,073 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: "Need(method='role', value='plugin_action_command_notification_show')")
2023-01-15 20:14:57,073 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: "Need(method='role', value='plugin_action_command_notification_clear')")
2023-01-15 20:14:57,074 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: "Need(method='role', value='plugin_action_command_prompt_interact')")
2023-01-15 20:14:57,075 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2023-01-15 20:14:57,075 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: "Need(method='role', value='plugin_announcements_read'), Need(method='role', value='plugin_announcements_manage')")
2023-01-15 20:14:57,076 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2023-01-15 20:14:57,076 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_GRANT (needs: "Need(method='role', value='plugin_appkeys_user')")
2023-01-15 20:14:57,077 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2023-01-15 20:14:57,078 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2023-01-15 20:14:57,078 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2023-01-15 20:14:57,085 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_RECEIVE_NOTIFICATIONS (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 20:14:57,088 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_GET_DATA (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 20:14:57,091 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2023-01-15 20:14:57,094 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_LIST (needs: "Need(method='role', value='plugin_pluginmanager_list')")
2023-01-15 20:14:57,096 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2023-01-15 20:14:57,099 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: "Need(method='role', value='plugin_pluginmanager_manage'), Need(method='role', value='plugin_pluginmanager_install')")
2023-01-15 20:14:57,101 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2023-01-15 20:14:57,103 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2023-01-15 20:14:57,105 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CONFIGURE (needs: "Need(method='role', value='plugin_softwareupdate_configure')")
2023-01-15 20:14:58,745 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:14:59,763 - octoprint.util.pip - INFO - Version of pip is 20.3.3
2023-01-15 20:14:59,791 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:14:59,791 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:14:59,992 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2023-01-15 20:15:00,023 - octoprint.plugins.softwareupdate - INFO - Loaded update log from disk
2023-01-15 20:15:00,160 - octoprint.plugins.firmwareupdater - INFO - Python binproto2 package installed: False
2023-01-15 20:15:00,175 - octoprint.plugin.core - INFO - Initialized 23 plugin implementation(s)
2023-01-15 20:15:00,215 - octoprint.plugin.core - INFO - 23 plugin(s) registered with the system:
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/discovery
|  Error Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  Event Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/eventmanager
|  File Check (2021.2.23) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2021.10.11) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.13.3) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
|  Floating Navbar (0.3.7) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_floatingnavbar
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
|  OctoApp (1.1.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_octoapp
|  Pi Support Plugin (2022.6.13) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Preheat Button (0.8.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_preheat
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_themeify
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2023-01-15 20:15:00,256 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|    cores: 4
|    freq: 1200.0
|    ram: 383967232
|  os:
|    bits: 32
|    id: linux
|    platform: linux
|  plugins:
|    pi_support:
|      model: Raspberry Pi Zero 2 Rev 1.0
|      octopi_version: 0.18.0
|      throttle_check_enabled: true
|      throttle_check_functional: true
|      throttle_state: '0x0'
|  python:
|    pip: 20.3.3
|    version: 3.7.3
|    virtualenv: /home/pi/oprint
2023-01-15 20:15:00,284 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2023-01-15 20:15:00,286 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2023-01-15 20:15:00,288 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-manifest.json...
2023-01-15 20:15:00,525 - octoprint.plugins.firmwareupdater - WARNING - The Blueprint of this plugin is relying on the default implementation of is_blueprint_csrf_protected (newly added in OctoPrint 1.8.3), which in a future version will be switched from False to True for security reasons. Plugin authors should ensure they explicitly declare the CSRF protection status in their BlueprintPlugin mixin implementation. Recommendation is to enable CSRF protection and exempt views that must not use it with the octoprint.plugin.BlueprintPlugin.csrf_exempt decorator.
2023-01-15 20:15:00,526 - octoprint.server - WARNING - CSRF Protection for Blueprint of plugin firmwareupdater is DISABLED
2023-01-15 20:15:01,214 - octoprint.plugins.firmwareupdater - INFO - Setting maximum upload size for /flash to 5243904
2023-01-15 20:15:01,215 - octoprint.server - INFO - Shutting down intermediary server...
2023-01-15 20:15:01,582 - octoprint.server - INFO - Intermediary server shut down
2023-01-15 20:15:01,587 - octoprint.events - INFO - Processing startup event, this is our first event
2023-01-15 20:15:01,588 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2023-01-15 20:15:01,596 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2023-01-15 20:15:01,612 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2023-01-15 20:15:01,675 - octoprint.server - INFO - Trying to connect to configured serial port /dev/ttyAMA0
2023-01-15 20:15:01,717 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2023-01-15 20:15:01,894 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2023-01-15 20:15:01,901 - octoprint.util.comm - INFO - Connecting to port /dev/ttyAMA0, baudrate 115200
2023-01-15 20:15:01,915 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2023-01-15 20:15:01,919 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2023-01-15 20:15:01,925 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2023-01-15 20:15:01,938 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 20:15:02,679 - octoprint.util.comm - WARNING - Received line:
2023-01-15 20:15:02,680 - octoprint.util.comm - WARNING - | e\x00cho:busy: paused for user
2023-01-15 20:15:02,680 - octoprint.util.comm - WARNING - The received line contains at least one null byte character at position 1, this hints at some data corruption going on
2023-01-15 20:15:02,771 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._http._tcp.local.' for _http._tcp.local.
2023-01-15 20:15:03,612 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._octoprint._tcp.local.' for _octoprint._tcp.local.
2023-01-15 20:15:03,631 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2023-01-15 20:15:03,689 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2023-01-15 20:15:03,856 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 20:15:04,306 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:15:04,654 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:15:04,654 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:15:04,809 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2023-01-15 20:15:04,944 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:15:04,945 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:15:04,945 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:15:05,102 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 53.7GB. That is considered sufficient for updating.
2023-01-15 20:15:05,103 - octoprint.plugins.softwareupdate - INFO - Not fetching check overlays, we are offline
2023-01-15 20:15:05,664 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2023-01-15 20:15:05,789 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:15:06,024 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 20:15:08,758 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:15:08,759 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:15:08,759 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:15:09,365 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2023-01-15 20:15:09,437 - octoprint.plugins.octoapp - INFO - OctoApp started, updating config
2023-01-15 20:15:09,606 - octoprint.plugins.themeify - INFO - Themeify initialized.
2023-01-15 20:15:10,335 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0', 'plugins': 'themeify:1.2.2,preheat:0.8.0,floatingnavbar:0.3.7,firmwareupdater:1.13.3,octoapp:1.1.0'}
2023-01-15 20:15:21,374 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2023-01-15 20:15:21,533 - octoprint.plugins.octoapp - INFO - OctoApp loaded config: {'maxUpdateIntervalSecs': 60, 'updatePercentModulus': 5, 'highPrecisionRangeStart': 5, 'highPrecisionRangeEnd': 5, 'sendNotificationUrl': 'https://europe-west1-octoapp-4e438.cloudfunctions.net/sendNotification'}
2023-01-15 20:15:21,778 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://octopi.local/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 20:15:21,901 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 14, 'printer_state': 'CONNECTING'}
2023-01-15 20:15:22,704 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0'}
2023-01-15 20:15:23,507 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2023-01-15 20:15:28,305 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:15:29,930 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:15:29,930 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:15:46,616 - octoprint.server.preemptive_cache - INFO - ... done in 24.84s
2023-01-15 20:15:46,616 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'https://192.168.0.100/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 20:15:48,467 - octoprint.server.preemptive_cache - INFO - ... done in 1.85s
2023-01-15 20:15:48,886 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:15:48,887 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:15:50,078 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:15:50,250 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:15:50,251 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:15:52,726 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:15:53,409 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:15:53,524 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:15:53,525 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:15:58,056 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:15:59,154 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:21:46,122 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:21:46,207 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:21:46,208 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:21:47,107 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:21:47,108 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:21:47,390 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:21:47,439 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:21:47,439 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:21:48,929 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:21:50,237 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:22:12,447 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:22:12,487 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:22:12,487 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:22:12,926 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:22:12,926 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:22:13,159 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:22:13,208 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:22:13,208 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:22:14,724 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:22:15,975 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:23:10,215 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.187
2023-01-15 20:23:18,182 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 20:23:20,763 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.170
2023-01-15 20:23:20,763 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:23:20,818 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.170
2023-01-15 20:23:20,876 - octoprint.plugins.octoapp - INFO - Registered app fVfmZ3-gRguklakZoLxlBc:APA91bF_MTCMQxXpHgYcNxp9uJL13XeVuT0n2hllXwb3gggVKimZF9OpqkuNvuL_zFT8YxSf5tJfpWrN9TT-SNX8gYedlLle6audoVffpJTN9-RoErOduczNyX3_x2mBrUix9yqbJjAe
2023-01-15 20:24:14,143 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2023-01-15 20:24:14,297 - octoprint.server - INFO - Shutting down...
2023-01-15 20:24:14,553 - octoprint.server - INFO - Calling on_shutdown on plugins
2023-01-15 20:24:14,555 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2023-01-15 20:24:14,683 - octoprint.server.api.system - WARNING - Command for core:restart failed with return code -15:
! 
! STDOUT:
! 
! 
! STDERR:
2023-01-15 20:24:15,124 - octoprint.plugins.tracking - INFO - Sent tracking event shutdown, payload: {}
2023-01-15 20:24:15,222 - octoprint.events - INFO - Event loop shut down
2023-01-15 20:24:15,224 - octoprint.server - INFO - Goodbye!
2023-01-15 20:24:17,727 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 20:24:17,730 - octoprint.startup - INFO - Starting OctoPrint 1.8.6
2023-01-15 20:24:17,731 - octoprint.startup - INFO - ******************************************************************************
2023-01-15 20:24:18,331 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity changed from offline to online
2023-01-15 20:24:18,461 - octoprint.util.connectivity.connectivity_checker - INFO - Connectivity state is currently: online
2023-01-15 20:24:18,462 - octoprint.util.connectivity.connectivity_checker - INFO - Connecting to 8.8.8.8:53 is working
2023-01-15 20:24:18,462 - octoprint.util.connectivity.connectivity_checker - INFO - Resolving octoprint.org is working
2023-01-15 20:24:18,987 - octoprint.startup - INFO - Blacklist processing done, adding 3 blacklisted plugin versions: roomtemp (any), GcodeEditor (>=0.1.1,<=0.2.8), gcodeleveling (>=0.1.0,<=0.1.1)
2023-01-15 20:24:19,009 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2023-01-15 20:24:22,616 - octoprint.plugin.core - ERROR - Error loading plugin onedrive_files
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 1274, in _import_plugin
    module = _load_module(module_name, spec)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/plugin/core.py", line 52, in _load_module
    return imp.load_module(name, f, filename, details)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 238, in load_module
    return load_package(name, filename)
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/vendor/imp.py", line 212, in load_package
    return _load(spec)
  File "<frozen importlib._bootstrap>", line 696, in _load
  File "<frozen importlib._bootstrap>", line 677, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 728, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_onedrive_files/__init__.py", line 4, in <module>
    import octo_onedrive.onedrive
ModuleNotFoundError: No module named 'octo_onedrive'
2023-01-15 20:24:23,493 - octoprint.plugin.core - INFO - Found 23 plugin(s) providing 23 mixin implementations, 52 hook handlers
2023-01-15 20:24:23,689 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2023-01-15 20:24:23,921 - octoprint.server - INFO - Intermediary server started
2023-01-15 20:24:23,966 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2023-01-15 20:24:24,088 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2023-01-15 20:24:24,096 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_SHOW (needs: "Need(method='role', value='plugin_action_command_notification_show')")
2023-01-15 20:24:24,097 - octoprint.server - INFO - Added new permission from plugin action_command_notification: PLUGIN_ACTION_COMMAND_NOTIFICATION_CLEAR (needs: "Need(method='role', value='plugin_action_command_notification_clear')")
2023-01-15 20:24:24,097 - octoprint.server - INFO - Added new permission from plugin action_command_prompt: PLUGIN_ACTION_COMMAND_PROMPT_INTERACT (needs: "Need(method='role', value='plugin_action_command_prompt_interact')")
2023-01-15 20:24:24,098 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_READ (needs: "Need(method='role', value='plugin_announcements_read')")
2023-01-15 20:24:24,098 - octoprint.server - INFO - Added new permission from plugin announcements: PLUGIN_ANNOUNCEMENTS_MANAGE (needs: "Need(method='role', value='plugin_announcements_read'), Need(method='role', value='plugin_announcements_manage')")
2023-01-15 20:24:24,099 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_ADMIN (needs: "Need(method='role', value='plugin_appkeys_admin')")
2023-01-15 20:24:24,099 - octoprint.server - INFO - Added new permission from plugin appkeys: PLUGIN_APPKEYS_GRANT (needs: "Need(method='role', value='plugin_appkeys_user')")
2023-01-15 20:24:24,100 - octoprint.server - INFO - Added new permission from plugin backup: PLUGIN_BACKUP_ACCESS (needs: "Need(method='role', value='plugin_backup_access')")
2023-01-15 20:24:24,101 - octoprint.server - INFO - Added new permission from plugin firmware_check: PLUGIN_FIRMWARE_CHECK_DISPLAY (needs: "Need(method='role', value='plugin_firmware_check_display')")
2023-01-15 20:24:24,101 - octoprint.server - INFO - Added new permission from plugin logging: PLUGIN_LOGGING_MANAGE (needs: "Need(method='role', value='plugin_logging_manage')")
2023-01-15 20:24:24,104 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_RECEIVE_NOTIFICATIONS (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 20:24:24,109 - octoprint.server - INFO - Added new permission from plugin octoapp: PLUGIN_OCTOAPP_GET_DATA (needs: "Need(method='role', value='plugin_octoapp_admin')")
2023-01-15 20:24:24,112 - octoprint.server - INFO - Added new permission from plugin pi_support: PLUGIN_PI_SUPPORT_STATUS (needs: "Need(method='role', value='plugin_pi_support_check')")
2023-01-15 20:24:24,114 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_LIST (needs: "Need(method='role', value='plugin_pluginmanager_list')")
2023-01-15 20:24:24,116 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_MANAGE (needs: "Need(method='role', value='plugin_pluginmanager_manage')")
2023-01-15 20:24:24,120 - octoprint.server - INFO - Added new permission from plugin pluginmanager: PLUGIN_PLUGINMANAGER_INSTALL (needs: "Need(method='role', value='plugin_pluginmanager_install'), Need(method='role', value='plugin_pluginmanager_manage')")
2023-01-15 20:24:24,123 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CHECK (needs: "Need(method='role', value='plugin_softwareupdate_check')")
2023-01-15 20:24:24,125 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_UPDATE (needs: "Need(method='role', value='plugin_softwareupdate_update')")
2023-01-15 20:24:24,127 - octoprint.server - INFO - Added new permission from plugin softwareupdate: PLUGIN_SOFTWAREUPDATE_CONFIGURE (needs: "Need(method='role', value='plugin_softwareupdate_configure')")
2023-01-15 20:24:25,357 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:24:26,375 - octoprint.util.pip - INFO - Version of pip is 20.3.3
2023-01-15 20:24:26,408 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:24:26,408 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:24:26,605 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2023-01-15 20:24:26,634 - octoprint.plugins.softwareupdate - INFO - Loaded update log from disk
2023-01-15 20:24:26,769 - octoprint.plugins.firmwareupdater - INFO - Python binproto2 package installed: False
2023-01-15 20:24:26,785 - octoprint.plugin.core - INFO - Initialized 23 plugin implementation(s)
2023-01-15 20:24:26,825 - octoprint.plugin.core - INFO - 23 plugin(s) registered with the system:
|  Action Command Notification Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_notification
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/action_command_prompt
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/announcements
|  Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/tracking
|  Application Keys Plugin (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/appkeys
|  Backup & Restore (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/backup
|  Core Wizard (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/corewizard
|  Discovery (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/discovery
|  Error Tracking (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/errortracking
|  Event Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/eventmanager
|  File Check (2021.2.23) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_file_check
|  Firmware Check (2021.10.11) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmware_check
|  Firmware Updater (1.13.3) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_firmwareupdater
|  Floating Navbar (0.3.7) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_floatingnavbar
|  GCode Viewer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/gcodeviewer
|  Logging (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/logging
|  OctoApp (1.1.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_octoapp
|  Pi Support Plugin (2022.6.13) (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_pi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/pluginmanager
|  Preheat Button (0.8.0) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_preheat
|  Software Update (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/softwareupdate
|  Themeify (1.2.2) = /home/pi/oprint/lib/python3.7/site-packages/octoprint_themeify
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python3.7/site-packages/octoprint/plugins/virtual_printer
Prefix legend: ! = disabled, # = blacklisted, * = incompatible
2023-01-15 20:24:26,865 - octoprint.environment - INFO - Detected environment is Python 3.7.3 under Linux (linux). Details:
|  hardware:
|    cores: 4
|    freq: 1200.0
|    ram: 383967232
|  os:
|    bits: 32
|    id: linux
|    platform: linux
|  plugins:
|    pi_support:
|      model: Raspberry Pi Zero 2 Rev 1.0
|      octopi_version: 0.18.0
|      throttle_check_enabled: true
|      throttle_check_functional: true
|      throttle_state: '0x0'
|  python:
|    pip: 20.3.3
|    version: 3.7.3
|    virtualenv: /home/pi/oprint
2023-01-15 20:24:26,891 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2023-01-15 20:24:26,891 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2023-01-15 20:24:26,892 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-manifest.json...
2023-01-15 20:24:27,061 - octoprint.plugins.firmwareupdater - WARNING - The Blueprint of this plugin is relying on the default implementation of is_blueprint_csrf_protected (newly added in OctoPrint 1.8.3), which in a future version will be switched from False to True for security reasons. Plugin authors should ensure they explicitly declare the CSRF protection status in their BlueprintPlugin mixin implementation. Recommendation is to enable CSRF protection and exempt views that must not use it with the octoprint.plugin.BlueprintPlugin.csrf_exempt decorator.
2023-01-15 20:24:27,061 - octoprint.server - WARNING - CSRF Protection for Blueprint of plugin firmwareupdater is DISABLED
2023-01-15 20:24:27,754 - octoprint.plugins.firmwareupdater - INFO - Setting maximum upload size for /flash to 5243904
2023-01-15 20:24:27,754 - octoprint.server - INFO - Shutting down intermediary server...
2023-01-15 20:24:28,018 - octoprint.server - INFO - Intermediary server shut down
2023-01-15 20:24:28,023 - octoprint.events - INFO - Processing startup event, this is our first event
2023-01-15 20:24:28,024 - octoprint.events - INFO - Adding 2 events to queue that were held back before startup event
2023-01-15 20:24:28,027 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2023-01-15 20:24:28,029 - octoprint.server - INFO - Autoconnect on startup is configured, trying to connect to the printer...
2023-01-15 20:24:28,102 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2023-01-15 20:24:28,187 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 20:24:28,509 - octoprint.server - INFO - Trying to connect to configured serial port /dev/ttyAMA0
2023-01-15 20:24:28,587 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2023-01-15 20:24:28,837 - octoprint.plugins.tracking - INFO - Sent tracking event system_unthrottled, payload: {'throttled_now': False, 'throttled_past': False, 'throttled_mask': 0, 'throttled_voltage_now': False, 'throttled_voltage_past': False, 'throttled_overheat_now': False, 'throttled_overheat_past': False}
2023-01-15 20:24:29,566 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"
2023-01-15 20:24:29,619 - octoprint.util.comm - INFO - Connecting to port /dev/ttyAMA0, baudrate 115200
2023-01-15 20:24:29,632 - octoprint.server.util.watchdog - INFO - Running initial scan on watched folder...
2023-01-15 20:24:29,714 - octoprint.server.util.watchdog - INFO - ... initial scan done.
2023-01-15 20:24:29,801 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"
2023-01-15 20:24:29,846 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 20:24:30,900 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._http._tcp.local.' for _http._tcp.local.
2023-01-15 20:24:31,767 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:24:31,774 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:24:31,774 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:24:31,807 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2023-01-15 20:24:31,820 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance on octopi._octoprint._tcp.local.' for _octoprint._tcp.local.
2023-01-15 20:24:31,873 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2023-01-15 20:24:32,053 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2023-01-15 20:24:32,054 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2023-01-15 20:24:32,060 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2023-01-15 20:24:32,148 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2023-01-15 20:24:33,027 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 20:24:33,166 - octoprint.server.util.sockjs - WARNING - Unknown user/session combo: pi:43B9601D7071472BB34460853F666D94
2023-01-15 20:24:33,268 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python3 -m pip" as command to invoke pip
2023-01-15 20:24:33,274 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python3.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2023-01-15 20:24:33,274 - octoprint.util.pip - INFO - ==> pip ok -> yes
2023-01-15 20:24:33,351 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.187
2023-01-15 20:24:33,377 - octoprint.plugins.softwareupdate - INFO - Minimum free storage across all update relevant locations is 53.7GB. That is considered sufficient for updating.
2023-01-15 20:24:34,086 - octoprint.plugins.octoapp - INFO - OctoApp started, updating config
2023-01-15 20:24:34,221 - octoprint.plugins.themeify - INFO - Themeify initialized.
2023-01-15 20:24:34,800 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 11, 'printer_state': 'CONNECTING'}
2023-01-15 20:24:35,149 - octoprint.plugins.octoapp - INFO - OctoApp loaded config: {'maxUpdateIntervalSecs': 60, 'updatePercentModulus': 5, 'highPrecisionRangeStart': 5, 'highPrecisionRangeEnd': 5, 'sendNotificationUrl': 'https://europe-west1-octoapp-4e438.cloudfunctions.net/sendNotification'}
2023-01-15 20:24:35,179 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'http://octopi.local/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 20:24:35,477 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0'}
2023-01-15 20:24:36,180 - octoprint.plugins.tracking - INFO - Sent tracking event pong, payload: {'version': '1.8.6', 'os': 'linux', 'bits': 32, 'python': '3.7.3', 'pip': '20.3.3', 'cores': 4, 'freq': 1200.0, 'ram': 383967232, 'pi_model': 'Raspberry Pi Zero 2 Rev 1.0', 'octopi_version': '0.18.0', 'plugins': 'themeify:1.2.2,preheat:0.8.0,floatingnavbar:0.3.7,firmwareupdater:1.13.3,octoapp:1.1.0'}
2023-01-15 20:24:36,644 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2023-01-15 20:24:39,436 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:24:39,723 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 20:24:39,828 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:24:39,829 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:24:39,988 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.170
2023-01-15 20:24:40,051 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:24:40,051 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:24:40,099 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:24:40,100 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:24:40,144 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.170
2023-01-15 20:24:40,145 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:24:40,187 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:24:40,257 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:24:40,258 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:24:58,797 - octoprint.server.preemptive_cache - INFO - ... done in 23.62s
2023-01-15 20:24:58,798 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'base_url': 'https://192.168.0.100/', 'path': '/', 'query_string': 'l10n=en'}
2023-01-15 20:25:01,578 - octoprint.plugins.octoapp - INFO - Registered app fVfmZ3-gRguklakZoLxlBc:APA91bF_MTCMQxXpHgYcNxp9uJL13XeVuT0n2hllXwb3gggVKimZF9OpqkuNvuL_zFT8YxSf5tJfpWrN9TT-SNX8gYedlLle6audoVffpJTN9-RoErOduczNyX3_x2mBrUix9yqbJjAe
2023-01-15 20:25:02,460 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 20:25:02,558 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.170
2023-01-15 20:25:02,611 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.170
2023-01-15 20:25:02,669 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.170
2023-01-15 20:25:02,913 - octoprint.server.preemptive_cache - INFO - ... done in 4.11s
2023-01-15 20:25:06,093 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:25:06,096 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:25:06,245 - octoprint.plugins.octoapp - INFO - Registered app fVfmZ3-gRguklakZoLxlBc:APA91bF_MTCMQxXpHgYcNxp9uJL13XeVuT0n2hllXwb3gggVKimZF9OpqkuNvuL_zFT8YxSf5tJfpWrN9TT-SNX8gYedlLle6audoVffpJTN9-RoErOduczNyX3_x2mBrUix9yqbJjAe
2023-01-15 20:25:12,701 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:25:12,778 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:25:12,779 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:25:16,330 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:25:17,643 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:25:21,445 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.170
2023-01-15 20:25:32,507 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 20:25:35,003 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.170
2023-01-15 20:25:35,523 - octoprint.plugins.octoapp - INFO - Registered app fVfmZ3-gRguklakZoLxlBc:APA91bF_MTCMQxXpHgYcNxp9uJL13XeVuT0n2hllXwb3gggVKimZF9OpqkuNvuL_zFT8YxSf5tJfpWrN9TT-SNX8gYedlLle6audoVffpJTN9-RoErOduczNyX3_x2mBrUix9yqbJjAe
2023-01-15 20:25:47,490 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.170
2023-01-15 20:39:23,691 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 20:39:34,592 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 911, 'printer_state': 'CONNECTING'}
2023-01-15 20:54:23,692 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 20:54:34,619 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 1811, 'printer_state': 'CONNECTING'}
2023-01-15 20:55:24,277 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:55:24,311 - octoprint.access.users - INFO - Cleaning up user session BD85BBF1BC804606BA94EF5487EF6C44 for user pi
2023-01-15 20:55:24,312 - octoprint.access.users - INFO - Logged out user: pi
2023-01-15 20:55:24,312 - octoprint.access.users - INFO - Cleaning up user session FFE88AFE68D749BAB34BE464E1FBE82D for user pi
2023-01-15 20:55:24,313 - octoprint.access.users - INFO - Logged out user: pi
2023-01-15 20:55:24,364 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:55:24,365 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:55:24,908 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:55:24,909 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:55:25,545 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:55:25,623 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:55:25,623 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:55:27,090 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:55:28,131 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:55:28,390 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:56:02,717 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 20:56:02,732 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 20:56:02,734 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyAMA0
2023-01-15 20:56:02,759 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 20:56:02,948 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
2023-01-15 20:56:02,993 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyAMA0 -D -U flash:w:/tmp/tmpvd2fu7ca:i' in /usr/bin
2023-01-15 20:56:30,034 - octoprint.plugins.firmwareupdater - ERROR - Flashing failed. Timeout communicating with programmer.
2023-01-15 20:57:25,883 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:57:26,097 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:57:26,236 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:26,236 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:26,301 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:57:28,660 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:57:30,090 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:30,091 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:31,192 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:57:31,270 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:57:32,573 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:32,574 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:33,776 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:57:33,831 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:33,831 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:36,550 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:57:37,831 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 20:57:43,229 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:57:43,379 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:57:43,474 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:43,475 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:43,542 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:57:52,295 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:57:52,502 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:57:52,590 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:57:52,591 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:57:52,651 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:59:44,462 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 20:59:44,472 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 20:59:44,473 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 20:59:44,491 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 20:59:44,691 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
2023-01-15 20:59:44,739 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmpicusswm5:i' in /usr/bin
2023-01-15 20:59:54,264 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:59:54,468 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:59:54,626 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:59:54,628 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:59:54,700 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 20:59:56,500 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 20:59:57,577 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 20:59:57,578 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 20:59:58,684 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 20:59:58,733 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:00:00,171 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:00,172 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:01,248 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:00:01,298 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:01,298 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:04,086 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:00:05,314 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 21:00:08,690 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:00:08,926 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:00:09,002 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:09,002 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:09,047 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:00:11,194 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:00:11,432 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:00:11,541 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:11,542 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:11,618 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:00:48,136 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:00:48,176 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:48,176 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:48,881 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:48,881 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:49,140 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:00:49,203 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:00:49,204 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:00:50,711 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:00:51,922 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 21:01:53,236 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.235
2023-01-15 21:01:55,861 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.235
2023-01-15 21:01:55,862 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:01:55,912 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.235
2023-01-15 21:01:55,963 - octoprint.plugins.octoapp - INFO - Registered app fM3v7LcwQU-baqsZsYJtZg:APA91bHANl1XphUl53o_wAmOJgjLmd3fekusfr8VkiCW4QHJV2a2Pq6wN95X9yO60MTEXk_ZFO087f_AS_VbwPsy0qiVdT2uW8ngGpuyKXDToK4cEZ1lBjTdrZaPuUDkd1pVi_h0uJ4A
2023-01-15 21:02:20,011 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.235
2023-01-15 21:09:23,694 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 21:09:34,580 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 2711, 'printer_state': 'CONNECTING'}
2023-01-15 21:13:33,486 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 21:13:33,494 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2023-01-15 21:13:33,525 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2023-01-15 21:13:33,531 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2023-01-15 21:13:33,574 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2023-01-15 21:13:33,622 - octoprint.util.comm - INFO - Printer reports firmware name "Prusa-Firmware 3.9.1 based on Marlin"
2023-01-15 21:13:33,622 - octoprint.util.comm - INFO - Detected Prusa firmware, enabling relevant features for issue free communication
2023-01-15 21:13:34,169 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {'firmware_name': 'Prusa-Firmware 3.9.1 based on Marlin', 'printer_port': '/dev/ttyAMA0', 'printer_baudrate': 115200}
2023-01-15 21:21:01,730 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:21:01,774 - octoprint.access.users - INFO - Cleaning up user session 35DF655FC31C4C9FB2D03E64F226506B for user pi
2023-01-15 21:21:01,775 - octoprint.access.users - INFO - Logged out user: pi
2023-01-15 21:21:01,803 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:21:01,803 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:21:02,340 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:21:02,341 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:21:02,744 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:21:02,791 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:21:02,791 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:21:04,139 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:21:05,445 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 21:21:26,217 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 21:21:26,228 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 21:21:26,228 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 21:21:26,239 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 21:24:23,694 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 21:24:34,584 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 3611, 'printer_state': 'OPERATIONAL'}
2023-01-15 21:27:16,331 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:27:20,674 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:27:20,777 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:27:20,778 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:27:20,912 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:27:24,128 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 21:27:24,219 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 21:27:24,220 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 21:27:24,284 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 21:27:28,658 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 21:30:45,138 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 21:30:45,156 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 21:30:45,156 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 21:30:45,178 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 21:39:23,695 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 21:39:34,595 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 4511, 'printer_state': 'OPERATIONAL'}
2023-01-15 21:54:23,696 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 21:54:34,576 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 5411, 'printer_state': 'OPERATIONAL'}
2023-01-15 22:09:23,697 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 22:09:34,607 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 6311, 'printer_state': 'OPERATIONAL'}
2023-01-15 22:12:04,938 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.170
2023-01-15 22:12:07,463 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.170
2023-01-15 22:12:07,464 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:12:07,693 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.170
2023-01-15 22:12:07,826 - octoprint.plugins.octoapp - INFO - Registered app fVfmZ3-gRguklakZoLxlBc:APA91bF_MTCMQxXpHgYcNxp9uJL13XeVuT0n2hllXwb3gggVKimZF9OpqkuNvuL_zFT8YxSf5tJfpWrN9TT-SNX8gYedlLle6audoVffpJTN9-RoErOduczNyX3_x2mBrUix9yqbJjAe
2023-01-15 22:13:01,577 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.170
2023-01-15 22:24:23,698 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 22:24:34,578 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 7211, 'printer_state': 'OPERATIONAL'}
2023-01-15 22:39:23,698 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 22:39:34,617 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 8111, 'printer_state': 'OPERATIONAL'}
2023-01-15 22:44:46,708 - octoprint.access.users - INFO - Cleaning up user session EE768DCC7A554B74A25861756CD0A396 for user pi
2023-01-15 22:44:46,709 - octoprint.access.users - INFO - Logged out user: pi
2023-01-15 22:49:18,017 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
2023-01-15 22:49:18,027 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
2023-01-15 22:49:18,027 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
2023-01-15 22:49:18,039 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
2023-01-15 22:49:25,302 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 22:49:25,345 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:25,345 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:25,852 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:25,852 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:26,059 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 22:49:26,111 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:26,112 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:28,852 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 22:49:30,061 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 22:49:48,510 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 22:49:49,591 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:49,591 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:52,625 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:52,626 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:53,714 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-15 22:49:53,805 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-15 22:49:53,805 - octoprint.access.users - INFO - Logged in user: pi
2023-01-15 22:49:55,347 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-15 22:49:56,587 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-15 22:54:23,699 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 22:54:34,801 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 9011, 'printer_state': 'OPERATIONAL'}
2023-01-15 23:09:23,700 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 23:09:34,635 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 9911, 'printer_state': 'OPERATIONAL'}
2023-01-15 23:24:23,701 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 23:24:34,638 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 10811, 'printer_state': 'OPERATIONAL'}
2023-01-15 23:34:28,084 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
2023-01-15 23:39:23,702 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 23:39:34,707 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 11711, 'printer_state': 'OPERATIONAL'}
2023-01-15 23:54:23,702 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-15 23:54:34,688 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 12611, 'printer_state': 'OPERATIONAL'}
2023-01-16 00:09:23,703 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 00:09:34,711 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 13511, 'printer_state': 'OPERATIONAL'}
2023-01-16 00:24:23,704 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 00:24:34,730 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 14411, 'printer_state': 'OPERATIONAL'}
2023-01-16 00:39:23,705 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 00:39:34,735 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 15311, 'printer_state': 'OPERATIONAL'}
2023-01-16 00:54:23,706 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 00:54:34,738 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 16211, 'printer_state': 'OPERATIONAL'}
2023-01-16 01:09:23,706 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 01:09:34,748 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 17111, 'printer_state': 'OPERATIONAL'}
2023-01-16 01:24:23,707 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 01:24:34,786 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 18011, 'printer_state': 'OPERATIONAL'}
2023-01-16 01:39:23,708 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 01:39:34,817 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 18911, 'printer_state': 'OPERATIONAL'}
2023-01-16 01:54:23,709 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 01:54:34,779 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 19811, 'printer_state': 'OPERATIONAL'}
2023-01-16 02:09:23,710 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 02:09:34,823 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 20711, 'printer_state': 'OPERATIONAL'}
2023-01-16 02:24:23,711 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 02:24:34,853 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 21611, 'printer_state': 'OPERATIONAL'}
2023-01-16 02:39:23,711 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 02:39:34,856 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 22511, 'printer_state': 'OPERATIONAL'}
2023-01-16 02:54:23,712 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 02:54:34,892 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 23411, 'printer_state': 'OPERATIONAL'}
2023-01-16 03:09:23,713 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 03:09:34,879 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 24311, 'printer_state': 'OPERATIONAL'}
2023-01-16 03:24:23,714 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 03:24:35,006 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 25211, 'printer_state': 'OPERATIONAL'}
2023-01-16 03:39:23,715 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 03:39:34,901 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 26112, 'printer_state': 'OPERATIONAL'}
2023-01-16 03:54:23,715 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 03:54:34,973 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 27012, 'printer_state': 'OPERATIONAL'}
2023-01-16 04:09:23,716 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 04:09:34,985 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 27912, 'printer_state': 'OPERATIONAL'}
2023-01-16 04:24:23,717 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 04:24:35,041 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 28812, 'printer_state': 'OPERATIONAL'}
2023-01-16 04:39:23,718 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 04:39:34,963 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 29712, 'printer_state': 'OPERATIONAL'}
2023-01-16 04:54:23,719 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 04:54:35,018 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 30612, 'printer_state': 'OPERATIONAL'}
2023-01-16 05:09:23,719 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 05:09:35,018 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 31512, 'printer_state': 'OPERATIONAL'}
2023-01-16 05:24:23,720 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 05:24:35,027 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 32412, 'printer_state': 'OPERATIONAL'}
2023-01-16 05:39:23,721 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 05:39:35,072 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 33312, 'printer_state': 'OPERATIONAL'}
2023-01-16 05:54:23,722 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 05:54:35,037 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 34212, 'printer_state': 'OPERATIONAL'}
2023-01-16 06:09:23,723 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 06:09:35,036 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 35112, 'printer_state': 'OPERATIONAL'}
2023-01-16 06:24:23,724 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 06:24:35,050 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 36012, 'printer_state': 'OPERATIONAL'}
2023-01-16 06:39:23,724 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 06:39:35,056 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 36912, 'printer_state': 'OPERATIONAL'}
2023-01-16 06:54:23,725 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 06:54:35,081 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 37812, 'printer_state': 'OPERATIONAL'}
2023-01-16 07:09:23,726 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 07:09:35,095 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 38712, 'printer_state': 'OPERATIONAL'}
2023-01-16 07:24:23,727 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 07:24:35,038 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 39612, 'printer_state': 'OPERATIONAL'}
2023-01-16 07:39:23,728 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 07:39:36,126 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 40512, 'printer_state': 'OPERATIONAL'}
2023-01-16 07:54:23,728 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 07:54:35,092 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 41412, 'printer_state': 'OPERATIONAL'}
2023-01-16 08:09:23,729 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 08:09:35,570 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 42312, 'printer_state': 'OPERATIONAL'}
2023-01-16 08:24:23,730 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 08:24:35,146 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 43212, 'printer_state': 'OPERATIONAL'}
2023-01-16 08:39:23,731 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 08:39:35,157 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 44112, 'printer_state': 'OPERATIONAL'}
2023-01-16 08:54:23,731 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 08:54:35,185 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 45012, 'printer_state': 'OPERATIONAL'}
2023-01-16 09:09:23,732 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 09:09:35,146 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 45912, 'printer_state': 'OPERATIONAL'}
2023-01-16 09:24:23,733 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 09:24:35,206 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 46812, 'printer_state': 'OPERATIONAL'}
2023-01-16 09:39:23,734 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 09:39:35,234 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 47712, 'printer_state': 'OPERATIONAL'}
2023-01-16 09:54:23,735 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 09:54:35,227 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 48612, 'printer_state': 'OPERATIONAL'}
2023-01-16 10:09:23,735 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 10:09:35,215 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 49512, 'printer_state': 'OPERATIONAL'}
2023-01-16 10:24:23,736 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 10:24:35,272 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 50412, 'printer_state': 'OPERATIONAL'}
2023-01-16 10:39:23,737 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 10:39:35,260 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 51312, 'printer_state': 'OPERATIONAL'}
2023-01-16 10:54:23,738 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 10:54:35,260 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 52212, 'printer_state': 'OPERATIONAL'}
2023-01-16 11:09:23,739 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 11:09:35,301 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 53112, 'printer_state': 'OPERATIONAL'}
2023-01-16 11:24:23,740 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 11:24:35,278 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 54012, 'printer_state': 'OPERATIONAL'}
2023-01-16 11:39:23,740 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 11:39:35,347 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 54912, 'printer_state': 'OPERATIONAL'}
2023-01-16 11:54:23,741 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 11:54:35,335 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 55812, 'printer_state': 'OPERATIONAL'}
2023-01-16 12:09:23,742 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 12:09:35,494 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 56712, 'printer_state': 'OPERATIONAL'}
2023-01-16 12:24:23,743 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 12:24:35,324 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 57612, 'printer_state': 'OPERATIONAL'}
2023-01-16 12:39:23,744 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 12:39:35,342 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 58512, 'printer_state': 'OPERATIONAL'}
2023-01-16 12:54:23,744 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 12:54:35,370 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 59412, 'printer_state': 'OPERATIONAL'}
2023-01-16 13:09:23,745 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 13:09:35,338 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 60312, 'printer_state': 'OPERATIONAL'}
2023-01-16 13:24:23,746 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 13:24:35,626 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 61212, 'printer_state': 'OPERATIONAL'}
2023-01-16 13:39:23,747 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 13:39:35,388 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 62112, 'printer_state': 'OPERATIONAL'}
2023-01-16 13:54:23,748 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 13:54:35,401 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 63012, 'printer_state': 'OPERATIONAL'}
2023-01-16 14:09:23,749 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 14:09:35,394 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 63912, 'printer_state': 'OPERATIONAL'}
2023-01-16 14:24:23,749 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-16 14:24:35,423 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 64812, 'printer_state': 'OPERATIONAL'}
2023-01-16 14:28:02,164 - octoprint.access.users - INFO - Cleaning up user session C71E57564B224EB1AA81997FFF4BC8E4 for user pi
2023-01-16 14:28:02,164 - octoprint.access.users - INFO - Logged out user: pi
2023-01-16 14:28:02,192 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-16 14:28:02,193 - octoprint.access.users - INFO - Logged in user: pi
2023-01-16 14:28:02,269 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-16 14:28:02,269 - octoprint.access.users - INFO - Logged in user: pi
2023-01-16 14:28:02,351 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-16 14:28:02,352 - octoprint.access.users - INFO - Logged in user: pi
2023-01-16 14:28:03,197 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.0.54
2023-01-16 14:28:03,247 - octoprint.server.util.flask - INFO - Passively logging in user pi from ::ffff:192.168.0.54
2023-01-16 14:28:03,247 - octoprint.access.users - INFO - Logged in user: pi
2023-01-16 14:28:03,851 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2023-01-16 14:28:05,225 - octoprint.server.util.sockjs - INFO - User pi logged in on the socket from client ::ffff:192.168.0.54
2023-01-16 14:28:06,011 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.45s
2023-01-16 14:28:06,578 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.46s
2023-01-16 14:28:07,110 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.48s
2023-01-16 14:28:07,638 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.47s
2023-01-16 14:28:08,200 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.47s
2023-01-16 14:28:09,368 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2023-01-16 14:28:10,533 - octoprint.plugins.tracking - INFO - Sent tracking event webui_load, payload: {'browser_name': 'Firefox', 'browser_version': '108.0', 'os_name': 'Linux', 'os_version': 'x86_64'}
2023-01-16 14:28:13,813 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.54
benlye commented 1 year ago

Can you add it as an attachment?

benlye commented 1 year ago

Here's what I see:

  1. You tried to flash a few times but the process errored with an avrdude comms error, then you tried to flash but for some reason it didn't error or end:
    2023-01-15 20:59:44,462 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile index: 0
    2023-01-15 20:59:44,472 - octoprint.plugins.firmwareupdater - INFO - Firmware update profile name: Default
    2023-01-15 20:59:44,473 - octoprint.plugins.firmwareupdater - INFO - Printer port: /dev/ttyS0
    2023-01-15 20:59:44,491 - octoprint.plugins.firmwareupdater - INFO - Flash method: avrdude
    2023-01-15 20:59:44,691 - octoprint.plugins.firmwareupdater - INFO - Firmware update started
    2023-01-15 20:59:44,739 - octoprint.plugins.firmwareupdater - INFO - Running '/usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyS0 -D -U flash:w:/tmp/tmpicusswm5:i' in /usr/bin

Now every time you try the process stops but it's unclear why. Since the attempt logged above I don't see any restarts of OctoPrint in the log files. So, can you try to restart OctoPrint once more, please - maybe just reboot the Pi that it's running on.

Once that's done, try to flash again. If you get an error, attach the console log and the octoprint log and I'll see if I can figure out what's going on.

jaymedavis commented 1 year ago

Sure, thanks for the help.

Here's the two files again. There will be two more attempts: first was restarting octoprint, second was rebooting the system. Here is my settings as well:

plugin_firmwareupdater_console.log octoprint.log Screenshot from 2023-01-16 20-27-58

benlye commented 1 year ago

Right, so you're no longer getting the 'Already flashing' error, are you? Now you get the error from avrdude?

2023-01-17 01:33:46,955 - octoprint.plugins.firmwareupdater - ERROR - Flashing failed. Timeout communicating with programmer.

More details from the console log:

2023-01-17 01:33:15,908 /usr/bin/avrdude -v -q -p m2560 -c wiring -P /dev/ttyAMA0 -D -U flash:w:/tmp/tmpxzzty4eh:i
2023-01-17 01:33:16,570 > 
2023-01-17 01:33:16,571 > avrdude: Version 6.3-20171130
2023-01-17 01:33:16,571 >          Copyright (c) 2000-2005 Brian Dean, http://www.bdmicro.com/
2023-01-17 01:33:16,572 >          Copyright (c) 2007-2014 Joerg Wunsch
2023-01-17 01:33:16,573 > 
2023-01-17 01:33:16,573 >          System wide configuration file is "/etc/avrdude.conf"
2023-01-17 01:33:16,574 >          User configuration file is "/home/pi/.avrduderc"
2023-01-17 01:33:16,574 >          User configuration file does not exist or is not a regular file, skipping
2023-01-17 01:33:16,575 > 
2023-01-17 01:33:16,575 >          Using Port                    : /dev/ttyAMA0
2023-01-17 01:33:16,576 >          Using Programmer              : wiring
2023-01-17 01:33:16,576 > 
2023-01-17 01:33:21,916 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:21,917 > 
2023-01-17 01:33:26,921 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:26,922 > 
2023-01-17 01:33:31,926 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:31,927 > 
2023-01-17 01:33:36,932 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:36,932 > 
2023-01-17 01:33:41,937 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:41,938 > 
2023-01-17 01:33:46,947 > avrdude: stk500v2_ReceiveMessage(): timeout
2023-01-17 01:33:46,948 > avrdude: stk500v2_getsync(): timeout communicating with programmer
2023-01-17 01:33:46,951 > 
2023-01-17 01:33:46,952 > avrdude done.  Thank you.
2023-01-17 01:33:46,953 > 
2023-01-17 01:33:46,953 > 

That means that your configuration is not correct for your board. I can't help you with that as I don't have the board/printer and can't tell you what settings will work. Your best bet is to find a user community for your board / setup and ask there.

jaymedavis commented 1 year ago

Yeah, it is a different error now, at least. It's the prusa mk3. I have followed https://mattwidmann.net/notes/updating-prusa-i3-mk3s-firmware-with-octoprint/ and https://blog.svenadolph.net/update-prusa-i3-m-k3-s-firmware-from-octo-pi-using-the-octo-print-firmware-updater-plugin/ to verify those settings.

I think I'll have to flash it manually. Thanks again for looking.

github-actions[bot] commented 1 year ago

This issue has been automatically locked because there was no further activity after it was closed. Please open a new issue for any related problems.