USB/UPS connectivity issue on Intel DP55KG Motherboard

USB/UPS connectivity issue on Intel DP55KG Motherboard

[Justin Piszcz]

Hello,

I use the following in my ups.conf:

# USB:
[apc]
   driver = usbhid-ups
   port = auto
   desc = "APC 1500VA"
   pollfreq = 5

On my new motherboard (an Intel DP55KG), every once and awhile I get this:

Broadcast Message from nut@box.com
         (somewhere) at 17:48 ...

Communications with UPS apc@localhost lost


Broadcast Message from nut@box.com
         (somewhere) at 17:48 ...

Communications with UPS apc@localhost established

On my previous motherboard (a DG965WH), the exact same configuration was used
and I never had this issue.

Any hints?

Should I increase the pollfreq to say 30 seconds?

Would this 'workaround' the problem?

Is this a known bug on this chipset?

Justin.

Re: USB/UPS connectivity issue on Intel DP55KG Motherboard

[Justin Piszcz]

On Tue, 13 Oct 2009, Justin Piszcz wrote:

> Hello,
>
> I use the following in my ups.conf:
>
> # USB:
> [apc]
>  driver = usbhid-ups
>  port = auto
>  desc = "APC 1500VA"
>  pollfreq = 5
>
> On my new motherboard (an Intel DP55KG), every once and awhile I get this:
>
> Broadcast Message from nut@box.com
>        (somewhere) at 17:48 ...
>
> Communications with UPS apc@localhost lost
>
>
> Broadcast Message from nut@box.com
>        (somewhere) at 17:48 ...
>
> Communications with UPS apc@localhost established
>
> On my previous motherboard (a DG965WH), the exact same configuration was used
> and I never had this issue.
>
> Any hints?
>
> Should I increase the pollfreq to say 30 seconds?
>
> Would this 'workaround' the problem?
>
> Is this a known bug on this chipset?
>
> Justin.
>
>
>

More logs:

Oct 13 18:01:46 p34 upsd[7338]: Data for UPS [apc] is stale - check driver
Oct 13 18:01:46 p34 upsmon[7342]: Poll UPS [apc@localhost] failed - Data stale
Oct 13 18:01:46 p34 upsmon[7342]: Communications with UPS apc@localhost lost
Oct 13 18:01:50 p34 upsd[7338]: UPS [apc] data is no longer stale
Oct 13 18:01:51 p34 upsmon[7342]: Communications with UPS apc@localhost established
Oct 13 18:02:48 p34 upsd[7338]: Data for UPS [apc] is stale - check driver
Oct 13 18:02:51 p34 upsmon[7342]: Poll UPS [apc@localhost] failed - Data stale
Oct 13 18:02:51 p34 upsmon[7342]: Communications with UPS apc@localhost lost
Oct 13 18:02:52 p34 upsd[7338]: UPS [apc] data is no longer stale
Oct 13 18:02:56 p34 upsmon[7342]: Communications with UPS apc@localhost established

Justin.

Re: USB/UPS connectivity issue on Intel DP55KG Motherboard

[Robert Hancock]

On 10/13/2009 03:55 PM, Justin Piszcz wrote:
> Hello,
>
> I use the following in my ups.conf:
>
> # USB:
> [apc]
> driver = usbhid-ups
> port = auto
> desc = "APC 1500VA"
> pollfreq = 5
>
> On my new motherboard (an Intel DP55KG), every once and awhile I get this:
>
> Broadcast Message from nut@box.com
> (somewhere) at 17:48 ...
>
> Communications with UPS apc@localhost lost
>
>
> Broadcast Message from nut@box.com
> (somewhere) at 17:48 ...
>
> Communications with UPS apc@localhost established
>
> On my previous motherboard (a DG965WH), the exact same configuration was
> used
> and I never had this issue.
>
> Any hints?
>
> Should I increase the pollfreq to say 30 seconds?
>
> Would this 'workaround' the problem?
>
> Is this a known bug on this chipset?

Anything unusual showing up in dmesg?

Re: USB/UPS connectivity issue on Intel DP55KG Motherboard

[Justin Piszcz]

On Tue, 13 Oct 2009, Robert Hancock wrote:

> On 10/13/2009 03:55 PM, Justin Piszcz wrote:
>> Hello,
>> 
>> I use the following in my ups.conf:
>> 
>> # USB:
>> [apc]
>> driver = usbhid-ups
>> port = auto
>> desc = "APC 1500VA"
>> pollfreq = 5
>> 
>> On my new motherboard (an Intel DP55KG), every once and awhile I get this:
>> 
>> Broadcast Message from nut@box.com
>> (somewhere) at 17:48 ...
>> 
>> Communications with UPS apc@localhost lost
>> 
>> 
>> Broadcast Message from nut@box.com
>> (somewhere) at 17:48 ...
>> 
>> Communications with UPS apc@localhost established
>> 
>> On my previous motherboard (a DG965WH), the exact same configuration was
>> used
>> and I never had this issue.
>> 
>> Any hints?
>> 
>> Should I increase the pollfreq to say 30 seconds?
>> 
>> Would this 'workaround' the problem?
>> 
>> Is this a known bug on this chipset?
>
> Anything unusual showing up in dmesg?
>

Hi Robert,

Nothing abormal..

[10729.035092] 3w-9xxx: scsi1: AEN: INFO (0x04:0x004E): Battery capacity 
test started:.
[10729.035485] 3w-9xxx: scsi1: AEN: INFO (0x04:0x0055): Battery charging 
started:.
[10730.253460] 3w-9xxx: scsi1: AEN: INFO (0x04:0x0056): Battery charging 
completed:.

Should I run the upsmon/etc with maximum debug/to get a trace?

Justin.

Re: [Nut-upsuser] USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

Hi,

I have included debugging logs-- see below, is this a nut or kernel/USB 
subsystem issue?

There are no kernel messages in dmesg/syslog that relate to this event. 
The same exact hardware was used on a different motherboard (DG965WH) 
without any problems.

Justin.

On Wed, 14 Oct 2009, Justin Piszcz wrote:

> On Tue, 13 Oct 2009, Robert Hancock wrote:
>
>> On 10/13/2009 03:55 PM, Justin Piszcz wrote:
>>> Hello,
>>> 
>>> I use the following in my ups.conf:
>>> 
>>> # USB:
>>> [apc]
>>> driver = usbhid-ups
>>> port = auto
>>> desc = "APC 1500VA"
>>> pollfreq = 5
>>> 
>>> On my new motherboard (an Intel DP55KG), every once and awhile I get this:
>>> 
>>> Broadcast Message from nut@box.com
>>> (somewhere) at 17:48 ...
>>> 
>>> Communications with UPS apc@localhost lost
>>> 
>>> 
>>> Broadcast Message from nut@box.com
>>> (somewhere) at 17:48 ...
>>> 
>>> Communications with UPS apc@localhost established
>>> 
>>> On my previous motherboard (a DG965WH), the exact same configuration was
>>> used
>>> and I never had this issue.
>>> 
>>> Any hints?
>>> 
>>> Should I increase the pollfreq to say 30 seconds?
>>> 
>>> Would this 'workaround' the problem?
>>> 
>>> Is this a known bug on this chipset?
>> 
>> Anything unusual showing up in dmesg?
>> 
>

Robert/Nut User List--

Looks like the data goes stale, please let me know if any more 
logs/debugging is required, is this a kernel/usb problem or a nut issue? 
I recall a change in the USB subsystem a few kernel versions back caused a 
different issue (on a different UPS, but nevertheless it was kernel 
related).

The following output before/during/after the lost connection:

1. upsmon -DDDDDDDDDDDDDD

polling ups: apc@localhost
get_var: apc@localhost / status
      status: [OL]
     parsing: [OL]: ups_on_line(apc@localhost) (no change)

polling ups: apc@localhost
get_var: apc@localhost / status
Poll UPS [apc@localhost] failed - Data stale
do_notify: ntype 0x0005 (COMMBAD)
Communications with UPS apc@localhost lost
polling ups: apc@localhost
get_var: apc@localhost / status
      status: [OL]
do_notify: ntype 0x0004 (COMMOK)
Communications with UPS apc@localhost established
     parsing: [OL]: ups_on_line(apc@localhost) (no change)

polling ups: apc@localhost
get_var: apc@localhost / status
      status: [OL]
     parsing: [OL]: ups_on_line(apc@localhost) (no change)

2. upsd -DDDDDDDDDDD

Pinging UPS [apc]
mainloop: polling 3 filedescriptors
Got PONG from UPS [apc]
mainloop: polling 3 filedescriptors
write: [destfd=6] [len=24] [VAR apc ups.status "OL"]
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
write: [destfd=6] [len=24] [VAR apc ups.status "OL"]
Pinging UPS [apc]
mainloop: polling 3 filedescriptors
Got PONG from UPS [apc]
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
sstate_dead: driver for UPS [apc] says data is stale
Data for UPS [apc] is stale - check driver
mainloop: polling 3 filedescriptors
mainloop: no data available
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors
Sending error [DATA-STALE] to client 127.0.0.1
write: [destfd=6] [len=15] [ERR DATA-STALE]
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors
mainloop: no data available
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors
UPS [apc] data is no longer stale
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
write: [destfd=6] [len=24] [VAR apc ups.status "OL"]
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
write: [destfd=6] [len=24] [VAR apc ups.status "OL"]
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
mainloop: no data available
Pinging UPS [apc]
mainloop: polling 3 filedescriptors
Got PONG from UPS [apc]

3. /lib/nut/usbhid-ups -a apc -i 5 -u nut -DDDDDDDD

Scroll down ~149 lines to where the problem occurs, before this, all is OK:

  149 = device has been disconnected, try to reconnect =

It takes roughly 3-5 minutes until this problem occurs.

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
send_to_one: PONG
upsdrv_updateinfo...
  ok
Report[int]: (4 bytes) => 06 00 00 08
Got 3 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850044 -> Charging
Path: UPS.PowerSummary.Charging, Type: Input, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850045 -> Discharging
Path: UPS.PowerSummary.Discharging, Type: Input, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: ff860060 -> APCStatusFlag
Path: UPS.PowerSummary.APCStatusFlag, Type: Input, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Full update...
Entering libusb_get_report
Report[get]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.RemainingCapacity, Type: Feature, ReportID: 0x0c, Offset: 0, Size: 8, Value: 100.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 0f 32
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.WarningCapacityLimit, Type: Feature, ReportID: 0x0f, Offset: 0, Size: 8, Value: 50.000000
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature, ReportID: 0x0c, Offset: 8, Size: 16, Value: 1484.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 09 4d 0a
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.PowerSummary.Voltage, Type: Feature, ReportID: 0x09, Offset: 0, Size: 16, Value: 26.370000
Entering libusb_get_report
Report[get]: (3 bytes) => 25 60 09
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Battery.ConfigVoltage, Type: Feature, ReportID: 0x25, Offset: 0, Size: 16, Value: 24.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 03 04
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.iDeviceChemistry, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 4.000000
hu_find_infoval: searching for value = 4

-> String: PbAc (len = 4/20)
hu_find_infoval: found PbAc (value: 4)

Entering libusb_get_report
Report[get]: (3 bytes) => 20 be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.ManufacturerDate, Type: Feature, ReportID: 0x20, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

Entering libusb_get_report
refresh_report_buffer: expected 4 bytes, but got only 3
Report[get]: (4 bytes) => 1c be 38 00
PhyMax = 0, PhyMin = 0, LogMax = 16777215, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.APCBattReplaceDate, Type: Feature, ReportID: 0x1c, Offset: 0, Size: 24, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2024/00/38 (value: 14526)

Entering libusb_get_report
Report[get]: (2 bytes) => 50 16
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerConverter.PercentLoad, Type: Feature, ReportID: 0x50, Offset: 0, Size: 8, Value: 22.000000
Entering libusb_get_report
Can't retrieve Report 21: Broken pipe
send_to_one: PONG
upsdrv_updateinfo...
Got to reconnect!

==================================================
= device has been disconnected, try to reconnect =
==================================================
Checking device (0461/4D15) (001/005)
- VendorID: 0461
- ProductID: 4d15
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (413C/2002) (001/004)
- VendorID: 413c
- ProductID: 2002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (413C/1002) (001/003)
- VendorID: 413c
- ProductID: 1002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (8087/0020) (001/002)
- VendorID: 8087
- ProductID: 0020
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (1D6B/0002) (001/001)
- VendorID: 1d6b
- ProductID: 0002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (0A12/0001) (002/003)
- VendorID: 0a12
- ProductID: 0001
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (8087/0020) (002/002)
- VendorID: 8087
- ProductID: 0020
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (1D6B/0002) (002/001)
- VendorID: 1d6b
- ProductID: 0002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (051D/0002) (002/004)
- VendorID: 051d
- ProductID: 0002
- Manufacturer: American Power Conversion
- Product: unknown
- Serial Number: 8B0822R34475 
- Bus: 002
Trying to match device
Device does not match - skipping
No appropriate HID device found
send_to_all: DATASTALE
upsdrv_updateinfo...
Got to reconnect!

==================================================
= device has been disconnected, try to reconnect =
==================================================
Checking device (0461/4D15) (001/005)
- VendorID: 0461
- ProductID: 4d15
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (413C/2002) (001/004)
- VendorID: 413c
- ProductID: 2002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (413C/1002) (001/003)
- VendorID: 413c
- ProductID: 1002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (8087/0020) (001/002)
- VendorID: 8087
- ProductID: 0020
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (1D6B/0002) (001/001)
- VendorID: 1d6b
- ProductID: 0002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 001
Trying to match device
Device does not match - skipping
Checking device (0A12/0001) (002/003)
- VendorID: 0a12
- ProductID: 0001
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (8087/0020) (002/002)
- VendorID: 8087
- ProductID: 0020
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (1D6B/0002) (002/001)
- VendorID: 1d6b
- ProductID: 0002
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 002
Trying to match device
Device does not match - skipping
Checking device (051D/0002) (002/004)
- VendorID: 051d
- ProductID: 0002
- Manufacturer: American Power Conversion
- Product: Back-UPS RS 1500 LCD FW:839.H7 .D USB FW:H7 
- Serial Number: 8B0822R34475 
- Bus: 002
Trying to match device
Device matches
failed to claim USB device: could not claim interface 0: Device or resource busy
detached kernel driver from USB device...
Entering libusb_get_report
Report[get]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.RemainingCapacity, Type: Feature, ReportID: 0x0c, Offset: 0, Size: 8, Value: 100.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 11 0a
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.RemainingCapacityLimit, Type: Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 10.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 0f 32
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.WarningCapacityLimit, Type: Feature, ReportID: 0x0f, Offset: 0, Size: 8, Value: 50.000000
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature, ReportID: 0x0c, Offset: 8, Size: 16, Value: 1484.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 17 78 00
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.RemainingTimeLimit, Type: Feature, ReportID: 0x17, Offset: 0, Size: 16, Value: 120.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 09 4d 0a
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.PowerSummary.Voltage, Type: Feature, ReportID: 0x09, Offset: 0, Size: 16, Value: 26.370000
Entering libusb_get_report
Report[get]: (3 bytes) => 25 60 09
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Battery.ConfigVoltage, Type: Feature, ReportID: 0x25, Offset: 0, Size: 16, Value: 24.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: ConfigVoltage -> 00840040
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: Battery -> 00840012
hid_lookup_usage: Temperature -> 00840036
string_to_path: depth = 3
Entering libusb_get_report
Report[get]: (2 bytes) => 03 04
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.iDeviceChemistry, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 4.000000
hu_find_infoval: searching for value = 4

-> String: PbAc (len = 4/20)
hu_find_infoval: found PbAc (value: 4)

Entering libusb_get_report
Report[get]: (3 bytes) => 20 be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.ManufacturerDate, Type: Feature, ReportID: 0x20, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: APCBattReplaceDate -> ff860016
string_to_path: depth = 3
Entering libusb_get_report
refresh_report_buffer: expected 4 bytes, but got only 3
Report[get]: (4 bytes) => 1c be 38 00
PhyMax = 0, PhyMin = 0, LogMax = 16777215, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.APCBattReplaceDate, Type: Feature, ReportID: 0x1c, Offset: 0, Size: 24, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2024/00/38 (value: 14526)

hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: Output -> 0084001c
hid_lookup_usage: PercentLoad -> 00840035
string_to_path: depth = 3
Entering libusb_get_report
Report[get]: (2 bytes) => 50 16
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerConverter.PercentLoad, Type: Feature, ReportID: 0x50, Offset: 0, Size: 8, Value: 22.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: DelayBeforeStartup -> 00840056
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCGeneralCollection -> ff860005
hid_lookup_usage: APCDelayBeforeStartup -> ff86007e
string_to_path: depth = 3
Entering libusb_get_report
Report[get]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 41 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeShutdown, Type: Feature, ReportID: 0x41, Offset: 0, Size: 16, Value: -1.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: DelayBeforeStartup -> 00840056
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCGeneralCollection -> ff860005
hid_lookup_usage: APCDelayBeforeStartup -> ff86007e
string_to_path: depth = 3
Report[buf]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCGeneralCollection -> ff860005
hid_lookup_usage: APCDelayBeforeShutdown -> ff86007d
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: DelayBeforeReboot -> 00840055
string_to_path: depth = 3
Entering libusb_get_report
Report[get]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 21 06
PhyMax = 0, PhyMin = 0, LogMax = 6, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.Test, Type: Feature, ReportID: 0x21, Offset: 0, Size: 8, Value: 6.000000
hu_find_infoval: searching for value = 6

hu_find_infoval: found No test initiated (value: 6)

Entering libusb_get_report
Report[get]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
hu_find_infoval: searching for value = 2

hu_find_infoval: found enabled (value: 2)

Entering libusb_get_report
Report[get]: (3 bytes) => 7b be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.ManufacturerDate, Type: Feature, ReportID: 0x7b, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: ManufacturerDate -> 00850085
string_to_path: depth = 3
Entering libusb_get_report
refresh_report_buffer: expected 5 bytes, but got only 3
Report[get]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ShutdownImminent, Type: Feature, ReportID: 0x16, Offset: 5, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Overload, Type: Feature, ReportID: 0x16, Offset: 9, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !overload (value: 0)

process_boolean_info: !overload
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Feature, ReportID: 0x16, Offset: 8, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !replacebatt (value: 0)

process_boolean_info: !replacebatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.RemainingTimeLimitExpired, Type: Feature, ReportID: 0x16, Offset: 6, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !timelimitexp (value: 0)

process_boolean_info: !timelimitexp
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BatteryPresent, Type: Feature, ReportID: 0x16, Offset: 3, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found !nobattery (value: 1)

process_boolean_info: !nobattery
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ShutdownImminent, Type: Feature, ReportID: 0x14, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Entering libusb_get_report
Report[get]: (3 bytes) => 31 7a 00
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.Voltage, Type: Feature, ReportID: 0x31, Offset: 0, Size: 16, Value: 122.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 30 78
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.ConfigVoltage, Type: Feature, ReportID: 0x30, Offset: 0, Size: 8, Value: 120.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 32 58 00
PhyMax = 0, PhyMin = 0, LogMax = 88, LogMin = 78
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.LowVoltageTransfer, Type: Feature, ReportID: 0x32, Offset: 0, Size: 16, Value: 88.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 33 8b 00
PhyMax = 0, PhyMin = 0, LogMax = 142, LogMin = 136
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.HighVoltageTransfer, Type: Feature, ReportID: 0x33, Offset: 0, Size: 16, Value: 139.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: Output -> 0084001c
hid_lookup_usage: Voltage -> 00840030
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: Output -> 0084001c
hid_lookup_usage: ConfigVoltage -> 00840040
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCEnvironment -> ff860006
hid_lookup_usage: APCProbe1 -> ff860007
hid_lookup_usage: Temperature -> 00840036
string_to_path: depth = 4
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCEnvironment -> ff860006
hid_lookup_usage: APCProbe1 -> ff860007
hid_lookup_usage: Humidity -> 00840037
string_to_path: depth = 4
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: BatterySystem -> 00840010
hid_lookup_usage: Battery -> 00840012
hid_lookup_usage: Test -> 00840058
string_to_path: depth = 4
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: BatterySystem -> 00840010
hid_lookup_usage: Battery -> 00840012
hid_lookup_usage: Test -> 00840058
string_to_path: depth = 4
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: BatterySystem -> 00840010
hid_lookup_usage: Battery -> 00840012
hid_lookup_usage: Test -> 00840058
string_to_path: depth = 4
Entering libusb_get_report
Report[get]: (2 bytes) => 79 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCPanelTest, Type: Feature, ReportID: 0x79, Offset: 0, Size: 8, Value: 0.000000
Report[buf]: (2 bytes) => 79 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCPanelTest, Type: Feature, ReportID: 0x79, Offset: 0, Size: 8, Value: 0.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: APCPanelTest -> ff860072
string_to_path: depth = 3
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: APCPanelTest -> ff860072
string_to_path: depth = 3
Report[buf]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: DelayBeforeStartup -> 00840056
string_to_path: depth = 3
Report[buf]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: PowerSummary -> 00840024
hid_lookup_usage: DelayBeforeReboot -> 00840055
string_to_path: depth = 3
Report[buf]: (3 bytes) => 41 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeShutdown, Type: Feature, ReportID: 0x41, Offset: 0, Size: 16, Value: -1.000000
hid_lookup_usage: UPS -> 00840004
hid_lookup_usage: APCGeneralCollection -> ff860005
hid_lookup_usage: APCDelayBeforeStartup -> ff86007e
string_to_path: depth = 3
Report[buf]: (3 bytes) => 41 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeShutdown, Type: Feature, ReportID: 0x41, Offset: 0, Size: 16, Value: -1.000000
Report[buf]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Report[buf]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
Report[buf]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
Report[buf]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
Report[buf]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
Report[buf]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
  ok
Report[int]: (4 bytes) => 06 00 00 08
Got 3 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850044 -> Charging
Path: UPS.PowerSummary.Charging, Type: Input, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850045 -> Discharging
Path: UPS.PowerSummary.Discharging, Type: Input, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: ff860060 -> APCStatusFlag
Path: UPS.PowerSummary.APCStatusFlag, Type: Input, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Quick update...
Report[buf]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Report[buf]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
send_to_all: DATAOK
upsdrv_updateinfo...
  ok
Report[int]: (4 bytes) => 0c 64 cc 05
Got 2 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850066 -> RemainingCapacity
Path: UPS.PowerSummary.RemainingCapacity, Type: Input, ReportID: 0x0c, Offset: 0, Size: 8, Value: 100.000000
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850068 -> RunTimeToEmpty
Path: UPS.PowerSummary.RunTimeToEmpty, Type: Input, ReportID: 0x0c, Offset: 8, Size: 16, Value: 1484.000000
Full update...
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.RemainingCapacity, Type: Feature, ReportID: 0x0c, Offset: 0, Size: 8, Value: 100.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 0f 32
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.WarningCapacityLimit, Type: Feature, ReportID: 0x0f, Offset: 0, Size: 8, Value: 50.000000
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature, ReportID: 0x0c, Offset: 8, Size: 16, Value: 1484.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 09 3c 0a
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.PowerSummary.Voltage, Type: Feature, ReportID: 0x09, Offset: 0, Size: 16, Value: 26.200000
send_to_all: SETINFO battery.voltage "26.2"
Entering libusb_get_report
Report[get]: (3 bytes) => 25 60 09
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Battery.ConfigVoltage, Type: Feature, ReportID: 0x25, Offset: 0, Size: 16, Value: 24.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 03 04
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.iDeviceChemistry, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 4.000000
hu_find_infoval: searching for value = 4

-> String: PbAc (len = 4/20)
hu_find_infoval: found PbAc (value: 4)

Entering libusb_get_report
Report[get]: (3 bytes) => 20 be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.ManufacturerDate, Type: Feature, ReportID: 0x20, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

Entering libusb_get_report
refresh_report_buffer: expected 4 bytes, but got only 3
Report[get]: (4 bytes) => 1c be 38 00
PhyMax = 0, PhyMin = 0, LogMax = 16777215, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.APCBattReplaceDate, Type: Feature, ReportID: 0x1c, Offset: 0, Size: 24, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2024/00/38 (value: 14526)

Entering libusb_get_report
Report[get]: (2 bytes) => 50 16
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerConverter.PercentLoad, Type: Feature, ReportID: 0x50, Offset: 0, Size: 8, Value: 22.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 21 06
PhyMax = 0, PhyMin = 0, LogMax = 6, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.Test, Type: Feature, ReportID: 0x21, Offset: 0, Size: 8, Value: 6.000000
hu_find_infoval: searching for value = 6

hu_find_infoval: found No test initiated (value: 6)

Entering libusb_get_report
Report[get]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
hu_find_infoval: searching for value = 2

hu_find_infoval: found enabled (value: 2)

Entering libusb_get_report
Report[get]: (3 bytes) => 7b be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.ManufacturerDate, Type: Feature, ReportID: 0x7b, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

Entering libusb_get_report
refresh_report_buffer: expected 5 bytes, but got only 3
Report[get]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ShutdownImminent, Type: Feature, ReportID: 0x16, Offset: 5, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Overload, Type: Feature, ReportID: 0x16, Offset: 9, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !overload (value: 0)

process_boolean_info: !overload
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Feature, ReportID: 0x16, Offset: 8, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !replacebatt (value: 0)

process_boolean_info: !replacebatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.RemainingTimeLimitExpired, Type: Feature, ReportID: 0x16, Offset: 6, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !timelimitexp (value: 0)

process_boolean_info: !timelimitexp
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BatteryPresent, Type: Feature, ReportID: 0x16, Offset: 3, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found !nobattery (value: 1)

process_boolean_info: !nobattery
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ShutdownImminent, Type: Feature, ReportID: 0x14, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Entering libusb_get_report
Report[get]: (3 bytes) => 31 7a 00
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.Voltage, Type: Feature, ReportID: 0x31, Offset: 0, Size: 16, Value: 122.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 30 78
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.ConfigVoltage, Type: Feature, ReportID: 0x30, Offset: 0, Size: 8, Value: 120.000000
upsdrv_updateinfo...
  ok
Report[int]: (4 bytes) => 06 00 00 08
Got 3 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850044 -> Charging
Path: UPS.PowerSummary.Charging, Type: Input, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850045 -> Discharging
Path: UPS.PowerSummary.Discharging, Type: Input, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: ff860060 -> APCStatusFlag
Path: UPS.PowerSummary.APCStatusFlag, Type: Input, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Quick update...
Entering libusb_get_report
Report[get]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Entering libusb_get_report
refresh_report_buffer: expected 5 bytes, but got only 3
Report[get]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
send_to_one: PONG
upsdrv_updateinfo...
  ok
Report[int]: (4 bytes) => 06 00 00 08
Got 3 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850044 -> Charging
Path: UPS.PowerSummary.Charging, Type: Input, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850045 -> Discharging
Path: UPS.PowerSummary.Discharging, Type: Input, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: ff860060 -> APCStatusFlag
Path: UPS.PowerSummary.APCStatusFlag, Type: Input, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Full update...
Entering libusb_get_report
Report[get]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.RemainingCapacity, Type: Feature, ReportID: 0x0c, Offset: 0, Size: 8, Value: 100.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 0f 32
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.WarningCapacityLimit, Type: Feature, ReportID: 0x0f, Offset: 0, Size: 8, Value: 50.000000
Report[buf]: (4 bytes) => 0c 64 cc 05
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature, ReportID: 0x0c, Offset: 8, Size: 16, Value: 1484.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 09 4d 0a
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.PowerSummary.Voltage, Type: Feature, ReportID: 0x09, Offset: 0, Size: 16, Value: 26.370000
send_to_all: SETINFO battery.voltage "26.4"
Entering libusb_get_report
Report[get]: (3 bytes) => 25 60 09
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Battery.ConfigVoltage, Type: Feature, ReportID: 0x25, Offset: 0, Size: 16, Value: 24.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 03 04
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.iDeviceChemistry, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 4.000000
hu_find_infoval: searching for value = 4

-> String: PbAc (len = 4/20)
hu_find_infoval: found PbAc (value: 4)

Entering libusb_get_report
Report[get]: (3 bytes) => 20 be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.ManufacturerDate, Type: Feature, ReportID: 0x20, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

Entering libusb_get_report
refresh_report_buffer: expected 4 bytes, but got only 3
Report[get]: (4 bytes) => 1c be 38 00
PhyMax = 0, PhyMin = 0, LogMax = 16777215, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.APCBattReplaceDate, Type: Feature, ReportID: 0x1c, Offset: 0, Size: 24, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2024/00/38 (value: 14526)

Entering libusb_get_report
Report[get]: (2 bytes) => 50 16
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerConverter.PercentLoad, Type: Feature, ReportID: 0x50, Offset: 0, Size: 8, Value: 22.000000
Entering libusb_get_report
Report[get]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 21 06
PhyMax = 0, PhyMin = 0, LogMax = 6, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.Battery.Test, Type: Feature, ReportID: 0x21, Offset: 0, Size: 8, Value: 6.000000
hu_find_infoval: searching for value = 6

hu_find_infoval: found No test initiated (value: 6)

Entering libusb_get_report
Report[get]: (2 bytes) => 18 02
PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x18, Offset: 0, Size: 8, Value: 2.000000
hu_find_infoval: searching for value = 2

hu_find_infoval: found enabled (value: 2)

Entering libusb_get_report
Report[get]: (3 bytes) => 7b be 38
PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.ManufacturerDate, Type: Feature, ReportID: 0x7b, Offset: 0, Size: 16, Value: 14526.000000
hu_find_infoval: searching for value = 14526

hu_find_infoval: found 2008/05/30 (value: 14526)

Entering libusb_get_report
refresh_report_buffer: expected 5 bytes, but got only 3
Report[get]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ShutdownImminent, Type: Feature, ReportID: 0x16, Offset: 5, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Overload, Type: Feature, ReportID: 0x16, Offset: 9, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !overload (value: 0)

process_boolean_info: !overload
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Feature, ReportID: 0x16, Offset: 8, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !replacebatt (value: 0)

process_boolean_info: !replacebatt
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.RemainingTimeLimitExpired, Type: Feature, ReportID: 0x16, Offset: 6, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !timelimitexp (value: 0)

process_boolean_info: !timelimitexp
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BatteryPresent, Type: Feature, ReportID: 0x16, Offset: 3, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found !nobattery (value: 1)

process_boolean_info: !nobattery
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ShutdownImminent, Type: Feature, ReportID: 0x14, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !shutdownimm (value: 0)

process_boolean_info: !shutdownimm
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Entering libusb_get_report
Report[get]: (3 bytes) => 31 7a 00
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.Voltage, Type: Feature, ReportID: 0x31, Offset: 0, Size: 16, Value: 122.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 30 78
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00f0d121 found 7
Path: UPS.Input.ConfigVoltage, Type: Feature, ReportID: 0x30, Offset: 0, Size: 8, Value: 120.000000
upsdrv_updateinfo...
  ok
Report[int]: (4 bytes) => 06 00 00 08
Got 3 HID objects...
Entering libusb_get_report
Report[get]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850044 -> Charging
Path: UPS.PowerSummary.Charging, Type: Input, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: 00850045 -> Discharging
Path: UPS.PowerSummary.Discharging, Type: Input, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
hid_lookup_path: 00840004 -> UPS
hid_lookup_path: 00840024 -> PowerSummary
hid_lookup_path: ff860060 -> APCStatusFlag
Path: UPS.PowerSummary.APCStatusFlag, Type: Input, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Quick update...
Entering libusb_get_report
Report[get]: (3 bytes) => 15 ff ff
PhyMax = 0, PhyMin = 0, LogMax = 32767, LogMin = -1
get_unit_expo: 00001001 found 0
Path: UPS.PowerSummary.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: -1.000000
Entering libusb_get_report
Report[get]: (2 bytes) => 40 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.APCGeneralCollection.APCDelayBeforeReboot, Type: Feature, ReportID: 0x40, Offset: 0, Size: 8, Value: 0.000000
Entering libusb_get_report
refresh_report_buffer: expected 5 bytes, but got only 3
Report[get]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x16, Offset: 2, Size: 1, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x16, Offset: 1, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x16, Offset: 0, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (5 bytes) => 16 0c 00 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x16, Offset: 4, Size: 1, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Charging, Type: Feature, ReportID: 0x06, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !chrg (value: 0)

process_boolean_info: !chrg
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.Discharging, Type: Feature, ReportID: 0x06, Offset: 8, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !dischrg (value: 0)

process_boolean_info: !dischrg
Entering libusb_get_report
Report[get]: (2 bytes) => 13 01
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.ACPresent, Type: Feature, ReportID: 0x13, Offset: 0, Size: 8, Value: 1.000000
hu_find_infoval: searching for value = 1

hu_find_infoval: found online (value: 1)

process_boolean_info: online
Entering libusb_get_report
Report[get]: (3 bytes) => 14 00 00
PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 0.000000
hu_find_infoval: searching for value = 0

hu_find_infoval: found !lowbatt (value: 0)

process_boolean_info: !lowbatt
Report[buf]: (4 bytes) => 06 00 00 08
PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerSummary.APCStatusFlag, Type: Feature, ReportID: 0x06, Offset: 16, Size: 8, Value: 8.000000
hu_find_infoval: searching for value = 8

hu_find_infoval: found !off (value: 8)

process_boolean_info: !off
Signal 2: exiting
upsdrv_cleanup...

2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

On Wed, 14 Oct 2009, Justin Piszcz wrote:

>
>
> On Wed, 14 Oct 2009, Justin Piszcz wrote:
>
>> Hi,
>> 
>> I have included debugging logs-- see below, is this a nut or kernel/USB 
>> subsystem issue?
>> 
>> Robert/Nut User List--
>> 
>> Looks like the data goes stale, please let me know if any more 
>> logs/debugging is required, is this a kernel/usb problem or a nut issue? I 
>> recall a change in the USB subsystem a few kernel versions back caused a 
>> different issue (on a different UPS, but nevertheless it was kernel 
>> related).
>

The details+logs are here (previous e-mail did not go through, too large for
the list):
wget http://home.comcast.net/~jpiszcz/20091014/nut-problem.txt

For now I have disabled nut-- is there any more debugging that I can do to
help find/solve the problem?  Also cc'ing linux-usb & linux-kernel on this 
one.

Highlights from the above txt file:

Pinging UPS [apc]
mainloop: polling 3 filedescriptors
Got PONG from UPS [apc]
mainloop: polling 3 filedescriptors
mainloop: no data available
mainloop: polling 3 filedescriptors
sstate_dead: driver for UPS [apc] says data is stale
Data for UPS [apc] is stale - check driver
mainloop: polling 3 filedescriptors
mainloop: no data available
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors
Sending error [DATA-STALE] to client 127.0.0.1
write: [destfd=6] [len=15] [ERR DATA-STALE]
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors
mainloop: no data available
sstate_dead: driver for UPS [apc] says data is stale
mainloop: polling 3 filedescriptors

Entering libusb_get_report
Report[get]: (2 bytes) => 50 16
PhyMax = 0, PhyMin = 0, LogMax = 100, LogMin = 0
get_unit_expo: 00000000 found 0
Path: UPS.PowerConverter.PercentLoad, Type: Feature, ReportID: 0x50, Offset: 0, Size: 8, Value: 22.000000
Entering libusb_get_report
Can't retrieve Report 21: Broken pipe
send_to_one: PONG
upsdrv_updateinfo...
Got to reconnect!

The same cable, UPS etc was used on another motherboard for 1-2+ years without
any issue, after moving it to a DP55KG, this problem began.

Justin.

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Alan Stern]

On Sun, 18 Oct 2009, Justin Piszcz wrote:

> >> I have included debugging logs-- see below, is this a nut or kernel/USB 
> >> subsystem issue?
> >> 
> >> Robert/Nut User List--
> >> 
> >> Looks like the data goes stale, please let me know if any more 
> >> logs/debugging is required, is this a kernel/usb problem or a nut issue? I 
> >> recall a change in the USB subsystem a few kernel versions back caused a 
> >> different issue (on a different UPS, but nevertheless it was kernel 
> >> related).
> >
> 
> The details+logs are here (previous e-mail did not go through, too large for
> the list):
> wget http://home.comcast.net/~jpiszcz/20091014/nut-problem.txt
> 
> For now I have disabled nut-- is there any more debugging that I can do to
> help find/solve the problem?  Also cc'ing linux-usb & linux-kernel on this 
> one.

You could collect a usbmon trace showing the problem.  For 
instructions, see the kernel source file Documentation/usb/usbmon.txt.

It might also help to provide the dmesg log from a kernel built with 
CONFIG_USB_DEBUG enabled.

Alan Stern

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

On Sun, 18 Oct 2009, Alan Stern wrote:

> On Sun, 18 Oct 2009, Justin Piszcz wrote:
>
>>>> I have included debugging logs-- see below, is this a nut or kernel/USB
>>>> subsystem issue?
>>>>
>>>> Robert/Nut User List--
>>>>
>>>> Looks like the data goes stale, please let me know if any more
>>>> logs/debugging is required, is this a kernel/usb problem or a nut issue? I
>>>> recall a change in the USB subsystem a few kernel versions back caused a
>>>> different issue (on a different UPS, but nevertheless it was kernel
>>>> related).
>>>
>>
>> The details+logs are here (previous e-mail did not go through, too large for
>> the list):
>> wget http://home.comcast.net/~jpiszcz/20091014/nut-problem.txt
>>
>> For now I have disabled nut-- is there any more debugging that I can do to
>> help find/solve the problem?  Also cc'ing linux-usb & linux-kernel on this
>> one.
>
> You could collect a usbmon trace showing the problem.  For
> instructions, see the kernel source file Documentation/usb/usbmon.txt.
>
> It might also help to provide the dmesg log from a kernel built with
> CONFIG_USB_DEBUG enabled.
>
> Alan Stern
>

Thanks Alan,

I have performed all of the steps you recommended, there is also a bug in
the docs, the directory seems to be different, or at least if you have
everything compiled into the kernel and not using modules.

wget http://home.comcast.net/~jpiszcz/20091018/1.mon.out
wget http://home.comcast.net/~jpiszcz/20091018/2.6.31.4-dmesg-after.txt
wget http://home.comcast.net/~jpiszcz/20091018/2.6.31.4-dmesg-usb-debug2.txt
wget http://home.comcast.net/~jpiszcz/20091018/2.6.31.4-dmesg-usb-debug.txt

Steps from the USB documentation:

# mount -t debugfs none_debugs /sys/kernel/debug
#

The kernel documentation is outdated:

# ls /sys/kernel/debug/usbmon
0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
#

The directory is: 
# ls /sys/kernel/debug/usb/usbmon
0s  0u  1s  1t  1u  2s  2t  2u

Capture all output:
cat /sys/kernel/debug/usb/usbmon/0u > /tmp/1.mon.out

Start nut:
# /etc/init.d/nut start
Starting Network UPS Tools: upsdrvctl upsd upsmon.

Within ~20-30 seconds it already broke:
============================================================================
Broadcast Message from nut@p34.internal.lan
         (somewhere) at 17:22 ...

Communications with UPS apc@localhost lost 
============================================================================
I waited another 20-30 seconds:
============================================================================
Broadcast Message from nut@p34.internal.lan
         (somewhere) at 17:23 ...

Communications with UPS apc@localhost established 
============================================================================
Then a few seconds later:
============================================================================
Broadcast Message from nut@p34.internal.lan
         (somewhere) at 17:23 ...

Communications with UPS apc@localhost lost 
============================================================================

# /etc/init.d/nut stop
Stopping Network UPS Tools: upsdrvctl upsd upsmon.

# control-c
# cat /sys/kernel/debug/usb/usbmon/0u > /tmp/1.mon.out

# ls -l /tmp/1.mon.out
-rw-r--r-- 1 root root 88354 2009-10-18 17:24 /tmp/1.mon.out

# dmesg > /tmp/2.6.31.4-dmesg-after.txt

Text from dmesg-after.txt of interest:

[    9.245770] 0000:04:00.0: eth2: 10/100 speed: disabling TSO
[   35.448243] usb usb1: uevent
[   35.448271] usb 1-0:1.0: uevent
[   35.448303] usb 1-1: uevent
[   35.448333] usb 1-1.1: uevent
[   35.448361] usb 1-1.1.1: uevent
[   35.448388] usb 1-1.1.1:1.0: uevent
[   35.448543] usb 1-1.1.1:1.1: uevent
[   35.448698] usb 1-1.1.2: uevent
[   35.448727] usb 1-1.1.2:1.0: uevent
[   35.448915] usb 1-1.1:1.0: uevent
[   35.448939] usb 1-1:1.0: uevent
[   35.449737] usb usb2: uevent
[   35.449764] usb 2-0:1.0: uevent
[   35.449788] usb 2-1: uevent
[   35.449816] usb 2-1.6: uevent
[   35.449843] usb 2-1.6:1.0: uevent
[   35.449866] usb 2-1.6:1.1: uevent
[   35.449890] usb 2-1.7: uevent
[   35.449917] usb 2-1.7:1.0: uevent
[   35.450018] usb 2-1:1.0: uevent
[   35.631602] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 2 [1/2 us]
[   35.661556] usb 2-1: clear tt buffer port 7, a4 ep0 t00080e42
[   38.095486] usb 1-1.1.2: link qh8-0601/ffff8800cf0086c0 start 5 [1/2 us]
[  203.323838] usb 2-1: clear tt buffer port 7, a4 ep0 t00080e42
[  203.344727] usbhid 2-1.7:1.0: disconnect by usbfs
[  203.344744] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 2 [1/2 us]
[  203.344754] ehci_hcd 0000:00:1d.0: shutdown urb ffff88022d921540 ep1in-intr
[  203.344772] drivers/usb/core/file.c: removing 96 minor
[  204.144370] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  204.395021] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  204.395386] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  204.395389] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  204.487841] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  206.396322] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  206.396328] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  206.407416] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  208.397531] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  208.397537] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  208.454951] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  210.397943] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  210.397950] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  210.438499] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  212.398246] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  212.398252] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  212.422050] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  214.398555] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  214.398560] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  214.405607] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  216.398863] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  216.398869] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  216.453142] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  218.399177] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  218.399183] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  218.436710] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  220.399484] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  220.399489] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  220.420256] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  222.399787] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  222.399793] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  222.403809] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  224.400095] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  224.400101] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  224.451340] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  226.400405] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  226.400410] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  226.434901] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  228.400717] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  228.400723] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  228.418457] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  230.401025] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  230.401031] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  230.402020] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  232.401339] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  232.401341] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  232.449547] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 3 [1/2 us]
[  232.490278] usb 2-1: clear tt buffer port 7, a4 ep0 t00080e42
[  290.428240] usb 2-1: clear tt buffer port 7, a4 ep0 t00080e42
[  290.454378] usbfs 2-1.7:1.0: disconnect by usbfs
[  290.671011] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 4 [1/2 us]
[  290.677315] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 4 [1/2 us]
[  292.410579] ehci_hcd 0000:00:1d.0: reused qh ffff8800cf00c3c0 schedule
[  292.410585] usb 2-1.7: link qh64-0601/ffff8800cf00c3c0 start 4 [1/2 us]
[  292.469048] usb 2-1.7: unlink qh64-0601/ffff8800cf00c3c0 start 4 [1/2 us]
[  292.473781] usb 2-1: clear tt buffer port 7, a4 ep0 t00080e42

A snippet from 1.mon.out:

ffff88022bee2380 341311138 S Ci:2:004:0 s 80 06 0300 0000 00ff 255 <
ffff88022bee2380 341312510 C Ci:2:004:0 0 4 = 04030904
ffff88022bee2380 341312515 S Ci:2:004:0 s 80 06 0302 0409 00ff 255 <
ffff88022bee2380 341331883 C Ci:2:004:0 0 30 = 1e033800 42003000 38003200 32005200 33003400 34003700 35002000 2000
ffff88022bee2380 343276840 S Ci:2:004:0 s 80 06 0300 0000 00ff 255 <
ffff88022bee2380 343282777 C Ci:2:004:0 0 4 = 04030904
ffff88022bee2380 343282783 S Ci:2:004:0 s 80 06 0303 0409 00ff 255 <
ffff88022bee2380 343293150 C Ci:2:004:0 0 52 = 34034100 6d006500 72006900 63006100 6e002000 50006f00 77006500 72002000
ffff88022bee2380 343293157 S Ci:2:004:0 s 80 06 0300 0000 00ff 255 <
ffff88022bee2380 343295400 C Ci:2:004:0 0 4 = 04030904
ffff88022bee2380 343295406 S Ci:2:004:0 s 80 06 0301 0409 00ff 255 <
ffff88022bee2380 343312151 C Ci:2:004:0 0 90 = 5a034200 61006300 6b002d00 55005000 53002000 52005300 20003100 35003000
ffff88022bee2380 343312157 S Ci:2:004:0 s 80 06 0300 0000 00ff 255 <
ffff88022bee2380 343316151 C Ci:2:004:0 0 4 = 04030904
ffff88022bee2380 343316155 S Ci:2:004:0 s 80 06 0302 0409 00ff 255 <
ffff88022bee2380 343335654 C Ci:2:004:0 0 30 = 1e033800 42003000 38003200 32005200 33003400 34003700 35002000 2000
ffff88022bee2380 345277876 S Ci:2:004:0 s 80 06 0300 0000 00ff 255 <
ffff88022bee2380 345283673 C Ci:2:004:0 0 4 = 04030904
ffff88022bee2380 345283681 S Ci:2:004:0 s 80 06 0303 0409 00ff 255 <
ffff88022bee2380 345294172 C Ci:2:004:0 0 52 = 34034100 6d006500 72006900 63006100 6e002000 50006f00 77006500 72002000

Please let me know if this helps.

Justin.

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Alan Stern]

On Sun, 18 Oct 2009, Justin Piszcz wrote:

> I have performed all of the steps you recommended, there is also a bug in
> the docs, the directory seems to be different, or at least if you have
> everything compiled into the kernel and not using modules.

> Steps from the USB documentation:
> 
> # mount -t debugfs none_debugs /sys/kernel/debug
> #
> 
> The kernel documentation is outdated:
> 
> # ls /sys/kernel/debug/usbmon
> 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
> #
> 
> The directory is: 
> # ls /sys/kernel/debug/usb/usbmon
> 0s  0u  1s  1t  1u  2s  2t  2u

This has already been corrected in the 2.6.32-rc kernels.

However there is another respect in which the documentation is
outdated: It mentions /proc/bus/usb/devices.  That file has moved; it
is now named /sys/kernel/debug/usb/devices.  Would you like to submit a
patch fixing this?

Alan Stern

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2215 bytes --]



On Mon, 19 Oct 2009, Alan Stern wrote:

> On Sun, 18 Oct 2009, Justin Piszcz wrote:
>
>> I have performed all of the steps you recommended, there is also a bug in
>> the docs, the directory seems to be different, or at least if you have
>> everything compiled into the kernel and not using modules.
>
>> Steps from the USB documentation:
>>
>> # mount -t debugfs none_debugs /sys/kernel/debug
>> #
>>
>> The kernel documentation is outdated:
>>
>> # ls /sys/kernel/debug/usbmon
>> 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
>> #
>>
>> The directory is:
>> # ls /sys/kernel/debug/usb/usbmon
>> 0s  0u  1s  1t  1u  2s  2t  2u
>
> This has already been corrected in the 2.6.32-rc kernels.
Great to hear, I will try the latest 2.6.31-rcX kernel!

>
> However there is another respect in which the documentation is
> outdated: It mentions /proc/bus/usb/devices.  That file has moved; it
> is now named /sys/kernel/debug/usb/devices.  Would you like to submit a
> patch fixing this?
>
> Alan Stern
>

Hi,

Sure, what I meant is:

usbmon.txt states:
/sys/kernel/debug/usbmon/3u
             ^^^^^

Actual location:
/sys/kernel/debug/usb/usbmon/3u
             ^^^^^^^^^

Patch below (and attached):

diff -uprN linux-2.6.31.1/Documentation/usb/usbmon.txt linux-2.6.31.1.patch/Documentation/usb/usbmon.txt
--- linux-2.6.31.1/Documentation/usb/usbmon.txt 2009-09-24 11:45:25.000000000 -0400
+++ linux-2.6.31.1.patch/Documentation/usb/usbmon.txt   2009-10-19 10:51:06.725516874 -0400
@@ -33,7 +33,7 @@ if usbmon is built into the kernel.

  Verify that bus sockets are present.

-# ls /sys/kernel/debug/usbmon
+# ls /sys/kernel/debug/usb/usbmon
  0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
  #

@@ -58,11 +58,11 @@ Bus=03 means it's bus 3.

  3. Start 'cat'

-# cat /sys/kernel/debug/usbmon/3u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/3u > /tmp/1.mon.out

  to listen on a single bus, otherwise, to listen on all buses, type:

-# cat /sys/kernel/debug/usbmon/0u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/0u > /tmp/1.mon.out

  This process will be reading until killed. Naturally, the output can be
  redirected to a desirable location. This is preferred, because it is going

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: TEXT/x-diff; name=usbmon-documentation-fix.patch, Size: 1168 bytes --]

Binary files linux-2.6.31.1/Documentation/.SubmittingPatches.swp and linux-2.6.31.1.patch/Documentation/.SubmittingPatches.swp differ
diff -uprN linux-2.6.31.1/Documentation/usb/usbmon.txt linux-2.6.31.1.patch/Documentation/usb/usbmon.txt
--- linux-2.6.31.1/Documentation/usb/usbmon.txt	2009-09-24 11:45:25.000000000 -0400
+++ linux-2.6.31.1.patch/Documentation/usb/usbmon.txt	2009-10-19 10:51:06.725516874 -0400
@@ -33,7 +33,7 @@ if usbmon is built into the kernel.
 
 Verify that bus sockets are present.
 
-# ls /sys/kernel/debug/usbmon
+# ls /sys/kernel/debug/usb/usbmon
 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
 #
 
@@ -58,11 +58,11 @@ Bus=03 means it's bus 3.
 
 3. Start 'cat'
 
-# cat /sys/kernel/debug/usbmon/3u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/3u > /tmp/1.mon.out
 
 to listen on a single bus, otherwise, to listen on all buses, type:
 
-# cat /sys/kernel/debug/usbmon/0u > /tmp/1.mon.out
+# cat /sys/kernel/debug/usb/usbmon/0u > /tmp/1.mon.out
 
 This process will be reading until killed. Naturally, the output can be
 redirected to a desirable location. This is preferred, because it is going

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

On Mon, 19 Oct 2009, Justin Piszcz wrote:

>
>
> On Mon, 19 Oct 2009, Alan Stern wrote:
>
>> On Sun, 18 Oct 2009, Justin Piszcz wrote:
>> 
>>> I have performed all of the steps you recommended, there is also a bug in
>>> the docs, the directory seems to be different, or at least if you have
>>> everything compiled into the kernel and not using modules.
>> 
>>> Steps from the USB documentation:
>>> 
>>> # mount -t debugfs none_debugs /sys/kernel/debug
>>> #
>>> 
>>> The kernel documentation is outdated:
>>> 
>>> # ls /sys/kernel/debug/usbmon
>>> 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
>>> #
>>> 
>>> The directory is:
>>> # ls /sys/kernel/debug/usb/usbmon
>>> 0s  0u  1s  1t  1u  2s  2t  2u
>> 
>> This has already been corrected in the 2.6.32-rc kernels.
> Great to hear, I will try the latest 2.6.31-rcX kernel!
Disregard this ^

Misread, thought you meant the bug was fixed in the latest kernel but saw
your follow-up that this appears to be nut-related.

Justin.

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Alan Stern]

On Mon, 19 Oct 2009, Justin Piszcz wrote:

> >> The kernel documentation is outdated:
> >>
> >> # ls /sys/kernel/debug/usbmon
> >> 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
> >> #
> >>
> >> The directory is:
> >> # ls /sys/kernel/debug/usb/usbmon
> >> 0s  0u  1s  1t  1u  2s  2t  2u
> >
> > This has already been corrected in the 2.6.32-rc kernels.
> Great to hear, I will try the latest 2.6.31-rcX kernel!

It looks like you misunderstood.  I was referring to the 2.6.32-rc 
kernels, not 2.6.31-rc.  In particular, check out this commit:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=f0cc82a831d4d839eb6b67c7c046ebd2d1d7c4c2

> Hi,
> 
> Sure, what I meant is:
> 
> usbmon.txt states:
> /sys/kernel/debug/usbmon/3u
>              ^^^^^
> 
> Actual location:
> /sys/kernel/debug/usb/usbmon/3u
>              ^^^^^^^^^

Yes, I know.

> Patch below (and attached):

As I said, this correction has already been made.

Alan Stern

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Alan Stern]

On Sun, 18 Oct 2009, Justin Piszcz wrote:

> Thanks Alan,
> 
> I have performed all of the steps you recommended, there is also a bug in
> the docs, the directory seems to be different, or at least if you have
> everything compiled into the kernel and not using modules.

> Start nut:
> # /etc/init.d/nut start
> Starting Network UPS Tools: upsdrvctl upsd upsmon.
> 
> Within ~20-30 seconds it already broke:
> ============================================================================
> Broadcast Message from nut@p34.internal.lan
>          (somewhere) at 17:22 ...

Well, the usbmon trace shows that wherever the problem lies, it isn't 
in the kernel.  There were a few problems in the device itself -- it 
was queried for a report and did not provide any data.  The nut program 
should be smart enough to retry when this happens, but it didn't.

It did try to re-establish communcation with the device, but it appears
that nut got caught in a loop during this attempt.  During this loop
nut did nothing but transfer a bunch of string descriptors from the
device, over and over again at 2-second intervals.  The loop lasted for
almost a minute, until another device error occurred.  Then nut
recovered properly -- until a third error happened and nut got stuck in
its loop again.

Alan Stern

Re: 2.6.31.4: USB/UPS connectivity issue on Intel DP55KG Motherboard [DEBUG logs included upsd/upsmon/usbhid-ups]

[Justin Piszcz]

On Mon, 19 Oct 2009, Alan Stern wrote:

> On Sun, 18 Oct 2009, Justin Piszcz wrote:
>
>> Thanks Alan,
>>
>> I have performed all of the steps you recommended, there is also a bug in
>> the docs, the directory seems to be different, or at least if you have
>> everything compiled into the kernel and not using modules.
>
>> Start nut:
>> # /etc/init.d/nut start
>> Starting Network UPS Tools: upsdrvctl upsd upsmon.
>>
>> Within ~20-30 seconds it already broke:
>> ============================================================================
>> Broadcast Message from nut@p34.internal.lan
>>          (somewhere) at 17:22 ...
>
> Well, the usbmon trace shows that wherever the problem lies, it isn't
> in the kernel.  There were a few problems in the device itself -- it
> was queried for a report and did not provide any data.  The nut program
> should be smart enough to retry when this happens, but it didn't.
>
> It did try to re-establish communcation with the device, but it appears
> that nut got caught in a loop during this attempt.  During this loop
> nut did nothing but transfer a bunch of string descriptors from the
> device, over and over again at 2-second intervals.  The loop lasted for
> almost a minute, until another device error occurred.  Then nut
> recovered properly -- until a third error happened and nut got stuck in
> its loop again.
>
> Alan Stern
>

Hi,

To the nut list, the last time nut changed was 2009-06-13:

2009-06-13 04:29:25 configure nut-cgi 2.4.1-3 2.4.1-3
2009-06-13 04:29:25 status unpacked nut-cgi 2.4.1-3
2009-06-13 04:29:25 status unpacked nut-cgi 2.4.1-3
2009-06-13 04:29:25 status unpacked nut-cgi 2.4.1-3
2009-06-13 04:29:25 status unpacked nut-cgi 2.4.1-3
2009-06-13 04:29:25 status unpacked nut-cgi 2.4.1-3
2009-06-13 04:29:25 status half-configured nut-cgi 2.4.1-3
2009-06-13 04:29:26 status installed nut-cgi 2.4.1-3

I made no changes to the nut configuration or install.

What did change was the motherboard.

From: Intel DG965WH -> Intel DP55KG

Then this problem began.

Justin.