Header Shadow Image


UPS Monitoring: Linux apcupsd Back-UPS RS 1000G

Time to setup some APC ( Battery bacup or uninterruptible power supply – UPS ) monitoring for the home equipment.  The tool we'll use for this is the APCUPSD daemon available in RPM format. We've set one up for our HTPCB server for a home redundancy / backup solution to protect against power surges and bridge the various power outages in the neighborhood that have been happening recently.

apcupsd-cgi.x86_64 : Web interface for apcupsd
apcupsd-gui.x86_64 : GUI interface for apcupsd
apcupsd.x86_64 : APC UPS Power Control Daemon for Linux

Unfortunately, when setting it up and configuring it, we got this result:

 

Sep  6 22:27:01 mbpc apcupsd[12526]: apcupsd FATAL ERROR in linux-usb.c at line 605#012Cannot open UPS device: "/dev/ttyS0" –#012For a link to detailed USB trouble shooting information,#012please see <http://www.apcupsd.com/support.html>.
Sep  6 22:27:01 mbpc apcupsd[12526]: apcupsd error shutdown completed

 

Here's how we went about solving this one.  APC uses HID so it should be using one of the corresponding hid* devices in /dev:

# ls -al /dev/hiddev0
ls: cannot access /dev/hiddev0: No such file or directory
# ls -al /dev/usb
usb/     usbmon0  usbmon1  usbmon2  usbmon3  usbmon4  usbmon5  usbmon6  usbmon7 
# ls -al /dev/usb/hiddev0
crw-rw—-. 1 root root 180, 96 Sep  6 01:49 /dev/usb/hiddev0

# service apcupsd restart
Shutting down UPS monitoring:                              [FAILED]
Starting UPS monitoring:                                   [  OK  ]
# apctest
2012-09-06 22:39:32 apctest 3.14.10 (13 September 2011) redhat
Checking configuration …
Attached to driver: usb
sharenet.type = Network & ShareUPS Disabled
cable.type = USB Cable
mode.type = USB UPS Driver
Setting up the port …
apctest FATAL ERROR in linux-usb.c at line 605
Cannot open UPS device: "/dev/usb/hiddev0" –

For a link to detailed USB trouble shooting information,
please see <http://www.apcupsd.com/support.html>.
apctest error termination completed
 

Unfortunately, the only one available above, doesn't list anything.  When trying to use /dev/ttyS0 instead, we got this:

Sep  8 00:33:03 mbpc apcupsd[16170]: apcupsd FATAL ERROR in smartsetup.c at line 70#012Cannot open UPS port : No such file or directory
Sep  8 00:33:03 mbpc apcupsd[16170]: apcupsd error shutdown completed

and

# lspci|grep -i american

doesn't list any entries either and lsusb freezes at the command line.  The last thing we did is look at the USB messages in dmesg and /var/log/messages for any clues to the issue.  Sure enough, we found some clues that could fit into the output of USB commands above:


usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110
usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110
usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110
usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 10 ret -110
usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 4 ret -110
usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 6 len 255 ret -110
usb 3-3: USB setup failed (-19).
usb 3-3: USB setup failed (-19).

usb 3-4: usbfs: USBDEVFS_CONTROL failed cmd lsusb rqt 128 rq 0 len 2 ret -108
usb 3-4: USB disconnect, device number 3

 

usb 3-3: Atheros AR9170 is registered as 'phy0'
usb 3-3: USB disconnect, device number 2
 [] usb_disconnect+0xee/0×220
 [] usb_unbind_interface+0×124/0×170
 [] usb_disable_device+0xb0/0x2a0
 [] usb_set_configuration+0×185/0x7f0
 [] usb_unbind_device+0x1a/0×20
 [] usb_disconnect+0xee/0×220
 [] usb_unbind_interface+0×124/0×170
 [] usb_disable_device+0xb0/0x2a0
 [] usb_set_configuration+0×185/0x7f0
 [] usb_unbind_device+0x1a/0×20
 [] usb_disconnect+0xee/0×220
 [] usb_unbind_interface+0×124/0×170
 [] usb_disable_device+0xb0/0x2a0
 [] usb_set_configuration+0×185/0x7f0
 [] usb_unbind_device+0x1a/0×20
 [] usb_disconnect+0xee/0×220
 [] usb_unbind_interface+0×124/0×170
 [] usb_disable_device+0xb0/0x2a0
 [] usb_set_configuration+0×185/0x7f0
 [] usb_unbind_device+0x1a/0×20
 [] usb_disconnect+0xee/0×220
 [] usb_unbind_interface+0×124/0×170
 [] usb_disable_device+0xb0/0x2a0
 [] usb_set_configuration+0×185/0x7f0
 [] usb_unbind_device+0x1a/0×20

We also refer to the apcupsd.com manual pages for some hints and confirmation if in fact APC does use HID or not.  And it does use HID.  This is important because at least we have an idea exactly where to look for or to add to the DEVICE parameter in the apcupsd.conf file.

Of course, some are due to other devices.  Ultimately, we tested the cables with a different system and OS, a Windows 7 workstation, to ensure results were the same and activity will be seen in some fashion.  True enough one cable showed activity, the other didn't.  So we swapped the cables to the HTPC but still the results were the same as above.  Meanwhile, we tested the first cable on the Windows 7 workstation, and this time no activity was found on that cable.  So it looks like the cable might have been part of the problem though there is a bit of doubt in that Windows 7 might have simply already installed the software earlier when the second cable was plugged in first so no activity might have shown for the first cable.  Irrespective of that, we decided to do a reboot of the HTPC server to find out if that would make a difference.  And it looks like it did.  This time the devices file didn't halt and results were written (unlike before):

# cat /proc/bus/usb/devices|grep -i american
S:  Manufacturer=American Power Conversion
#

# cat /proc/bus/usb/devices|sed -e '/./{H;$!d;}' -e 'x;/American/!d;'

T:  Bus=07 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=12   MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=051d ProdID=0002 Rev= 0.90
S:  Manufacturer=American Power Conversion
S:  Product=Back-UPS RS 1000G FW:869.L3 .D USB FW:L3
S:  SerialNumber=3B1212X04489 
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  2mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=03(HID  ) Sub=00 Prot=00 Driver=usbhid
E:  Ad=81(I) Atr=03(Int.) MxPS=   8 Ivl=100ms
#

# ls -altri /dev/usb/hiddev*
6241 crw-rw—-. 1 root root 180, 96 Sep  8 14:27 /dev/usb/hiddev0
6270 crw-rw—-. 1 root root 180, 97 Sep  8 14:27 /dev/usb/hiddev1
#

# grep -v "#" /etc/apcupsd/apcupsd.conf|sed -e "/^$/d"
UPSCABLE usb
UPSTYPE usb
DEVICE /dev/usb/hiddev1
LOCKFILE /var/lock
SCRIPTDIR /etc/apcupsd
PWRFAILDIR /etc/apcupsd
NOLOGINDIR /etc
ONBATTERYDELAY 6
BATTERYLEVEL 5
MINUTES 3
TIMEOUT 0
ANNOY 300
ANNOYDELAY 60
NOLOGON disable
KILLDELAY 0
NETSERVER on
NISIP 0.0.0.0
NISPORT 3551
EVENTSFILE /var/log/apcupsd.events
EVENTSFILEMAX 10
UPSCLASS standalone
UPSMODE disable
STATTIME 5
STATFILE /var/log/apcupsd.status
LOGSTATS on
DATATIME 1
#

And running service apcupsd restart gave us the results we've been looking for.

Sep  8 14:40:18 mbpc apcupsd[4881]: 000.0,000.0,000.0,27.14,00.00,18.0,00.0,000.0,000.0,120.0,100.0,1
Sep  8 14:40:20 mbpc apcupsd[4881]: 000.0,000.0,000.0,27.14,00.00,18.0,00.0,000.0,000.0,120.0,100.0,0
Sep  8 14:40:20 mbpc apcupsd[4881]: APC      : 001,036,0887
Sep  8 14:40:20 mbpc apcupsd[4881]: DATE     : 2012-09-08 14:40:19 -0400 
Sep  8 14:40:20 mbpc apcupsd[4881]: HOSTNAME : mbpc
Sep  8 14:40:20 mbpc apcupsd[4881]: VERSION  : 3.14.10 (13 September 2011) redhat
Sep  8 14:40:20 mbpc apcupsd[4881]: UPSNAME  : mbpc
Sep  8 14:40:20 mbpc apcupsd[4881]: CABLE    : USB Cable
Sep  8 14:40:20 mbpc apcupsd[4881]: DRIVER   : USB UPS Driver
Sep  8 14:40:20 mbpc apcupsd[4881]: UPSMODE  : Stand Alone
Sep  8 14:40:20 mbpc apcupsd[4881]: STARTTIME: 2012-09-08 14:39:49 -0400 
Sep  8 14:40:20 mbpc apcupsd[4881]: MODEL    : Back-UPS RS 1000G
Sep  8 14:40:20 mbpc apcupsd[4881]: STATUS   : ONLINE
Sep  8 14:40:20 mbpc apcupsd[4881]: LINEV    : 120.0 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: LOADPCT  :  18.0 Percent Load Capacity
Sep  8 14:40:20 mbpc apcupsd[4881]: BCHARGE  : 100.0 Percent
Sep  8 14:40:20 mbpc apcupsd[4881]: TIMELEFT :  57.9 Minutes
Sep  8 14:40:20 mbpc apcupsd[4881]: MBATTCHG : 5 Percent
Sep  8 14:40:20 mbpc apcupsd[4881]: MINTIMEL : 3 Minutes
Sep  8 14:40:20 mbpc apcupsd[4881]: MAXTIME  : 0 Seconds
Sep  8 14:40:20 mbpc apcupsd[4881]: SENSE    : Medium
Sep  8 14:40:20 mbpc apcupsd[4881]: LOTRANS  : 088.0 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: HITRANS  : 139.0 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: ALARMDEL : 30 seconds
Sep  8 14:40:20 mbpc apcupsd[4881]: BATTV    : 27.1 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: LASTXFER : Low line voltage
Sep  8 14:40:20 mbpc apcupsd[4881]: NUMXFERS : 0
Sep  8 14:40:20 mbpc apcupsd[4881]: TONBATT  : 0 seconds
Sep  8 14:40:20 mbpc apcupsd[4881]: CUMONBATT: 0 seconds
Sep  8 14:40:20 mbpc apcupsd[4881]: XOFFBATT : N/A
Sep  8 14:40:20 mbpc apcupsd[4881]: SELFTEST : NO
Sep  8 14:40:20 mbpc apcupsd[4881]: STATFLAG : 0×07000008 Status Flag
Sep  8 14:40:20 mbpc apcupsd[4881]: SERIALNO : 3B1212X04489 
Sep  8 14:40:20 mbpc apcupsd[4881]: BATTDATE : 2012-03-21
Sep  8 14:40:20 mbpc apcupsd[4881]: NOMINV   : 120 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: NOMBATTV :  24.0 Volts
Sep  8 14:40:20 mbpc apcupsd[4881]: NOMPOWER : 600 Watts
Sep  8 14:40:20 mbpc apcupsd[4881]: FIRMWARE : 869.L3 .D USB FW:L3
Sep  8 14:40:20 mbpc apcupsd[4881]: END APC  : 2012-09-08 14:40:20 -0400 
Sep  8 14:40:21 mbpc apcupsd[4881]: 000.0,000.0,000.0,27.14,00.00,18.0,00.0,000.0,000.0,120.0,100.0,1

And sure enough, apcaccess now worked fine:

# apcaccess
APC      : 001,036,0899
DATE     : 2012-09-08 15:00:04 -0400 
HOSTNAME : mbpc
VERSION  : 3.14.10 (13 September 2011) redhat
UPSNAME  : Back-UPS.XS.1000
CABLE    : USB Cable
DRIVER   : USB UPS Driver
UPSMODE  : Stand Alone
STARTTIME: 2012-09-08 15:00:02 -0400 
MODEL    : Back-UPS RS 1000G
STATUS   : ONLINE
LINEV    : 119.0 Volts
LOADPCT  :  18.0 Percent Load Capacity
BCHARGE  : 100.0 Percent
TIMELEFT :  57.9 Minutes
MBATTCHG : 5 Percent
MINTIMEL : 3 Minutes
MAXTIME  : 0 Seconds
SENSE    : Medium
LOTRANS  : 088.0 Volts
HITRANS  : 139.0 Volts
ALARMDEL : 30 seconds
BATTV    : 27.1 Volts
LASTXFER : Low line voltage
NUMXFERS : 0
TONBATT  : 0 seconds
CUMONBATT: 0 seconds
XOFFBATT : N/A
SELFTEST : NO
STATFLAG : 0×07000008 Status Flag
SERIALNO : 3B1212X04489 
BATTDATE : 2012-03-21
NOMINV   : 120 Volts
NOMBATTV :  24.0 Volts
NOMPOWER : 600 Watts
FIRMWARE : 869.L3 .D USB FW:L3
END APC  : 2012-09-08 15:00:43 -0400 
#

Here is the final config file:

# grep -v "#" /etc/apcupsd/apcupsd.conf|sed -e "/^$/d"
UPSNAME Back-UPS.XS.1000
UPSCABLE usb
UPSTYPE usb
DEVICE /dev/usb/hiddev1
LOCKFILE /var/lock
SCRIPTDIR /etc/apcupsd
PWRFAILDIR /etc/apcupsd
NOLOGINDIR /etc
ONBATTERYDELAY 6
BATTERYLEVEL 5
MINUTES 3
TIMEOUT 0
ANNOY 300
ANNOYDELAY 60
NOLOGON disable
KILLDELAY 0
NETSERVER on
NISIP 0.0.0.0
NISPORT 3551
EVENTSFILE /var/log/apcupsd.events
EVENTSFILEMAX 10
UPSCLASS standalone
UPSMODE disable
STATTIME 0
STATFILE /var/log/apcupsd.status
LOGSTATS off
DATATIME 0
[root@mbpc ~]#

APC Test command should on the other hand give this output if the daemon is running (which is fine)

# apctest
2012-09-08 15:23:01 apctest 3.14.10 (13 September 2011) redhat
Checking configuration …
Attached to driver: usb
sharenet.type = Network & ShareUPS Disabled
cable.type = USB Cable
mode.type = USB UPS Driver
Setting up the port …
apctest FATAL ERROR in device.c at line 71
Unable to create UPS lock file.
  If apcupsd or apctest is already running,
  please stop it and run this program again.
apctest error termination completed
#

And you should be good.  Notice that the default apcupsd.conf file already included a time when it would shutdown the system if the UPS power falls below a certain level or time left: 3 minutes.  For us this was fine though you may wish to tweak this for your installation.

April 13 2013

A recent power outage lasted longer then the battery life allowed resulting in an automatic shutdown of the system.  Here are some messages of how this unfolded and worked:

Apr 11 12:45:40 mbpc apcupsd[18059]: Battery charge below low limit.
Apr 11 12:45:40 mbpc apcupsd[18059]: Initiating system shutdown!
Apr 11 12:45:40 mbpc wall[28627]: wall: user root broadcasted 1 lines (79 chars)
Apr 11 12:45:40 mbpc apcupsd[18059]: User logins prohibited
Apr 11 12:45:40 mbpc wall[28631]: wall: user root broadcasted 1 lines (50 chars)

Apr 11 12:45:41 mbpc init: tty (/dev/tty2) main process (18387) killed by TERM signal
Apr 11 12:45:41 mbpc init: tty (/dev/tty3) main process (18389) killed by TERM signal
Apr 11 12:45:41 mbpc init: tty (/dev/tty4) main process (18393) killed by TERM signal
Apr 11 12:45:41 mbpc init: tty (/dev/tty5) main process (18397) killed by TERM signal
Apr 11 12:45:41 mbpc init: tty (/dev/tty6) main process (18402) killed by TERM signal
Apr 11 12:45:45 mbpc init: prefdm main process (18382) killed by KILL signal
 

Cheers,
TK

Leave a Reply

 


     
  Copyright © 2003 - 2013 Tom Kacperski (microdevsys.com). All rights reserved.

Creative Commons License
This work is licensed under a Creative Commons Attribution 3.0 Unported License