jneilliii / OctoPrint-TPLinkSmartplug

106 stars 57 forks source link

TP-Link Smartplug (0.9.10) HS105 not working consistantly. #85

Closed santanig5 closed 5 years ago

santanig5 commented 5 years ago

Greetings, I've recently purchased TP-Link HS105 plugs and connected one to my printer, installed your plugin and what I'm finding is that when I click on the lightning bolt it does not change the plug state consistently. I will click it when it is off, the icon rotates but does not change color and the plug remains off, I click a second time and the icon rotates, the plug turns on, but the icon color does not change. I have the polling set to 1 minute and after 60 seconds the color will change to green. When I attempt to turn it off, I have to click the icon several times before it will change the state of the plug. Again, it is not consistent. I captured a log, but am not sure how to retrieve it for you.

Thanks in advance.

jneilliii commented 5 years ago

If you have debug enabled go into logging section in octoprint's settings and find the tpkinsmartplug log file, download and upload here.

santanig5 commented 5 years ago

Found it! Thanks, I hope its ok that I attached it here and not in GitHub.

Sent from Mailhttps://go.microsoft.com/fwlink/?LinkId=550986 for Windows 10


From: jneilliii notifications@github.com Sent: Thursday, January 31, 2019 11:32:24 AM To: jneilliii/OctoPrint-TPLinkSmartplug Cc: santanig5; Author Subject: Re: [jneilliii/OctoPrint-TPLinkSmartplug] TP-Link Smartplug (0.9.10) HS105 not working consistantly. (#85)

If you have debug enabled go into logging section in octoprint's settings and find the tpkinsmartplug log file, download and upload here.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHubhttps://github.com/jneilliii/OctoPrint-TPLinkSmartplug/issues/85#issuecomment-459411187, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AniL71iptrev7IaKLbIUrQRGdJOD4OrFks5vIxqYgaJpZM4aclrB.

jneilliii commented 5 years ago

Doesn't look like it came through via email.

santanig5 commented 5 years ago

Take two, file is attached and here are the contents

2019-01-28 23:55:34,727 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-28 23:55:34,731 - octoprint.server - INFO - --- Log roll over detected --------------------------------------------------- 2019-01-28 23:55:34,732 - octoprint.server - INFO - OctoPrint 1.3.10 2019-01-28 23:55:34,734 - octoprint.plugin.core - INFO - 28 plugin(s) registered with the system: | Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt | Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements | Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking | Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys | Autoscroll (0.0.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_autoscroll | Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup | Bed Visualizer (0.1.7) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_bedlevelvisualizer | Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard | !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura | Custom Control Editor (0.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_customControl | Detailed Progress Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress | Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery | !EEPROM Marlin Editor Plugin (1.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_eeprom_marlin | Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin | Fullscreen Plugin (0.0.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_fullscreen | Gcodebar Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_GCodeBar | Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging | Octolapse (0.3.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_octolapse | Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support | Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager | Print History Plugin (1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_printhistory | Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check | !ProgressBasedOntime Plugin (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_ProgressBasedOnTime | SMS Notifier (with Twilio) (0.3.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_smsnotifier | Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate | TouchUI (0.3.12) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui | TP-Link Smartplug (0.9.10) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_tplinksmartplug | !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer 2019-01-28 23:55:34,748 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details: | hardware: | cores: 4 | freq: 1400.0 | ram: 918188032 | os: | id: linux | platform: linux2 | plugins: | pi_support: | model: Raspberry Pi 3 Model B Plus Rev 1.3 | octopi_version: 0.15.1 | python: | pip: 9.0.3 | version: 2.7.13 | virtualenv: /home/pi/oprint 2019-01-28 23:55:34,749 - octoprint.server - INFO - ------------------------------------------------------------------------------ 2019-01-28 23:57:42,322 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-28 23:57:47,156 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 00:10:34,738 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 00:12:42,324 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 00:12:47,138 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 00:23:41,620 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rudder_lh.gcode 2019-01-29 00:23:41,622 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rudder_lh.gcode 2019-01-29 00:23:53,258 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 00:23:53,269 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 00:23:53,282 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 00:23:54,008 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7'} 2019-01-29 00:25:34,723 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 00:27:42,325 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 00:27:47,112 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 00:29:16,586 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 00:29:16,593 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rudder_lh.gcode 2019-01-29 00:29:16,605 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rudder_lh.gcode 2019-01-29 00:29:16,627 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 00:29:16,866 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 00:29:16,883 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 00:29:17,341 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7'} 2019-01-29 00:29:17,846 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7', 'elapsed': 323} 2019-01-29 00:29:18,599 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 00:29:44,315 - octoprint.filemanager.analysis - INFO - Analysis of entry local:rudder_lh.gcode finished, needed 27.72s 2019-01-29 00:32:40,953 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rudder_lh.gcode 2019-01-29 00:32:40,955 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rudder_lh.gcode 2019-01-29 00:32:43,576 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 00:32:43,586 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 00:32:43,593 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 00:32:44,273 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7'} 2019-01-29 00:38:42,592 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 00:38:42,598 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rudder_lh.gcode 2019-01-29 00:38:42,603 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rudder_lh.gcode 2019-01-29 00:38:42,641 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 00:38:42,784 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 00:38:43,230 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 00:38:43,272 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7'} 2019-01-29 00:38:43,787 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7', 'elapsed': 359} 2019-01-29 00:38:44,720 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 00:38:51,440 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 00:38:51,450 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 00:38:51,458 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 00:38:51,981 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7'} 2019-01-29 00:40:34,889 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 00:42:42,326 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 00:42:47,158 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 00:55:34,737 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 00:57:42,327 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 00:57:47,326 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 01:10:34,760 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 01:12:42,329 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 01:12:47,673 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 01:25:34,825 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 01:27:42,330 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 01:27:47,090 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 01:40:34,804 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 01:42:42,331 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 01:42:47,165 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 01:54:31,175 - tornado.access - WARNING - 404 GET /favicon.ico (::ffff:192.168.198.224) 26.82ms 2019-01-29 01:55:34,799 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 01:57:42,332 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 01:57:47,169 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 02:10:34,810 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 02:12:42,334 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 02:12:47,178 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 02:25:34,792 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 02:27:42,338 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 02:27:47,111 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 02:40:34,794 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 02:42:42,339 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 02:42:47,275 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 02:55:34,808 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 02:57:42,341 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 02:57:47,161 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 03:04:46,572 - tornado.access - WARNING - 404 GET //a2billing/customer/templates/default/footer.tpl (::ffff:194.147.32.109) 7.73ms 2019-01-29 03:10:34,839 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 03:12:42,342 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 03:12:47,128 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 03:14:39,529 - tornado.access - WARNING - 404 GET //recordings/ (::ffff:194.147.32.109) 8.04ms 2019-01-29 03:24:39,473 - tornado.access - WARNING - 404 GET //vtigercrm/vtigerservice.php (::ffff:194.147.32.109) 9.70ms 2019-01-29 03:25:34,846 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 03:27:42,343 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 03:27:47,233 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 03:40:34,835 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 03:42:42,344 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 03:42:47,145 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 03:44:40,127 - octoprint.util.comm - INFO - Finished in 11148.692 s. 2019-01-29 03:44:40,128 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2019-01-29 03:44:40,131 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rudder_lh.gcode 2019-01-29 03:44:40,133 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rudder_lh.gcode 2019-01-29 03:44:40,182 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 03:44:40,210 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2019-01-29 03:44:40,581 - octoprint.plugins.smsnotifier - INFO - Print notification sent to 9737152190 2019-01-29 03:44:41,125 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'local', 'file': 'd42901adca082449eeef77356e7d0beb96a71ec7', 'elapsed': 11148} 2019-01-29 03:24:46,319 - octoprint.startup - INFO - ** 2019-01-29 03:24:46,321 - octoprint.startup - INFO - Starting OctoPrint 1.3.10 2019-01-29 03:24:46,334 - octoprint.startup - INFO - ** 2019-01-29 03:24:46,582 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist 2019-01-29 03:24:46,676 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages... 2019-01-29 03:24:48,724 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled. 2019-01-29 03:24:48,751 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled. 2019-01-29 03:24:49,999 - octoprint.plugin.core - INFO - Plugin ProgressBasedOntime Plugin (0.1.2) is disabled. 2019-01-29 03:24:50,111 - octoprint.plugin.core - INFO - Plugin EEPROM Marlin Editor Plugin (1.2.1) is disabled. 2019-01-29 03:24:52,940 - octoprint.plugin.core - INFO - Found 28 plugin(s) providing 24 mixin implementations, 37 hook handlers 2019-01-29 03:24:52,945 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval 2019-01-29 03:24:53,051 - octoprint.server - INFO - Intermediary server started 2019-01-29 03:24:53,052 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages... 2019-01-29 03:24:53,755 - octoprint.plugin.core - INFO - Found 28 plugin(s) providing 24 mixin implementations, 37 hook handlers 2019-01-29 03:24:53,798 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads... 2019-01-29 03:24:54,370 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully. 2019-01-29 03:24:54,632 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk 2019-01-29 03:24:54,639 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking 2019-01-29 03:24:57,208 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 03:24:59,153 - octoprint.util.pip - INFO - Version of pip is 9.0.3 2019-01-29 03:24:59,155 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2019-01-29 03:24:59,155 - octoprint.util.pip - INFO - ==> pip ok -> yes 2019-01-29 03:24:59,161 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s) 2019-01-29 03:24:59,178 - octoprint.plugin.core - INFO - 28 plugin(s) registered with the system: | Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt | Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements | Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking | Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys | Autoscroll (0.0.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_autoscroll | Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup | Bed Visualizer (0.1.7) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_bedlevelvisualizer | Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard | !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura | Custom Control Editor (0.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_customControl | Detailed Progress Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress | Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery | !EEPROM Marlin Editor Plugin (1.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_eeprom_marlin | Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin | Fullscreen Plugin (0.0.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_fullscreen | Gcodebar Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_GCodeBar | Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging | Octolapse (0.3.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_octolapse | Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support | Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager | Print History Plugin (1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_printhistory | Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check | !ProgressBasedOntime Plugin (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_ProgressBasedOnTime | SMS Notifier (with Twilio) (0.3.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_smsnotifier | Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate | TouchUI (0.3.12) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui | TP-Link Smartplug (0.9.10) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_tplinksmartplug | !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer 2019-01-29 03:24:59,197 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details: | hardware: | cores: 4 | freq: 1400.0 | ram: 918188032 | os: | id: linux | platform: linux2 | plugins: | pi_support: | model: Raspberry Pi 3 Model B Plus Rev 1.3 | octopi_version: 0.15.1 | python: | pip: 9.0.3 | version: 2.7.13 | virtualenv: /home/pi/oprint 2019-01-29 03:24:59,210 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets... 2019-01-29 03:24:59,231 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache... 2019-01-29 03:24:59,281 - octoprint.plugins.octolapse - INFO - Octolapse is loading assets. 2019-01-29 03:24:59,704 - octoprint.server - INFO - Shutting down intermediary server... 2019-01-29 03:25:00,173 - octoprint.server - INFO - Intermediary server shut down 2019-01-29 03:25:00,179 - octoprint.events - INFO - Processing startup event, this is our first event 2019-01-29 03:25:00,180 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event 2019-01-29 03:25:00,199 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue... 2019-01-29 03:25:00,228 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue 2019-01-29 03:25:00,390 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port" 2019-01-29 03:25:00,393 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting" 2019-01-29 03:25:00,399 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "CGS3D"' for _http._tcp 2019-01-29 03:25:00,407 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 03:25:00,414 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "CGS3D"' for _octoprint._tcp 2019-01-29 03:25:00,426 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "CGS3D" for SSDP 2019-01-29 03:25:00,446 - octoprint.server - INFO - Listening on http://127.0.0.1:5000 2019-01-29 03:25:00,449 - octoprint.plugins.octolapse - INFO - Loading existing settings file from: /home/pi/.octoprint/data/octolapse/settings.json. 2019-01-29 03:25:00,631 - octoprint.plugins.bedlevelvisualizer - INFO - OctoPrint-BedLevelVisualizer loaded! 2019-01-29 03:25:00,639 - octoprint.plugins.pluginmanager - INFO - Looks like we are offline, can't fetch repository from network 2019-01-29 03:25:00,640 - octoprint.plugins.pluginmanager - INFO - Looks like we are offline, can't fetch notices from network 2019-01-29 03:25:00,647 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _important from network 2019-01-29 03:25:00,650 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _releases from network 2019-01-29 03:25:00,652 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _blog from network 2019-01-29 03:25:00,654 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _plugins from network 2019-01-29 03:25:00,656 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _octopi from network 2019-01-29 03:25:02,204 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 03:25:02,674 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 03:25:02,676 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2019-01-29 03:25:02,677 - octoprint.util.pip - INFO - ==> pip ok -> yes 2019-01-29 03:25:02,718 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online 2019-01-29 03:25:02,769 - octoprint.plugins.tplinksmartplug - INFO - TPLinkSmartplug loaded! 2019-01-29 03:25:02,813 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://cr-10minipi.lan/'} 2019-01-29 03:25:03,410 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.15.1', 'version': u'1.3.10', 'pip': '9.0.3', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'} 2019-01-29 03:25:03,431 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.69s 2019-01-29 03:25:03,665 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json 2019-01-29 03:25:04,352 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.62s 2019-01-29 03:25:04,826 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json 2019-01-29 03:25:04,943 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.52s 2019-01-29 03:25:05,544 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.53s 2019-01-29 03:25:06,362 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.64s 2019-01-29 03:25:06,900 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational" 2019-01-29 03:25:06,905 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 03:25:07,018 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin TH3D U1.R2.3" 2019-01-29 03:25:07,757 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': '/dev/ttyUSB0', 'firmware_name': 'Marlin TH3D U1.R2.3'} 2019-01-29 13:00:05,992 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 13:00:06,552 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 13:00:17,187 - octoprint.server.preemptive_cache - INFO - ... done in 34514.37s 2019-01-29 13:10:35,204 - tornado.access - WARNING - 403 GET /api/plugin/tplinksmartplug?checkStatus=192.168.198.181 (::ffff:192.168.198.236) 15.42ms 2019-01-29 13:15:06,009 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 13:15:06,481 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 13:19:09,799 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly 2019-01-29 13:19:09,802 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s 2019-01-29 13:20:42,875 - octoprint.util.comm - INFO - Communication timeout while idle, trying to trigger response from printer. 2019-01-29 13:25:35,246 - tornado.access - WARNING - 403 GET /api/plugin/tplinksmartplug?checkStatus=192.168.198.181 (::ffff:192.168.198.236) 15.87ms 2019-01-29 13:27:26,193 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rear_cover.gcode 2019-01-29 13:27:26,196 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rear_cover.gcode 2019-01-29 13:28:27,359 - octoprint.filemanager.analysis - INFO - Analysis of entry local:rear_cover.gcode finished, needed 61.17s 2019-01-29 13:30:06,016 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 13:30:06,496 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 13:30:51,051 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.198.236 2019-01-29 13:30:51,261 - octoprint.server.util.flask - INFO - Passively logging in user santanig5 from ::ffff:192.168.198.236 2019-01-29 13:30:51,277 - octoprint.server.util.sockjs - INFO - User santanig5 logged in on the socket from client ::ffff:192.168.198.236 2019-01-29 13:30:53,606 - octoprint.server.util.flask - INFO - Passively logging in user santanig5 from ::ffff:192.168.198.236 2019-01-29 13:30:53,720 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.198.236 2019-01-29 13:30:56,176 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.198.236 2019-01-29 13:30:56,324 - octoprint.server.util.flask - INFO - Passively logging in user santanig5 from ::ffff:192.168.198.236 2019-01-29 13:30:57,201 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 13:30:57,982 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.5s 2019-01-29 13:30:58,772 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.52s 2019-01-29 13:30:59,322 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.47s 2019-01-29 13:30:59,929 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.54s 2019-01-29 13:31:00,555 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.47s 2019-01-29 13:31:04,267 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 13:31:04,416 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 13:31:04,715 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 13:31:04,879 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 13:31:05,533 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 13:31:11,022 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages/ (writable -> yes), --user flag needed -> no, virtual env -> yes 2019-01-29 13:31:11,022 - octoprint.util.pip - INFO - ==> pip ok -> yes 2019-01-29 13:31:11,917 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk 2019-01-29 13:31:12,043 - octoprint.server.util.sockjs - INFO - User santanig5 logged in on the socket from client ::ffff:192.168.198.236 2019-01-29 13:31:39,600 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 13:31:39,608 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 13:31:39,617 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 13:31:40,208 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78'} 2019-01-29 13:39:02,531 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 13:39:02,551 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 13:39:02,837 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 13:39:03,104 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78'} 2019-01-29 13:39:03,610 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78', 'elapsed': 442} 2019-01-29 13:39:04,317 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 13:39:05,759 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 13:40:07,328 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rear_cover.gcode 2019-01-29 13:40:07,331 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rear_cover.gcode 2019-01-29 13:41:38,438 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rear_cover.gcode 2019-01-29 13:41:38,440 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rear_cover.gcode 2019-01-29 13:41:42,198 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 13:41:42,209 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 13:41:42,222 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 13:41:42,767 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78'} 2019-01-29 13:45:06,021 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 13:45:06,516 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 13:45:57,207 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 14:00:06,030 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 14:00:06,530 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 14:00:57,214 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 14:15:06,033 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 14:15:06,515 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 14:15:57,216 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 14:30:06,034 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 14:30:06,544 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 14:30:57,246 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 14:45:06,035 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 14:45:06,625 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 14:45:57,225 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 15:00:06,036 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 15:00:07,103 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 15:00:57,240 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 15:15:06,037 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 15:15:06,500 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 15:15:57,269 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 15:30:06,038 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 15:30:06,480 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 15:30:57,229 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 15:35:49,720 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 15:35:49,722 - octoprint.filemanager.analysis - INFO - Starting analysis of local:rear_cover.gcode 2019-01-29 15:35:49,725 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/rear_cover.gcode 2019-01-29 15:35:49,771 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 15:35:49,941 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 15:35:50,392 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78'} 2019-01-29 15:35:50,535 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 15:35:50,880 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78', 'elapsed': 6847} 2019-01-29 15:35:54,519 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 15:36:53,989 - octoprint.filemanager.analysis - INFO - Analysis of entry local:rear_cover.gcode finished, needed 64.27s 2019-01-29 15:44:18,600 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 15:44:18,617 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 15:44:18,635 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 15:44:19,216 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78'} 2019-01-29 15:45:06,040 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 15:45:06,503 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 15:45:57,227 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 16:00:06,046 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 16:00:06,603 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 16:00:57,282 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 16:15:06,057 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 16:15:06,523 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 16:15:57,301 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 16:30:06,059 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 16:30:06,511 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 16:30:57,304 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 16:45:06,059 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 16:45:06,537 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 16:45:57,316 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 17:00:06,061 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 17:00:06,548 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 17:00:57,367 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 17:15:06,062 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 17:15:06,555 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 17:15:57,323 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 17:30:06,063 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 17:30:06,501 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 17:30:57,330 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 17:45:06,064 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 17:45:06,513 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 17:45:57,326 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 17:50:24,152 - tornado.access - WARNING - 404 GET /menu.js (::ffff:182.200.5.122) 7.90ms 2019-01-29 18:00:06,065 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 18:00:06,693 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 18:00:57,347 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 18:15:06,066 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 18:15:06,585 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 18:15:57,363 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 18:30:06,068 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 18:30:06,579 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 18:30:57,355 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 18:45:06,069 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 18:45:06,597 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 18:45:57,359 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 19:00:06,071 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 19:00:06,621 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 19:00:57,381 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 19:15:06,075 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 19:15:06,536 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 19:15:57,437 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 19:30:06,076 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 19:30:06,542 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 19:30:57,425 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 19:45:06,079 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 19:45:06,551 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 19:45:57,464 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 20:00:06,080 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 20:00:06,586 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 20:00:57,758 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 20:09:30,416 - octoprint.util.comm - INFO - Finished in 15911.819 s. 2019-01-29 20:09:30,418 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing" 2019-01-29 20:09:30,435 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 20:09:30,496 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational" 2019-01-29 20:09:31,350 - octoprint.plugins.smsnotifier - INFO - Print notification sent to 9737152190 2019-01-29 20:09:31,851 - octoprint.plugins.tracking - INFO - Sent tracking event print_done, payload: {'origin': 'local', 'file': '198a9049267858f7f9919c789a3f09e86a4f7e78', 'elapsed': 15911} 2019-01-29 20:15:06,081 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 20:15:06,547 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 20:15:57,772 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 20:30:06,083 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 20:30:06,538 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 20:30:58,754 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 20:45:06,086 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 20:45:06,577 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 20:45:58,761 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 20:58:27,608 - octoprint.filemanager.analysis - INFO - Starting analysis of local:top_cover_hollow_1.gcode 2019-01-29 20:58:27,610 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/top_cover_hollow_1.gcode 2019-01-29 20:58:31,039 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 20:58:31,050 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 20:58:31,052 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 20:58:31,681 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:00:06,087 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 21:00:06,565 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 21:00:58,757 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 21:04:09,238 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 21:04:09,246 - octoprint.filemanager.analysis - INFO - Starting analysis of local:top_cover_hollow_1.gcode 2019-01-29 21:04:09,251 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python2 -m octoprint analysis gcode --speed-x=4800 --speed-y=4800 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/top_cover_hollow_1.gcode 2019-01-29 21:04:09,290 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:04:09,426 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:04:09,965 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:04:10,459 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e', 'elapsed': 338} 2019-01-29 21:04:12,338 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 21:04:14,057 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 21:04:38,655 - octoprint.filemanager.analysis - INFO - Analysis of entry local:top_cover_hollow_1.gcode finished, needed 29.41s 2019-01-29 21:08:39,765 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 21:08:39,775 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 21:08:39,806 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 21:08:40,430 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:13:37,632 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 21:13:37,654 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:13:37,742 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:13:38,362 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:13:38,826 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e', 'elapsed': 297} 2019-01-29 21:13:42,652 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 21:13:45,804 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 21:15:06,088 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 21:15:06,586 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 21:15:58,767 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 21:17:31,649 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing" 2019-01-29 21:17:31,658 - octoprint.plugins.detailedprogress - INFO - Printing started. Detailed progress started. 2019-01-29 21:17:31,666 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 21:17:32,173 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:21:19,364 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Cancelling" 2019-01-29 21:21:19,382 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:21:19,471 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped. 2019-01-29 21:21:19,954 - octoprint.plugins.tracking - INFO - Sent tracking event print_cancelled, payload: {'origin': 'local', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e'} 2019-01-29 21:21:20,734 - octoprint.plugins.tracking - INFO - Sent tracking event print_failed, payload: {'origin': 'local', 'reason': 'cancelled', 'file': '25624a79b7564ca31583add033c3cbeffb03f93e', 'elapsed': 227} 2019-01-29 21:21:24,285 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational" 2019-01-29 21:21:50,407 - octoprint.timelapse - WARNING - Cannot capture image, image number is unset 2019-01-29 21:30:06,089 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-29 21:30:06,557 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-29 21:30:58,782 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.198.181')]) 2019-01-29 21:31:45,858 - octoprint.startup - INFO - ** 2019-01-29 21:31:45,860 - octoprint.startup - INFO - Starting OctoPrint 1.3.10 2019-01-29 21:31:45,863 - octoprint.startup - INFO - ** 2019-01-29 21:31:45,995 - octoprint.startup - INFO - We don't appear to be online, not fetching plugin blacklist 2019-01-29 21:31:46,233 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages... 2019-01-29 21:31:48,362 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled. 2019-01-29 21:31:48,390 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled. 2019-01-29 21:31:50,257 - octoprint.plugin.core - INFO - Plugin ProgressBasedOntime Plugin (0.1.2) is disabled. 2019-01-29 21:31:50,579 - octoprint.plugin.core - INFO - Plugin EEPROM Marlin Editor Plugin (1.2.1) is disabled. 2019-01-29 21:31:52,992 - octoprint.plugin.core - INFO - Found 28 plugin(s) providing 24 mixin implementations, 37 hook handlers 2019-01-29 21:31:52,997 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval 2019-01-29 21:31:53,050 - octoprint.server - INFO - Intermediary server started 2019-01-29 21:31:53,050 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages... 2019-01-29 21:31:53,698 - octoprint.plugin.core - INFO - Found 28 plugin(s) providing 24 mixin implementations, 37 hook handlers 2019-01-29 21:31:53,735 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads... 2019-01-29 21:31:54,306 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully. 2019-01-29 21:31:54,592 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk 2019-01-29 21:31:54,599 - octoprint.plugins.tracking - INFO - Initialized anonymous tracking 2019-01-29 21:31:57,160 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 21:31:59,048 - octoprint.util.pip - INFO - Version of pip is 9.0.3 2019-01-29 21:31:59,049 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2019-01-29 21:31:59,050 - octoprint.util.pip - INFO - ==> pip ok -> yes 2019-01-29 21:31:59,055 - octoprint.plugin.core - INFO - Initialized 24 plugin implementation(s) 2019-01-29 21:31:59,073 - octoprint.plugin.core - INFO - 28 plugin(s) registered with the system: | Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt | Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements | Anonymous Usage Tracking (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/tracking | Application Keys Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/appkeys | Autoscroll (0.0.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_autoscroll | Backup & Restore (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/backup | Bed Visualizer (0.1.7) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_bedlevelvisualizer | Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard | !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura | Custom Control Editor (0.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_customControl | Detailed Progress Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_detailedprogress | Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery | !EEPROM Marlin Editor Plugin (1.2.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_eeprom_marlin | Force Login (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/forcelogin | Fullscreen Plugin (0.0.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_fullscreen | Gcodebar Plugin (0.1.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_GCodeBar | Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging | Octolapse (0.3.4) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_octolapse | Pi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pi_support | Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager | Print History Plugin (1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_printhistory | Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check | !ProgressBasedOntime Plugin (0.1.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_ProgressBasedOnTime | SMS Notifier (with Twilio) (0.3.2) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_smsnotifier | Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate | TouchUI (0.3.12) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui | TP-Link Smartplug (0.9.10) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_tplinksmartplug | !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer 2019-01-29 21:31:59,092 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details: | hardware: | cores: 4 | freq: 1400.0 | ram: 918188032 | os: | id: linux | platform: linux2 | plugins: | pi_support: | model: Raspberry Pi 3 Model B Plus Rev 1.3 | octopi_version: 0.15.1 | python: | pip: 9.0.3 | version: 2.7.13 | virtualenv: /home/pi/oprint 2019-01-29 21:31:59,104 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets... 2019-01-29 21:31:59,126 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache... 2019-01-29 21:31:59,177 - octoprint.plugins.octolapse - INFO - Octolapse is loading assets. 2019-01-29 21:31:59,611 - octoprint.server - INFO - Shutting down intermediary server... 2019-01-29 21:31:59,822 - octoprint.server - INFO - Intermediary server shut down 2019-01-29 21:31:59,824 - octoprint.events - INFO - Processing startup event, this is our first event 2019-01-29 21:31:59,834 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event 2019-01-29 21:31:59,836 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue... 2019-01-29 21:31:59,842 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue 2019-01-29 21:31:59,956 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port" 2019-01-29 21:31:59,962 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting" 2019-01-29 21:31:59,963 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "CGS3D"' for _http._tcp 2019-01-29 21:31:59,967 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 21:31:59,980 - octoprint.plugins.discovery - INFO - Registered 'OctoPrint instance "CGS3D"' for _octoprint._tcp 2019-01-29 21:31:59,992 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "CGS3D" for SSDP 2019-01-29 21:32:00,010 - octoprint.server - INFO - Listening on http://127.0.0.1:5000 2019-01-29 21:32:00,014 - octoprint.plugins.octolapse - INFO - Loading existing settings file from: /home/pi/.octoprint/data/octolapse/settings.json. 2019-01-29 21:32:00,104 - octoprint.plugins.bedlevelvisualizer - INFO - OctoPrint-BedLevelVisualizer loaded! 2019-01-29 21:32:00,112 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _important from network 2019-01-29 21:32:00,114 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _releases from network 2019-01-29 21:32:00,116 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _blog from network 2019-01-29 21:32:00,118 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _plugins from network 2019-01-29 21:32:00,120 - octoprint.plugins.announcements - INFO - Looks like we are offline, can't fetch announcements for channel _octopi from network 2019-01-29 21:32:00,137 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid 2019-01-29 21:32:00,448 - octoprint.plugins.pluginmanager - INFO - Looks like we are offline, can't fetch notices from network 2019-01-29 21:32:01,767 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 21:32:02,438 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip 2019-01-29 21:32:02,439 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes 2019-01-29 21:32:02,440 - octoprint.util.pip - INFO - ==> pip ok -> yes 2019-01-29 21:32:02,479 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online 2019-01-29 21:32:02,503 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid 2019-01-29 21:32:02,818 - octoprint.plugins.tplinksmartplug - INFO - TPLinkSmartplug loaded! 2019-01-29 21:32:02,931 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://cr-10minipi.lan/'} 2019-01-29 21:32:03,312 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.73s 2019-01-29 21:32:03,544 - octoprint.plugins.tracking - INFO - Sent tracking event startup, payload: {'python': '2.7.13', 'ram': 918188032, 'octopi_version': '0.15.1', 'version': u'1.3.10', 'pip': '9.0.3', 'cores': 4, 'freq': 1400.0, 'pi_model': 'Raspberry Pi 3 Model B Plus Rev 1.3', 'os': 'linux'} 2019-01-29 21:32:03,610 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json 2019-01-29 21:32:04,153 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.54s 2019-01-29 21:32:05,168 - octoprint.plugins.announcements - INFO - Loaded channel _blog from https://octoprint.org/feeds/octoblog.xml in 0.94s 2019-01-29 21:32:06,021 - octoprint.plugins.announcements - INFO - Loaded channel _plugins from https://plugins.octoprint.org/feed.xml in 0.74s 2019-01-29 21:32:06,538 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational" 2019-01-29 21:32:06,548 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2019-01-29 21:32:06,592 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin TH3D U1.R2.3" 2019-01-29 21:32:07,139 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.6s 2019-01-29 21:32:07,299 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 115200, u'printer_port': '/dev/ttyUSB0', 'firmware_name': 'Marlin TH3D U1.R2.3'} 2019-01-30 13:33:35,479 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-30 13:33:35,515 - octoprint.util.comm - INFO - Communication timeout while idle, trying to trigger response from printer. 2019-01-30 13:33:36,002 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {} 2019-01-30 13:33:46,210 - octoprint.server.preemptive_cache - INFO - ... done in 57703.28s 2019-01-30 13:48:35,483 - octoprint.server.heartbeat - INFO - Server heartbeat <3 2019-01-30 13:48:36,082 - octoprint.plugins.tr

zlcoburn commented 5 years ago

Hi,

I have a similar issue...The plugin is intermittent sometimes it will work and sometimes it wont. I noticed in the attached log that sometimes it seems to be able to connect and others it cannot. When it doesn't seem to work, I am still able to ping the device and control it with Kasa, so it itsn't a signal issue. Thanks in advance for your help!

Zach

plugin_tplinksmartplug_debug.log

jneilliii commented 5 years ago

Thanks @zlcoburn. From the log it seems at some point the device just stops responding to the messages being sent to it. For example, taking the following snippet of your log.

[2019-01-31 17:16:01,738] DEBUG: Checking status of 192.168.2.28.
[2019-01-31 17:16:01,740] DEBUG: {"system":{"get_sysinfo":{}},"emeter":{"get_realtime":{}}}
[2019-01-31 17:16:01,742] DEBUG: IP 192.168.2.28 is valid.
[2019-01-31 17:16:02,402] DEBUG: Sending command {"system":{"get_sysinfo":{}},"emeter":{"get_realtime":{}}} to 192.168.2.28
[2019-01-31 17:16:02,407] DEBUG: « ™K"system":{"get_sysinfo":{"sw_ver":"1.5.3 Build 180528 Rel.120721","hw_ver":"1.0","type":"IOT.SMARTPLUGSWITCH","model":"HS103(US)","mac":"B0:BE:76:DB:AB:9C","dev_name":"Smart Wi-Fi Plug Lite","alias":"3dPrinter","relay_state":1,"on_time":159,"active_mode":"none","feature":"TIM","updating":0,"icon_hash":"","rssi":-58,"led_off":0,"longitude_i":-748488,"latitude_i":399677,"hwId":"5D6724C33274433C7435032F3906DFAD","fwId":"00000000000000000000000000000000","deviceId":"8006A08C711C54DE7D8E55C0953324621B008F35","oemId":"0C4BB88C3A7DB96DD7A093FEAA9CD43C","next_action":{"type":-1},"err_code":0}},"emeter":{"get_realtime":{"err_code":-1,"err_msg":"module not support"}}}
[2019-01-31 17:19:13,181] DEBUG: Turning off 192.168.2.28.
[2019-01-31 17:19:13,184] DEBUG: {'autoConnect': True, 'ip': '192.168.2.28', 'btnColor': '#808080', 'autoDisconnectDelay': 0, 'sysCmdOff': False, 'gcodeEnabled': True, 'gcodeOnDelay': '10', 'emeter': None, 'countdownOnDelay': 0, 'label': 'TP-LINK', 'warnPrinting': True, 'gcodeOffDelay': '10', 'sysCmdOnDelay': 0, 'countdownOffDelay': 0, 'sysRunCmdOff': '', 'sysRunCmdOn': '', 'autoDisconnect': True, 'useCountdownRules': False, 'icon': 'icon-bolt', 'displayWarning': True, 'autoConnectDelay': 10, 'currentState': 'unknown', 'sysCmdOn': False, 'sysCmdOffDelay': 0}
[2019-01-31 17:19:13,216] DEBUG: IP 192.168.2.28 is valid.
[2019-01-31 17:19:23,218] DEBUG: Could not connect to 192.168.2.28.

at 5:16 it's able to send the get status command, but then a couple of minutes later the device is not responding to the commands being sent to it, but the plugin does see the device as the ip is valid. This means it's seeing it on the network, but the TP-Link protocol is not responding. I honestly don't know how I could debug this situation as the communication protocol being used was code appropriated from other sources (linked in readme). I personally have not tested with a HS103 only HS100 and HS110 and wonder if there may be some difference there. The only time I've seen issues like this the device would never respond and the only way to resolve was to unplug the unit from the wall and plug it back in and all was well.

Are there any errors in your octoprint.log at all?

I'd be curious if an older version of the plugin prior to the energy monitoring additions would make a difference in this situation. Maybe the plug sees that error message and then blocks communication with the pi for some security reason maybe. If you don't mind try installing the plugin from the url below in plugin manager and see if it is more stable for you or not.

https://github.com/jneilliii/OctoPrint-TPLinkSmartplug/archive/0.9.6.zip

zlcoburn commented 5 years ago

@jneilliii thanks for the quick reply! I have attached my log below and will try to uninstall and reinstall from the link you gave me above. I did find some TPLink errors in the log attached:

2019-01-31 15:54:49,307 - octoprint - ERROR - Exception on /api/plugin/tplinksmartplug [POST] Traceback (most recent call last): File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app response = self.full_dispatch_request() File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request rv = self.handle_user_exception(e) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception reraise(exc_type, exc_value, tb) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request rv = self.dispatch_request() File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request return self.view_functionsrule.endpoint File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 1149, in decorated_view return no_firstrun_access(flask_login.login_required(func))(*args, kwargs) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/octoprint/server/util/flask.py", line 1168, in decorated_view return func(*args, *kwargs) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask_login.py", line 758, in decorated_view return func(args, kwargs) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/octoprint/server/api/init.py", line 99, in pluginCommand response = api_plugin.on_api_command(command, data) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/octoprint_tplinksmartplug/init.py", line 201, in on_api_command return flask.jsonify(response) File "/home/pi/OctoPrint/venv/local/lib/python2.7/site-packages/flask/json.py", line 237, in jsonify return current_app.response_class(dumps(dict(*args, **kwargs), TypeError: 'NoneType' object is not iterable 2019-01-31 15:54:49,314 - tornado.access - ERROR - 500 POST /api/plugin/tplinksmartplug (192.168.2.35) 10047.26ms octoprint.log

jneilliii commented 5 years ago

I don't think the error we are seeing here is related to the issue, but I have identified the cause. I've incorporated a fix into the next version 0.9.11 that has some additional energy monitoring fixes and was awaiting feedback from other users before releasing. If you want to try that version as well you can install using the following url.

https://github.com/jneilliii/OctoPrint-TPLinkSmartplug/archive/0.9.11.zip

santanig5 commented 5 years ago

octoprint (1).log Unfortunately, it did not work any better for me. I will try the 9.6 version and report back

santanig5 commented 5 years ago

YES! 9.6 works consistently for me!! Log file attached. octoprint (2).log

Edit: After further testing I did find that the app does not like zero intervals, I set the polling interval to 0 and had a hell of a time changing it as the UI was locked up. Then I enabled countdown timers and 0 in the on delay would cause inconsistent starts, but changed to 1 and it works every time. Is this the expected behavior?

jneilliii commented 5 years ago

Thanks. The difference between 9.6 and the later versions was that the state logic was changed to be part of the api response rather than a saved value in the settings. I may go back to the previous logic in order for it to be more stable.

As for the intervals, if polling interval was set to 0 then every 0 minutes the plugin would be sending a request to the plug to get the data and then saving every time which is probably why you were having troubles getting it to change after making that setting. In cases like that, it's usually easier to open up the config.yaml and edit out the faulting setting.

Not really sure about the countdown timer option as that is something I don't really use and was added as a feature request. My assumption is that the plug's software doesn't like the 0 in it's own built in timer maybe.

santanig5 commented 5 years ago

Great! I will stay on 9.6 until told otherwise. Also worth noting your temperature failsafe plugin works with this configuration as well, although it seems to utilize the countdown timer delay, I would have thought the shutdown would be immediate. I will have to play with the shutdown timer and determine if and what the delay should be, I added the code to my OctoPrint Gcode, not my slicer. Is this the recommended use?

zlcoburn commented 5 years ago

@jneilliii I went straight to the 0.9.11 version, and it has work perfectly! Thanks for the quick reply and all of the help.

12345Josparky commented 5 years ago

Ok so can someone tell me what works here and if 0.9.11 works with HS105. Mine is grayed out also and does nothing. I have the HS105 plug and version 0.9.10?? Thanks for any help.

santanig5 commented 5 years ago

I've reinstalled 0.9.11 since zlcoburn had success and it is working for me too with the intervals set to more than 0. image

image

Copy the link from the post above and pate it as shown.

image

12345Josparky commented 5 years ago

Thanks for the reply. Ok well get this I just used my phone to power it on and off and now it works even shuts the printer off at the 900 sec. 15 min I told it too after the print. so I will just stay with this one long as it is working now. Till he uploads the update to the plugin manager. So if anyone else is having the troubles I would recommend turning the plug on and off with your phone app to try it.

santanig5 commented 5 years ago

I probably did the same during my testing without even thinking about it. Good callout!

Sent from my Verizon, Samsung Galaxy smartphone

-------- Original message -------- From: 12345Josparky notifications@github.com Date: 2/3/19 5:58 PM (GMT-05:00) To: jneilliii/OctoPrint-TPLinkSmartplug OctoPrint-TPLinkSmartplug@noreply.github.com Cc: santanig5 santaniellog@hotmail.com, Author author@noreply.github.com Subject: Re: [jneilliii/OctoPrint-TPLinkSmartplug] TP-Link Smartplug (0.9.10) HS105 not working consistantly. (#85)

Thanks for the reply. Ok well get this I just used my phone to power it on and off and now it works even shuts the printer off at the 900 sec. 15 min I told it too after the print. so I will just stay with this one long as it is working now. Till he uploads the update to the plugin manager. So if anyone else is having the troubles I would recommend turning the plug on and off with your phone app to try it.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHubhttps://github.com/jneilliii/OctoPrint-TPLinkSmartplug/issues/85#issuecomment-460097189, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AniL7553vG6qXviXkBADLWtcppkAYQlvks5vJ2mcgaJpZM4aclrB.

jneilliii commented 5 years ago

Officially released 0.9.11.