PSU-Control fails from time to time #82

azalanono · 2017-12-11T13:18:15Z

Hello.
From time to time I notice that PSU control fails either on automatically turning the ATX power on or off.
It happened right now again that it turned the ATX on correctly, but didn't turn it off (but the temperature of extruder was already on room temperature for more than 2 hours. (I came back into the room and noticed that all fans were still running). I clicked then the "flash-icon" in octoprint and PSU control turned the ATX off.

My suggestion is to slightly extend PSU control. It will hurt nobody when PSU-control repeatedly checks the temperature and repeats from time to time the ON and OFF command. I don't know if the ATX status can be read back from marlin, but sending a G80 or G81 every five minutes should not be problem at all and ensure that - even with delay - the PSU will finally be switched correctly.

kantlivelong · 2017-12-11T14:14:34Z

Going to need more info.

What hardware is OctoPrint running on?
OctoPrint Version?
Firmware Version?
PSUControl Version?

Additionally please provide DEBUG logs with the issue occurring. Steps below:

Enable DEBUG logging ( http://docs.octoprint.org/en/master/configuration/logging_yaml.html ) [Use octoprint.plugins.psucontrol for the component name]
Stop OctoPrint
Clear OctoPrint Logs
Start OctoPrint
Replicate the issue
Attach logs

azalanono · 2017-12-15T12:29:03Z

Hi, Bruce.

Hardware is a good old raspberry Pi version "B". The first one.
Printer is based on Marlin. Nothing has changed on hardware and firmware within last 3-4 months. Everything worked before your last update (except of 1-2 cases that it didn't turn PSU off, it always worked).

Software: It is actually "octopi" with all automated updates.
pi@octopi:~ $ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)"
NAME="Raspbian GNU/Linux"
VERSION_ID="8"
VERSION="8 (jessie)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
pi@octopi:~

This is one of the latest logs (but not the very latest one).
octoprint.log.zip

As I changed right now the folders for recording timelapses to an nfs mount (don't want to write my SD to death with unnecessary writing operations), I have now restarted octoprint. A job is running, I will see what happens afterwards.

azalanono · 2017-12-15T12:34:39Z

I forgot to mention that absolutely nothing appears in point of psucontrol tries to turn the PSU off, but i see that it logs that it turns the PSU on.

Suggestion:
it would be a good (safe) approach to send the PSU-ON/OFF command in intervals of some minutes.
So when one command got lost/ignored/..., it will come again after 2-3 minutes. Perhaps add a field to PSU Control where I can "re-send ON/OFF command interval" in ... minutes (or seconds)?

kantlivelong · 2017-12-15T15:00:22Z

Hi,

The logs that were attached are not fresh and I am not seeing any DEBUG statements. Can you follow the steps outlined and reattach?

Thanks

azalanono · 2017-12-15T20:53:09Z

Hi, Bruce.
I am always very careful when it comes to modify octoprint (as I am not familiar with its internals), so I please for confirming that I did it right.

I created the file ~/.octoprint/logging.yaml (owned by pi:pi with right 644) with following content:

loggers:
  octoprint.plugin.psucontrol:
    level: DEBUG

Then I restarted octoprint from its menu. Will this create the expected debug-level logfile you need? I cannot start a new printjob right now because I have a part on the printer and I am not there till monday.

This might be of interest for you:

After a printjob, the PSU remains on until I click then the PSU-Control icon. Only then it turns the PSU off.
When PSU is off and I enter a command, the PSU is automatically turned on, but now it is automatically turned off when IDLE time is reached.

kantlivelong · 2017-12-15T21:05:59Z

Looks correct.

I would also suggest enabling serial logging as that would help a lot. The only downside is that it can impact performance depending on the print.

When PSU is off and I enter a command, the PSU is automatically turned on, but now it is automatically turned off when IDLE time is reached.

Are you saying that it works properly when simply running a command(I imagine non-temperature related) and then waiting for timeout?

See if you can replicate the issue with the following tests:

Test 1

Ensure PSU is OFF
Manually send M104 S0
Wait timeout and see if it shuts off.

Test 2

Ensure PSU is OFF
Manually send M104 S100 Ensure that it is safe to heat your hotend
Wait timeout and see if it shuts off a few minutes after (timeout + cooldown time)

If either test results in the PSU not shutting off then send the logs.

azalanono · 2017-12-15T21:48:55Z

Hi, Bruce.
Surprisingly both tests ended with a turned-off PSU. As it should.

In Test 2, nozzle heating turns off after IDLE time, and when temperature goes below 50°C, PSU turns off, too.

kantlivelong · 2017-12-15T23:32:07Z

Do you know if this occurs with a specific gcode file or any? If a specific gcode file, can you upload the gcode from the print that failed as well the contents of ~/.octoprint/scripts/gcode?

azalanono · 2017-12-18T07:55:48Z

Hi, Bruce.
Today (back in my office) I did several tests.
It does not matter what file I send, today it was even worser than before. I tried to repeat what we tested on weekend. I manually turned off the PSU by clicking the flash-icon, then sent "M104 S55", waited that the extruder exceeds 50°C, and finally sent "M104 S0". This time it did not turn off the PSU.

Here you find the requested scripts.
all_scripts.zip

I also attach here the testing G-Code file (downloaded from printer, so it is what actually is stored there).
P_coin.gcode.zip

Here is the latest logfile, too:
octoprint.log.zip
Don't get confused, I copied the file after starting a new job (the job is running right now. But it should contain before the printed coin.

Hope this info helps.

kantlivelong · 2017-12-18T14:54:09Z

Since you are able to easily replicate it now can you supply fresh DEBUG logs with the issue occurring?

kantlivelong · 2017-12-18T14:55:31Z

... as well as serial logs.

kantlivelong · 2017-12-19T17:41:57Z

I just noticed. Your logging like has octoprint.plugin.psucontrol instead of octoprint.plugins.psucontrol. Bad on my part for missing when checking but shoot the logs whenever you can.

azalanono · 2017-12-21T15:07:04Z

Hi, Bruce.
I also was wondering about how you will find any useful detail in the log (noticed no difference), but now it is definitely verbose. :)

The behaviour is now as follows:

PSU starts up with printjob (as exprected).
After the printjob finished, I can see the decreasing extruder temperature while I watch in parallel the temperature graph and the logfile.
When the temperature got below 50°C, I'd expect that something would appear in the log, but nothing happens.
Finally I clicked the "Flash icon" to turn the PSU manually off. In same moment I got this logfile entries:

2017-12-21 15:46:26,661 - octoprint.plugins.psucontrol - INFO - Switching PSU Off
2017-12-21 15:46:26,668 - octoprint.plugins.psucontrol - DEBUG - Switching PSU Off Using GCODE: M81

After that I used the octoprint terminal to manually set the temperature to 55°C (M104 S55) and to turn heating off again (M104 S0).

2017-12-21 15:48:35,167 - octoprint.plugins.psucontrol - INFO - Auto-On - Turning PSU On (Triggered by M104)
2017-12-21 15:48:35,171 - octoprint.plugins.psucontrol - INFO - Switching PSU On
2

THIS TIME it triggered and did shut off the PSU, but this happened with a delay (when timeout triggered), and not when the nozzle temperature got below 50°C.
octoprint.log.zip

Seems that PSU control can/does not read the temperature continuously?

kantlivelong · 2017-12-21T15:13:49Z

Need a serial log.

azalanono · 2017-12-21T15:44:48Z

Hi, Bruce.
I did another test print meanwhile. Same again.

2017-12-21 16:26:18,324 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:23,342 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:28,357 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:33,371 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:35,640 - octoprint.util.comm - INFO - Finished in 846.090 s.
2017-12-21 16:26:35,689 - octoprint.plugins.detailedprogress - INFO - Printing stopped. Detailed progress stopped.
2017-12-21 16:26:38,386 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:43,464 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:48,486 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True
2017-12-21 16:26:53,586 - octoprint.plugins.psucontrol - DEBUG - isPSUOn: True

The message in last line repeats infinitely, even when both (nozzle and bed) are cold.

About serial log...
Please tell me exactly what I have to do to enable it.

kantlivelong · 2017-12-21T15:51:32Z

Going from memory but Settings > Serial > Enable serial logging. Make sure you send both fresh octoprint.log and serial.log files with the issue occurring.

azalanono · 2017-12-21T15:59:01Z

Please show me that lines I have to copy&paste into ~/.octoprint/logging.yaml

I noticed that the above path is wrong (oversaw that) and tried then /home/pi/.octoprint/logs/serial.log as well as a nfs share (/goliath/pi/serial.log). In both cases octoprint terminates its startup after a few seconds.

kantlivelong · 2017-12-21T16:00:55Z

http://docs.octoprint.org/en/master/configuration/config_yaml.html#id16

ntoff · 2017-12-21T16:29:29Z

You can enable serial logging here

No need to mess with configuration files manually. Once ticked, restart octoprint (I think, do it anyway just to be safe) and then the serial.log will appear in the regular logs section of octoprint's settings where you can download all the other logs.

Just, whatever you do, do NOT post any configuration files publicly, especially config.yaml, as it can contain things like your API key which can be used to gain full control over your printer if it's exposed to the internet.

azalanono · 2017-12-21T17:06:34Z

Ok, here with serial log, too....
logs.zip

And here some time marks:
2017-12-21 17:31:52 Octoprint starts its internal GCODE startup to load filament
2017-12-21 17:34:43 Bed leveling and print start....
2017-12-21 17:45:25 Send: M117 "OctoPi finish done"

2017-12-21 17:59:11,100 - Recv: ok T:23.2 /0.0 B:42.9 /0.0 @:0 B@:0

Printer is cold. I click now the flash icon.
2017-12-21 18:00:00,098 - Send: M81
2017-12-21 18:00:01,144 - Recv: ok
2017-12-21 18:00:01,217 - Send: M105
2017-12-21 18:00:01,245 - Recv: ok T:23.2 /0.0 B:42.5 /0.0 @:0 B@:0
...

kantlivelong · 2017-12-21T17:46:17Z

I do see in the logs that the job has stopped and indeed the idler timer isn't kicking in but so far I'm unable to replicate it here.

Can you try disabling all other 3rd party plugins and run again?

azalanono · 2017-12-21T18:37:14Z

I have disabled several 3rd party plugins.
The only enabled plugins are now:

EEPROM Marlin Editor Plugin (1.0.4)
FileManager (0.1.2)
Fullscreen Plugin (0.0.4)
Navbar Temperature Plugin (0.9)
PSU Control (0.1.6)
This plugins are installed since I use octoprint. They cannot be the cause.

kantlivelong · 2017-12-21T18:51:02Z

Please try this debug build.

Uninstall PSU Control
Restart OctoPrint
Install PSU Control using this URL https://github.com/kantlivelong/OctoPrint-PSUControl/archive/issue_82_debug.zip
Retest with DEBUG logs and serial logging.
Send logs

azalanono · 2017-12-21T20:28:50Z

octoprint.log.zip

kantlivelong · 2017-12-21T20:41:56Z

Thanks. It looks as if the idle limit is reached before your hotend is ready and then afterwards never restarted. Can you confirm by setting a longer timeout and retry? I'll adjust my tests here to replicate.

azalanono · 2017-12-21T21:01:30Z

octoprint.log.zip

kantlivelong · 2017-12-21T21:07:30Z

Confirmed and also replicated here.

Thanks for the help.

kantlivelong · 2017-12-26T15:55:38Z

I've committed a fix if you would like to try it. Same URL (https://github.com/kantlivelong/OctoPrint-PSUControl/archive/issue_82_debug.zip)

long running commands will still cause the idle timer limit to be reached but the idle sequence will be skipped. On the next command the timer will be restarted.

Example:
G28 - Timer started/reset
M109 - Timer limit reached in cases where heatup > idle timer. In such cases the idle process skips and the timer is essentially left off until the next command. (This is the same behavior as 0.1.5)
G1 E1 - Timer started/reset

kantlivelong · 2017-12-29T14:59:39Z

@azalanono have you had any chance to test this?

)

kantlivelong · 2018-01-01T18:41:10Z

Considering this fixed as of 5808be2. Closing

kantlivelong added the awaiting information label Dec 11, 2017

kantlivelong added awaiting information and removed awaiting information labels Dec 15, 2017

kantlivelong removed the awaiting information label Dec 18, 2017

kantlivelong added the awaiting information label Dec 18, 2017

kantlivelong added awaiting information and removed awaiting information labels Dec 21, 2017

kantlivelong added the bug label Dec 21, 2017

kantlivelong removed the awaiting information label Dec 21, 2017

Repository owner deleted a comment from azalanono Dec 26, 2017

kantlivelong added the awaiting feedback label Dec 26, 2017

kantlivelong added a commit that referenced this issue Jan 1, 2018

Only reset idleTimer if the timer object exists and is still alive. (#82

5808be2

)

kantlivelong removed the awaiting feedback label Jan 1, 2018

kantlivelong closed this as completed Jan 1, 2018

kantlivelong added the solved label Jan 1, 2018

rbk1rbk mentioned this issue Jul 11, 2018

Automatic switching off doesn't work #107

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PSU-Control fails from time to time #82

PSU-Control fails from time to time #82

azalanono commented Dec 11, 2017

kantlivelong commented Dec 11, 2017

azalanono commented Dec 15, 2017

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017 •

edited

Loading

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017

azalanono commented Dec 18, 2017 •

edited

Loading

kantlivelong commented Dec 18, 2017

kantlivelong commented Dec 18, 2017

kantlivelong commented Dec 19, 2017

azalanono commented Dec 21, 2017 •

edited

Loading

kantlivelong commented Dec 21, 2017

azalanono commented Dec 21, 2017 •

edited

Loading

kantlivelong commented Dec 21, 2017 via email •

edited

Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 via email •

edited

Loading

ntoff commented Dec 21, 2017

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 •

edited

Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 •

edited

Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 •

edited

Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017

kantlivelong commented Dec 26, 2017

kantlivelong commented Dec 29, 2017

kantlivelong commented Jan 1, 2018

PSU-Control fails from time to time #82

PSU-Control fails from time to time #82

Comments

azalanono commented Dec 11, 2017

kantlivelong commented Dec 11, 2017

azalanono commented Dec 15, 2017

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017 • edited Loading

Test 1

Test 2

azalanono commented Dec 15, 2017

kantlivelong commented Dec 15, 2017

azalanono commented Dec 18, 2017 • edited Loading

kantlivelong commented Dec 18, 2017

kantlivelong commented Dec 18, 2017

kantlivelong commented Dec 19, 2017

azalanono commented Dec 21, 2017 • edited Loading

kantlivelong commented Dec 21, 2017

azalanono commented Dec 21, 2017 • edited Loading

kantlivelong commented Dec 21, 2017 via email • edited Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 via email • edited Loading

ntoff commented Dec 21, 2017

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 • edited Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 • edited Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017 • edited Loading

azalanono commented Dec 21, 2017

kantlivelong commented Dec 21, 2017

kantlivelong commented Dec 26, 2017

kantlivelong commented Dec 29, 2017

kantlivelong commented Jan 1, 2018

kantlivelong commented Dec 15, 2017 •

edited

Loading

azalanono commented Dec 18, 2017 •

edited

Loading

azalanono commented Dec 21, 2017 •

edited

Loading

azalanono commented Dec 21, 2017 •

edited

Loading

kantlivelong commented Dec 21, 2017 via email •

edited

Loading

kantlivelong commented Dec 21, 2017 via email •

edited

Loading

kantlivelong commented Dec 21, 2017 •

edited

Loading

kantlivelong commented Dec 21, 2017 •

edited

Loading

kantlivelong commented Dec 21, 2017 •

edited

Loading