SIGSEGV from libusb_control_transfer() when called from nut_libusb_get_report in usbhid-ups driver

[nbriggs]

Talking to the folowing UPS:

   0.042299     [D2] Checking device 1 of 5 (04B3/0001)
   0.393839     [D2] - VendorID: 04b3
   0.393940     [D2] - ProductID: 0001
   0.393996     [D2] - Manufacturer: IBM
   0.394053     [D2] - Product: IBM 1000VA/750W Tower UPS
   0.394110     [D2] - Serial Number: 23A4881                     
   0.394164     [D2] - Bus: 002
   0.394219     [D2] - Bus Port: 001
   0.394287     [D2] - Device: 005
   0.394341     [D2] - Device release number: 0100

the usbhid-ups driver takes a SIGSEGV always within the first 30s or so of startup. It's always at the same call to libusb_control_transfer(), and it has often gone through the same lines of code a few times before the segmentation fault happens.

There's no debug version of libusb-1.0 easily available, so I can't localize this more accurately.

  18.504005     [D1] upsdrv_updateinfo...
  18.504107     [D1] Not using interrupt pipe...
  18.504169     [D1] Quick update...
  18.504228     [D4] Entering libusb_get_report

Thread 2 received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1 (LWP 1)]
0xffffffff7c010cd0 in libusb_control_transfer () from /usr/lib/64/libusb-1.0.so.0
(gdb) 
(gdb) bt
#0  0xffffffff7c010cd0 in libusb_control_transfer () from /usr/lib/64/libusb-1.0.so.0
#1  0x0000000100023e70 in nut_libusb_get_report (udev=0x100165f40, ReportId=<optimized out>, raw_buf=0x100160700 "&\004\004", ReportSize=3) at libusb1.c:924
#2  0x0000000100022ec4 in refresh_report_buffer (pData=0x100166f00, rbuf=0x10016b4a0, udev=0x100165f40, age=<optimized out>) at libhid.c:231
#3  get_item_buffered (rbuf=0x10016b4a0, udev=0x100165f40, pData=0x100166f00, Value=0xffffffff7fffe728, age=<optimized out>) at libhid.c:268
#4  HIDGetDataValue (udev=0x100165f40, hiddata=0x100166f00, Value=0xffffffff7fffe7f8, age=<optimized out>) at libhid.c:523
#5  0x000000010001f0e8 in hid_ups_walk (mode=HU_WALKMODE_QUICK_UPDATE) at usbhid-ups.c:1753
#6  0x000000010002050c in upsdrv_updateinfo () at usbhid-ups.c:1185
#7  0x0000000100031c08 in main (argc=<optimized out>, argv=<optimized out>) at main.c:2682

The full debug level 4 trace is attached.

usbhid-sigsegv.txt

[nbriggs]

The problem seems to happen at:

Dump of assembler code for function libusb_control_transfer:
   0xffffffff7c010ca0 <+0>:       save  %sp, -192, %sp
   0xffffffff7c010ca4 <+4>:       ldx  [ %i0 + 0x30 ], %g1
   0xffffffff7c010ca8 <+8>:       sll  %i1, 8, %g4
   0xffffffff7c010cac <+12>:      ldx  [ %g1 + 0x20 ], %g1
   0xffffffff7c010cb0 <+16>:      sethi  %hi(0x105000), %l7
   0xffffffff7c010cb4 <+20>:      call  0xffffffff7c009220 <__sparc_get_pc_thunk.l7>
   0xffffffff7c010cb8 <+24>:      add  %l7, 0x34c, %l7      ! 0x10534c
   0xffffffff7c010cbc <+28>:      lduh  [ %fp + 0x8b5 ], %l3
   0xffffffff7c010cc0 <+32>:      ld  [ %fp + 0x8bb ], %l1
   0xffffffff7c010cc4 <+36>:      or  %g4, %i2, %i2
   0xffffffff7c010cc8 <+40>:      clr  [ %fp + 0x7fb ]
   0xffffffff7c010ccc <+44>:      call  0xffffffff7c1165c0 <pthread_getspecific@got.plt>
=> 0xffffffff7c010cd0 <+48>:      ld  [ %g1 + 0xf4 ], %o0
   0xffffffff7c010cd4 <+52>:      brnz,a,pn   %o0, 0xffffffff7c010eac <libusb_control_transfer+524>
   0xffffffff7c010cd8 <+56>:      mov  -6, %i4
   0xffffffff7c010cdc <+60>:      call  0xffffffff7c116980 <libusb_alloc_transfer@got.plt>

and the source looks like:

int API_EXPORTED libusb_control_transfer(libusb_device_handle *dev_handle,
        uint8_t bmRequestType, uint8_t bRequest, uint16_t wValue, uint16_t wIndex,
        unsigned char *data, uint16_t wLength, unsigned int timeout)
{
        struct libusb_transfer *transfer;
        unsigned char *buffer;
        int completed = 0;
        int r;

        if (usbi_handling_events(HANDLE_CTX(dev_handle)))
                return LIBUSB_ERROR_BUSY;

        transfer = libusb_alloc_transfer(0);
        if (!transfer)
                return LIBUSB_ERROR_NO_MEM;

with the following definitions:

#define usbi_handling_events(ctx) \
        (usbi_tls_key_get((ctx)->event_handling_key) != NULL)

static inline void *usbi_tls_key_get(usbi_tls_key_t key)
{
        return pthread_getspecific(key);
}

#define HANDLE_CTX(handle)   (DEVICE_CTX((handle)->dev))
#define DEVICE_CTX(dev)              ((dev)->ctx)

so we've got

if (pthread_getspecific(handle->dev->ctx->event_handling_key) != NULL) return LIBUSB_ERROR_BUSY;

and the registers at that point are

#0  0xffffffff7c010cd0 in libusb_control_transfer () from /usr/lib/64/libusb-1.0.so.0
(gdb) info r
g0             0x0                 0
g1             0x0                 0
g2             0x1388              5000
g3             0x0                 0
g4             0xa100              41216
g5             0x83fef000          2214522880
g6             0x0                 0
g7             0xffffffff7f5c2a40  -2158220736
o0             0x0                 0
o1             0x68d7119c          1758925212
o2             0x1e565440          508974144

so with %g1 being 0, it's no wonder that ld [ %g1 + 0xf4 ], %o0 is faulting.

[jimklimov]

Is this a build you mentioned in #3099 - a 32-bit SPARC? Then "64" in lib path looks fishy :\

[jimklimov]

Also Network UPS Tools version 2.8.2-119-g53335865c looks a bit odd/old.

[nbriggs]

It is the same system as for the #3099 issue - I'm compiling everything 64-bit, though the system can build and run 32- or 64-bit mode on a per-application basis.

# file /usr/local/ups/bin/usbhid-ups
/usr/local/ups/bin/usbhid-ups:  ELF 64-bit MSB executable SPARCV9 Version 1, UltraSPARC3 Extensions Required, dynamically linked, not stripped
# ldd /usr/local/ups/bin/usbhid-ups
        libusb-1.0.so.0 =>       /usr/lib/64/libusb-1.0.so.0
        libm.so.2 =>     /lib/64/libm.so.2
        libc.so.1 =>     /lib/64/libc.so.1
        libdevinfo.so.1 =>       /lib/64/libdevinfo.so.1
        libnvpair.so.1 =>        /lib/64/libnvpair.so.1
        libsec.so.1 =>   /lib/64/libsec.so.1
        libgen.so.1 =>   /lib/64/libgen.so.1
        libsysevent.so.1 =>      /lib/64/libsysevent.so.1
        libavl.so.1 =>   /lib/64/libavl.so.1
        libidmap.so.1 =>         /usr/lib/64/libidmap.so.1
        libuutil.so.1 =>         /lib/64/libuutil.so.1

[jimklimov]

FWIW there's libusb debug support, maybe newer than 2.8.2 though,

[nbriggs]

I rebuilt using 2.8.4 (the most recent tagged version, I think) - same problem. I'll rebuild using the head of master - but I suspect it's likely a problem within libusb-1.0 and its interaction with Solaris pthreads, so I doubt that will help, and I'm not sure how long it will take me to track down the problem if I even can.

[nbriggs]

Rebuilt at head of master -- SEMVER=2.8.4; TRUNK='master'; BASE='87008cfc7cba30872f2a190cba51e5c2a3751ae1'; DESC='v2.8.4-123+g87008cfc7'

Same SIGSEGV.

[jimklimov]

Thanks for checking! FWIW, rebuilding libusb is also an option ;) Just in case it is fixed on their master/feature branch, or you come up with some fix,

In order to not confuse other programs, you can install that build into a dedicated area (perhaps under /usr/local/ups too), and use NUT configure options to find that.

[nbriggs]

Yeah, I'm going to pull a newer version of libusb-1 -- the 0.23 that Oracle is shipping is at least 5 years out of date, and I know there have been changes made in pthread related areas in more recent versions, and the patches that Oracle supplied for 0.23 have been incorporated upstream. Here's hoping!

[nbriggs]

Success - using libusb-1.0.29 in place of Oracle's shipping libusb-1.0.23 allows the usbhid-ups driver to run without taking a SIGSEGV. Github won't let me tag Alan Coopersmith on this to alert him -- can you?

[jimklimov]

CC @alanc - it seems right to bump Solaris libusb-1 version by half a decade, if possible, please :)

[alanc]

I've added a note pointing to this issue to our internal bug 35226777 requesting an update to this library.