System rebooting after running script

[gonzalomorenorovetto]

Hi
I was running this script in ubuntu server 22.04 in a pr2100 for a long time, but suddenly it stopped working, so I reinstalled it, and after that everytime the system boots, it inmediately shuts down when running the daemon.

If I remove it, everything works, except fan control.

If I reinstall the script, it starts working, the fans spin down, but after a sudo reboot, it starts shutting down after booting.
If I use sudo shutdown it does shutdown, and when powering on, it boots fine, but the wdnas-hwtools daemon is not working and the fans are spinning at full speed.

It looks like when the daemon tries to change fan speed, it crashes an panics.

install.sh (the fan spins down after the script)

gonzalo@pr2100:~/wdnas-hwtools$ sudo ./install.sh
Check the model
Model name:                      Intel(R) Pentium(R) CPU  N3710  @ 1.60GHz
Check that the 8250_lpss driver is loaded
        Kernel driver in use: 8250_lpss
        Kernel modules: 8250_lpss
        Kernel driver in use: 8250_lpss
        Kernel modules: 8250_lpss
Get the serial port
Found PMC module at serial port /dev/ttyS5
Install wdhw tools dependencies
Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
python3-serial is already the newest version (3.5-1).
python3-smbus is already the newest version (4.3-2build1).
python3 is already the newest version (3.10.6-1~22.04).
hddtemp is already the newest version (0.3-beta15-54).
0 upgraded, 0 newly installed, 0 to remove and 3 not upgraded.
Create wdhwd user
uid=998(wdhwd) gid=998(wdhwd) groups=998(wdhwd),20(dialout)
Create wdhwd configuration file
Install wdhwd
Create client binary
Register wdhwd in systemd

log

gonzalo@pr2100:~$ sudo cat /var/log/wdhwd/daemon.log
2023-08-03 11:21:58,058 - __main__ - ERROR - FanControllerImpl: Fan error detected
2023-08-03 11:24:53,662 - __main__ - ERROR - WdHwDaemon: Daemon failed with PMCCommandRejectedException: ; exiting
2023-08-03 11:24:59,483 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:00,337 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:01,190 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:02,040 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting

journalctl

gonzalo@pr2100:~$ journalctl -b -u wdhwd
Aug 03 11:25:01 pr2100 systemd[1]: Started WD Hardware Controller Daemon.
Aug 03 11:25:02 pr2100 python3[2176]: Traceback (most recent call last):
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 322, in open
Aug 03 11:25:02 pr2100 python3[2176]:     self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
Aug 03 11:25:02 pr2100 python3[2176]: OSError: [Errno 16] Device or resource busy: '/dev/ttyS5'
Aug 03 11:25:02 pr2100 python3[2176]: During handling of the above exception, another exception occurred:
Aug 03 11:25:02 pr2100 python3[2176]: Traceback (most recent call last):
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
Aug 03 11:25:02 pr2100 python3[2176]:     return _run_code(code, main_globals, None,
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/lib/python3.10/runpy.py", line 86, in _run_code
Aug 03 11:25:02 pr2100 python3[2176]:     exec(code, run_globals)
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 942, in <module>
Aug 03 11:25:02 pr2100 python3[2176]:     ret = d.main(sys.argv)
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 827, in main
Aug 03 11:25:02 pr2100 python3[2176]:     pmc.connect(cfg.pmc_port)
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/local/lib/wdhwd/wdhwlib/wdpmcprotocol.py", line 385, in connect
Aug 03 11:25:02 pr2100 python3[2176]:     serial_port = serial.Serial(port = port_name,
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/lib/python3/dist-packages/serial/serialutil.py", line 244, in __init__
Aug 03 11:25:02 pr2100 python3[2176]:     self.open()
Aug 03 11:25:02 pr2100 python3[2176]:   File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 325, in open
Aug 03 11:25:02 pr2100 python3[2176]:     raise SerialException(msg.errno, "could not open port {}: {}".format(self._port, msg))
Aug 03 11:25:02 pr2100 python3[2176]: serial.serialutil.SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'
Aug 03 11:25:02 pr2100 systemd[1]: wdhwd.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 11:25:02 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:25:02 pr2100 systemd[1]: wdhwd.service: Scheduled restart job, restart counter is at 5.
Aug 03 11:25:02 pr2100 systemd[1]: Stopped WD Hardware Controller Daemon.
Aug 03 11:25:02 pr2100 systemd[1]: wdhwd.service: Start request repeated too quickly.
Aug 03 11:25:02 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:25:02 pr2100 systemd[1]: Failed to start WD Hardware Controller Daemon.

tty list

gonzalo@pr2100:~$ ll /sys/class/tty/*/device/driver
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS0/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS10/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS11/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS12/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS13/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS14/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS15/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS16/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS17/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS18/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS19/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS1/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS20/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS21/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS22/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS23/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS24/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS25/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS26/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS27/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS28/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS29/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS2/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS30/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS31/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS3/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS4/device/driver -> ../../../bus/pci/drivers/8250_lpss/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS5/device/driver -> ../../../bus/pci/drivers/8250_lpss/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS6/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS7/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS8/device/driver -> ../../../bus/platform/drivers/serial8250/
lrwxrwxrwx 1 root root 0 Aug  3 11:24 /sys/class/tty/ttyS9/device/driver -> ../../../bus/platform/drivers/serial8250/

first boot after installing (fans still spinning at max speed):

gonzalo@pr2100:~$ journalctl -b -u wdhwd
Aug 03 11:47:33 pr2100 systemd[1]: Started WD Hardware Controller Daemon.
Aug 03 11:47:39 pr2100 python3[1373]: Traceback (most recent call last):
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
Aug 03 11:47:39 pr2100 python3[1373]:     return _run_code(code, main_globals, None,
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/lib/python3.10/runpy.py", line 86, in _run_code
Aug 03 11:47:39 pr2100 python3[1373]:     exec(code, run_globals)
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 942, in <module>
Aug 03 11:47:39 pr2100 python3[1373]:     ret = d.main(sys.argv)
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 829, in main
Aug 03 11:47:39 pr2100 python3[1373]:     pmc_version = pmc.getVersion()
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/local/lib/wdhwd/wdhwlib/wdpmcprotocol.py", line 434, in getVersion
Aug 03 11:47:39 pr2100 python3[1373]:     return self.__processor.transceiveCommand(_PMC_COMMAND_VERSION)
Aug 03 11:47:39 pr2100 python3[1373]:   File "/usr/local/lib/wdhwd/wdhwlib/wdpmcprotocol.py", line 357, in transceiveCommand
Aug 03 11:47:39 pr2100 python3[1373]:     raise PMCCommandRejectedException()
Aug 03 11:47:39 pr2100 python3[1373]: wdhwlib.wdpmcprotocol.PMCCommandRejectedException
Aug 03 11:47:39 pr2100 systemd[1]: wdhwd.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 11:47:39 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:47:39 pr2100 systemd[1]: wdhwd.service: Scheduled restart job, restart counter is at 1.
Aug 03 11:47:39 pr2100 systemd[1]: Stopped WD Hardware Controller Daemon.
Aug 03 11:47:40 pr2100 systemd[1]: Started WD Hardware Controller Daemon.
Aug 03 11:47:40 pr2100 python3[2168]: Traceback (most recent call last):
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 322, in open
Aug 03 11:47:40 pr2100 python3[2168]:     self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
Aug 03 11:47:40 pr2100 python3[2168]: OSError: [Errno 16] Device or resource busy: '/dev/ttyS5'
Aug 03 11:47:40 pr2100 python3[2168]: During handling of the above exception, another exception occurred:
Aug 03 11:47:40 pr2100 python3[2168]: Traceback (most recent call last):
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
Aug 03 11:47:40 pr2100 python3[2168]:     return _run_code(code, main_globals, None,
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/lib/python3.10/runpy.py", line 86, in _run_code
Aug 03 11:47:40 pr2100 python3[2168]:     exec(code, run_globals)
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 942, in <module>
Aug 03 11:47:40 pr2100 python3[2168]:     ret = d.main(sys.argv)
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/local/lib/wdhwd/wdhwdaemon/daemon.py", line 827, in main
Aug 03 11:47:40 pr2100 python3[2168]:     pmc.connect(cfg.pmc_port)
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/local/lib/wdhwd/wdhwlib/wdpmcprotocol.py", line 385, in connect
Aug 03 11:47:40 pr2100 python3[2168]:     serial_port = serial.Serial(port = port_name,
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/lib/python3/dist-packages/serial/serialutil.py", line 244, in __init__
Aug 03 11:47:40 pr2100 python3[2168]:     self.open()
Aug 03 11:47:40 pr2100 python3[2168]:   File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 325, in open
Aug 03 11:47:40 pr2100 python3[2168]:     raise SerialException(msg.errno, "could not open port {}: {}".format(self._port, msg))
Aug 03 11:47:40 pr2100 python3[2168]: serial.serialutil.SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'
Aug 03 11:47:40 pr2100 systemd[1]: wdhwd.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 11:47:40 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:47:40 pr2100 systemd[1]: wdhwd.service: Scheduled restart job, restart counter is at 2.
Aug 03 11:47:40 pr2100 systemd[1]: Stopped WD Hardware Controller Daemon.
Aug 03 11:47:40 pr2100 systemd[1]: Started WD Hardware Controller Daemon.
Aug 03 11:47:41 pr2100 python3[2207]: Traceback (most recent call last):
Aug 03 11:47:41 pr2100 python3[2207]:   File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 322, in open
Aug 03 11:47:41 pr2100 python3[2207]:     self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
Aug 03 11:47:41 pr2100 python3[2207]: OSError: [Errno 16] Device or resource busy: '/dev/ttyS5'
Aug 03 11:47:42 pr2100 systemd[1]: wdhwd.service: Main process exited, code=exited, status=1/FAILURE
Aug 03 11:47:42 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:47:43 pr2100 systemd[1]: wdhwd.service: Scheduled restart job, restart counter is at 5.
Aug 03 11:47:43 pr2100 systemd[1]: Stopped WD Hardware Controller Daemon.
Aug 03 11:47:43 pr2100 systemd[1]: wdhwd.service: Start request repeated too quickly.
Aug 03 11:47:43 pr2100 systemd[1]: wdhwd.service: Failed with result 'exit-code'.
Aug 03 11:47:43 pr2100 systemd[1]: Failed to start WD Hardware Controller Daemon.

gonzalo@pr2100:~$ sudo cat /var/log/wdhwd/daemon.log
2023-08-03 11:21:58,058 - __main__ - ERROR - FanControllerImpl: Fan error detected
2023-08-03 11:24:53,662 - __main__ - ERROR - WdHwDaemon: Daemon failed with PMCCommandRejectedException: ; exiting
2023-08-03 11:24:59,483 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:00,337 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:01,190 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:25:02,040 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:36:02,873 - __main__ - ERROR - WdHwDaemon: Daemon failed with PMCCommandRejectedException: ; exiting
2023-08-03 11:47:34,384 - __main__ - ERROR - WdHwDaemon: Daemon failed with PMCCommandRejectedException: ; exiting
2023-08-03 11:47:40,211 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:47:41,027 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:47:41,885 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting
2023-08-03 11:47:42,717 - __main__ - ERROR - WdHwDaemon: Daemon failed with SerialException: [Errno 16] could not open port /dev/ttyS5: [Errno 16] Device or resource busy: '/dev/ttyS5'; exiting

edit:

Processes still using /dev/ttyS5:
                     USER        PID ACCESS COMMAND
/dev/ttyS5:          root     kernel mount /dev
                     root         37 .rc.. kdevtmpfs

[gonzalomorenorovetto]

just found this on the log when doing systemctl stat wdhwd

2023-08-03 12:30:18,423 - __main__ - ERROR - WdHwDaemon: Daemon failed with PMCCommandRejectedException: ; exiting
2023-08-03 12:30:35,059 - __main__ - ERROR - FanControllerImpl: Overheat condition requires immediate shutdown

[Mtillmann]

Did you ever find a resolution? I am struggling with similar issues

[Mtillmann]

This is how I worked around the issue on my PR2100:

sudo crontab -e

enter these 2 lines at the end of the file:

*/3 * * * * systemctl start wdhwd.service
*/3 * * * * wdhwc led -P -s -G

This will attempt to start the service every 3 minutes. This should actually kick in only once after boot. Still, the service never comes up on boot AND a reboot will result in the unit shutting itself down. It's not ideal but it somewhat remedies the issue.

Also, the second line will turn the power LED to solid green to indicate that the service is running although that should be audible as well :)

[gonzalomorenorovetto]

I think I did something similar, manually starting the service. I forgot about this issue, but it's still there.
Maybe it has to do with the serial console being on the same serial port? (I used serial console to install Ubuntu)

edit: this was my solution on crontab
@reboot sleep 90 && systemctl restart wdhwd.service

if I set the fan speed to 0, it inmediatly shuts down

[Mtillmann]

I installed ubuntu following this guide but still have the issue. Thanks for sharing