kantlivelong / OctoPrint-PSUControl

Smart control of your power supply via GPIO, GCODE Command, System Command, or variety of sub-plugins.
GNU Affero General Public License v3.0
203 stars 113 forks source link

PSUControl shuts down PSU on Raspberry Pi just few seconds after startup #265

Open ArkBrj opened 1 year ago

ArkBrj commented 1 year ago

Hello, I have spent several hours debugging why PSUControl shuts down my printer right after startup of OctoPi and finally found the root cause. Strictly speaking the problem is not on the PSUControl's side, but I think PSUControl should at least document my findings on a wiki page (I could not find any) and maybe even have some workaround. The root cause of my problems was that after PSUControl's wait for idle timeout starts the system time gets changed by NTP and PSUControl's wait gets terminated prematurely. In my case the system time advanced by more than one day while the idle timeout was set for 30 mins, Instead of waiting for 30 mins it finished in few seconds and led to printer shutdown. I am using official OctoPi on Raspberry Pi with few plugins but I do not think they matter. What does matter is that Raspberry Pi does not maintain system time while being off. Instead, on startup it restores the time as it was at the moment of the last shutdown, which could have been hours, days or months ago. Later on, NTP sets the correct time but this can happen seconds or even minutes later depending on many reasons. Especially if only WiFi connectivity is available. So if it happens that PSUControl starts its idle timer before NTP advances system time, PSUControl's wait might take just few seconds.

PSUControl uses threading.Event.wait function to wait for timeout. Right now OctoPi with all Raspbian updates uses Python 3.9.2. According to the documentation, Python 3 is supposed to use monotonic clock for waits so they should not be affected by changes in the system time. However it is easy to see that this is not the case, at least for python 3.9.2. Simple repro on my octopi: 1) Open 2 ssh sessions to OctoPi 2) In one session run "date; python -c "from threading import Event; Event().wait(3600)"; date". This is supposed to print the current date/time, wait for 1 hour (3600 secs) and then print the current date/time again. 3) In another session just change the system data advancing it by couple of hours: "sudo date -s '2023-04-24 19:00'" (change the actual data/time accordingly). 4) Look at the first session and see that wait finishes the moment you change the system date/time instead of waiting for an hour.

As I mentioned above, this is strictly not PSUControl's problem and seems to be genuine bug in Python. However, given the fact that Raspberry Pi is a widely used platform for OctoPrint, maybe PSUControl can have some kind of protection logic to make sure that it does not turn off the printer due to sudden changes in the system date/time?

kantlivelong commented 1 year ago

Not really a bug in Python or the plugin. This should help you though https://raspberrypi.stackexchange.com/questions/94635/how-can-i-delay-the-startup-of-systemd-services-until-the-datetime-is-set-no-rt. Have the OctoPrint service depend on systemd-time-wait-sync.service

ArkBrj commented 1 year ago

It is for sure a bug in Python that periodically gets fixed and then reappears again. For example, a similar bug with condition variable: https://bugs.python.org/issue23428 I am aware about possibility to start octoprint only after time sync happens. But before I do this I need to see what happens if my Internet connection is down, which happens from time to time. Will octoprint start? How soon will it start? A lot to investigate...