Raspberry shutdown

[Hesi-Re]

Hi! I configured TPLink Smartplug plugin so when I press the flash icon Raspberry Pi shutdown and after 15s shutdown printer. Raspberry Pi website goes off but the green flash led doesn't blinks as usual. I have on external activity LED witch is supposed to power of, but stays on until the plug cuts power. Something is happening with the shutdown command so looks like Raspberry Pi doesn't goes off completely. When I don't use this plugin, I can shutdown raspberry pi with shutdown command and I can see raspberry green led blinking 10 times before goes off.

[jneilliii]

Please share screenshot of your plug's settings.

[Hesi-Re]

I jus realized that Raspberry also shuts down, but it takes much longer to do it (+/- 35 seconds). If I shutdown raspberry using ssh commands or octoprint website, it shuts down in 10 seconds. Do you know why?

[jneilliii]

I need to go back to the code and workflow the process with all the options again. Just don't remember some of the timing introduced over the various versions. It may very well be some condition I didn't think about when I added the countdown option.

[Hesi-Re]

Hi. Did you find out what is the problem?

[stale[bot]]

This issue has been automatically marked as stale because it has not had activity in 14 days. It will be closed if no further activity occurs in 7 days.

[Hesi-Re]

This problem is solved in the last Octoprint release.

[lenabnana]

I'm having the same issue. Up to date on 1.3.12

[jneilliii]

The delay is in seconds. Your pi probably can't shutdown fast enough. Increase your off delay in the countdown timer section.

[lenabnana]

If I use the shutdown system button within Octoprint I see the green lights come on within 2 seconds and it shuts down after 5, but for the sake of troubleshooting I have adjusted it to 30 seconds and unfortunately same result. Solid red and the plug just flips off after 30. Doesn't seem to be shutting down Octoprint before killing power.

[jneilliii]

Ok, I'll take a look into this over the weekend hopefully. Can you test my current dev branch to see if thre same problem exists? Install by putting the url below into plugin manager.

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

[lenabnana]

Got some green flashing lights w the dev branch, but I was able to refresh and connect to octoprint right up until power down of the plug.

[jneilliii]

So I haven't been able to test yet, but the logic seems to be correct in code. Starting at the line here in the turn_off function the plugin sends the countdown rule to the plugin first and then starts a timer for the System Command. Just curious, does the same thing happen if you put a a value of 1 in the system command delay setting?

[lenabnana]

Yes, just tested with a delay of 1 instead of 0 and the result is the same.
I’m able to connect to octoprint right up until the power is cut.

Sent from my iPhone

On Feb 2, 2020, at 2:50 PM, jneilliii notifications@github.com wrote:

 So I haven't been able to test yet, but the logic seems to be correct in code. Starting at the line here in the turn_off function the plugin sends the countdown rule to the plugin first and then starts a timer for the System Command. Just curious, does the same thing happen if you put a a value of 1 in the system command delay setting?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

[jneilliii]

If not already enabled, enable debug logging and restart OctoPrint. Try the steps and then check octoprint.log and plugin_tplinksmartplug_debug.log for errors after. Let me know if you see anything.

[jneilliii]

Reading logs isn’t really my forte, so I’ll include them for you incase there is something that stands out to you.

From plugin_tplinksmartplug_debug:

[2020-02-02 20:44:19,162] DEBUG: Sending command {'system': {'get_sysinfo': {}}} to 192.168.1.8
[2020-02-02 20:44:19,452] DEBUG: «R€"system":{"get_sysinfo":{"sw_ver":"1.0.18 Build 191113 Rel.105413","hw_ver":"3.3","model":"HS105(US)","deviceId":"8006A980E1CB0C9914F8A68FD9CDE0311C27DB95","oemId":"16DD56EA45BADD08327504B19CFBA217","hwId":"E48B1F649DC598BDE89F2216EE4FACAA","rssi":-65,"longitude_i":-829849,"latitude_i":422762,"alias":"3D Printer","status":"new","mic_type":"IOT.SMARTPLUGSWITCH","feature":"TIM","mac":"50:D4:F7:EC:00:39","updating":0,"led_off":0,"obd_src":"tplink","relay_state":1,"on_time":353,"active_mode":"none","icon_hash":"","dev_name":"Smart Wi-Fi Plug Mini","next_action":{"type":-1},"err_code":0}}}
[2020-02-02 20:44:19,485] DEBUG: TIM
[2020-02-02 20:44:25,325] DEBUG: Turning off 192.168.1.8.
[2020-02-02 20:44:25,327] DEBUG: {'autoConnect': True, 'ip': '192.168.1.8', 'btnColor': '#808080', 'autoDisconnectDelay': 0, 'sysCmdOff': True, 'gcodeEnabled': False, 'gcodeOnDelay': 0, 'emeter': {'get_realtime': {}}, 'countdownOnDelay': '', 'label': 'Ender 5', 'warnPrinting': True, 'thermal_runaway': True, 'gcodeOffDelay': 0, 'sysCmdOnDelay': 0, 'event_on_error': False, 'countdownOffDelay': '30', 'sysRunCmdOff': 'sudo shutdown -h now', 'sysRunCmdOn': '', 'autoDisconnect': False, 'useCountdownRules': True, 'icon': 'icon-bolt', 'displayWarning': True, 'autoConnectDelay': '', 'event_on_disconnect': False, 'currentState': 'unknown', 'sysCmdOn': False, 'sysCmdOffDelay': '1'}
[2020-02-02 20:44:25,328] DEBUG: IP 192.168.1.8 is valid.
[2020-02-02 20:44:25,328] DEBUG: Sending command {u'count_down': {u'delete_all_rules': None}} to 192.168.1.8
[2020-02-02 20:44:25,724] DEBUG: «2â"count_down":{"delete_all_rules":{"err_code":0}}}
[2020-02-02 20:44:25,732] DEBUG: IP 192.168.1.8 is valid.
[2020-02-02 20:44:25,732] DEBUG: Sending command {u'count_down': {u'add_rule': {u'delay': 30, u'enable': 1, u'name': u'turn off', u'act': 0}}} to 192.168.1.8
[2020-02-02 20:44:26,106] DEBUG: «R‚"count_down":{"add_rule":{"id":"F4F370C5F3A045C12B49784AE85AF8B2","err_code":0}}}
[2020-02-02 20:41:04,907] DEBUG: OPERATIONAL
[2020-02-02 23:52:34,944] DEBUG: Checking status of 192.168.1.8.
[2020-02-02 23:52:34,945] DEBUG: {'system': {'get_sysinfo': {}}}
[2020-02-02 23:52:34,946] DEBUG: IP 192.168.1.8 is valid.
[2020-02-02 23:52:34,946] DEBUG: Sending command {'system': {'get_sysinfo': {}}} to 192.168.1.8
[2020-02-02 23:52:35,023] DEBUG: «R€"system":{"get_sysinfo":{"sw_ver":"1.0.18 Build 191113 Rel.105413","hw_ver":"3.3","model":"HS105(US)","deviceId":"8006A980E1CB0C9914F8A68FD9CDE0311C27DB95","oemId":"16DD56EA45BADD08327504B19CFBA217","hwId":"E48B1F649DC598BDE89F2216EE4FACAA","rssi":-66,"longitude_i":-829849,"latitude_i":422762,"alias":"3D Printer","status":"new","mic_type":"IOT.SMARTPLUGSWITCH","feature":"TIM","mac":"50:D4:F7:EC:00:39","updating":0,"led_off":0,"obd_src":"tplink","relay_state":1,"on_time":319,"active_mode":"none","icon_hash":"","dev_name":"Smart Wi-Fi Plug Mini","next_action":{"type":-1},"err_code":0}}}
[2020-02-02 23:52:35,052] DEBUG: TIM

I see a bunch of errors here but I don’t really know what they mean. Looks like a lot of them do not relate to your plugin. From octoprint_log:

020-02-02 20:40:58,207 - octoprint.plugins.tplinksmartplug - INFO - TPLinkSmartplug loaded!
2020-02-02 20:40:58,446 - backoff - INFO - Backing off wait_for_auth_token(...) for 0.9s (None)
2020-02-02 20:40:59,346 - backoff - INFO - Backing off wait_for_auth_token(...) for 0.8s (None)
2020-02-02 20:41:04,724 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2020-02-02 20:41:04,817 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2020-02-02 20:41:04,911 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin Creality 3D"
2020-02-02 20:41:04,919 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2020-02-02 20:41:20,200 - backoff - INFO - Backing off wait_for_auth_token(...) for 3.6s (None)
2020-02-02 23:48:02,907 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2020-02-02 23:48:12,629 - backoff - INFO - Backing off wait_for_auth_token(...) for 4.5s (None)
2020-02-02 23:48:27,143 - backoff - INFO - Backing off wait_for_auth_token(...) for 5.6s (None)
2020-02-02 23:48:42,765 - backoff - INFO - Backing off wait_for_auth_token(...) for 1.1s (None)
2020-02-02 23:48:53,929 - backoff - INFO - Backing off wait_for_auth_token(...) for 29.7s (None)
2020-02-02 23:49:25,334 - octoprint.plugins.thespaghettidetective - ERROR - Server websocket is closing
2020-02-02 23:49:42,783 - backoff - INFO - Backing off wait_for_auth_token(...) for 68.6s (None)
2020-02-02 23:50:52,872 - backoff - INFO - Backing off wait_for_auth_token(...) for 230.2s (None)
2020-02-02 23:51:50,048 - octoprint.server.util.flask - INFO - Passively logging in user lenabanana from ::ffff:192.168.1.25
2020-02-02 23:52:34,283 - octoprint.server.util.sockjs - INFO - New connection from client: fe80::1443:4cf:a3e7:a580
2020-02-02 23:52:34,403 - octoprint.server.util.flask - INFO - Passively logging in user lenabanana from ::ffff:192.168.1.25
2020-02-02 23:52:34,944 - octoprint.plugins.tplinksmartplug - INFO - ImmutableMultiDict([('checkStatus', u'192.168.1.8')])
2020-02-02 23:52:39,260 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2020-02-02 23:52:39,522 - octoprint.server.api - ERROR - Error calling SimpleApiPlugin pluginmanager
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/api/__init__.py", line 68, in pluginData
    response = api_plugin.on_api_get(request)
  File "/home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager/__init__.py", line 284, in on_api_get
    if refresh_notices or not self._is_notices_cache_valid():
  File "/home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager/__init__.py", line 865, in _is_notices_cache_valid
    return mtime + self._notices_cache_ttl >= time.time() > mtime
TypeError: unsupported operand type(s) for +: 'NoneType' and 'int'
2020-02-02 23:52:39,527 - tornado.access - ERROR - 500 GET /api/plugin/pluginmanager (::ffff:192.168.1.25) 4259.31ms
2020-02-02 23:52:43,455 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-02-02 23:52:55,555 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-02-02 23:52:55,559 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-02-02 23:52:55,593 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-02-02 23:52:55,623 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2020-02-02 23:53:07,314 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages/ (writable -> yes), --user flag needed -> no, virtual env -> yes
2020-02-02 23:53:07,315 - octoprint.util.pip - INFO - ==> pip ok -> yes
2020-02-02 23:53:26,769 - octoprint.plugins.softwareupdate - INFO - Saved version cache to disk
2020-02-02 23:53:26,837 - octoprint.server.util.sockjs - INFO - User lenabanana logged in on the socket from client fe80::1443:4cf:a3e7:a580
2020-02-02 23:54:47,469 - octoprint.plugins.thespaghettidetective - INFO - User account: {u'is_pro': True}
2020-02-02 23:54:47,470 - octoprint.plugins.thespaghettidetective - INFO - Starting webcam streamer
2020-02-02 23:54:49,593 - octoprint.plugins.thespaghettidetective - ERROR - Backing off 0.190809 seconds: Failed to connect to websocket server
2020-02-02 23:54:49,976 - octoprint.plugins.thespaghettidetective - ERROR - Backing off 0.387818 seconds: Failed to connect to websocket server
2020-02-02 23:54:50,478 - octoprint.plugins.thespaghettidetective - ERROR - Backing off 1.401017 seconds: Failed to connect to websocket server
2020-02-02 23:55:00,896 - backoff - INFO - Backing off wait_for_janus(...) for 0.7s (error: [Errno 111] Connection refused)
2020-02-02 23:55:02,575 - backoff - INFO - Backing off wait_for_janus(...) for 1.1s (error: [Errno 111] Connection refused)
2020-02-02 23:55:04,693 - backoff - INFO - Backing off wait_for_janus(...) for 3.2s (error: [Errno 111] Connection refused)

Hope that helps, I appreciate you trying to troubleshoot this. I did install a plugin called auto shut down so I will use that in conjunction with your add on to shut down pi before killing the power.
Thanks for all your hard work!

Edit: I re-created the post to be able to get formatting options since e-mail replies apparently don't allow for markdown editing.

[jneilliii]

Looks like I'll have to add some additional debug traps to the code. I don't see anything weird. You're right the errors in octoprint log appear to be unrelated, except I do utilize the SimpleApiPlugin mixin but that specific error appears to be related to pluginmanager and it's caching. The one weird thing I do see in the tplink debug log is this part.

[2020-02-02 20:44:26,106] DEBUG: «R�"count_down":{"add_rule":{"id":"F4F370C5F3A045C12B49784AE85AF8B2","err_code":0}}}
[2020-02-02 20:41:04,907] DEBUG: OPERATIONAL
[2020-02-02 23:52:34,944] DEBUG: Checking status of 192.168.1.8.

Somehow my plugin has achieved time travel, notice the skip back in time and back forward. The OPERATIONAL being logged there is from a PrinterStateChange event. I assume that's being triggered earlier and not writing to the log right away for some reason, and then the Checking Status is from when you brought the printer back online.

I'll try to run through some tests on my end to see if it acts the same for me or not. It would be good to know which version of OctoPrint you are running and what other plugins are installed. Taking a quick look at that auto shut down plugin there is some accomodation for timelapse rendering it seems, do you have timelapse options enabled? If not, then that plugin author is just allowing for that as a feature to avoid cutting timelapse renderding mid-process.

[lenabnana]

I’m on 1.3.12 I do have octolapse installed as well as the following plugins: The Spaghetti Detective Simple emergency stop Navbar temperature Fullscreen plugin Display eta Gcode editor Change filament Automatic shutdown

Sent from my iPhone

On Feb 2, 2020, at 11:33 PM, jneilliii notifications@github.com wrote:

 Looks like I'll have to add some additional debug traps to the code. I don't see anything weird. You're right the errors in octoprint log appear to be unrelated, except I do utilize the SimpleApiPlugin mixin but that specific error appears to be related to pluginmanager and it's caching. The one weird thing I do see in the tplink debug log is this part.

[2020-02-02 20:44:26,106] DEBUG: «R�"count_down":{"add_rule":{"id":"F4F370C5F3A045C12B49784AE85AF8B2","err_code":0}}} [2020-02-02 20:41:04,907] DEBUG: OPERATIONAL [2020-02-02 23:52:34,944] DEBUG: Checking status of 192.168.1.8. Somehow my plugin has achieved time travel, notice the skip back in time and back forward. The OPERATIONAL being logged there is from a PrinterStateChange event. I assume that's being triggered earlier and not writing to the log right away for some reason, and then the Checking Status is from when you brought the printer back online.

I'll try to run through some tests on my end to see if it acts the same for me or not. It would be good to know which version of OctoPrint you are running and what other plugins are installed. Taking a quick look at that auto shut down plugin there is some accomodation for timelapse rendering it seems, do you have timelapse options enabled? If not, then that plugin author is just allowing for that as a feature to avoid cutting timelapse renderding mid-process.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

[jneilliii]

Is this still an issue with the latest version 0.9.26 of the plugin ?

[github-actions[bot]]

This issue has been automatically marked as stale because it has not had activity in 14 days. It will be closed if no further activity occurs in 7 days