[Nut-upsuser] usbhid-ups and "data stale"

[Czuczy Gergely]

On Thu, 7 Feb 2008 11:38:12 +0100 (CET)
"Arjen de Korte" <nut+users at de-korte.org> wrote:

> > I'm using nut 2.2.0 on FreeBSD 7.0-RC1. I've got two UPSes
> > (Back-UPS RS 1500) connected to the host, and I often see them to
> > go away. All the system logs are full of "Poll UPS [ups1 at upshost]
> > failed - Data stale".
> 
> First of all, it helps if you post the *full* line from the logs and
> also show some context (how often these messages occur).
That was the *full* line from the logs, except the syslog timestamp.
But I hardly think the timestamp and the hostname could be at any use
here.


> > What causes this issue?
> 
> The messages to the logs are reported by upsmon (a NUT client).
> Apparently, upsd (the NUT server) has lost the connection to the UPS
> and it is telling that it doesn't have fresh data available.
> 
> > Is this a known issue, is it going to be fixed?
> 
> This could be due to a known issue. Sometimes USB devices suddenly
> dissappear, due to interference. Depending on your hardware and
> environment, this may seldom happen or very often. If this happens
> (and the USB devices reconnect), up to (and including) nut-2.2.0
> would declare the data stale immediately. Since nut-2.2.1 we delay
> this, until an attempt to reconnect fails.
> 
> If the above is the problem, it would be solved by upgrading to
> nut-2.2.1 or at least, it should happen less frequently.
> 
> > What farther investigations should I do to get some more info on
> > this issue?
> 
> Before all, upgrade to nut-2.2.1.
Now, I've done the upgrade, after a few adjustments to the ports
Makefile I will submit the patches to the FreeBSD ports collection, so
everyone can make use of 2.2.1.

The problem is still there, after a few hours all the UPSes become
stale, and just nothing happens until I restart the driver processes.

some information from the UPSes (we've got two from the same model):
# upsc ups1
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.date: 2001/09/25
battery.mfr.date: 2004/09/04
battery.runtime: 1740
battery.runtime.low: 600
battery.type: PbAc
battery.voltage: 26.6
battery.voltage.nominal: 24.0
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.parameter.productid: 0002
driver.parameter.serial: JB0436038663
driver.parameter.vendorid: 051d
driver.version: 2.2.1
driver.version.data: APC HID 0.92
driver.version.internal: 0.32
input.transfer.high: 264
input.transfer.low: 194
input.voltage: 230.0
input.voltage.nominal: 230
ups.beeper.status: enabled
ups.delay.shutdown: -1
ups.firmware: 8.g8 .I
ups.firmware.aux: g8
ups.load: 70
ups.mfr: American Power Conversion
ups.mfr.date: 2004/09/04
ups.model: Back-UPS RS 1500
ups.productid: 0002
ups.serial: JB0436038663
ups.status: OL
ups.test.result: No test initiated
ups.vendorid: 051d
# upsc ups2
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.date: 2001/09/25
battery.mfr.date: 2004/09/04
battery.runtime: 64800
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 26.6
battery.voltage.nominal: 24.0
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.parameter.productid: 0002
driver.parameter.serial: JB0436038664
driver.parameter.vendorid: 051d
driver.version: 2.2.1
driver.version.data: APC HID 0.92
driver.version.internal: 0.32
input.transfer.high: 264
input.transfer.low: 194
input.voltage: 230.0
input.voltage.nominal: 230
ups.beeper.status: enabled
ups.delay.shutdown: -1
ups.firmware: 8.g8 .I
ups.firmware.aux: g8
ups.load: 0
ups.mfr: American Power Conversion
ups.mfr.date: 2004/09/04
ups.model: Back-UPS RS 1500
ups.productid: 0002
ups.serial: JB0436038664
ups.status: OL
ups.test.result: No test initiated
ups.vendorid: 051d

I've checked the logs, but there's nothing before/after the messages
that is become stale, no USB errors, no driver notices, nothing at all.

Some other logs for you -- unchopped. Before these entries, both UPSes
worked for a few hours:
Feb 14 19:20:06 luggage upsmon[82188]: Poll UPS [ups1 at luggage] failed - Data stale
Feb 14 19:20:06 luggage kernel: Feb 14 19:20:06 luggage upsmon[82188]: Poll UPS [ups1 at luggage] failed - Data stale
Feb 14 19:20:06 luggage upsmon[82188]: Communications with UPS ups1 at luggage lost
Feb 14 19:20:06 luggage upsd[22040]: Connection from 192.168.x,y
Feb 14 19:20:06 luggage upsd[22040]: Client on 192.168.x.y logged out
Feb 14 19:20:06 luggage upsd[22040]: Connection from 192.168.x.z
Feb 14 19:20:06 luggage upsd[22040]: Client on 192.168.x.z logged out
Feb 14 19:20:26 luggage upsmon[82188]: Poll UPS [ups1 at luggage] failed - Data stale
Feb 14 19:20:46 luggage upsmon[82188]: Poll UPS [ups1 at luggage] failed - Data stale
Feb 14 19:20:46 luggage kernel: Feb 14 19:20:46 luggage last message repeated 2 times
Feb 14 19:21:06 luggage upsmon[82188]: Poll UPS [ups1 at luggage] failed - Data stale



-- 
Sincerely,

CZUCZY Gergely
Publishing Factory Kft
http://www.publishing.hu/
Tel: +36-20-9554512