Nut upsuser - Dec 2013 - APC Smart-UPS 1500; system shutdown is not initiated.

Dear list,

I have an APC Smart-UPS 1500 hooked up via the USB port. Recently, when
we had a power outage, the only entry in the logs was:

Dec  3 14:43:43 afs1 upsmon[3035]: UPS apc at localhost on battery

and then the machine seems to have run until the battery was empty. It
only notices the "battery low" after I turn the system back on:

Dec  3 16:01:39 afs1 usbhid-ups[21973]: Startup successful
Dec  3 16:01:39 afs1 upsd[21975]: listening on 192.168.103.221 port 3493
Dec  3 16:01:39 afs1 upsd[21975]: listening on 127.0.0.1 port 3493
Dec  3 16:01:39 afs1 upsd[21975]: Connected to UPS [apc]: usbhid-ups-apc
Dec  3 16:01:39 afs1 upsd[21995]: Startup successful
Dec  3 16:01:39 afs1 upsmon[22054]: Startup successful
Dec  3 16:01:39 afs1 upsd[21995]: User monuser at 127.0.0.1 logged into UPS
[apc]
Dec  3 16:01:39 afs1 upsmon[22056]: UPS apc at localhost battery is low

Any ideas?

I include my config below... Thanks,

Christian

nut is debian wheezy's 2.6.4-2.3.

/etc/nut/ups.conf:
[apc]
        driver = usbhid-ups
        port = auto
        desc = "APC SmartUPS 1500"

Occasionally, i get these in daemon.log:
Dec  4 03:11:54 afs1 usbhid-ups[21973]: libusb_get_interrupt: could not
claim interface 0: Device or resource busy
Dec  6 11:50:55 afs1 usbhid-ups[21973]: libusb_get_interrupt: error
sending control message: Connection timed out

afs1:/var/log# upsc apc at localhost
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.mfr.date: 2008/05/22
battery.runtime: 3420
battery.runtime.low: 120
battery.temperature: 24.7
battery.type: PbAc
battery.voltage: 27.7
battery.voltage.nominal: 24.0
device.mfr: American Power Conversion
device.model: Smart-UPS 1500
device.serial: AS0821131402
device.type: ups
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.version: 2.6.4
driver.version.data: APC HID 0.95
driver.version.internal: 0.37
input.sensitivity: high
input.transfer.high: 253
input.transfer.low: 208
input.voltage: 231.8
output.current: 1.05
output.frequency: 50.0
output.voltage: 231.8
output.voltage.nominal: 230.0
ups.beeper.status: enabled
ups.delay.shutdown: 20
ups.delay.start: 30
ups.firmware: 653.18.I
ups.firmware.aux: 7.3
ups.load: 22.7
ups.mfr: American Power Conversion
ups.mfr.date: 2008/05/22
ups.model: Smart-UPS 1500
ups.productid: 0002
ups.serial: AS0821131402
ups.status: OL
ups.test.result: No test initiated
ups.timer.reboot: -1
ups.timer.shutdown: -1
ups.timer.start: -1
ups.vendorid: 051d

On Dec 7, 2013, at 2:38 PM, Christian wrote:
> Dear list,
> 
> I have an APC Smart-UPS 1500 hooked up via the USB port. Recently, when
> we had a power outage, the only entry in the logs was:
> 
> Dec  3 14:43:43 afs1 upsmon[3035]: UPS apc at localhost on battery
> 
> and then the machine seems to have run until the battery was empty. It
> only notices the "battery low" after I turn the system back on:
[...]
> Occasionally, i get these in daemon.log:
> Dec  4 03:11:54 afs1 usbhid-ups[21973]: libusb_get_interrupt: could not
> claim interface 0: Device or resource busy
This isn't great, but I don't think it's related.

It is normal to get a "could not claim interface 0" error once after
the USB cable is first plugged into a Linux box. When usbhid-ups starts up, if
it gets that error, it has to detach the kernel HID driver. After that point
(until the USB cable is unplugged or the box is rebooted), you shouldn't see
that error. I don't think you should see it from the libusb_get_interrupt
function, either. I'd check the logs here, but the usbhid-ups driver is
running on a BSD box at the moment, which doesn't have the same problem as
Linux.

How often do you see it? Is there a possibility of another program trying to
access the UPS?
> Dec  6 11:50:55 afs1 usbhid-ups[21973]: libusb_get_interrupt: error
> sending control message: Connection timed out
We increased the USB timeout in 2.7.1, so this should go away after upgrading.

These sorts of transient errors are not a problem unless you get several in a
row, and the driver should log a different message at that point.
> afs1:/var/log# upsc apc at localhost
> battery.charge: 100
> battery.charge.low: 10
> battery.charge.warning: 50
> battery.mfr.date: 2008/05/22
^ If this date is accurate (and I don't know for sure if our code can
reliably update this), then you may want to consider a new battery. Although an
UPS battery doesn't see the extreme temperature cycling that a car battery
does, it does typically run a few degrees above ambient, and the lead-acid
chemistry is only good for 3-5 years of reliable service.
> [...]
> ups.test.result: No test initiated
^ Occasional battery tests are needed to ensure that the calibration values can
predict when the battery is about to run out.

Some info is here:

http://forums.apc.com/thread/8669

If you post the output of 'upscmd -l apc', we can try to figure out
which calibration command would be the best to try.

-- 
Charles Lepple
clepple at gmail

Charles,

thanks for your detailed answer.
>> Occasionally, i get these in daemon.log: Dec  4 03:11:54 afs1 
>> usbhid-ups[21973]: libusb_get_interrupt: could not claim interface 
>> 0: Device or resource busy
> 
> This isn't great, but I don't think it's related.
> 
> It is normal to get a "could not claim interface 0" error once
after
> the USB cable is first plugged into a Linux box. When usbhid-ups 
> starts up, if it gets that error, it has to detach the kernel HID 
> driver. After that point (until the USB cable is unplugged or the
> box is rebooted), you shouldn't see that error. I don't think you
> should see it from the libusb_get_interrupt function, either. I'd
> check the logs here, but the usbhid-ups driver is running on a BSD
> box at the moment, which doesn't have the same problem as Linux.
> 
> How often do you see it?
This is does not appear following any plugging in or unplugging. It
appears roughly once a day, though not exactly regularly or at a
specific time of day. The box is in a locked server cabinet and nobody
is touching it.
> Is there a possibility of another program trying to access the UPS?
Not that I know of.
>> Dec  6 11:50:55 afs1 usbhid-ups[21973]: libusb_get_interrupt: error
>> sending control message: Connection timed out
> 
> We increased the USB timeout in 2.7.1, so this should go away after 
> upgrading.
> 
> These sorts of transient errors are not a problem unless you get 
> several in a row, and the driver should log a different message at 
> that point.
That is certainly not the case.
>> afs1:/var/log# upsc apc at localhost battery.charge: 100 
>> battery.charge.low: 10 battery.charge.warning: 50
>> battery.mfr.date: 2008/05/22
> 
> ^ If this date is accurate (and I don't know for sure if our code
> can reliably update this), then you may want to consider a new
> battery. Although an UPS battery doesn't see the extreme temperature
> cycling that a car battery does, it does typically run a few degrees
> above ambient, and the lead-acid chemistry is only good for 3-5 years
> of reliable service.
The date is correct. Though the UPS with the battery had been sitting on
a shelf in the basement unused for a significant fraction of that time...
>> [...] ups.test.result: No test initiated
> 
> ^ Occasional battery tests are needed to ensure that the calibration 
> values can predict when the battery is about to run out.
> 
> Some info is here:
> 
> http://forums.apc.com/thread/8669
> 
> If you post the output of 'upscmd -l apc', we can try to figure out
> which calibration command would be the best to try.
afs1:~# upscmd -l apc
Instant commands supported on UPS [apc]:

beeper.disable - Disable the UPS beeper
beeper.enable - Enable the UPS beeper
beeper.mute - Temporarily mute the UPS beeper
beeper.off - Obsolete (use beeper.disable or beeper.mute)
beeper.on - Obsolete (use beeper.enable)
load.off - Turn off the load immediately
load.off.delay - Turn off the load with a delay (seconds)
load.on - Turn on the load immediately
load.on.delay - Turn on the load with a delay (seconds)
shutdown.reboot - Shut down the load briefly while rebooting the UPS
shutdown.return - Turn off the load and return when power is back
shutdown.stayoff - Turn off the load and remain off
shutdown.stop - Stop a shutdown in progress
test.battery.start.deep - Start a deep battery test
test.battery.start.quick - Start a quick battery test
test.battery.stop - Stop the battery test
test.panel.start - Start testing the UPS panel
test.panel.stop - Stop a UPS panel test

Thanks,

Christian