[Nut-upsdev] libusb_get_string: invalid argument

[please use reply-all to include the list, as the list does not override the Reply-To header.]

Post by Greg Hersch
Here is the driver debug log. If I just let it run, it pops up with
libusb_get_string_invalid argument over and over again, mixed in the
debug output. seems to be several issues reported in the log, but they
arent easily interpreted.

Does the libusb_get_string error occur only every 30 seconds or so?

Post by Greg Hersch
1.164089 Path: UPS.ffff0015.[1].ffff00c5, Type: Feature,
ReportID: 0x9b, Offset: 0, Size: 16, Value: 3
1.172696 libusb_get_report: Value too large for defined data type
1.172928 Can't retrieve Report c2: Value too large for defined data type

The entries with hex numbers in the path aren't important - the driver tries to dump them once at startup, then does not refer to them again.

Post by Greg Hersch
3.402389 libusb_get_string: Invalid argument

I think this is from trying to retrieve the value corresponding to "device.part" - which should also only be attempted once at startup.

Try the attached patch?

Also, I would be interested in the output of "lsusb -vvv -d 09ae:" for your UPS.

--
Charles Lepple
***@gmail

Greg Hersch

2015-06-08 16:34:48 UTC

Post by Charles Lepple
[please use reply-all to include the list, as the list does not override the Reply-To header.]

Does the libusb_get_string error occur only every 30 seconds or so?

Yes - thats correct. perhaps more like every 15 sec.

The entries with hex numbers in the path aren't important - the driver tries to dump them once at startup, then does not refer to them again.

ok thanks

Post by Greg Hersch
3.402389 libusb_get_string: Invalid argument

I think this is from trying to retrieve the value corresponding to "device.part" - which should also only be attempted once at startup.
Try the attached patch?

Will do. i'll write back with how it goes - thank you

Post by Charles Lepple
Also, I would be interested in the output of "lsusb -vvv -d 09ae:" for your UPS.
--
Charles Lepple

Greg Hersch

2015-06-09 00:23:03 UTC

Hi Charles. I patched, reconfigured, remake'd, remake install'd - but
no change. however, some more likely helpful information below for
you. Thank you

Post by Charles Lepple
[please use reply-all to include the list, as the list does not override
the Reply-To header.]

Does the libusb_get_string error occur only every 30 seconds or so?

Yes - thats correct. perhaps more like every 15 sec.

I was incorrect. they occur every 6 seconds. and there are two of them
each time.
hopefully that narrows it down!

The entries with hex numbers in the path aren't important - the driver
tries to dump them once at startup, then does not refer to them again.

ok thanks

Post by Greg Hersch
3.402389 libusb_get_string: Invalid argument

I think this is from trying to retrieve the value corresponding to
"device.part" - which should also only be attempted once at startup.
Try the attached patch?

Will do. i'll write back with how it goes - thank you

Post by Charles Lepple
Also, I would be interested in the output of "lsusb -vvv -d 09ae:" for your UPS.

Here it is:

Bus 001 Device 006: ID 09ae:1007 Tripp Lite
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 8
idVendor 0x09ae Tripp Lite
idProduct 0x1007
bcdDevice 0.10
iManufacturer 3 Tripp Lite
iProduct 1 TRIPP LITE UPS
iSerial 2 FW-2263 E
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 34
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xa0
(Bus Powered)
Remote Wakeup
MaxPower 100mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 3 Human Interface Device
bInterfaceSubClass 0
bInterfaceProtocol 0
iInterface 0
HID Device Descriptor:
bLength 9
bDescriptorType 33
bcdHID 1.10
bCountryCode 0 Not supported
bNumDescriptors 1
bDescriptorType 34 Report
wDescriptorLength 447
Report Descriptor: (length is 447)
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Local ): Usage, data= [ 0x04 ] 4
UPS
Item(Main ): Collection, data= [ 0x01 ] 1
Application
Item(Local ): Usage, data= [ 0x24 ] 36
Power Summary
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report ID, data= [ 0x28 ] 40
Item(Local ): Usage, data= [ 0xfe ] 254
iProduct
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0xff 0x00 ] 255
Item(Global): Logical Minimum, data= [ 0x00 ] 0
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x29 ] 41
Item(Local ): Usage, data= [ 0xff ] 255
iSerialNumber
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x2b ] 43
Item(Local ): Usage, data= [ 0xfd ] 253
iManufacturer
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Local ): Usage, data= [ 0x1a ] 26
Input
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Local ): Usage, data= [ 0x40 ] 64
Config Voltage
Item(Global): Report ID, data= [ 0x30 ] 48
Item(Main ): Feature, data= [ 0x83 ] 131
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Global): Report ID, data= [ 0x11 ] 17
Item(Local ): Usage, data= [ 0x5a ] 90
Audible Alarm Control
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Global): Usage Page, data= [ 0x85 ] 133
Battery System Page
Item(Global): Report ID, data= [ 0x2a ] 42
Item(Local ): Usage, data= [ 0x89 ] 137
iDeviceChemistry
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x33 ] 51
Item(Local ): Usage, data= [ 0x2c ] 44
Capacity Mode
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Logical Maximum, data= [ 0xff 0xff 0x00 0x00 ] 65535
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report ID, data= [ 0x35 ] 53
Item(Local ): Usage, data= [ 0x68 ] 104
Run Time To Empty
Item(Main ): Input, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report ID, data= [ 0x35 ] 53
Item(Local ): Usage, data= [ 0x68 ] 104
Run Time To Empty
Item(Main ): Feature, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Logical Maximum, data= [ 0x64 ] 100
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Report ID, data= [ 0x34 ] 52
Item(Local ): Usage, data= [ 0x66 ] 102
Remaining Capacity
Item(Main ): Input, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report ID, data= [ 0x34 ] 52
Item(Local ): Usage, data= [ 0x66 ] 102
Remaining Capacity
Item(Main ): Feature, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report ID, data= [ 0x37 ] 55
Item(Local ): Usage, data= [ 0x67 ] 103
Full Charge Capacity
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Local ): Usage, data= [ 0x02 ] 2
Present Status
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Logical Maximum, data= [ 0x01 ] 1
Item(Global): Report Size, data= [ 0x01 ] 1
Item(Global): Report ID, data= [ 0x32 ] 50
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Local ): Usage, data= [ 0x69 ] 105
Shutdown Imminent
Item(Main ): Input, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Local ): Usage, data= [ 0xd0 ] 208
(null)
Item(Main ): Input, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report Count, data= [ 0x03 ] 3
Item(Local ): Usage, data= [ 0x44 ] 68
Config Active Power
Item(Local ): Usage, data= [ 0x45 ] 69
Config Percent Load
Item(Local ): Usage, data= [ 0x4b ] 75
(null)
Item(Main ): Input, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report Count, data= [ 0x03 ] 3
Item(Main ): Input, data= [ 0x01 ] 1
Constant Array Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x32 ] 50
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report Size, data= [ 0x01 ] 1
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Local ): Usage, data= [ 0x69 ] 105
Shutdown Imminent
Item(Main ): Feature, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Usage Page, data= [ 0x85 ] 133
Battery System Page
Item(Local ): Usage, data= [ 0xd0 ] 208
AC Present
Item(Main ): Feature, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report Count, data= [ 0x03 ] 3
Item(Local ): Usage, data= [ 0x44 ] 68
Charging
Item(Local ): Usage, data= [ 0x45 ] 69
Discharging
Item(Local ): Usage, data= [ 0x4b ] 75
Need Replacement
Item(Main ): Feature, data= [ 0xa2 ] 162
Data Variable Absolute No_Wrap Linear
No_Preferred_State No_Null_Position
Volatile Bitfield
Item(Global): Report Count, data= [ 0x03 ] 3
Item(Main ): Feature, data= [ 0x01 ] 1
Constant Array Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Local ): Usage, data= [ 0x10 ] 16
Battery System
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Local ): Usage, data= [ 0x12 ] 18
Battery
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Report ID, data= [ 0x04 ] 4
Item(Local ): Usage, data= [ 0x40 ] 64
Config Voltage
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0xff 0xff 0x00 0x00 ] 65535
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Local ): Usage, data= [ 0x02 ] 2
Present Status
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Report ID, data= [ 0x23 ] 35
Item(Global): Usage Page, data= [ 0x85 ] 133
Battery System Page
Item(Global): Report Size, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0x01 ] 1
Item(Global): Report Count, data= [ 0x03 ] 3
Item(Local ): Usage, data= [ 0x44 ] 68
Charging
Item(Local ): Usage, data= [ 0x45 ] 69
Discharging
Item(Local ): Usage, data= [ 0x4b ] 75
Need Replacement
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Global): Report Count, data= [ 0x05 ] 5
Item(Main ): Feature, data= [ 0x01 ] 1
Constant Array Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Logical Maximum, data= [ 0xff 0x00 ] 255
Item(Local ): Usage, data= [ 0x58 ] 88
Test
Item(Global): Report ID, data= [ 0x10 ] 16
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Local ): Usage, data= [ 0x1e ] 30
Flow
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Report ID, data= [ 0x01 ] 1
Item(Local ): Usage, data= [ 0x40 ] 64
Config Voltage
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x02 ] 2
Item(Local ): Usage, data= [ 0x42 ] 66
Config Frequency
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report ID, data= [ 0x03 ] 3
Item(Local ): Usage, data= [ 0x43 ] 67
Config Apparent Power
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0xff 0xff 0x00 0x00 ] 65535
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0x84 ] 132
Power Device Page
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Logical Maximum, data= [ 0xff 0x00 ] 255
Item(Local ): Usage, data= [ 0x18 ] 24
Outlet System
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Local ): Usage, data= [ 0x20 ] 32
Outlet
Item(Main ): Collection, data= [ 0x02 ] 2
Logical
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Logical Maximum, data= [ 0xff 0xff 0x00 0x00 ] 65535
Item(Global): Report ID, data= [ 0x15 ] 21
Item(Local ): Usage, data= [ 0x57 ] 87
Delay Before Shutdown
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Logical Maximum, data= [ 0xff 0x00 ] 255
Item(Global): Usage Page, data= [ 0xff 0xff ] 65535
(null)
Item(Global): Report ID, data= [ 0x51 ] 81
Item(Local ): Usage, data= [ 0x91 ] 145
(null)
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Global): Report ID, data= [ 0x52 ] 82
Item(Local ): Usage, data= [ 0x92 ] 146
(null)
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Global): Report ID, data= [ 0xb6 ] 182
Item(Local ): Usage, data= [ 0xc7 ] 199
(null)
Item(Main ): Feature, data= [ 0x82 ] 130
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0xff 0xff ] 65535
(null)
Item(Local ): Usage, data= [ 0x10 ] 16
(null)
Item(Main ): Collection, data= [ 0x81 ] 129
Vendor defined
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0xff 0xff 0x00 0x00 ] 65535
Item(Global): Report ID, data= [ 0x6c ] 108
Item(Local ): Usage, data= [ 0x7d ] 125
(null)
Item(Main ): Feature, data= [ 0x03 ] 3
Constant Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Global): Usage Page, data= [ 0xff 0xff ] 65535
(null)
Item(Local ): Usage, data= [ 0x15 ] 21
(null)
Item(Main ): Collection, data= [ 0x81 ] 129
Vendor defined
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Report Count, data= [ 0x01 ] 1
Item(Global): Logical Maximum, data= [ 0xff 0x00 ] 255
Item(Global): Report ID, data= [ 0x96 ] 150
Item(Local ): Usage, data= [ 0xc0 ] 192
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report Size, data= [ 0x20 ] 32
Item(Global): Report ID, data= [ 0xb4 ] 180
Item(Local ): Usage, data= [ 0xd2 ] 210
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report ID, data= [ 0x97 ] 151
Item(Local ): Usage, data= [ 0xc1 ] 193
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report Size, data= [ 0x08 ] 8
Item(Global): Report ID, data= [ 0x98 ] 152
Item(Local ): Usage, data= [ 0xc2 ] 194
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report Size, data= [ 0x10 ] 16
Item(Global): Report ID, data= [ 0x99 ] 153
Item(Local ): Usage, data= [ 0xc3 ] 195
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x9b ] 155
Item(Local ): Usage, data= [ 0xc5 ] 197
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report Size, data= [ 0x20 ] 32
Item(Global): Report ID, data= [ 0xc2 ] 194
Item(Local ): Usage, data= [ 0xd6 ] 214
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Global): Report ID, data= [ 0x9a ] 154
Item(Local ): Usage, data= [ 0xc4 ] 196
(null)
Item(Main ): Feature, data= [ 0x02 ] 2
Data Variable Absolute No_Wrap Linear
Preferred_State No_Null_Position
Non_Volatile Bitfield
Item(Main ): End Collection, data=none
Item(Main ): End Collection, data=none
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0008 1x 8 bytes
bInterval 40
can't get debug descriptor: Resource temporarily unavailable
Device Status: 0x0000
(Bus Powered)

Charles Lepple

2015-06-09 03:20:15 UTC

Post by Greg Hersch
Hi Charles. I patched, reconfigured, remake'd, remake install'd - but
no change. however, some more likely helpful information below for
you. Thank you

Odd. Are you sure that the new version of usbhid-ups got installed to the same path you are running? Also, there is no protection against running two drivers if one is in debug mode. Please check that usbhid-ups is not still running in the background from an earlier run.

You can also add some text to the version string in drivers/tripplite-hid.c - it will show up as "Using subdriver: TrippLite HID 0.81" in the stock version.

Post by Charles Lepple
[please use reply-all to include the list, as the list does not override
the Reply-To header.]

Does the libusb_get_string error occur only every 30 seconds or so?

Yes - thats correct. perhaps more like every 15 sec.

I was incorrect. they occur every 6 seconds. and there are two of them
each time.
hopefully that narrows it down!

Unfortunately, no. I was thinking either every 30 seconds or every two seconds, and I'm not sure why they would occur two at a time every six seconds.

I'm not sure if we have enough log messages in the code already. If you can use GDB, you could do something like the following:

gdb /usr/local/ups/bin/usbhid-ups
...
(gdb) break libusb_get_string
(gdb) run -DD -a tripplite
...
(gdb) c
...
(gdb) bt

Keep pressing "c" until you get past the initial detection, which probably succeeds.

That last line should print a backtrace showing which function called the offending function.

Post by Charles Lepple
Also, I would be interested in the output of "lsusb -vvv -d 09ae:" for your UPS.

Thanks. Doesn't look too different than what we've seen before, so I'm optimistic.

--
Charles Lepple
***@gmail

Greg Hersch

2015-06-09 20:55:08 UTC

Post by Greg Hersch
Hi Charles. I patched, reconfigured, remake'd, remake install'd - but
no change. however, some more likely helpful information below for
you. Thank you

Odd. Are you sure that the new version of usbhid-ups got installed to the same path you are running? Also, there is no protection against running two drivers if one is in debug mode. Please check that usbhid-ups is not still running in the background from an earlier run.
You can also add some text to the version string in drivers/tripplite-hid.c - it will show up as "Using subdriver: TrippLite HID 0.81" in the stock version.

I have done this and verified - here is my output from
/usr/local/ups/sbin/upsdrvctl start:. You can see the "MODIFIED" tag i
placed in the code

Network UPS Tools - UPS driver controller 2.7.3
Network UPS Tools - Generic HID driver 0.39 (2.7.3)
USB communication driver 0.32
Using subdriver: TrippLite HID 0.81_MODIFIED

Post by Charles Lepple
[please use reply-all to include the list, as the list does not override
the Reply-To header.]

Does the libusb_get_string error occur only every 30 seconds or so?

Yes - thats correct. perhaps more like every 15 sec.

I was incorrect. they occur every 6 seconds. and there are two of them
each time.
hopefully that narrows it down!

Unfortunately, no. I was thinking either every 30 seconds or every two seconds, and I'm not sure why they would occur two at a time every six seconds.
gdb /usr/local/ups/bin/usbhid-ups
...
(gdb) break libusb_get_string
(gdb) run -DD -a tripplite
...
(gdb) c
...
(gdb) bt
Keep pressing "c" until you get past the initial detection, which probably succeeds.
That last line should print a backtrace showing which function called the offending function.

Okay - here is my attempt at doing that. i did a backtrace after i saw
the invalid argument line come up. let me know if thats right.

Post by Charles Lepple
~ % sudo gdb /usr/local/ups/bin/usbhid-ups

GNU gdb (GDB) 7.9.1
Copyright (C) 2015 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "armv5tel-unknown-linux-gnueabi".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/ups/bin/usbhid-ups...done.
(gdb) break libusb_get_string
Breakpoint 1 at 0x16134: file libusb.c, line 496.
(gdb) run -DD -a tripplite
Starting program: /usr/local/ups/bin/usbhid-ups -DD -a tripplite
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
Network UPS Tools - Generic HID driver 0.39 (2.7.3)
USB communication driver 0.32
0.000000 debug level is '2'
0.066603 upsdrv_initups...
0.080042 Checking device (09AE/1007) (001/006)
0.249698 - VendorID: 09ae
0.250669 - ProductID: 1007
0.251615 - Manufacturer: Tripp Lite
0.252487 - Product: TRIPP LITE UPS
0.253342 - Serial Number: FW-2263 E
0.254194 - Bus: 001
0.254709 Trying to match device
0.255059 Device matches
0.274850 HID descriptor length 447
0.752620 Report Descriptor size = 447
0.753610 Using subdriver: TrippLite HID 0.81_MODIFIED
0.769401 Path: UPS.PowerSummary.iProduct, Type: Feature,
ReportID: 0x28, Offset: 0, Size: 8, Value: 1
0.786121 Path: UPS.PowerSummary.iSerialNumber, Type: Feature,
ReportID: 0x29, Offset: 0, Size: 8, Value: 2
0.802865 Path: UPS.PowerSummary.iManufacturer, Type: Feature,
ReportID: 0x2b, Offset: 0, Size: 8, Value: 3
0.819524 Path: UPS.PowerSummary.Input.ConfigVoltage, Type:
Feature, ReportID: 0x30, Offset: 0, Size: 8, Value: 120
0.836279 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
0.852997 Path: UPS.PowerSummary.iDeviceChemistry, Type:
Feature, ReportID: 0x2a, Offset: 0, Size: 8, Value: 24
0.869730 Path: UPS.PowerSummary.CapacityMode, Type: Feature,
ReportID: 0x33, Offset: 0, Size: 8, Value: 2
0.886509 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Input,
ReportID: 0x35, Offset: 0, Size: 16, Value: 1440
0.886923 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature,
ReportID: 0x35, Offset: 0, Size: 16, Value: 1440
0.903240 Path: UPS.PowerSummary.RemainingCapacity, Type: Input,
ReportID: 0x34, Offset: 0, Size: 8, Value: 100
0.903393 Path: UPS.PowerSummary.RemainingCapacity, Type:
Feature, ReportID: 0x34, Offset: 0, Size: 8, Value: 100
0.919985 Path: UPS.PowerSummary.FullChargeCapacity, Type:
Feature, ReportID: 0x37, Offset: 0, Size: 8, Value: 100
0.936759 Path: UPS.PowerSummary.PresentStatus.ShutdownImminent,
Type: Input, ReportID: 0x32, Offset: 0, Size: 1, Value: 0
0.936859 Path: UPS.PowerSummary.PresentStatus.TLACPresent,
Type: Input, ReportID: 0x32, Offset: 1, Size: 1, Value: 1
0.936931 Path: UPS.PowerSummary.PresentStatus.TLCharging, Type:
Input, ReportID: 0x32, Offset: 2, Size: 1, Value: 1
0.936996 Path: UPS.PowerSummary.PresentStatus.TLDischarging,
Type: Input, ReportID: 0x32, Offset: 3, Size: 1, Value: 0
0.937062 Path:
UPS.PowerSummary.PresentStatus.TLNeedReplacement, Type: Input,
ReportID: 0x32, Offset: 4, Size: 1, Value: 0
0.937129 Path: UPS.PowerSummary.PresentStatus.ShutdownImminent,
Type: Feature, ReportID: 0x32, Offset: 0, Size: 1, Value: 0
0.937199 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type:
Feature, ReportID: 0x32, Offset: 1, Size: 1, Value: 1
0.937265 Path: UPS.PowerSummary.PresentStatus.Charging, Type:
Feature, ReportID: 0x32, Offset: 2, Size: 1, Value: 1
0.937334 Path: UPS.PowerSummary.PresentStatus.Discharging,
Type: Feature, ReportID: 0x32, Offset: 3, Size: 1, Value: 0
0.937401 Path: UPS.PowerSummary.PresentStatus.NeedReplacement,
Type: Feature, ReportID: 0x32, Offset: 4, Size: 1, Value: 0
0.953533 Path: UPS.BatterySystem.Battery.ConfigVoltage, Type:
Feature, ReportID: 0x04, Offset: 0, Size: 16, Value: 12
0.970234 Path:
UPS.BatterySystem.Battery.PresentStatus.Charging, Type: Feature,
ReportID: 0x23, Offset: 0, Size: 1, Value: 1
0.970796 Path:
UPS.BatterySystem.Battery.PresentStatus.Discharging, Type: Feature,
ReportID: 0x23, Offset: 1, Size: 1, Value: 0
0.970928 Path:
UPS.BatterySystem.Battery.PresentStatus.NeedReplacement, Type:
Feature, ReportID: 0x23, Offset: 2, Size: 1, Value: 0
0.987027 Path: UPS.BatterySystem.Test, Type: Feature, ReportID:
0x10, Offset: 0, Size: 8, Value: 0
1.003749 Path: UPS.Flow.ConfigVoltage, Type: Feature, ReportID:
0x01, Offset: 0, Size: 8, Value: 120
1.020490 Path: UPS.Flow.ConfigFrequency, Type: Feature,
ReportID: 0x02, Offset: 0, Size: 8, Value: 60
1.037271 Path: UPS.Flow.ConfigApparentPower, Type: Feature,
ReportID: 0x03, Offset: 0, Size: 16, Value: 900
1.054007 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
1.070622 Path: UPS.OutletSystem.Outlet.ffff0091, Type: Feature,
ReportID: 0x51, Offset: 0, Size: 8, Value: 0
1.087506 Path: UPS.OutletSystem.Outlet.TLWatchdog, Type:
Feature, ReportID: 0x52, Offset: 0, Size: 8, Value: 0
1.104124 Path: UPS.OutletSystem.Outlet.ffff00c7, Type: Feature,
ReportID: 0xb6, Offset: 0, Size: 8, Value: 1
1.121003 Path: UPS.TLCustom.[1].CommunicationProtocolVersion,
Type: Feature, ReportID: 0x6c, Offset: 0, Size: 16, Value: 4103
1.137767 Path: UPS.ffff0015.[1].ffff00c0, Type: Feature,
ReportID: 0x96, Offset: 0, Size: 8, Value: 255
1.154468 refresh_report_buffer: expected 5 bytes, but got 2 instead
1.154581 Path: UPS.ffff0015.[1].ffff00d2, Type: Feature,
ReportID: 0xb4, Offset: 0, Size: 32, Value: 255
1.171262 Path: UPS.ffff0015.[1].ffff00c1, Type: Feature,
ReportID: 0x97, Offset: 0, Size: 16, Value: 255
1.188284 Path: UPS.ffff0015.[1].ffff00c2, Type: Feature,
ReportID: 0x98, Offset: 0, Size: 8, Value: 255
1.205022 Path: UPS.ffff0015.[1].ffff00c3, Type: Feature,
ReportID: 0x99, Offset: 0, Size: 16, Value: 255
1.221761 Path: UPS.ffff0015.[1].ffff00c5, Type: Feature,
ReportID: 0x9b, Offset: 0, Size: 16, Value: 3
1.230623 libusb_get_report: Value too large for defined data type
1.231014 Can't retrieve Report c2: Value too large for defined data type
1.231393 Path: UPS.ffff0015.[1].ffff00d6, Type: Feature,
ReportID: 0xc2, Offset: 0, Size: 32
1.238633 libusb_get_report: Value too large for defined data type
1.238766 Can't retrieve Report 9a: Value too large for defined data type
1.239023 Path: UPS.ffff0015.[1].ffff00c4, Type: Feature,
ReportID: 0x9a, Offset: 0, Size: 32
1.239478 Report descriptor retrieved (Reportlen = 447)
1.239577 Found HID device
1.239934 Detected a UPS: Tripp Lite /TRIPP LITE UPS
1.240468 Path: UPS.PowerSummary.RemainingCapacity, Type:
Feature, ReportID: 0x34, Offset: 0, Size: 8, Value: 100
1.241196 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Feature,
ReportID: 0x35, Offset: 0, Size: 16, Value: 1440
1.241629 Path: UPS.BatterySystem.Battery.ConfigVoltage, Type:
Feature, ReportID: 0x04, Offset: 0, Size: 16, Value: 12
1.242090 Path: UPS.PowerSummary.iDeviceChemistry, Type:
Feature, ReportID: 0x2a, Offset: 0, Size: 8, Value: 24
[New Thread 0x40b51460 (LWP 8120)]

Breakpoint 1, libusb_get_string (udev=0x43110, StringIdx=24,
buf=0x40400 <buf> "", buflen=20) at libusb.c:496
496 if (!udev) {
(gdb) c
Continuing.
27.433807 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
27.450415 Path: UPS.BatterySystem.Test, Type: Feature, ReportID:
0x10, Offset: 0, Size: 8, Value: 0
27.467292 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.483919 Path: UPS.Flow.ConfigApparentPower, Type: Feature,
ReportID: 0x03, Offset: 0, Size: 16, Value: 900
27.500786 Path: UPS.OutletSystem.Outlet.TLWatchdog, Type:
Feature, ReportID: 0x52, Offset: 0, Size: 8, Value: 0
27.517668 Path: UPS.PowerSummary.PresentStatus.ShutdownImminent,
Type: Feature, ReportID: 0x32, Offset: 0, Size: 1, Value: 0
27.517877 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type:
Feature, ReportID: 0x32, Offset: 1, Size: 1, Value: 1
27.518369 Path: UPS.PowerSummary.PresentStatus.Charging, Type:
Feature, ReportID: 0x32, Offset: 2, Size: 1, Value: 1
27.518752 Path: UPS.PowerSummary.PresentStatus.Discharging,
Type: Feature, ReportID: 0x32, Offset: 3, Size: 1, Value: 0
27.519154 Path: UPS.PowerSummary.PresentStatus.NeedReplacement,
Type: Feature, ReportID: 0x32, Offset: 4, Size: 1, Value: 0
27.534423 Path: UPS.PowerSummary.Input.ConfigVoltage, Type:
Feature, ReportID: 0x30, Offset: 0, Size: 8, Value: 120
27.551295 Path: UPS.Flow.ConfigVoltage, Type: Feature, ReportID:
0x01, Offset: 0, Size: 8, Value: 120
27.568055 Path: UPS.Flow.ConfigFrequency, Type: Feature,
ReportID: 0x02, Offset: 0, Size: 8, Value: 60
27.568535 Path: UPS.BatterySystem.Test, Type: Feature, ReportID:
0x10, Offset: 0, Size: 8, Value: 0
27.568978 Path: UPS.BatterySystem.Test, Type: Feature, ReportID:
0x10, Offset: 0, Size: 8, Value: 0
27.569349 Path: UPS.BatterySystem.Test, Type: Feature, ReportID:
0x10, Offset: 0, Size: 8, Value: 0
27.569789 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
27.569999 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
27.570458 Path: UPS.OutletSystem.Outlet.TLWatchdog, Type:
Feature, ReportID: 0x52, Offset: 0, Size: 8, Value: 0
27.570831 Path: UPS.OutletSystem.Outlet.TLWatchdog, Type:
Feature, ReportID: 0x52, Offset: 0, Size: 8, Value: 0
27.571228 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.571645 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.572021 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.572224 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.572590 Path: UPS.PowerSummary.AudibleAlarmControl, Type:
Feature, ReportID: 0x11, Offset: 0, Size: 8, Value: 2
27.572935 find_nut_info: unknown info type: load.on.delay
27.573263 find_nut_info: unknown info type: load.on.delay
27.573458 upsdrv_initinfo...
27.573842 upsdrv_updateinfo...
27.581201 Got 1 HID objects...
27.581559 Path: UPS.PowerSummary.RemainingCapacity, Type: Input,
ReportID: 0x34, Offset: 0, Size: 8, Value: 100
27.581677 Quick update...
27.582023 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
27.582160 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type:
Feature, ReportID: 0x32, Offset: 1, Size: 1, Value: 1
27.582675 Path: UPS.PowerSummary.PresentStatus.Charging, Type:
Feature, ReportID: 0x32, Offset: 2, Size: 1, Value: 1
27.583327 Path: UPS.PowerSummary.PresentStatus.Discharging,
Type: Feature, ReportID: 0x32, Offset: 3, Size: 1, Value: 0
27.584090 dstate_init: sock /var/state/ups/usbhid-ups-tripplite
open on fd 13
27.584935 upsdrv_updateinfo...
27.613190 Got 1 HID objects...
27.613602 Path: UPS.PowerSummary.RunTimeToEmpty, Type: Input,
ReportID: 0x35, Offset: 0, Size: 16, Value: 1440
27.613931 Quick update...
27.614057 Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown,
Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535
27.614467 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type:
Feature, ReportID: 0x32, Offset: 1, Size: 1, Value: 1
27.614838 Path: UPS.PowerSummary.PresentStatus.Charging, Type:
Feature, ReportID: 0x32, Offset: 2, Size: 1, Value: 1
27.615222 Path: UPS.PowerSummary.PresentStatus.Discharging,
Type: Feature, ReportID: 0x32, Offset: 3, Size: 1, Value: 0
29.585702 upsdrv_updateinfo...
29.597279 Got 5 HID objects...
29.597393 Path: UPS.PowerSummary.PresentStatus.ShutdownImminent,
Type: Input, ReportID: 0x32, Offset: 0, Size: 1, Value: 0
29.597484 Path: UPS.PowerSummary.PresentStatus.TLACPresent,
Type: Input, ReportID: 0x32, Offset: 1, Size: 1, Value: 1

Breakpoint 1, libusb_get_string (udev=0x43110, StringIdx=1,
buf=0x40204 <buf> "", buflen=20) at libusb.c:496
496 if (!udev) {
(gdb) c
Continuing.
41.813239 Path: UPS.PowerSummary.PresentStatus.TLCharging, Type:
Input, ReportID: 0x32, Offset: 2, Size: 1, Value: 1

Breakpoint 1, libusb_get_string (udev=0x43110, StringIdx=1,
buf=0x40204 <buf> "TRIPP LITE UPS ", buflen=20) at libusb.c:496
496 if (!udev) {
(gdb) c
Continuing.
48.812952 Path: UPS.PowerSummary.PresentStatus.TLDischarging,
Type: Input, ReportID: 0x32, Offset: 3, Size: 1, Value: 0

Breakpoint 1, libusb_get_string (udev=0x43110, StringIdx=0,
buf=0x40204 <buf> "TRIPP LITE UPS ", buflen=20) at libusb.c:496
496 if (!udev) {
(gdb) c
Continuing.
50.329396 libusb_get_string: Invalid argument
50.329543 Path:
UPS.PowerSummary.PresentStatus.TLNeedReplacement, Type: Input,
ReportID: 0x32, Offset: 4, Size: 1, Value: 0

Breakpoint 1, libusb_get_string (udev=0x43110, StringIdx=0,
buf=0x40204 <buf> "", buflen=20) at libusb.c:496
496 if (!udev) {
(gdb) bt
#0 libusb_get_string (udev=0x43110, StringIdx=0, buf=0x40204 <buf>
"", buflen=20) at libusb.c:496
#1 0x00015330 in HIDGetIndexString (udev=<optimized out>,
Index=<optimized out>, buf=0x40204 <buf> "", buflen=<optimized out>)
at libhid.c:407
#2 0x00012e18 in ups_infoval_set (item=0x3ee48 <tripplite_hid2nut>,
value=<optimized out>) at usbhid-ups.c:1552
#3 0x00013da8 in upsdrv_updateinfo () at usbhid-ups.c:835
#4 0x00012410 in main (argc=<optimized out>, argv=<optimized out>) at
main.c:708

Charles Lepple

2015-06-10 03:10:44 UTC

Post by Charles Lepple
(gdb) bt
#0 libusb_get_string (udev=0x43110, StringIdx=0, buf=0x40204 <buf>
"", buflen=20) at libusb.c:496
#1 0x00015330 in HIDGetIndexString (udev=<optimized out>,
Index=<optimized out>, buf=0x40204 <buf> "", buflen=<optimized out>)
at libhid.c:407
#2 0x00012e18 in ups_infoval_set (item=0x3ee48 <tripplite_hid2nut>,
value=<optimized out>) at usbhid-ups.c:1552
#3 0x00013da8 in upsdrv_updateinfo () at usbhid-ups.c:835
#4 0x00012410 in main (argc=<optimized out>, argv=<optimized out>) at
main.c:708

You did everything right on the backtrace, but that is puzzling.

At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.

The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.

Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.

Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.

--
Charles Lepple
***@gmail

Greg Hersch

2015-06-10 15:31:03 UTC

I've attached the gzipp'd log -DDDDD log here.

i will work on your recompilation instructions next

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.
The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.
Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

Greg Hersch

2015-06-10 16:18:34 UTC

And here are the logs and GDB output from the reconfigured/recompiled CFLAGS=-G
program. You will notice i made a change to the version definition of
tripplite-hid.c just to make sure i am working with the updated version.

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.
The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.
Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

Charles Lepple

2015-06-11 13:13:06 UTC

Greg,

I'm still not 100% on what is going on, but after comparing the call stack with a debug session here, I think I have at least identified why I wasn't seeing similar behavior.

There are two ways that the driver can get information from the UPS: asking the UPS for a specific report (which returns one or more values), and checking the interrupt pipe (which the UPS can fill with whatever has changed). With the interrupt pipe results, the driver has to do an additional HID table lookup to determine exactly what is being returned.

It looks like the driver is processing the latter case when it throws that error. I wasn't seeing that here, apparently because my MGE UPS on FreeBSD is never getting anything via the interrupt pipe. (The driver falls back to the polling method.)

I might have some time later to reconnect that UPS to a Linux system and see if the error crops up there. However, I have a suspicion that the bug is triggered because the first entry in the Tripp Lite table has a conversion function, and when the table lookup fails (your UPS does not have the HID item corresponding to a manufacturer's part number), the lookup function incorrectly returns that first table entry by default.

- Charles

And here are the logs and GDB output from the reconfigured/recompiled CFLAGS=-G program. You will notice i made a change to the version definition of tripplite-hid.c just to make sure i am working with the updated version.

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.
The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.
Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>

Charles Lepple

2015-06-12 13:27:43 UTC

Greg,

I think I fixed it. Thanks for your patience.

https://github.com/networkupstools/nut/pull/213

Diffs: https://github.com/networkupstools/nut/compare/usbhid_ups_input_vs_feature

If anyone else can test usbhid-ups against their hardware before I merge this to master, I would appreciate it. I tried my MGE UPS on a Linux box as well, and it does not get interrupt events there, either.

- Charles Lepple

Post by Charles Lepple
Greg,
I'm still not 100% on what is going on, but after comparing the call stack with a debug session here, I think I have at least identified why I wasn't seeing similar behavior.
There are two ways that the driver can get information from the UPS: asking the UPS for a specific report (which returns one or more values), and checking the interrupt pipe (which the UPS can fill with whatever has changed). With the interrupt pipe results, the driver has to do an additional HID table lookup to determine exactly what is being returned.
It looks like the driver is processing the latter case when it throws that error. I wasn't seeing that here, apparently because my MGE UPS on FreeBSD is never getting anything via the interrupt pipe. (The driver falls back to the polling method.)
I might have some time later to reconnect that UPS to a Linux system and see if the error crops up there. However, I have a suspicion that the bug is triggered because the first entry in the Tripp Lite table has a conversion function, and when the table lookup fails (your UPS does not have the HID item corresponding to a manufacturer's part number), the lookup function incorrectly returns that first table entry by default.
- Charles

And here are the logs and GDB output from the reconfigured/recompiled CFLAGS=-G program. You will notice i made a change to the version definition of tripplite-hid.c just to make sure i am working with the updated version.

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.
The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.
Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>

Greg Hersch

2015-06-12 14:33:04 UTC

thanks - this has been fun.

There is one other thing I have been having trouble with - and i've tried it on
two archlinuxarm installs and gotten the same thing. i am not even sure if its
important for me. but if i try to configure and make with neon support - it cant
find the neon libraries. despite neon having been installed several
different ways (i tried pacman, as well as compiling and installign neon from
source)

i only came across this because when i originally tried installing nut, i tried
doing it from the archlinux AUR. There, neon is enabled by default. and i
couldnt get it to build. so i ended up going to the source.

Greg

Post by Charles Lepple
Greg,
I think I fixed it. Thanks for your patience.
https://github.com/networkupstools/nut/pull/213
Diffs: https://github.com/networkupstools/nut/compare/usbhid_ups_input_vs_feature
If anyone else can test usbhid-ups against their hardware before I merge this to master, I would appreciate it. I tried my MGE UPS on a Linux box as well, and it does not get interrupt events there, either.
- Charles Lepple

And here are the logs and GDB output from the reconfigured/recompiled CFLAGS=-G program. You will notice i made a change to the version definition of tripplite-hid.c just to make sure i am working with the updated version.

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I don't see where it does that in the code. There must be some pointers, or something.
The easiest thing might be to crank the debug output up a bit more (5x -D, even) but since that will be a bit more output, please redirect it to a file, and gzip the log before attaching it. Doesn't need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not set already, so adding "CFLAGS=-g" to the ./configure line should do it.
Arnaud, am I missing something obvious here? After making "device.part" HU_STATIC, there shouldn't be any other string descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>

Greg Hersch

2015-06-12 19:52:56 UTC

By the way, in nut-driver.service - i had to comment out StopWhenUnneeded=yes

for some reason systemd would end it each time - no matter if the server was
loaded beforehand or not. once i did that it was fine

Post by Greg Hersch
thanks - this has been fun.
There is one other thing I have been having trouble with - and i've tried it
on two archlinuxarm installs and gotten the same thing. i am not even sure if
its important for me. but if i try to configure and make with neon support -
it cant find the neon libraries. despite neon having been installed several
different ways (i tried pacman, as well as compiling and installign neon from
source)
i only came across this because when i originally tried installing nut, i
tried doing it from the archlinux AUR. There, neon is enabled by default. and
i couldnt get it to build. so i ended up going to the source.
Greg

Post by Charles Lepple
Greg,
I think I fixed it. Thanks for your patience.
https://github.com/networkupstools/nut/pull/213
https://github.com/networkupstools/nut/compare/usbhid_ups_input_vs_feature
If anyone else can test usbhid-ups against their hardware before I merge
this to master, I would appreciate it. I tried my MGE UPS on a Linux box
as well, and it does not get interrupt events there, either.
- Charles Lepple

Post by Charles Lepple
Greg,
I'm still not 100% on what is going on, but after comparing the call
stack with a debug session here, I think I have at least identified why
I wasn't seeing similar behavior.
asking the UPS for a specific report (which returns one or more values),
and checking the interrupt pipe (which the UPS can fill with whatever
has changed). With the interrupt pipe results, the driver has to do an
additional HID table lookup to determine exactly what is being returned.
It looks like the driver is processing the latter case when it throws
that error. I wasn't seeing that here, apparently because my MGE UPS on
FreeBSD is never getting anything via the interrupt pipe. (The driver
falls back to the polling method.)
I might have some time later to reconnect that UPS to a Linux system and
see if the error crops up there. However, I have a suspicion that the
bug is triggered because the first entry in the Tripp Lite table has a
conversion function, and when the table lookup fails (your UPS does not
have the HID item corresponding to a manufacturer's part number), the
lookup function incorrectly returns that first table entry by default.
- Charles

Post by Greg Hersch
And here are the logs and GDB output from the reconfigured/recompiled
CFLAGS=-G program. You will notice i made a change to the version
definition of tripplite-hid.c just to make sure i am working with the
updated version.

Post by Charles Lepple
(gdb) bt
#0 libusb_get_string (udev=0x43110, StringIdx=0, buf=0x40204 <buf>
"", buflen=20) at libusb.c:496
#1 0x00015330 in HIDGetIndexString (udev=<optimized out>,
Index=<optimized out>, buf=0x40204 <buf> "", buflen=<optimized out>)
at libhid.c:407
#2 0x00012e18 in ups_infoval_set (item=0x3ee48
<tripplite_hid2nut>,
value=<optimized out>) at usbhid-ups.c:1552
#3 0x00013da8 in upsdrv_updateinfo () at usbhid-ups.c:835
#4 0x00012410 in main (argc=<optimized out>, argv=<optimized out>) at
main.c:708

You did everything right on the backtrace, but that is puzzling.
At #2, ups_infoval_set() apparently calls HIDGetIndexString(), but I
don't see where it does that in the code. There must be some
pointers, or something.
The easiest thing might be to crank the debug output up a bit more
(5x -D, even) but since that will be a bit more output, please
redirect it to a file, and gzip the log before attaching it. Doesn't
need to be long, just enough to see one or two errors.
Another idea is to recompile without optimizations, to see if that
helps the gdb backtrace. NUT apparently sets CFLAGS=-O if it is not
set already, so adding "CFLAGS=-g" to the ./configure line should do
it.
Arnaud, am I missing something obvious here? After making
"device.part" HU_STATIC, there shouldn't be any other string
descriptors retrieved in drivers/tripplite-hid.c.
--
Charles Lepple

<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>

Charles Lepple

2015-06-13 00:24:45 UTC

Post by Greg Hersch
thanks - this has been fun.
There is one other thing I have been having trouble with - and i've tried it on two archlinuxarm installs and gotten the same thing. i am not even sure if its important for me. but if i try to configure and make with neon support - it cant find the neon libraries. despite neon having been installed several different ways (i tried pacman, as well as compiling and installign neon from source)
i only came across this because when i originally tried installing nut, i tried doing it from the archlinux AUR. There, neon is enabled by default. and i couldnt get it to build. so i ended up going to the source.

Short answer: you don't need it for usbhid-ups.

libneon is used by http://www.networkupstools.org/docs/man/netxml-ups.html to connect to some MGE/Eaton hardware, and by the corresponding nut-scanner module.

I'm not familiar with archlinux or AUR, but if you still have the logs, we can certainly take a look. It might be that NUT is looking for an older version of libneon, or that there is another dependency that is needed at build time.

--
Charles Lepple
***@gmail

Greg Hersch

2015-06-13 14:12:55 UTC

Thanks - i won't sweat it then... i've now got upsmon running across 3
machines (a router (DDWRT optware), a raspberry pi (raspbian), and the
master archlinux system). and all seems to work well after a few
workarounds. thank you Charles

Greg