[BUG]:Printer does not turn off after the idle period

[Anathema-Device]

Describe the bug
Configuring the printer to be turned off after a 30 minute idle time does not seem to result in it being turned off. The printer can be turned off and on with the icon that the plugin puts in the Octoprint toolbar but does not turn off when the printer is idle

To Reproduce
Steps to reproduce the behavior:

1. Enable the checkbox to turn off on idle
2. Set the idle delay to be 30 minutes
3. Print something
4. Wait for it to turn off and nothing happens.

Expected behavior
The TPLink smart plug should be turned off after the idle time

Desktop (please complete the following information):

• Windows 11
• Brave
• OctoPrint Version : current release
• Plugin Version : current version

plugin_tplinksmartplug_debug.log

[github-actions]

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

[lethuer]

Sometimes I also observe that described behaviour, but isn't needed to print something. Just turn on the plug, connect and wait should turn off the printer.
My idle time is set to 3min...
Also not switching off after a print and reaching idle temperature...

But it's not present everytime, so I can't reproduce it yet.
Often after restarting OctoPrint (or System ?!) it's working again...
Any recommendations ?

M81 in terminal does not turn off the plug.
Shouldn't that be the case ?
Lightning button is working as expected.
HS110 with Firmware 1.0.6

[jneilliii]

Both of you need to share screenshots of your settings please. For M81 to work you have to include the IP address of the plug you want to turn off.

[lethuer]

Here are my settings.

For M81 I included the ip address...
But the plug didn't switched off.

In terminal:
Send: M81 192.168.178.46 Recv: M106 P0 S0 Recv: //action:notification Artillery Genius (lethuer) OFF. Recv: ok P15 B3

In log file:
[2024-04-01 16:25:45,237] DEBUG: Received M81 command, attempting power off of 192.168.178.46. [2024-04-01 16:25:45,242] DEBUG: {'autoConnect': True, 'autoConnectDelay': 10, 'autoDisconnect': True, 'autoDisconnectDelay': 0, 'automaticShutdownEnabled': True, 'btnColor': '#808080', 'countdownOffDelay': 1, 'countdownOnDelay': 1, 'currentState': 'off', 'displayWarning': True, 'emeter': {'get_realtime': {'current_ma': 13, 'err_code': 0, 'power_mw': 0, 'total_wh': 358, 'voltage_mv': 231418}}, 'event_on_disconnect': False, 'event_on_error': True, 'event_on_shutdown': False, 'event_on_startup': False, 'event_on_upload': False, 'gcodeCmdOff': False, 'gcodeCmdOn': False, 'gcodeEnabled': False, 'gcodeOffDelay': 0, 'gcodeOnDelay': 0, 'gcodeRunCmdOff': '', 'gcodeRunCmdOn': '', 'icon': 'icon-bolt', 'ip': '192.168.178.46', 'label': '3D Drucker', 'sysCmdOff': False, 'sysCmdOffDelay': 0, 'sysCmdOn': False, 'sysCmdOnDelay': 0, 'sysRunCmdOff': '', 'sysRunCmdOn': '', 'thermal_runaway': True, 'useCountdownRules': False, 'warnPrinting': True} [2024-04-01 16:27:58,798] DEBUG: resetting idle timer due to ClientOpened event.

Log file manual clicking lightning button for turning off (works):

[2024-04-01 16:37:01,151] DEBUG: Turning off 192.168.178.46. [2024-04-01 16:37:01,152] INFO: Turning off 192.168.178.46 at 2024-04-01 16:37:01.150941 [2024-04-01 16:37:01,157] DEBUG: {'autoConnect': True, 'autoConnectDelay': 10, 'autoDisconnect': True, 'autoDisconnectDelay': 0, 'automaticShutdownEnabled': True, 'btnColor': '#808080', 'countdownOffDelay': 1, 'countdownOnDelay': 1, 'currentState': 'off', 'displayWarning': True, 'emeter': {'get_realtime': {'current_ma': 13, 'err_code': 0, 'power_mw': 0, 'total_wh': 358, 'voltage_mv': 231418}}, 'event_on_disconnect': False, 'event_on_error': True, 'event_on_shutdown': False, 'event_on_startup': False, 'event_on_upload': False, 'gcodeCmdOff': False, 'gcodeCmdOn': False, 'gcodeEnabled': False, 'gcodeOffDelay': 0, 'gcodeOnDelay': 0, 'gcodeRunCmdOff': '', 'gcodeRunCmdOn': '', 'icon': 'icon-bolt', 'ip': '192.168.178.46', 'label': '3D Drucker', 'sysCmdOff': False, 'sysCmdOffDelay': 0, 'sysCmdOn': False, 'sysCmdOnDelay': 0, 'sysRunCmdOff': '', 'sysRunCmdOn': '', 'thermal_runaway': True, 'useCountdownRules': False, 'warnPrinting': True} [2024-04-01 16:37:01,284] DEBUG: IP 192.168.178.46 is valid. [2024-04-01 16:37:01,293] DEBUG: Sending command {'system': {'set_relay_state': {'state': 0}}} to 192.168.178.46 [2024-04-01 16:37:01,374] DEBUG: «��-ý"system":{"set_relay_state":{"err_code":0}}} [2024-04-01 16:37:01,400] DEBUG: 0 [2024-04-01 16:37:01,401] DEBUG: Checking status of 192.168.178.46.

[jneilliii]

@lethuer for gcode to work you have to enable the gcode trigger option.

[lethuer]

Awesome ! That works immediately if I send this manually in terminal :)

Now let me ask: After Idle time I can't observe M81 command in the terminal.
If gcode trigger is enabled, is M81 command send automatically and under which conditions ?
Is it possible to send M81 command when a desired nozzle temp is reached after a print ?

[jneilliii]

You could do that in your end gcode of your slicer or in OctoPrint's gcode script section. Can't remember if sending the wait for temp command will block until the temp is reached and then allow power off.

[lethuer]

Okay I will try if it is waited until reaching desired nozzle temperature...

Is here the correct location ?

[lethuer]

I also configured @TPLINKOFF code in section of cancelling a print.
Unfortunately I can't observe in terminal that this is sent.
Not directly after aborting the print and also not when nozzle is reaching 50 degree again.
Maybe because printer has changed it's status to "Operational" directly after "Cancelling" and long before reaching 50 degree ?

Send: N16 M118 P0 A1 action:cancel*14 Recv: //action:cancel Cancelling on request of the printer... Recv: ok N16 P15 B3 Send: N17 M84*41 Recv: ok N17 P15 B3 Send: N18 M104 T0 S0*24 Recv: ok N18 P15 B3 Send: N19 M140 S0*93 Recv: //action:notification Bed Cooling... Recv: ok N19 P15 B3 Send: N20 M106 S0*85 Recv: M106 P0 S0 Recv: ok N20 P15 B3 Changing monitoring state from "Cancelling" to "Operational" [...] Send: M117 L=-/- E=- Recv: ok P15 B3 Connection closed, closing down monitor Changing monitoring state from "Operational" to "Offline"

[lethuer]

I tried again and now received this:

Changing monitoring state from "Printing" to "Cancelling" Send: N15 M108*30 Recv: ok N14 P15 B3 Recv: ok N15 P15 B3 Send: N16 M117 L=-/83 E=-*62 Recv: ok N16 P15 B3 Send: N17 M118 P0 A1 action:cancel*15 Recv: //action:cancel Cancelling on request of the printer... Recv: ok N17 P15 B3 Send: N18 M84*38 Recv: ok N18 P15 B3 Send: N19 M104 T0 S0*25 Recv: ok N19 P15 B3 Send: N20 M140 S0*87 Recv: //action:notification Bed Cooling... Recv: ok N20 P15 B3 Send: N21 M106 S0*84 Recv: M106 P0 S0 Recv: ok N21 P15 B3 Send: N22 M81 192.168.178.46*29 Recv: M106 P0 S0 Recv: //action:notification Artillery Genius (lethuer) OFF. Recv: ok N22 P15 B3

I think the problem was that in my previous post I used @TPLINKOFF 192.168.178.46 instead of M81 192.168.178.46 in gcode section.

So now M81 was sent which I can observe in the terminal.
But nethertheless the plug didn't turned off.
I thought maybe because temperature was higher than needed for idle but tried also aborting a print when nozzle temp was below 50 degree and got the same result.
If I manually type M81 in the terminal the plug switches of immediately, so my assumption is that the plugin does prevent switching off somehow ?

[jneilliii]

Based on your printer response to m81 I suspect the other option of using @TPLINKOFF command would be better. Also, typically what I see with gcode processing is that the delay isn't long enough to allow the final commands from the file to clear the printing buffer. If you want me to assist further I need you to enable debug logging in the plugin's settings and restart OctoPrint. After attempting and it fails share plugin_tplinksmartplug_debug.log. That will help determine what the plugin is doing.

[lethuer]

Based on your printer response to m81 I suspect the other option of using @TPLINKOFF command would be better

But I didn't observe any command is sent if @TPLINKOFF was set up in gcode script section

If you want me to assist further I need you to enable debug logging in the plugin's settings and restart OctoPrint. After attempting and it fails share plugin_tplinksmartplug_debug.log. That will help determine what the plugin is doing.

Logging was active the hole time, here is the file also containing yesterday evening. Can you work with that ?
plugin_tplinksmartplug_debug.log

1st try with @TPLINKOFF
2nd try with M81

[lethuer]

I missed that option in plugin settings, so here is another try...

Nothing configured in gcode script section
14:39 turn on
14:39 start print
14:41 cancel print (nozzle temp in heating phase about 60 degree)
14:45 plug switches off (idle)

terminal:

Recv: echo:busy: processing
[...]
Changing monitoring state from "Printing" to "Cancelling"
Recv: echo:busy: processing
Send: N15 M108*30
Recv: ok N14 P15 B3
Recv: ok N15 P15 B3
Send: N16 M117 L=-/124 E=15:05*20
Recv: ok N16 P15 B3
[...]
Send: N17 M117 L=-/124 E=-*3
Recv: ok N17 P15 B3
Send: N18 M118 P0 A1 action:cancel*0
Recv: //action:cancel
Cancelling on request of the printer...
Recv: ok N18 P15 B3
Send: N19 M84*39
Recv: ok N19 P15 B3
Send: N20 M104 T0 S0*19
Recv: ok N20 P15 B3
Send: N21 M140 S0*86
Recv: //action:notification Bed Cooling...
Recv: ok N21 P15 B3
Send: N22 M106 S0*87
Recv: M106 P0 S0
Recv: ok N22 P15 B3
Changing monitoring state from "Cancelling" to "Operational"
[...]
Send: M117 L=-/- E=-
Recv: ok P15 B3
Connection closed, closing down monitor
Changing monitoring state from "Operational" to "Offline"

M81 configured in gcode script section
14:46 turn on
14:46 start print
14:48 cancel print (nozzle temp in heating phase about 70 degree)
14:52 plug switches off (idle)

terminal:

Recv: echo:busy: processing
[...]
Changing monitoring state from "Printing" to "Cancelling"
Send: N15 M108*30
Recv: ok N14 P15 B2
Recv: ok N15 P15 B3
Send: N16 M117 L=-/124 E=-*2
Recv: ok N16 P15 B3
Send: N17 M118 P0 A1 action:cancel*15
Recv: //action:cancel
Cancelling on request of the printer...
Recv: ok N17 P15 B3
Send: N18 M84*38
Recv: ok N18 P15 B3
Send: N19 M104 T0 S0*25
Recv: ok N19 P15 B3
Send: N20 M140 S0*87
Recv: //action:notification Bed Cooling...
Recv: ok N20 P15 B3
Send: N21 M106 S0*84
Recv: M106 P0 S0
Recv: ok N21 P15 B3
Send: N22 M81 192.168.178.46*29
Recv: M106 P0 S0
Recv: //action:notification Artillery Genius (lethuer) OFF.
Recv: ok N22 P15 B3
[...]
Changing monitoring state from "Cancelling" to "Operational"
[...]
Send: M117 L=-/- E=-
Recv: ok P15 B3
Connection closed, closing down monitor
Changing monitoring state from "Operational" to "Offline"

@TPLINKOFF configured in gcode script section
14:53 turn on
14:53 start print
14:55 cancel print (nozzle temp in heating phase about 60 degree)
14:58 plug switches off (idle)

terminal output: Again I didn't observe any command is sent if @TPLINKOFF was set up in gcode script section

Recv: echo:busy: processing
Changing monitoring state from "Printing" to "Cancelling"
Send: N14 M108*31
Recv: ok N13 P15 B2
Recv: ok N14 P15 B3
Send: N15 M117 L=-/124 E=15:18*27
Recv: ok N15 P15 B3
Send: N16 M117 L=-/124 E=-*2
[...]
Recv: ok N16 P15 B3
Send: N17 M118 P0 A1 action:cancel*15
Recv: //action:cancel
Cancelling on request of the printer...
Recv: ok N17 P15 B3
Send: N18 M84*38
Recv: ok N18 P15 B3
Send: N19 M104 T0 S0*25
Recv: ok N19 P15 B3
Send: N20 M140 S0*87
Recv: //action:notification Bed Cooling...
Recv: ok N20 P15 B3
Send: N21 M106 S0*84
Recv: M106 P0 S0
Recv: ok N21 P15 B3
Changing monitoring state from "Cancelling" to "Operational"
[...]
Send: M117 L=-/- E=-
Recv: ok P15 B3
Connection closed, closing down monitor
Changing monitoring state from "Operational" to "Offline"

The log file:
plugin_tplinksmartplug_debug.log

[jneilliii]

ok, so idle timeout is working properly. honestly that's the preferred approach as it will account for temperatures to be below a certain threshold before powering off.

It's normal to not see @ commands in the terminal, because those aren't sent to the printer, they are specifically used internally by OctoPrint. It is strange that it doesn't work as expected. Based on your comment you added that command to OctoPrint's on cancel gcode script?

[lethuer]

ok, so idle timeout is working properly.

Yes this time it worked like it should but in the past I had problems with it...
But don't know what was the reason for it.
Anyhow, this was the reason I was looking for another possibility to switch off the plug after a print.
Let's say kind of redundant if everything is working but double functionality if one approach does not work because of any circumstances :)

Based on your comment you added that command to OctoPrint's on cancel gcode script?

Correct, just like this.

[jneilliii]

Thanks I'll do some additional testing with gcode scripts being used to trigger. There's a chance that those commands might not go through the processing queue like the file commands do that the plugin is using to do the work.

[lethuer]

Hi ! I again observe this issue that printer does not turn off after printing...
Did you have the chance to look into it ?

[jneilliii]

Sorry, no, my focus has been on one of the many other plugins I maintain lately. Did you still have debug logging enabled? Could you share an updated log file if so. Also, by chance are you running the current stable version or the latest rc version?

[lethuer]

Here is an updated log file, print finished at 21:15
20241108_plugin_tplinksmartplug_debug.log

Version: 1.0.3

Settings:

[jneilliii]

Your settings are probably preventing the process from happening properly. Turn off run gcode command, and increase the GCODE off delay to allow the printer's printing buffer to complete and the printing status to change away from "printing". I'd start with trying 30 seconds.

[lethuer]

GCode was disabled before but I never tried with the delay.
Now I did but this makes no difference.

[jneilliii]

Did you happen to restart OctoPrint after the change?

[lethuer]

Yes sure :)

[jneilliii]

ok, had a chance to look at the actual log and noticed this...

resetting idle timer due to ClientOpened event.

but that was way after the idle timeout, any errors in octoprint.log?

what version are you running of the plugin? I just tested on my OctoPrint instance and powered on the printer from the button, it auto-connected and after the 3 minute timeout I got the message in the UI to allow me to cancel the power off if I wanted to and then it powered off.

[lethuer]

what version are you running of the plugin?

Version: 1.0.3

I just tested on my OctoPrint instance and powered on the printer from the button, it auto-connected and after the 3 minute timeout I got the message in the UI to allow me to cancel the power off if I wanted to and then it powered off.

Yes. this is also working for me but the printer does not turn off after a print.

This were the settings of the print today:

And the tp link log file:
20241111_plugin_tplinksmartplug_debug.log

Print was started at 16:33 and finished at 19:48.
At start I have this message:
[2024-11-11 16:33:25,096] DEBUG: Resetting idle timer since plug 192.168.178.46 was just turned on.
and approx 40min after finishing this one:
[2024-11-11 20:29:46,344] DEBUG: resetting idle timer due to ClientOpened event.
no such messages during printing...

Also I have enabled this one for logging:

I'm not really sure what to search for. The file is to large to upload here, but here is a download link:
https://1drv.ms/u/s!AmTrnLTKnK36iuoUUfBW8yk-SdGiKw?e=DGPUPO

[jneilliii]

let's see if the issue persists in the current rc version. in OctoPrint's software update settings change the release channel for the plugin to release candidate and update when prompted.

[lethuer]

Ok. Did so and started a print...

I powered on the printer from the button, it auto-connected and after the 3 minute timeout I got the message in the UI to allow me to cancel the power off if I wanted to and then it powered off.
We'll see in a few hours what is happening after a print...

[lethuer]

Okay print was started at 19:19 and finished at 22:34, nozzle temp of about 50 degree (idle target temperature) was reached again at 22:45.
TP Link plug did not turn off after print, here is the log with messages until 23:14
20241112_plugin_tplinksmartplug_debug_1.0.4rc4.log

I found this with "idle timer"

[2024-11-12 19:05:50,271] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:08:20,011] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:09:16,622] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:11:12,073] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:12:25,945] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:13:15,389] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:14:36,816] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-12 19:14:56,599] DEBUG: Resetting idle timer since plug 192.168.178.46 was just turned on.
[2024-11-12 19:19:17,964] DEBUG: Resetting idle timer since plug 192.168.178.46 was just turned on.
[2024-11-12 23:14:09,227] DEBUG: resetting idle timer due to ClientOpened event.

[jneilliii]

ok, this ClientOpened event apparently is getting in the way here. I don't know what application/plugin that is causing that, but it might be the telegram plugin? Basically the idle timer is getting reset because it detects "someone" connecting to OctoPrint's web interface, or potentially directly to the server/API backend.

Instead of using idle timers it seems you may need to use gcode triggers to get around that. Change your settings to this:

and then in OctoPrint's gcode scripts for after print completes and cancelled sections add the line @TPLINKOFF 192.168.178.46

[lethuer]

ok, this ClientOpened event apparently is getting in the way here. I don't know what application/plugin that is causing that, but it might be the telegram plugin?

I tried to disable telegram to check if this is the problem. TP link again did not switch off after the print was done.
Print was started at 11:00 and finished at 14:15, here is the log from that
20241113_plugin_tplinksmartplug_debug_telegram_disabled.log

I can still observe this ClientOpened event (so telegram seems not to be the issue):
How to evaluate which addin is responsible for those ClientOpened events ?

[2024-11-13 10:54:54,694] DEBUG: Settings saved, Automatic Power Off Enabled, starting idle timer...
[2024-11-13 10:55:49,293] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-13 10:59:34,259] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-13 10:59:39,056] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-13 10:59:44,693] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-13 10:59:54,730] DEBUG: Resetting idle timer since plug 192.168.178.46 was just turned on.
[2024-11-13 15:56:10,817] DEBUG: resetting idle timer due to ClientOpened event.

Instead of using idle timers it seems you may need to use gcode triggers to get around that.

Also tried this, here tp link does immediately switch off after the print was done.
It takes about 10 minutes to reach 50 degree again so would you recommend to set delay of gcode off to 10*60sec = 600 sec ?

[jneilliii]

It takes about 10 minutes to reach 50 degree again so would you recommend to set delay of gcode off to 10*60sec = 600 sec ?

Yes, since the gcode triggers don't support cooldown you can either increase this delay out to an estimated time frame, or alternatively use a cooldown command in your slicer's end gcode setting to do that for you. Adding the below line to the slicer's end gcode would wait until temp is reached.

M109 R50

this way the OctoPrint gcode scripts for print completion would not trigger immediately because the print job wouldn't complete until that 50 was reached. unfortunately this wouldn't work for cancelled prints so the long delay may be the way to go.

I don't know if there is a way to determine what client is being opened to troubleshoot that, but it's either someone opening the webpage or an external service/plugin doing it.

[lethuer]

This is a list of my installed plugins.
Any ideas which one could be the problem ?

[jneilliii]

ahh..ssd oled display might be the one. maybe not looking at its code.

[jneilliii]

if you enabled debug logging for octoprint.events.fire, it might help you determine where that is coming from.

It will show line like below in octoprint.log to see the username and ip address the client is connecting from.

2024-11-13 20:35:21,924 - octoprint.events.fire - DEBUG - Firing event: ClientOpened (Payload: {'remoteAddress': '::1'})
2024-11-13 20:35:22,071 - octoprint.events.fire - DEBUG - Firing event: UserLoggedIn (Payload: {'username': 'jneilliii'})

[lethuer]

if you enabled debug logging for octoprint.events.fire, it might help you determine where that is coming from.

plugin_tplinksmartplug_debug (2).log

Print started at 08:55 and finished at 10:19.
In that log file for example I can find:

[2024-11-15 08:53:31,400] DEBUG: Settings saved, Automatic Power Off Enabled, starting idle timer...
[2024-11-15 08:54:55,108] DEBUG: Resetting idle timer since plug 192.168.178.46 was just turned on.
[2024-11-15 08:56:51,280] DEBUG: resetting idle timer due to ClientOpened event.
[2024-11-15 08:56:57,412] DEBUG: resetting idle timer due to ClientOpened event.

After I enabled debug logging for octoprint.events.fire in octoprint.log I can see these "ClientOpened" events:

2024-11-15 08:56:51,268 - octoprint.events.fire - DEBUG - Firing event: ClientOpened (Payload: {'remoteAddress': '192.168.178.159'})
2024-11-15 08:56:57,396 - octoprint.events.fire - DEBUG - Firing event: ClientOpened (Payload: {'remoteAddress': '192.168.178.159'})
2024-11-15 11:28:29,880 - octoprint.events.fire - DEBUG - Firing event: ClientOpened (Payload: {'remoteAddress': '192.168.178.159'})

This is my laptop, maybe because I had the web view opened (but I have to to start the print job... )
No additional "ClientOpened" events beside these and tp link didn't turn off.

ahh..ssd oled display might be the one. maybe not looking at its code.

I give it a try and will disable the plugin.

[lethuer]

ahh..ssd oled display might be the one. maybe not looking at its code.

I give it a try and will disable the plugin.

Okay disabled the plugin and I'm wondering why there are still messages updated on the ssd display.
Anyhow, tp link does not switch off after the print when ssd add in is disabled.

[jneilliii]

I'm at a loss then for your issue. I am unable to reproduce and everything works fine for me with idle timeout.

[lethuer]

I think I've found the plugin which causes the problem...
Not 100% sure right now but if I disable "DisplayLayerProgress Plugin" tp link switches off after a print and reaching 50deg again.

I investigated a bit and it seems that as soon as I disable "Drucker Anzeige" in plugin settings of "DisplayLayerProgress Plugin" tp link does switch off after a print and reaching target temp again.