[Nut-upsuser] Data stale and Back UPS ES
Denis Serov
dns-srv at yandex.ru
Fri Aug 31 20:03:52 UTC 2012
Hi, Frederic!
> -----Original Message-----
> From: FredericBohe at Eaton.com [mailto:FredericBohe at Eaton.com]
> Sent: Friday, August 31, 2012 12:56 PM
> To: dns-srv at yandex.ru; nut-upsuser at lists.alioth.debian.org
> Subject: RE: [Nut-upsuser] Data stale and Back UPS ES
>
> Hello Denis,
>
>> From:
>> nut-upsuser-bounces+fredericbohe=eaton.com at lists.alioth.debian.org
>> [nut-upsuser-bounces+fredericbohe=eaton.com at lists.alioth.debian.org]
>> on behalf of Denis Serov [dns-srv at yandex.ru]
>> Sent: Thursday, August 30, 2012 7:39 PM
>> To: nut-upsuser at lists.alioth.debian.org
>> Subject: [Nut-upsuser] Data stale and Back UPS ES>
>>
>> Hello!
>>
>> I tried NUT 2.6.5-1 (Windows port) with my APC Back UPS ES. It seems
>> I have configured NUT properly, nut-scanner found my UPS:
>>
>> [nutdev1]
>> driver = "usbhid-ups"
>> port = "auto"
>> vendorid = "051D"
>> productid = "0002"
>> product = "Back-UPS ES 525 FW:851.t3.I USB FW:t3"
>> serial = "8B0745R23575 "
>> vendor = "American Power Conversion"
>> bus = "bus-0"
>>
>> I see some errors:
>> 1. UPSMON/UPSC tools are returning "data stale":
>>
>> Network UPS Tools upsmon 2.6.5-3691:3709M
>> 0.000000 UPS: upsa at 192.168.10.200 (master) (power value 1)
>> 0.012000 Using power down flag file /etc/killpower
>> 0.022001 debug level is '5'
>> 0.026001 Trying to connect to UPS [upsa at 192.168.10.200]
>> 0.039002 Login on UPS [upsa at 192.168.10.200] failed - got [ERR
>> ACCESS-DENIED]
>> 0.044002 Current power value: 1
>> 0.047002 Minimum power value: 1
>> 5.049289 pollups: upsa at 192.168.10.200
>> 5.055289 get_var: upsa at 192.168.10.200 / status
>> 5.064289 Poll UPS [upsa at 192.168.10.200] failed - Data stale
>> 5.075290 do_notify: ntype 0x0005 (COMMBAD)
>> 5.083290 Communications with UPS upsa at 192.168.10.200 lost
>> ...
>>
>> What should I check to fix ACCESS-DENIED error?
>>
>> 2. UPSHID-UPS fails with output:
>>
>> Network UPS Tools - Generic HID driver 0.37 (2.6.5-3691:3709M) USB
>> communication driver 0.31
>> 0.000000 debug level is '3'
>> 0.000000 upsdrv_initups...
>> 0.031200 Checking device (051D/0002)
>> (bus-0/\\.\libusb0-0001--0x051d-0x0002)
>> 0.109200 - VendorID: 051d
>> 0.109200 - ProductID: 0002
>> 0.109200 - Manufacturer: American Power Conversion
>> 0.124800 - Product: Back-UPS ES 525 FW:851.t3.I USB FW:t3
>> 0.124800 - Serial Number: 8B0745R23575
>> 0.140400 - Bus: bus-0
>> 0.140400 Trying to match device
>> 0.140400 Device matches
>> 0.187200 HID descriptor, method 1: (9 bytes) => 09 21 10 01 21 01 22
>> 78 04
>> 0.202800 HID descriptor, method 2: (9 bytes) => 09 21 10 01 21 01 22
>> 78 04
>> 0.218400 HID descriptor length 1144
>> ...
>> 3.556806 Report[get]: (3 bytes) => 60 00 00
>> 3.556806 Path: UPS.ff860001.ff860023, Type: Feature, ReportID: 0x60,
>> Offset: 0, Size: 16, Value: 0
>> 3.588006 Report[get]: (2 bytes) => 61 89
>> 3.588006 Path: UPS.ff860001.ff860026, Type: Feature, ReportID: 0x61,
>> Offset: 0, Size: 8, Value: 137
>> 3.603606 Report[get]: (5 bytes) => 62 00 01 02 03
>> 3.619206 Path: UPS.ff860001.ff860025, Type: Feature, ReportID: 0x62,
>> Offset: 0, Size: 32, Value: 5.0463e+007
>> 3.634806 Report[get]: (2 bytes) => 51 84
>> 3.634806 Path: UPS.PowerConverter.ff860024, Type: Feature, ReportID:
>> 0x51, Offset: 0, Size: 8, Value: 132
>> 3.650406 Report descriptor retrieved (Reportlen = 1144)
>> 3.666007 Found HID device
>> 3.666007 Detected a UPS: American Power Conversion/Back-UPS ES 525
>> FW:851.t3.I USB FW:t3
>> 3.681607 libusb_get_report: libusb0-dll:err [control_msg] sending
>> control message failed, win error: A device attached to the system is
>> not functioning.
>
>It seems that it is a libusb error.
>Can you give us the Windows version you are using please ?
>Does this happens with the embedded libusb driver (i.e. the driver installed with the NUT/others/wdi-simple.exe binary) or by a manual install of libusb (which version ?) ?
>
Sorry, I forgot about it. I have installed NUT on Windows 7 Ultimate x64 (physical machine) and on Windows 7 Ultimate x86 (virtual machine, clean installation) with the same result.
And I used as wdi-simple.exe setup as different versions of libusb driver (1.2.4, 1.2.6 from http://sourceforge.net/projects/libusb-win32/files) with no success. Maybe I should try more old versions?
>>
>> 3.712807 Can't retrieve Report 0c: Input/output error [A device
>> attached to the system is not functioning. ]
>> 3.728407 Can't initialize data from HID UPS
>>
>> I installed different versions of libusb driver, but no success.
>>
>> The most interesting thing is that one of previous version (2.6.0-1
>> or
>> 2.6.1-1) returned real data from UPS. Any ideas?
>
>Very interesting. Same question as above, was it with the embedded libusb driver or a manual libusb driver install (and which version) ?
Windows 7 x64/x86, wdi-simple.exe from original installation.
I've just played with previous versions and here are more details:
Version 2.6.0-1
UPSMON output:
Network UPS Tools upsmon 2.6.0-2988:2989M
0.000000 UPS: upsa at 192.168.10.200 (master) (power value 1)
0.015600 Using power down flag file /etc/killpower
0.015600 debug level is '3'
0.031200 Trying to connect to UPS [upsa at 192.168.10.200]
0.046800 Login on UPS [upsa at 192.168.10.200] failed - got [ERR ACCESS-DENIED]
0.062400 pollups: upsa at 192.168.10.200
0.062400 get_var: upsa at 192.168.10.200 / status
0.078000 parse_status: [OL]
0.078000 parsing: [OL]
0.078000 ups_on_line: upsa at 192.168.10.200 (first time)
0.109200 pollups: upsa at 192.168.10.200
0.109200 get_var: upsa at 192.168.10.200 / status
0.124800 parse_status: [OL]
0.124800 parsing: [OL]
0.140400 pollups: upsa at 192.168.10.200
0.140400 get_var: upsa at 192.168.10.200 / status
0.156000 parse_status: [OL]
0.156000 parsing: [OL]
0.171600 pollups: upsa at 192.168.10.200
0.171600 get_var: upsa at 192.168.10.200 / status
No data stale, upsmon returns correct status.
UPSC output:
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.date: 2011/12/30
battery.mfr.date: 2011/12/30
battery.runtime: 6975
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.6
battery.voltage.nominal: 12.0
device.mfr: American Power Conversion
device.model: Back-UPS ES 525
device.serial: 8B0745R23575
device.type: ups
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.version: 2.6.0-2988:2989M
driver.version.data: APC HID 0.95
driver.version.internal: 0.35
input.sensitivity: medium
input.transfer.high: 255
input.transfer.low: 195
input.voltage: 217.8
input.voltage.nominal: 230
output.voltage.nominal: 2300.0
ups.beeper.status: disabled
ups.delay.shutdown: 20
ups.firmware: 851.t3.I
ups.firmware.aux: t3
ups.load: 0.0
ups.mfr: American Power Conversion
ups.mfr.date: 2007/11/07
ups.model: Back-UPS ES 525
ups.productid: 0002
ups.realpower.nominal: 300
ups.serial: 8B0745R23575
ups.status: OL
ups.test.result: No test initiated
ups.timer.reboot: 0
ups.timer.shutdown: -1
ups.vendorid: 051d
Everything is ok, except "output.voltage.nominal" property (2300.0 volts instead of 230.0).
UPSHID-UPS output:
Network UPS Tools - Generic HID driver 0.35 (2.6.0-2988:2989M) USB communication driver 0.31
0.000000 debug level is '3'
0.015600 upsdrv_initups...
0.046800 Checking device (051D/0002) (bus-0/\\.\libusb0-0001--0x051d-0x0002)
0.109200 - VendorID: 051d
0.124800 - ProductID: 0002
0.124800 - Manufacturer: American Power Conversion
0.140400 - Product: Back-UPS ES 525 FW:851.t3.I USB FW:t3
0.140400 - Serial Number: 8B0745R23575
0.156000 - Bus: bus-0
0.156000 Trying to match device
0.156000 Device matches
0.202800 HID descriptor, method 1: (9 bytes) => 09 21 10 01 21 01 22 78 04
0.218400 HID descriptor, method 2: (9 bytes) => 09 21 10 01 21 01 22 78 04
0.218400 HID descriptor length 1144
0.468001 Report Descriptor size = 1144
0.483601 Report Descriptor: (1144 bytes) => 05 84 09 04 a1 01 09 24 a1 02 85 01 09
...
1.060802 b2 a2 01 c0 05 84 09 16 a1 00 85 51 06 86 ff 09 24 16 75 00 26 a5 00 95 01
1.076402 75 08 b1 a2 c0 c0
1.092002 Using subdriver: APC HID 0.95
1.092002 Report[get]: (2 bytes) => 01 01
1.107602 Path: UPS.PowerSummary.iProduct, Type: Feature, ReportID: 0x01, Offset: 0, Size: 8, Value: 1
1.123202 Report[get]: (2 bytes) => 02 02
1.138802 Path: UPS.PowerSummary.iSerialNumber, Type: Feature, ReportID: 0x02, Offset: 0, Size: 8, Value: 2
1.154402 Report[get]: (2 bytes) => 03 03
1.170002 Path: UPS.PowerSummary.iManufacturer, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 3
1.185602 Report[get]: (2 bytes) => 04 03
1.185602 Path: UPS.PowerSummary.iOEMInformation, Type: Feature, ReportID: 0x04, Offset: 0, Size: 8, Value: 3
1.216802 Report[get]: (2 bytes) => 05 04
1.216802 Path: UPS.PowerSummary.iDeviceChemistry, Type: Feature, ReportID: 0x05, Offset: 0, Size: 8, Value: 4
1.248002 Report[get]: (3 bytes) => 06 01 02
1.248002 Path: UPS.PowerSummary.Rechargeable, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 1
1.263602 Report[buf]: (3 bytes) => 06 01 02
1.279202 Path: UPS.PowerSummary.CapacityMode, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 2
1.294802 Report[get]: (3 bytes) => 0e 64 64
1.310402 Path: UPS.PowerSummary.DesignCapacity, Type: Feature, ReportID: 0x0e, Offset: 0, Size: 8, Value: 100
1.279202 Path: UPS.PowerSummary.CapacityMode, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 2
1.294802 Report[get]: (3 bytes) => 0e 64 64
1.310402 Path: UPS.PowerSummary.DesignCapacity, Type: Feature, ReportID: 0x0e, Offset: 0, Size: 8, Value: 100
1.326002 Report[buf]: (3 bytes) => 0e 64 64
1.341602 Path: UPS.PowerSummary.FullChargeCapacity, Type: Feature, ReportID: 0x0e, Offset: 8, Size: 8, Value: 100
1.357202 libusb_get_report: libusb0-dll:err [control_msg] sending control message failed, win error: A device attached to the system is not functioning.
1.404003 Can't retrieve Report 0c: No error
1.404003 Path: UPS.PowerSummary.RemainingCapacity, Type: Input, ReportID: 0x0c, Offset: 0, Size: 8
1.419603 libusb_get_report: libusb0-dll:err [control_msg] sending control message failed, win error: A device attached to the system is not functioning.
1.450803 Can't retrieve Report 0c: No error
1.466403 Path: UPS.PowerSummary.RemainingCapacity, Type: Feature, ReportID: 0x0c, Offset: 0, Size: 8
1.482003 Report[get]: (3 bytes) => 10 01 01
1.497603 Path: UPS.PowerSummary.CapacityGranularity1, Type: Feature, ReportID: 0x10, Offset: 0, Size: 8, Value: 1
1.513203 Report[buf]: (3 bytes) => 10 01 01
1.513203 Path: UPS.PowerSummary.CapacityGranularity2, Type: Feature, ReportID: 0x10, Offset: 8, Size: 8, Value: 1
1.544403 Report[get]: (2 bytes) => 0f 32
1.544403 Path: UPS.PowerSummary.WarningCapacityLimit, Type: Feature, ReportID: 0x0f, Offset: 0, Size: 8, Value: 50
1.575603 Report[get]: (2 bytes) => 11 0a
1.575603 Path: UPS.PowerSummary.RemainingCapacityLimit, Type: Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 10
1.606803 Report[get]: (3 bytes) => 09 67 37
1.606803 Path: UPS.PowerSummary.ManufacturerDate, Type: Feature, ReportID: 0x09, Offset: 0, Size: 16, Value: 14183
1.638003 Report[get]: (3 bytes) => 0d 3f 1b
1.638003 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Input, ReportID: 0x0d, Offset: 0, Size: 16, Value: 6975
1.653603 Report[buf]: (3 bytes) => 0d 3f 1b
1.669203 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature, ReportID: 0x0d, Offset: 0, Size: 16, Value: 6975
1.684803 Report[get]: (3 bytes) => 12 ff ff
1.700403 Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x12, Offset: 0, Size: 16, Value: -1
1.716003 Report[get]: (4 bytes) => 13 00 00 00
...
4.321208 Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 1
4.336808 find_nut_info: unknown info type: load.on.delay
4.336808 find_nut_info: unknown info type: load.on.delay
4.352408 upsdrv_initinfo...
4.352408 upsdrv_updateinfo...
4.383608 Report[int]: (2 bytes) => 38 00
4.399208 Got 1 HID objects...
4.399208 Report[buf]: (2 bytes) => 38 00
4.399208 Path: UPS.APCStatusFlag, Type: Input, ReportID: 0x38, Offset: 0, Size: 8, Value: 0
4.414808 NUT doesn't use this HID object
4.430408 Quick update...
4.430408 Report[buf]: (3 bytes) => 12 ff ff
4.446008 Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x12, Offset: 0, Size: 16, Value: -1
4.461608 Report[buf]: (4 bytes) => 13 00 00 00
4.477208 Path: UPS.PowerSummary.DelayBeforeReboot, Type: Feature, ReportID: 0x13, Offset: 0, Size: 24, Value: 0
4.492808 Report[buf]: (3 bytes) => 07 0c 00
4.492808 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x07, Offset: 2, Size: 1, Value: 1
4.524008 Report[buf]: (3 bytes) => 07 0c 00
4.524008 Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x07, Offset: 1, Size: 1, Value: 0
...
Please, look at the error "libusb_get_report: libusb0-dll:err [control_msg] sending control message failed, win error: A device attached to the system is not functioning." in this log. It the same as the error from 2.6.5-1 version, but process is not terminated.
Version 2.6.1-1
UPSMON output:
Network UPS Tools upsmon 2.6.1-3057:3116M
0.000000 UPS: upsa at 192.168.10.200 (master) (power value 1)
0.015600 Using power down flag file /etc/killpower
0.015600 debug level is '3'
0.031200 Trying to connect to UPS [upsa at 192.168.10.200]
0.046800 Login on UPS [upsa at 192.168.10.200] failed - got [ERR ACCESS-DENIED]
5.054409 pollups: upsa at 192.168.10.200
5.054409 get_var: upsa at 192.168.10.200 / status
5.054409 Poll UPS [upsa at 192.168.10.200] failed - Data stale
5.054409 do_notify: ntype 0x0005 (COMMBAD)
5.054409 Communications with UPS upsa at 192.168.10.200 lost
Data stale =(
UPSC output:
Error: Data stale
UPSHID-UPS output:
...
6.318011 send_to_all: SETINFO ups.firmware "851.t3.I"
6.318011 send_to_all: SETINFO ups.mfr "American Power Conversion"
6.333612 send_to_all: SETINFO ups.model "Back-UPS ES 525"
6.333612 send_to_all: SETINFO ups.serial "8B0745R23575 "
6.333612 send_to_all: SETINFO ups.vendorid "051d"
6.349212 send_to_all: SETINFO ups.productid "0002"
6.349212 Report descriptor retrieved (Reportlen = 1144)
6.349212 Found HID device
6.349212 Detected a UPS: American Power Conversion/Back-UPS ES 525 FW:851.t3.I USB FW:t3
6.364812 hid_lookup_usage: UPS -> 00840004
6.364812 hid_lookup_usage: PowerSummary -> 00840024
6.364812 hid_lookup_usage: RemainingCapacity -> 00850066
6.364812 string_to_path: depth = 3
6.364812 Entering libusb_get_report
6.380412 libusb_get_report: libusb0-dll:err [control_msg] sending control message failed, win error: A device attached to the system is not functioning.
6.396012 Can't retrieve Report 0c: Input/output error [A device attached to the system is not functioning. ]
6.396012 Can't initialize data from HID UPS
I see the different behavior of 2.6.0-1 and 2.6.1-1, but they are using equal drivers. I am not sure that the problem in libusb...
Finally, I installed 2.6.5-1 with drivers from 2.6.0-1 and got data stale (as in my first message).
I hope these logs can clean the situation.
Thank you for your hard work!
Denis
>Thanks for your feedback.
>Fred
>
>>
>> Thanks,
>> Denis
More information about the Nut-upsuser
mailing list