Nut upsdev - Jun 2015 - libusb_get_string: invalid argument (other usbhid-ups users, please test)

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

On Jun 10, 2015, at 12:18 PM, Greg Hersch <hersch.greg at gmail.com>
wrote:
> 
> 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.
> 
> On Tue, 9 Jun 2015, Charles Lepple wrote:
> 
>> On Jun 9, 2015, at 4:55 PM, Greg Hersch wrote:
>> 
>>> (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
>> clepple at gmail
>> 
>> 
>> 
>
<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>

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

On Jun 11, 2015, at 9:13 AM, Charles Lepple <clepple at gmail.com> wrote:
> 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
> 
> On Jun 10, 2015, at 12:18 PM, Greg Hersch <hersch.greg at gmail.com>
wrote:
> 
>> 
>> 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.
>> 
>> On Tue, 9 Jun 2015, Charles Lepple wrote:
>> 
>>> On Jun 9, 2015, at 4:55 PM, Greg Hersch wrote:
>>> 
>>>> (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
>>> clepple at gmail
>>> 
>>> 
>>> 
>>
<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>
>

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


On Fri, 12 Jun 2015, Charles Lepple wrote:
> 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
>
> On Jun 11, 2015, at 9:13 AM, Charles Lepple <clepple at gmail.com>
wrote:
>
>> 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
>>
>> On Jun 10, 2015, at 12:18 PM, Greg Hersch <hersch.greg at
gmail.com> wrote:
>>
>>>
>>> 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.
>>>
>>> On Tue, 9 Jun 2015, Charles Lepple wrote:
>>>
>>>> On Jun 9, 2015, at 4:55 PM, Greg Hersch wrote:
>>>>
>>>>> (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
>>>> clepple at gmail
>>>>
>>>>
>>>>
>>>
<typescript-GDB-withCFLAGchange.gz><typescript_LOG_withCFLAG.gz>
>>
>
>