Ups support broken? NAS does not respond to onbatt.

[Ryanmt]

Hi All,

I have just setup 2 nas's using freeNAS, one has an APC ups connceted to it via usb. The other is setup to remote monitor
(http://forums.freenas.org/showthread.php?3086-Network-UPS-Support-information-changes/page1)

I also have a pfsense router setup to monitor it too (although its disabled at the moment as it don't want it to power down )

So i can assume that the ups is connected correctly as all machines have full access to the stats. For example if i disconnect the ups from the supply I get this on both nas boxes.

Code:

[root@freenas] ~# tail -f /var/log/messages
May 21 08:00:19 freenas upsmon[2756]: UPS apc01 on line power
May 21 08:33:30 freenas upsmon[2756]: UPS apc01 on battery
May 21 08:37:15 freenas upsmon[2756]: UPS apc01 on line power
May 21 08:37:40 freenas upsmon[2756]: UPS apc01 on battery
May 21 08:38:20 freenas upsmon[2756]: UPS apc01 on line power

Only downside is that neither machines power down as expected when on battery. Eventually when the setup is up and running I want to have the remote boxes power down after 30 seconds of so on battery and the ups host machine on low battery (its hosting storage for VM's so the shutdown procedure is quite lengthy)


It seems like the upsmon service doesnt call the custom-upssched-cmd script atall on any event, if i manually trigger it the machine powers down as expected. (Might be barking up the wrong tree with this one...).

Code:

[root@freenas] ~# custom-upssched-cmd ONBATT
Network UPS Tools upsmon 2.6.2
[root@freenas] ~# tail -f /var/log/messages
May 22 02:36:09 freenas upssched-cmd: issuing shutdown
May 22 02:36:15 freenas upsmon[2756]: Executing automatic power-fail shutdown
May 22 02:36:15 freenas upsmon[2756]: Auto logout and shutdown proceeding

/usr/local/etc/nut/upsmon.conf

Code:

FINALDELAY 60
MONITOR apc01 1 upsmon fixmepass master
NOTIFYCMD "/usr/local/sbin/upssched"
NOTIFYFLAG ONBATT SYSLOG+WALL+EXEC
NOTIFYFLAG LOWBATT SYSLOG+WALL+EXEC
NOTIFYFLAG ONLINE SYSLOG+WALL+EXEC
NOTIFYFLAG FSD SYSLOG+EXEC
NOTIFYFLAG SHUTDOWN SYSLOG+EXEC
SHUTDOWNCMD "/sbin/shutdown -p now"

/usr/local/etc/nut/upssched.conf

Code:

CMDSCRIPT   /usr/local/bin/custom-upssched-cmd
PIPEFN      /var/db/nut/upssched.pipe
LOCKFN      /var/db/nut/upssched.lock

AT COMMBAD  * START-TIMER COMMBAD 10
AT COMMOK   * CANCEL-TIMER COMMBAD COMMOK
AT FSD      * EXECUTE FSD
AT LOWBATT  * START-TIMER LOWBATT 60
AT LOWBATT  * EXECUTE EMAIL
AT ONBATT   * START-TIMER ONBATT 60
AT ONBATT   * EXECUTE EMAIL
AT ONLINE   * CANCEL-TIMER ONBATT ONLINE
AT ONLINE   * CANCEL-TIMER LOWBATT ONLINE
AT REPLBATT * EXECUTE REPLBATT

Code:

[root@freenas] ~# upsc apc01@localhost
battery.charge: 78
battery.charge.low: 10
battery.charge.warning: 50
battery.runtime: 5100
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 49.7
battery.voltage.nominal: 24.0
device.mfr: American Power Conversion
device.model: Smart-UPS 3000
device.serial: IS1122000015  
device.type: ups
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: /dev/ugen1.1
driver.version: 2.6.2
driver.version.data: APC HID 0.95
driver.version.internal: 0.35
ups.beeper.status: enabled
ups.delay.shutdown: 20
ups.firmware: COM 02.1 / UPS.05.I
ups.mfr: American Power Conversion
ups.mfr.date: 2011/05/23
ups.model: Smart-UPS 3000
ups.productid: 0003
ups.serial: IS1122000015  
ups.status: OB DISCHRG
ups.timer.reboot: -1
ups.timer.shutdown: -1
ups.vendorid: 051d

Code:

[root@freenas] /usr/local/etc/nut# upsmon -D
Network UPS Tools upsmon 2.6.2
   0.000000	UPS: apc01 (master) (power value 1)
   0.000039	debug level is '1'
   0.000578	Trying to connect to UPS [apc01]
   0.000832	Logged into UPS apc01
  45.009188	UPS apc01 on battery
                                                                               
Broadcast Message from root@freenas.local                                      
        (/dev/pts/1) at 4:16 PDT...                                            
                                                                               
UPS apc01 on battery                                                           
                                                                               
Executing command: EMAIL
Error: unable to open database "/data/freenas-v1.db": unable to open database file

Im using the latest release of FreeNAS so am fully up to date. Does anybody else have a similar experience?


Thanks
Ryan

 

[Ryanmt]

After some trial and error I think I am a bit closer to the cause.

its in the custom-upssched-cmd script, whenever ran manually it works ok, however when run via the upsmon it errors out.

Code:

[root@freenas] /var/log# upsmon -D
Network UPS Tools upsmon 2.6.2
   0.000000	UPS: apc01@10.1.0.66 (slave) (power value 1)
   0.000039	debug level is '1'
   0.000599	Trying to connect to UPS [apc01@10.1.0.66]
   0.001067	Logged into UPS apc01@10.1.0.66
   0.001209	UPS apc01@10.1.0.66 on battery
                                                                               
Broadcast Message from root@freenas.local                                      
        (/dev/pts/0) at 6:47 PDT...                                            
                                                                               
UPS apc01@10.1.0.66 on battery                                                 
                                                                               
Executing command: EMAIL
Error: unable to open database "/data/freenas-v1.db": unable to open database file
^C  61.741642	Signal 2: exiting

I have tried commenting out the email functions from the script however it falls over then when it gets to onbatt, i tried commenting it out alltogether.. which removes the error but its still not working as intended :-(

Code:

#! /bin/sh
#
# This script should be called by upssched via the CMDSCRIPT directive.
#
# Here is a quick example to show how to handle a bunch of possible
# timer names with the help of the case structure.
#
# This script may be replaced with another program without harm.
#
# The first argument passed to your CMDSCRIPT is the name of the timer
# from your AT lines.

. /etc/rc.freenas

IFS=\|

f="ups_emailnotify ups_toemail ups_subject ups_shutdown"
sf=$(echo $f | sed -e 's/ /, /g')
#${FREENAS_SQLITE_CMD} ${FREENAS_CONFIG} \
#"SELECT $sf FROM services_ups ORDER BY -id LIMIT 1" | \
while eval read $f; do

case $1 in
        "ONBATT"|"LOWBATT")
#               if [ "${ups_shutdown}" = "lowbatt" -a "$1" = "LOWBATT" ] || [ "${ups_shutdown}" = "batt" -a "$1" = "ONBATT" ]; then
                        logger -t upssched-cmd "issuing shutdown"
                        /usr/local/sbin/upsmon -c fsd
#               fi
                ;;
        "SHUTDOWN"|"FSD")
#                if [ "${ups_emailnotify}" -eq 1 ]; then
#                      echo "$1" | mail -s "$(echo "${ups_subject}"|sed "s/%d/$(date)/"|sed "s/%h/$(hostname)/")" "${ups_toemail}"
#                fi
                ;;

I had a little play around and occaasionaly it seems to work, but from a fresh reboot it never does :-(

 

[Ryanmt]

Nobody got any ideas? Ive had another day playing with this issue and still cannot get reliable ups functionality from freeNAS, its never once managed to send an email during an onbatt, and I can only get it to shutdown if i remove all timers replace with execute and run "upsmon -DDDD".

I have this set-up on another centos server and its the exact same configs and it works flawlessly. Oddly that box reports when its starting a timer but freenas doesn't, as far as i can tell ups support on freenas is totally bust?

 

[Ryanmt]

Well i guess its a permissions issue, i edited /conf/base/etc/local/rc.d/nut_upsmon and changed the command to start upsmon with the -p flag. Not the best solution but when it runs as root everything works as expected. Ive tested the current and beta version of Freenas and it was the same on both, i don't think it was a configuration issue at my end.