[Nut-upsuser] Any suggestions why /bin/upssched-cmd isn't getting invoked?
Willcox David
dwillcoxster at gmail.com
Sat Apr 29 15:57:49 BST 2023
Hello, group. I hope this works. Question from a confused newbie...
I’ve been banging my head over this. As far as I can tell I’ve done everything as the instructions say, but one thing isn’t working. There must be something simple and basic I’m doing wrong, but just don’t see it.
About my setup. I have a CyberPower UPS serving as battery backup for a few “essential” things. It protects all of my internet connection boxes (fiber interface, WiFi, a switch, our VOIP phone), a couple of Raspberry Pis, and a Western Digital NAS (disk server).
Since the NAS is the least critical device and the biggest power drain, I’d like to shut it down relatively soon when the UPS goes on battery.
I have a Raspberry Pi 2 running a NUT server (and client for upsmon), using a USB connection to the UPS. The NAS happily talks to the Pi’s NUT server, and notices when the UPS goes on battery. (Whether it actually shuts itself down on low battery remains to be seen, but that’s for another day. I’m not even sure it will honor a FSD.)
So, all seems to be working, EXCEPT upsmon isn’t calling my CMDSCRIPT when expected. See the following syslog snippets. When I unplug/plug the UPS, I see upsmon “on battery” and “on line power” entries (so upsmon got the events), but none of the logs expected from the /bin/upssched-cmd script. When I manually call the script, I do get log entries.
Note that I don’t see the expected upssched.pipe and upssched.lock in /var/run/nut, though maybe those are transitory?
If anyone can see anything I’m missing I’d appreciate it.
Thanks!
When unplugging/plugging the UPS I see in the log:
> Apr 28 14:08:45 raspberrypi upsmon[558]: UPS usbhid at localhost on battery
> Apr 28 14:09:45 raspberrypi upsmon[558]: UPS usbhid at localhost on line power
And if I manually invoke "/bin/upssched-cmd test” I see:
> Apr 28 14:15:46 raspberrypi upssched-cmd: This is a test: test
> Apr 28 14:15:46 raspberrypi upssched-cmd: root
> Apr 28 14:15:46 raspberrypi upssched-cmd: Unrecognized command: test
So it's clear that upsmon is seeing events from the UPS, but isn't invoking upssched-cmd.
Note that I also don't see a WALL message, but maybe that's a Rasbperry thing. (The
wall command doesn't work, either.)
Versions of things:
Distributor ID: Raspbian
Description: Raspbian GNU/Linux 10 (buster)
Release: 10
Codename: buster
Linux raspberrypi 5.10.63-v7+ #1496 SMP Wed Dec 1 15:58:11 GMT 2021 armv7l GNU/Linux
ii nut 2.7.4-8 all network UPS tools
ii nut-cgi 2.7.4-8 armhf network UPS tools
ii nut-client 2.7.4-8 armhf network UPS tools
ii nut-server 2.7.4-8 armhf network UPS tools
Content of upsmon.conf: (I probably should have called it something other than “usbhid,” but that’s working for now.)
> RUN_AS_USER upsmon
> MONITOR usbhid at localhost 1 upsmon_master <thepassword> master
> MINSUPPLIES 1
> SHUTDOWNCMD "/sbin/shutdown -h +0"
> POLLFREQ 5
> POLLFREQALERT 5
> HOSTSYNC 15
> DEADTIME 15
> POWERDOWNFLAG /etc/killpower
> NOTIFYFLAG ONLINE SYSLOG+WALL+EXEC
> NOTIFYFLAG ONBATT SYSLOG+WALL+EXEC
> NOTIFYFLAG LOWBATT SYSLOG+WALL+EXEC
> NOTIFYFLAG REPLBATT SYSLOG+WALL+EXEC
> RBWARNTIME 43200
> NOCOMMWARNTIME 300
> FINALDELAY 5
Content of upssched.conf:
> Apr 28 14:09:45 raspberrypi upsmon[558]: UPS usbhid at localhost on line power
> CMDSCRIPT /bin/upssched-cmd
> PIPEFN /var/run/nut/upssched.pipe
> LOCKFN /var/run/nut/upssched.lock
> AT ONBATT * START-TIMER onbatt 30
> AT ONLINE * CANCEL-TIMER onbatt online
> AT LOWBAT * EXECUTE killnas
> AT SHUTDOWN * EXECUTE powerdown
Note: I tried changing the “AT ONBATT” to just do "EXECUTE test” to skip the timer, to no avail.
Content of upsd.users:
> [upsmon_master]
> password = <XXX>
> actions = SET,FSD
> instcmds = ALL
> upsmon master
> [upsmon]
> password = <XXX>
> upsmon slave
> [admin]
> password = <XXX>
> actions = SET,FSD
> instcmds = ALL
> upsmon master
Content of nut.conf:
> MODE=netserver
/bin/upssched-cmd:
> #! /bin/sh
>
> logger -t upssched-cmd "This is a test: $1"
> logger -t upssched-cmd `whoami`
>
> case $1 in
> onbatt)
> logger -t upssched-cmd "UPS running on battery"
> ;;
> killnas)
> logger -t upssched-cmd "Time to shut down NAS"
> /usr/sbin/upsmon -c fsd
> ;;
> earlyshutdown)
> logger -t upssched-cmd "UPS on battery too long, early shutdown"
> /usr/sbin/upsmon -c fsd
> ;;
> shutdowncritical)
> logger -t upssched-cmd "UPS on battery critical, forced shutdown"
> /usr/sbin/upsmon -c fsd
> ;;
> upsgone)
> logger -t upssched-cmd "The UPS has been gone for awhile"
> ;;
> *)
> logger -t upssched-cmd "Unrecognized command: $1"
> ;;
> esac
>
Existing directories and files:
> drwxr-xr-x 13 root root 4096 Apr 27 21:13 /var
> lrwxrwxrwx 1 root root 4 Dec 2 2020 /var/run -> /run
> drwxrwx--- 2 root nut 120 Apr 27 21:19 /run/nut
> -rw-r--r-- 1 nut nut 4 Apr 27 21:19 /var/run/nut/upsd.pid
> -rw-r--r-- 1 root root 4 Apr 27 21:19 /var/run/nut/upsmon.pid
> srw-rw---- 1 nut nut 0 Apr 27 21:19 /var/run/nut/usbhid-ups-usbhid
> -rw-r--r-- 1 nut nut 4 Apr 27 21:19 /var/run/nut/usbhid-ups-usbhid.pid
> -rwxr-xr-x 1 root root 986 Apr 27 14:11 /bin/upssched-cmd
Processes running:
> root root upsmon /lib/nut/upsmon
> upsmon nut upsmon /lib/nut/upsmon
Status:
root at raspberrypi:/etc/nut# service nut-server status
● nut-server.service - Network UPS Tools - power devices information server
Loaded: loaded (/lib/systemd/system/nut-server.service; enabled; vendor preset: enabled)
Active: active (running) since Thu 2023-04-27 21:19:44 CDT; 16h ago
Process: 428 ExecStart=/sbin/upsd (code=exited, status=0/SUCCESS)
Main PID: 446 (upsd)
Tasks: 1 (limit: 1935)
CGroup: /system.slice/nut-server.service
└─446 /lib/nut/upsd
Apr 27 21:19:44 raspberrypi upsd[428]: fopen /var/run/nut/upsd.pid: No such file or directory
Apr 27 21:19:44 raspberrypi upsd[428]: listening on 0.0.0.0 port 3493
Apr 27 21:19:44 raspberrypi upsd[428]: not listening on 127.0.0.1 port 3493
Apr 27 21:19:44 raspberrypi upsd[428]: listening on 0.0.0.0 port 3493
Apr 27 21:19:44 raspberrypi upsd[428]: not listening on 127.0.0.1 port 3493
Apr 27 21:19:44 raspberrypi upsd[428]: Connected to UPS [usbhid]: usbhid-ups-usbhid
Apr 27 21:19:44 raspberrypi upsd[428]: Connected to UPS [usbhid]: usbhid-ups-usbhid
Apr 27 21:19:44 raspberrypi upsd[446]: Startup successful
Apr 27 21:19:44 raspberrypi systemd[1]: Started Network UPS Tools - power devices information server.
Apr 27 21:19:46 raspberrypi upsd[446]: User upsmon_master at 127.0.0.1 <mailto:upsmon_master at 127.0.0.1> logged into UPS [usbhid]
> root at raspberrypi:/etc/nut# sudo service nut-client status
>
> Status:
> root at raspberrypi:/etc/nut# sudo service nut-client status
> ● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
> Loaded: loaded (/lib/systemd/system/nut-monitor.service; enabled; vendor preset: enabled)
> Active: active (running) since Thu 2023-04-27 21:19:46 CDT; 13h ago
> Process: 544 ExecStart=/sbin/upsmon (code=exited, status=0/SUCCESS)
> Main PID: 558 (upsmon)
> Tasks: 2 (limit: 1935)
> CGroup: /system.slice/nut-monitor.service
> ├─556 /lib/nut/upsmon
> └─558 /lib/nut/upsmon
>
> Apr 27 21:19:46 raspberrypi upsmon[544]: fopen /var/run/nut/upsmon.pid: No such file or directory
> Apr 27 21:19:46 raspberrypi upsmon[544]: UPS: usbhid at localhost (master) (power value 1)
> Apr 27 21:19:46 raspberrypi upsmon[544]: Using power down flag file /etc/killpower
> Apr 27 21:19:46 raspberrypi upsmon[556]: Startup successful
> Apr 27 21:19:46 raspberrypi upsmon[558]: Init SSL without certificate database
> Apr 27 21:19:46 raspberrypi systemd[1]: nut-monitor.service: Supervising process 558 which is not our child. We'
> Apr 27 21:19:46 raspberrypi systemd[1]: Started Network UPS Tools - power device monitor and shutdown controller
> Apr 27 21:54:33 raspberrypi upsmon[558]: UPS usbhid at localhost on battery
> Apr 27 22:01:33 raspberrypi upsmon[558]: UPS usbhid at localhost on line power
> Apr 28 09:41:11 raspberrypi upsmon[558]: Reloading configuration
>
> ● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
> Loaded: loaded (/lib/systemd/system/nut-monitor.service; enabled; vendor preset: enabled)
> Active: active (running) since Thu 2023-04-27 21:19:46 CDT; 13h ago
> Process: 544 ExecStart=/sbin/upsmon (code=exited, status=0/SUCCESS)
> Main PID: 558 (upsmon)
> Tasks: 2 (limit: 1935)
> CGroup: /system.slice/nut-monitor.service
> ├─556 /lib/nut/upsmon
> └─558 /lib/nut/upsmon
>
> Apr 27 21:19:46 raspberrypi upsmon[544]: fopen /var/run/nut/upsmon.pid: No such file or directory
> Apr 27 21:19:46 raspberrypi upsmon[544]: UPS: usbhid at localhost (master) (power value 1)
> Apr 27 21:19:46 raspberrypi upsmon[544]: Using power down flag file /etc/killpower
> Apr 27 21:19:46 raspberrypi upsmon[556]: Startup successful
> Apr 27 21:19:46 raspberrypi upsmon[558]: Init SSL without certificate database
> Apr 27 21:19:46 raspberrypi systemd[1]: nut-monitor.service: Supervising process 558 which is not our child. We'
> Apr 27 21:19:46 raspberrypi systemd[1]: Started Network UPS Tools - power device monitor and shutdown controller
> Apr 27 21:54:33 raspberrypi upsmon[558]: UPS usbhid at localhost on battery
> Apr 27 22:01:33 raspberrypi upsmon[558]: UPS usbhid at localhost on line power
> Apr 28 09:41:11 raspberrypi upsmon[558]: Reloading configuration
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20230429/9bad5c35/attachment-0001.htm>
More information about the Nut-upsuser
mailing list