Discussion:
Config descriptor read ok by libusb 0.1, but fails with short read on libusb-1.0 (incl. lsusb)
sdaau
2012-10-27 08:36:48 UTC
Permalink
Hi all,

I am trying to communicate with a device from Linux, and I'm experiencing a specific problem - with usblib-1.0 unable to retrieve the configuration from a device, while usblib 0.1 is able to do so (on the same computer and OS). Apologies for a slightly longer mail while I explain.

First of all, here are some infos on my PC:

$ cat /etc/issue
Ubuntu 11.04 \n \l

$ uname -a
Linux ljutntcol 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux

$ apt-show-versions -r libusb
libusb-0.1-4/natty uptodate 2:0.1.12-17
libusb-1.0-0/natty uptodate 2:1.0.8-2
libusb-1.0-0-dev/natty uptodate 2:1.0.8-2
libusb-dev/natty uptodate 2:0.1.12-17
libusbmuxd1/natty uptodate 1.0.7-1ubuntu0.11.04.1

$ gcc --version
gcc (Ubuntu/Linaro 4.5.2-8ubuntu4) 4.5.2


The device I'm trying to connect to (an oscilloscope; more info follows later) apparently doesn't have a driver for linux. I first tried to write a small application that includes <usb.h> - that is, which uses libusb 0.1 - based on the example in http://pvrusb2.dax.nu/ ... That application was able to connect to device, retrieve configuration settings, and send and retrieve data to and from the device via endpoints -- except that the responses I got from the device were wrong (had a correct header, but didn't carry correct data).

So, I thought I'd double check, by rewriting my small application, this time for libusb-1.0. Everything seems to function (although didn't check reading in via endpoint); except when one comes to this part in the code, where I was trying to retrieve the config descriptor:

...
struct libusb_config_descriptor *configDesc ;
...
// this line fails with "error [parse_endpoint] invalid descriptor length 0"
// r = libusb_get_config_descriptor(dev, 0x00, &configDesc);

// this line fails with response -5 (LIBUSB_ERROR_NOT_FOUND)
// r = libusb_get_config_descriptor(dev, 0x01, &configDesc);

// note; this device in lsusb shows: ...
// bNumInterfaces 1
// bConfigurationValue 1
// iConfiguration 0
// ...
// so I thought, maybe better to just ask for 'active'
// config descriptor - instead of specifying one
// explicitly myself:

r = libusb_get_active_config_descriptor(dev, &configDesc);
if (r < 0) {
fprintf(stderr, "failed to get config descriptor (%d)\n", r);
return;
}


Well, also here I got "failed to get config descriptor", but since I couldn't get any further, I had to get more debugging information. So I tried adding libusb_set_debug(NULL, 3); in the code - then it turns out that libusb-1.0 needs to be re-built from source, to --enable-debug-log. So this is what I did:

$ git clone http://git.libusb.org/libusb.git libusb-1.0
Cloning into libusb-1.0...
...
$ cd libusb-1.0/
$ ./autogen.sh # also runs ./configure
$ make
...
$ ./examples/listdevs # run example program - debug works:
libusb: 0.000000 debug [libusb_init] libusb-1.0.9 git:1.0.9-28-g7634714
...

Then, I tried recompiling my test program against the static version of this library:

$ gcc -g myTestProg.c libusb-1.0/libusb/.libs/libusb-1.0.a -I./libusb-1.0/libusb -lpthread -lrt -o myTestProg

... and could finally retrieve the following debug info. for the offending libusb_get_active_config_descriptor:

$ ./myTestProg
...
Got device from handle
libusb: 0.006148 debug [libusb_reset_device]
libusb: 0.286630 debug [libusb_set_configuration] configuration 1
libusb: 0.295627 debug [libusb_get_active_config_descriptor]
libusb: 0.295837 debug [sysfs_get_active_config_descriptor] active configuration 1
libusb: 0.296054 debug [sysfs_get_active_config_descriptor] active configuration 1
libusb: 0.296158 error [sysfs_get_active_config_descriptor] short read 40/49
failed to get config descriptor (-1)


So, I'm basically down to LIBUSB_ERROR_IO = -1, because of a "short read 40/49", when trying to do sysfs_get_active_config_descriptor.

Now, all I want to do here with the config descriptor, is retrieve the number of endpoints, and possibly their adresses. For the number of endpoints in libusb 0.1, I have used (and it worked fine):

...
struct usb_device *dev = NULL;
int numeps = 0;
...
dev = find_first_device();
...
numeps = dev->config[0].interface[0].altsetting[0].bNumEndpoints;


... while in libusb-1.0; apparently (via http://www.dreamincode.net/forums/topic/148707-introduction-to-using-libusb-10/) one has to use:

...
struct libusb_config_descriptor *configDesc ;
const struct libusb_interface *inter;
const struct libusb_interface_descriptor *interdesc;
...
// r = libusb_get_config_descriptor(dev, 0, &configDesc);
r = libusb_get_active_config_descriptor(dev, &configDesc);
inter = &configDesc->interface[0];
interdesc = &inter->altsetting[0];
numeps = (int)interdesc->bNumEndpoints;

... thus, I have to first retrieve the config descriptor for libusb-1.0, before I can retrieve number of endpoints; and that is where the process dies.

*********

At this point, I started wondering - how come in this program, config descriptor retrieval fails - while the `lsusb` program can show the number of endpoints properly?

So I thought, I should try rebuilding the Ubuntu version of `lsusb` (from the `usbutils` package); and try rebuilding the latest `lsusb` from git. Turns out, the Ubuntu version uses <usb.h> and builds against libusb-dev, which is actually libusb 0.1(.4) - while the one from git uses <libusb.h> and builds aganst libusb-1.0-0-dev packages in Ubuntu (I didn't want to mess with config files, to force the git `lsusb` version to build against the git `libusb-1.0` version of the library [which was built previously]).

So this is basically what I did to build the Ubuntu version of `lsusb`:

$ apt-get source usbutils
...
usbutils-0.87/usb.ids
$ cd usbutils-0.87/
$ ./configure
...
usbutils 0.87
============= ...
compiler: gcc
cflags: -g -O2
ldflags:
$ make V=1 lsusb # V=1 disables "silent make mode" from Automake
gcc -DHAVE_CONFIG_H -I. -DDATADIR=\"/usr/share\" -g -O2 -MT lsusb-lsusb.o -MD -MP -MF .deps/lsusb-lsusb.Tpo -c -o lsusb-lsusb.o `test -f 'lsusb.c' || echo './'`lsusb.c
mv -f .deps/lsusb-lsusb.Tpo .deps/lsusb-lsusb.Po
gcc -DHAVE_CONFIG_H -I. -DDATADIR=\"/usr/share\" -g -O2 -MT lsusb-lsusb-t.o -MD -MP -MF .deps/lsusb-lsusb-t.Tpo -c -o lsusb-lsusb-t.o `test -f 'lsusb-t.c' || echo './'`lsusb-t.c
mv -f .deps/lsusb-lsusb-t.Tpo .deps/lsusb-lsusb-t.Po
gcc -DHAVE_CONFIG_H -I. -DDATADIR=\"/usr/share\" -g -O2 -MT lsusb-names.o -MD -MP -MF .deps/lsusb-names.Tpo -c -o lsusb-names.o `test -f 'names.c' || echo './'`names.c
mv -f .deps/lsusb-names.Tpo .deps/lsusb-names.Po
gcc -DHAVE_CONFIG_H -I. -DDATADIR=\"/usr/share\" -g -O2 -MT lsusb-devtree.o -MD -MP -MF .deps/lsusb-devtree.Tpo -c -o lsusb-devtree.o `test -f 'devtree.c' || echo './'`devtree.c
mv -f .deps/lsusb-devtree.Tpo .deps/lsusb-devtree.Po
gcc -DHAVE_CONFIG_H -I. -DDATADIR=\"/usr/share\" -g -O2 -MT lsusb-usbmisc.o -MD -MP -MF .deps/lsusb-usbmisc.Tpo -c -o lsusb-usbmisc.o `test -f 'usbmisc.c' || echo './'`usbmisc.c
mv -f .deps/lsusb-usbmisc.Tpo .deps/lsusb-usbmisc.Po
gcc -g -O2 -Wl,--as-needed -o lsusb lsusb-lsusb.o lsusb-lsusb-t.o lsusb-names.o lsusb-devtree.o lsusb-usbmisc.o -lusb -lz
$ cd ..

... and this is what I did to build the git version of `lsusb`:

$ git clone https://github.com/gregkh/usbutils.git usbutils-git
Cloning into usbutils-git...
...
$ cd usbutils-git/
$ git submodule init
Submodule 'usbhid-dump' (git://digimend.git.sourceforge.net/gitroot/digimend/usbhid-dump.git) registered for path 'usbhid-dump'
$ git submodule update
Cloning into usbhid-dump...
...
$ autoreconf --install --symlink
libtoolize: putting auxiliary files in AC_CONFIG_AUX_DIR, `auxdir'.
...
$ ./configure
...
usbutils 006
============= ...
compiler: gcc
cflags: -g -O2
ldflags:
$ make V=1 lsusb # V=1 disables "silent make mode" from Automake
gcc -DHAVE_CONFIG_H -I. -I/usr/include/libusb-1.0 -DDATADIR=\"/usr/share\" -DHAVE_LIBZ -g -O2 -MT lsusb-lsusb.o -MD -MP -MF .deps/lsusb-lsusb.Tpo -c -o lsusb-lsusb.o `test -f 'lsusb.c' || echo './'`lsusb.c
mv -f .deps/lsusb-lsusb.Tpo .deps/lsusb-lsusb.Po
gcc -DHAVE_CONFIG_H -I. -I/usr/include/libusb-1.0 -DDATADIR=\"/usr/share\" -DHAVE_LIBZ -g -O2 -MT lsusb-lsusb-t.o -MD -MP -MF .deps/lsusb-lsusb-t.Tpo -c -o lsusb-lsusb-t.o `test -f 'lsusb-t.c' || echo './'`lsusb-t.c
mv -f .deps/lsusb-lsusb-t.Tpo .deps/lsusb-lsusb-t.Po
gcc -DHAVE_CONFIG_H -I. -I/usr/include/libusb-1.0 -DDATADIR=\"/usr/share\" -DHAVE_LIBZ -g -O2 -MT lsusb-names.o -MD -MP -MF .deps/lsusb-names.Tpo -c -o lsusb-names.o `test -f 'names.c' || echo './'`names.c
mv -f .deps/lsusb-names.Tpo .deps/lsusb-names.Po
gcc -DHAVE_CONFIG_H -I. -I/usr/include/libusb-1.0 -DDATADIR=\"/usr/share\" -DHAVE_LIBZ -g -O2 -MT lsusb-devtree.o -MD -MP -MF .deps/lsusb-devtree.Tpo -c -o lsusb-devtree.o `test -f 'devtree.c' || echo './'`devtree.c
mv -f .deps/lsusb-devtree.Tpo .deps/lsusb-devtree.Po
gcc -DHAVE_CONFIG_H -I. -I/usr/include/libusb-1.0 -DDATADIR=\"/usr/share\" -DHAVE_LIBZ -g -O2 -MT lsusb-usbmisc.o -MD -MP -MF .deps/lsusb-usbmisc.Tpo -c -o lsusb-usbmisc.o `test -f 'usbmisc.c' || echo './'`usbmisc.c
mv -f .deps/lsusb-usbmisc.Tpo .deps/lsusb-usbmisc.Po
gcc -g -O2 -Wl,--as-needed -o lsusb lsusb-lsusb.o lsusb-lsusb-t.o lsusb-names.o lsusb-devtree.o lsusb-usbmisc.o -lusb-1.0 -lz
$ cd ..


So finally, here are the results of calling of these versions of `lsusb` against the device (note, under Ubuntu `sudo` has to be used, otherwise a "cannot read device status, Operation not permitted (1)" may be generated):


$ ./usbutils-0.87/lsusb --version
lsusb (usbutils) 0.87
$ ./usbutils-git/lsusb --version
lsusb (usbutils) 006

$ sudo ./usbutils-git/lsusb -v -d f4ec:ee38
./usbutils-git/lsusb: cannot open "/usr/share/usb.ids", No such file or directory

Bus 002 Device 012: ID f4ec:ee38
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xf4ec
idProduct 0xee38
bcdDevice 1.00
iManufacturer 1 Siglent TechCo., Ltd.
iProduct 2 USB Digital Oscilloscope
iSerial 0
bNumConfigurations 1
Couldn't get configuration descriptor 0, some information will be missing
Couldn't get configuration descriptor 0, some information will be missing
Device Status: 0x0001
Self Powered

$ sudo ./usbutils-0.87/lsusb -v -d f4ec:ee38
./usbutils-0.87/lsusb: cannot open "/usr/share/usb.ids", No such file or directory

Bus 002 Device 012: ID f4ec:ee38
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xf4ec
idProduct 0xee38
bcdDevice 1.00
iManufacturer 1 Siglent TechCo., Ltd.
iProduct 2 USB Digital Oscilloscope
iSerial 0
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 49
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xc0
Self Powered
MaxPower 2mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 4
bInterfaceClass 220
bInterfaceSubClass 161
bInterfaceProtocol 181
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x84 EP 4 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x86 EP 6 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x05 EP 5 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 0
Device Status: 0x0001
Self Powered

Clearly, Ubuntu's lsusb (usbutils) 0.87 w/ libusb 0.1.4 can read configuration descriptor data without a problem; while lsusb (usbutils) 006 from git w/ libusb-1.0 cannot - arguably, because of the same "short read" problem.


That is about as much as I can state about the problem - would anyone have any idea why this "short read" problem happens when retrieving configuration descriptor with libusb-1.0; and how could I go around it?

Many thanks in advance for any comments,
Cheers!
Peter Stuge
2012-10-27 14:28:10 UTC
Permalink
Post by sdaau
$ uname -a
Linux ljutntcol 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux
Mhm, ok.
Post by sdaau
$ apt-show-versions -r libusb
libusb-0.1-4/natty uptodate 2:0.1.12-17
libusb-1.0-0/natty uptodate 2:1.0.8-2
libusb-1.0-0-dev/natty uptodate 2:1.0.8-2
libusb-dev/natty uptodate 2:0.1.12-17
Since Ubuntu follows debian they're always very far behind upstream.
Post by sdaau
$ ./myTestProg
...
Got device from handle
libusb: 0.006148 debug [libusb_reset_device]
libusb: 0.286630 debug [libusb_set_configuration] configuration 1
libusb: 0.295627 debug [libusb_get_active_config_descriptor]
libusb: 0.295837 debug [sysfs_get_active_config_descriptor] active configuration 1
libusb: 0.296054 debug [sysfs_get_active_config_descriptor] active configuration 1
libusb: 0.296158 error [sysfs_get_active_config_descriptor] short read 40/49
failed to get config descriptor (-1)
Interesting. The kernel returns a short read. Normally when using
read() it's neccessary to be prepared for fewer bytes than expected,
but I'm not sure if that is true for sysfs. Please help test that.
You may have found a bug (which will be easy enough to fix).
Post by sdaau
Now, all I want to do here with the config descriptor, is retrieve
the number of endpoints, and possibly their adresses.
Why? If you want to communicate with the device you generally need to
know what you will transfer to or from which endpoint at what time.
Devices typically do not change their endpoints.
Post by sdaau
At this point, I started wondering - how come in this program,
config descriptor retrieval fails - while the `lsusb` program can
show the number of endpoints properly?
libusb-0.1 always sends a GET_DESCRIPTOR control request to retrieve
the descriptor data from the device, while libusb-1.0 tries to avoid
communicating with the device as far as possible to avoid waking it
up from a power saving state. libusb-1.0 instead reads data cached by
the kernel.
Post by sdaau
Clearly, Ubuntu's lsusb (usbutils) 0.87 w/ libusb 0.1.4 can read
configuration descriptor data without a problem; while lsusb
(usbutils) 006 from git w/ libusb-1.0 cannot - arguably, because
of the same "short read" problem.
Yes, sure.
Post by sdaau
would anyone have any idea why this "short read" problem happens
when retrieving configuration descriptor with libusb-1.0;
As I wrote I'm not sure if the current code is buggy or not. Please
try the attached test program to find out. It is also available for
download at http://stuge.se/rdesc.c

Compile with: gcc -o rdesc rdesc.c

Run with: ./rdesc

It defaults to look for your scope but optionally takes two
hexadecimal vid pid parameters to test another device. It would be
interesting to see output for a few different devices in your system.

Run e.g.: ./rdesc
Run e.g.: ./rdesc 1d6b 0002
Run e.g.: ./rdesc 1d6b 0001

And also once for maybe some other USB device you have.
Post by sdaau
and how could I go around it?
Let's see. Please post the output of rdesc.


//Peter
sdaau
2012-10-28 08:05:13 UTC
Permalink
Hi Peter,

Many thanks for your response!
Post by Peter Stuge
Post by sdaau
$ ./myTestProg
...
libusb: 0.296158 error [sysfs_get_active_config_descriptor] short read 40/49
failed to get config descriptor (-1)
Interesting. The kernel returns a short read. Normally when using
read() it's neccessary to be prepared for fewer bytes than expected,
but I'm not sure if that is true for sysfs.
Thanks for this note; as I'm not very acquainted with low-level USB details, it's good to know what the default behavior in case of "short read" should be...
Post by Peter Stuge
Please help test that.
You may have found a bug (which will be easy enough to fix).
No problem, will gladly try to help with testing this.
Post by Peter Stuge
Post by sdaau
Now, all I want to do here with the config descriptor, is retrieve
the number of endpoints, and possibly their adresses.
Why? If you want to communicate with the device you generally need to
know what you will transfer to or from which endpoint at what time.
Devices typically do not change their endpoints.
Ah, yes - basically, as I am not that acquainted with usage of libusb, the first program for talking to the device that I made for libusb-0.1 was basically a patchwork of snippets I collected from the internet, one of which included reading of bNumEndpoints.

So, when I tried moving to libusb-1.0, I basically just tried to repeat/translate all actions from the libusb-0.1 program that I had, including reading of bNumEndpoints - mostly for the purpose of learning, as well as a sanity check (that is, to see if I'm getting back the same data that `lsusb` would get); I otherwise didn't have the intent of using that data for actual traffic, as I was hardcoding the endpoint addresses in write/read code (like in all the code examples I had found).
Post by Peter Stuge
libusb-0.1 always sends a GET_DESCRIPTOR control request to retrieve
the descriptor data from the device, while libusb-1.0 tries to avoid
communicating with the device as far as possible to avoid waking it
up from a power saving state. libusb-1.0 instead reads data cached by
the kernel.
Thanks for noting this - made me look up what I "GET_DESCRIPTOR control request" is, and I found http://www.beyondlogic.org/usbnutshell/usb6.shtml - which I should eventually read in more detail :)
Post by Peter Stuge
Post by sdaau
would anyone have any idea why this "short read" problem happens
when retrieving configuration descriptor with libusb-1.0;
As I wrote I'm not sure if the current code is buggy or not. Please
try the attached test program to find out. It is also available for
download at http://stuge.se/rdesc.c [...]
It defaults to look for your scope but optionally takes two
hexadecimal vid pid parameters to test another device. It would be
interesting to see output for a few different devices in your system.
[...]
And also once for maybe some other USB device you have.
Thanks for the rdesc code - tried looking through it, and the only thing I can see is that no usb.h or libusb.h is used; instead, there is apparently direct interaction with sysfs; should probably study that piece in more detail once I get the time :)

Anyways, the only easily accessible USB devices I have, are the scope, a USB mouse, and a USB flash drive; here are the relevant entries from the default lsusb 0.87 in Ubuntu 11.04:

...
Bus 003 Device 044: ID 046d:c040 Logitech, Inc. Corded Tilt-Wheel Mouse
Bus 002 Device 005: ID f4ec:ee38 # this is the scope
Bus 001 Device 013: ID 058f:6387 Alcor Micro Corp. Transcend JetFlash Flash Drive
...

Here is rdesc output for the mouse:

$ ./rdesc 046d c040
want 046d:c040
found /sys/bus/usb/devices/3-1
end=65553
len=34
have=0 want=34 rd=34
0000: 09 02 22 00 01 01 00 a0 31 09 04 00 00 01 03 01 ..".....1.......
0010: 02 00 09 21 10 01 00 01 22 3b 00 07 05 81 03 05 ...!....";......
0020: 00 0a ................

Output stops here; repeated calls to "./rdesc 046d c040" generate the exact same output.


Here is rdesc output for the flash drive:

$ ./rdesc 058f 6387
want 058f:6387
found /sys/bus/usb/devices/1-2
end=65553
len=32
have=0 want=32 rd=32
0000: 09 02 20 00 01 01 00 80 32 09 04 00 00 02 08 06 .. .....2.......
0010: 50 00 07 05 01 02 00 02 00 07 05 82 02 00 02 00 P...............

Output stops here; repeated calls to "./rdesc 046d c040" generate the exact same output.


Now, when I try to call rdesc for the scope, it "goes into a loop" and starts generating content constantly; so I had to capture stdout to be able to paste the start of the log:

$ ./rdesc > rdesc.out
^C
$ head rdesc.out
want f4ec:ee38
found /sys/bus/usb/devices/2-1
end=65553
len=49
have=0 want=49 rd=46
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0

... and this "have=46 want=3 rd=0" keeps on being dumped to the terminal constantly and fast... Not sure what this should mean, though (I guess, the program asks for 49 (or 0x49?) bytes; device responds with 46 (or 0x46?) bytes - and since 3 bytes are missing, the program keeps on polling the device, asking for those remaining three bytes?)


Well, please let me know if there is anything else I should check,
Cheers!
Post by Peter Stuge
Post by sdaau
and how could I go around it?
Let's see. Please post the output of rdesc.
//Peter
Tormod Volden
2012-10-28 12:00:28 UTC
Permalink
Post by sdaau
$ head rdesc.out
want f4ec:ee38
found /sys/bus/usb/devices/2-1
end=65553
len=49
have=0 want=49 rd=46
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
... and this "have=46 want=3 rd=0" keeps on being dumped to the terminal constantly and fast... Not sure what this should mean, though (I guess, the program asks for 49 (or 0x49?) bytes; device responds with 46 (or 0x46?) bytes - and since 3 bytes are missing, the program keeps on polling the device, asking for those remaining three bytes?)
Well, please let me know if there is anything else I should check,
You may also try if this works (replace "2-1" with the current value):
hexdump -C /sys/bus/usb/devices/2-1/descriptors

Tormod
Peter Stuge
2012-10-28 16:23:16 UTC
Permalink
Post by sdaau
Post by Peter Stuge
Please help test that.
You may have found a bug (which will be easy enough to fix).
No problem, will gladly try to help with testing this.
Thanks for your help!
Post by sdaau
Post by Peter Stuge
Post by sdaau
Now, all I want to do here with the config descriptor, is retrieve
the number of endpoints, and possibly their adresses.
Why? If you want to communicate with the device you generally need to
know what you will transfer to or from which endpoint at what time.
Devices typically do not change their endpoints.
Ah, yes - basically, as I am not that acquainted with usage of
libusb, the first program for talking to the device that I made for
libusb-0.1 was basically a patchwork of snippets I collected from
the internet, one of which included reading of bNumEndpoints.
It is usually not worthwhile to enumerate endpoints. Anytime you work
with one specific device a given interface (and thus the endpoints)
will stay the same. A firmware update could theoretically cause an
issue, but that would also require the host driver to be updated
along with it, which is generally avoided. USB devices generally have
some protocol over endpoints that don't change, so hardcoding
bEndpointAddress is perfectly fine, and common practise.
Post by sdaau
So, when I tried moving to libusb-1.0, I basically just tried to
repeat/translate all actions from the libusb-0.1 program that I had
Yes, fair enough. :)
Post by sdaau
Post by Peter Stuge
libusb-0.1 always sends a GET_DESCRIPTOR control request to retrieve
the descriptor data from the device, while libusb-1.0 tries to avoid
communicating with the device as far as possible to avoid waking it
up from a power saving state. libusb-1.0 instead reads data cached by
the kernel.
Thanks for noting this - made me look up what I "GET_DESCRIPTOR
control request" is, and I found
http://www.beyondlogic.org/usbnutshell/usb6.shtml - which I should
eventually read in more detail :)
I gave a USB intro talk a few years ago, feel free to have a look.

Slides: http://events.ccc.de/congress/2010/Fahrplan/events/4234.en.html
MP4: http://mirror.fem-net.de/CCC/27C3/mp4-h264-HQ/27c3-4234-en-usb_and_libusb.mp4
Flash:


I would also encourage you to grab the USB 2.0 spec from
http://www.usb.org/developers/docs/usb_20_101111.zip

The spec is some 500 pages, but rather readable, and an important
reference.
Post by sdaau
Thanks for the rdesc code - tried looking through it, and the only
thing I can see is that no usb.h or libusb.h is used; instead,
there is apparently direct interaction with sysfs;
Yes, this is on purpose. The program mimics some of what libusb-1.0
does on Linux, and tests a thesis about the problem you encountered.
Post by sdaau
should probably study that piece in more detail once I get the time :)
Sure, then you would have a taste of what is inside libusb. The sysfs
interaction is however not so relevant if your focus is to learn how
to use libusb-1.0 in your applications.
Post by sdaau
Anyways, the only easily accessible USB devices I have, are the
scope, a USB mouse, and a USB flash drive;
That's fine, those are good.
Post by sdaau
$ ./rdesc 046d c040
want 046d:c040
found /sys/bus/usb/devices/3-1
end=65553
len=34
have=0 want=34 rd=34
0000: 09 02 22 00 01 01 00 a0 31 09 04 00 00 01 03 01 ..".....1.......
0010: 02 00 09 21 10 01 00 01 22 3b 00 07 05 81 03 05 ...!....";......
0020: 00 0a ................
Output stops here; repeated calls to "./rdesc 046d c040" generate the exact same output.
$ ./rdesc 058f 6387
want 058f:6387
found /sys/bus/usb/devices/1-2
end=65553
len=32
have=0 want=32 rd=32
0000: 09 02 20 00 01 01 00 80 32 09 04 00 00 02 08 06 .. .....2.......
0010: 50 00 07 05 01 02 00 02 00 07 05 82 02 00 02 00 P...............
Output stops here; repeated calls to "./rdesc 046d c040" generate the exact same output.
Yep, this is the normal and expected behavior. The program reads and
outputs in hexadecimal form the configuration descriptor as cached by
the kernel.
Post by sdaau
Now, when I try to call rdesc for the scope, it "goes into a loop"
and starts generating content constantly; so I had to capture
$ ./rdesc > rdesc.out
^C
$ head rdesc.out
want f4ec:ee38
found /sys/bus/usb/devices/2-1
end=65553
len=49
have=0 want=49 rd=46
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
... and this "have=46 want=3 rd=0" keeps on being dumped to the
terminal constantly and fast... Not sure what this should mean,
though
Oops. As Alan pointed out I made an off-by-one error, causing that
loop. The intended behavior was for the program to exit on rd=0.

But the above tells me what I was hoping to find out. The kernel
simply does not have any more bytes for us, meaning that the
configuration descriptor wTotalLength sent by the device is
incorrect, and that causes libusb-1.0 to fail.
Post by sdaau
(I guess, the program asks for 49 (or 0x49?) bytes; device responds
with 46 (or 0x46?) bytes - and since 3 bytes are missing, the
program keeps on polling the device, asking for those remaining
three bytes?)
Remember that the device is not at all involved here. This is only
rdesc talking to Linux.

rdesc first reads four bytes of the cached configuration descriptor,
two uninteresting single-byte values and then the 16-bit wTotalLength.
len is set to wTotalLength, the program seeks back to the start of the
configuration descriptor, and then attempts to read len bytes into a
buffer. If all bytes can not be read at once (short read) the program
tries to read remaining bytes in a loop. The kernel always returns 0
(rd=0) after the first read, which means end of file.

wTotalLength in the descriptor says that there are 3 more bytes, but
the kernel doesn't have them. It is not likely that the kernel has
lost them, the more likely explanation is that the device never sent
them in the first place, and that the wTotalLength value in the
configuration descriptor is wrong.

You did find a bug in libusb, but a more tricky one than I first
thought. Fortunately I don't think data transfer is affected by this,
but yes, reading the cached configuration descriptor is indeed not
working at least on Linux when the wTotalLength sent by the device
is too large.

The question is how to handle this. If the error is smaller than a
minimal configuration descriptor then it would be safe to ignore the
error and forget about the non-existant trailing data. But that would
also be papering over the problem. I would like a way to both provide
the useful data, *and* somehow let the caller know that actually, the
device is broken.


//Peter
sdaau
2012-10-28 17:18:26 UTC
Permalink
Hi all,

Thanks for the prompt responses!
Post by Alan Stern
Another thing worth trying is to check the system log for the time when
the scope was plugged in. Problems parsing the descriptors are likely
to show up there.
Thanks Alan; I'm not really sure as to which system log to check - earlier in Ubuntu it was /var/log/messages and /var/log/syslog; in 11.04 there is only /var/log/syslog; so here is the output I got from /var/log/syslog when connecting the device:

$ tail -f /var/log/syslog
...
Oct 28 17:50:16 mypc kernel: [64596.368132] usb 2-2: new full speed USB device using uhci_hcd and address 11
Oct 28 17:50:17 mypc kernel: [64596.536139] usb 2-2: config 1 has an invalid descriptor of length 24, skipping remainder of the config

^C

These are the only two lines generated during hotplugging - and indeed, there is a problem with the descriptor parsing...
Post by Alan Stern
hexdump -C /sys/bus/usb/devices/2-1/descriptors
Thanks Tormod; wasn't sure what I should replace "2-1" with; lsusb gives me "Bus 002 Device 011: ID f4ec:ee38" - I tried "2-11" but there is "No such file or directory". Then I try:

$ ls /sys/bus/usb/devices/ | grep 2-
2-0:1.0
2-2
2-2:1.0

... and I can see this "2-2" is the same as the "usb 2-2" in the kernel log, so I'm trying that:

$ hexdump -C /sys/bus/usb/devices/2-2/descriptors
00000000 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02 |***@..8.....|
00000010 00 01 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 |....1...........|
00000020 dc a1 b5 00 07 05 84 02 40 00 00 07 05 03 02 40 |***@......@|
00000030 00 00 07 05 86 02 40 00 00 07 05 05 02 40 00 00 |***@......@..|
00000040
Post by Alan Stern
} while (rd >= 0 && have < len);
The ">=" should be ">". This accounts for the unending loop.
Fixed this in my copy, and this is what I get:

$ gcc -o rdesc1 rdesc.c
$ ./rdesc1
want f4ec:ee38
found /sys/bus/usb/devices/2-2
end=65553
len=49
have=0 want=49 rd=46
have=46 want=3 rd=0

... results same as before; but indeed, the endless loop stopped :) (Come to think of it, it was good the endless loop was there, made it obvious there was a problem :) )
Post by Alan Stern
I gave a USB intro talk a few years ago, feel free to have a look.
Slides: http://events.ccc.de/congress/2010/Fahrplan/events/4234.en.html
MP4: http://mirror.fem-net.de/CCC/27C3/mp4-h264-HQ/27c3-4234-en-usb_and_libusb.mp4
Flash: http://youtu.be/uBBE2gihv5I
I would also encourage you to grab the USB 2.0 spec from
http://www.usb.org/developers/docs/usb_20_101111.zip
The spec is some 500 pages, but rather readable, and an important
reference.
Many thanks for this (and your other clarifications), Peter - some great resources here!

(OT: started up on the talk for a bit, and I could really relate to the MC's opening - having mentioned RX & TX, the lack of RS232 serial ports on new machines, and the FTDI chip :) )
Post by Alan Stern
Post by sdaau
... and this "have=46 want=3 rd=0" keeps on being dumped to the
terminal constantly and fast... Not sure what this should mean,
though
Oops. As Alan pointed out I made an off-by-one error, causing that
loop. The intended behavior was for the program to exit on rd=0.
Actually - come to think of it, it was good the endless loop was there, made it obvious there was a problem :)
Post by Alan Stern
Post by sdaau
(I guess, the program asks for 49 (or 0x49?) bytes; device responds
with 46 (or 0x46?) bytes - and since 3 bytes are missing, the
program keeps on polling the device, asking for those remaining
three bytes?)
Remember that the device is not at all involved here. This is only
rdesc talking to Linux.
[...]
wTotalLength in the descriptor says that there are 3 more bytes, but
the kernel doesn't have them. It is not likely that the kernel has
lost them, the more likely explanation is that the device never sent
them in the first place, and that the wTotalLength value in the
configuration descriptor is wrong.
Thanks for noting this - good to keep it in mind, as I wasn't aware of it; I think I'm a bit clearer now on the interaction between device, kernel and libusb.
Post by Alan Stern
You did find a bug in libusb, but a more tricky one than I first
thought. Fortunately I don't think data transfer is affected by this,
Indeed, it isn't - just made some progress retrieving proper data [note to self: 1) bulk transfer timeout shouldn't be 0 ; 2) use `usleep` to introduce where delays are expected] from the scope, and it seems so far OK for libusb-1.0: both the Ubuntu 11.04 version, and the git version.
Post by Alan Stern
The question is how to handle this. If the error is smaller than a
minimal configuration descriptor then it would be safe to ignore the
error and forget about the non-existant trailing data. But that would
also be papering over the problem. I would like a way to both provide
the useful data, *and* somehow let the caller know that actually, the
device is broken.
I cannot really say much on this, except that the plan sounds good to me :)

Please let me know if I can provide any more info further (... and I'll be off watching the talk in the meanwhile :) ),
Cheers!
Post by Alan Stern
//Peter
Alan Stern
2012-10-28 14:52:52 UTC
Permalink
Post by Tormod Volden
Post by sdaau
$ head rdesc.out
want f4ec:ee38
found /sys/bus/usb/devices/2-1
end=65553
len=49
have=0 want=49 rd=46
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
have=46 want=3 rd=0
... and this "have=46 want=3 rd=0" keeps on being dumped to the terminal constantly and fast... Not sure what this should mean, though (I guess, the program asks for 49 (or 0x49?) bytes; device responds with 46 (or 0x46?) bytes - and since 3 bytes are missing, the program keeps on polling the device, asking for those remaining three bytes?)
Well, please let me know if there is anything else I should check,
hexdump -C /sys/bus/usb/devices/2-1/descriptors
Another thing worth trying is to check the system log for the time when
the scope was plugged in. Problems parsing the descriptors are likely
to show up there.

Peter, two problems stand out in the rdesc.c program. First, the
line

off = lseek(fd, 0, SEEK_END);

is not valid. The "descriptors" file doesn't support SEEK_END, as you
can see from the "end=65553" above. (The system does not keep accurate
track of the size of sysfs files in general.) The only reliable way to
determine the file size is to read all the way through to the end and
count up the number of bytes.

Second, there is a bug in the line:

} while (rd >= 0 && have < len);

The ">=" should be ">". This accounts for the unending loop.

Alan Stern
Peter Stuge
2012-10-28 16:34:05 UTC
Permalink
Post by Alan Stern
Another thing worth trying is to check the system log for the time when
the scope was plugged in. Problems parsing the descriptors are likely
to show up there.
Yes, please do check that with the oscilloscope. Run dmesg | tail -n 20
to get the last 20 lines, after plugging in the scope. They should have
the interesting stuff.
Post by Alan Stern
Peter, two problems stand out in the rdesc.c program.
Thanks for looking! It was a quick test program to find out if there
were more bytes to be had from the kernel than returned by read()
initially. Do you know if we actually do want to loop over read()
from sysfs, maybe for descriptors larger than a single page?
Post by Alan Stern
First, the line
off = lseek(fd, 0, SEEK_END);
is not valid. The "descriptors" file doesn't support SEEK_END, as you
can see from the "end=65553" above.
libusb uses this to determine if a device has become unconfigured. I
did notice that the end seems fixed, but included the code anyway to
closely replicate the algorithm in libusb.
Post by Alan Stern
} while (rd >= 0 && have < len);
The ">=" should be ">". This accounts for the unending loop.
Yes of course. Oops. Too quick.


//Peter
Alan Stern
2012-10-28 16:51:08 UTC
Permalink
Post by Peter Stuge
Post by Alan Stern
Peter, two problems stand out in the rdesc.c program.
Thanks for looking! It was a quick test program to find out if there
were more bytes to be had from the kernel than returned by read()
initially. Do you know if we actually do want to loop over read()
from sysfs, maybe for descriptors larger than a single page?
That's not necessary. If you wanted, you could just do a single giant
read() and get all the descriptors at once. There can't be more than
255 configurations (Linux doesn't support more than 8 anyway), and each
descriptor is limited to 65535 bytes.

As for handling incorrect descriptors, the situation is a little
unfortunate but I don't see how it can be improved.

The descriptors file simply contains the descriptors as sent by the
device, all concatenated. This means that when the dwTotalLength value
is wrong, as in this case, there is no way to determine where the
current descriptor ends and the next one begins. Here it doesn't
matter quite so much, because the bad descriptor is the last one.

I suppose we could have used a more robust kind of encapsulation, but
it's too late to change now.

Alan Stern
Alan Stern
2012-10-28 20:53:09 UTC
Permalink
Post by sdaau
Post by Alan Stern
Another thing worth trying is to check the system log for the time when
the scope was plugged in. Problems parsing the descriptors are likely
to show up there.
$ tail -f /var/log/syslog
...
Oct 28 17:50:16 mypc kernel: [64596.368132] usb 2-2: new full speed USB device using uhci_hcd and address 11
Oct 28 17:50:17 mypc kernel: [64596.536139] usb 2-2: config 1 has an invalid descriptor of length 24, skipping remainder of the config
^C
These are the only two lines generated during hotplugging - and indeed, there is a problem with the descriptor parsing...
Post by Alan Stern
hexdump -C /sys/bus/usb/devices/2-1/descriptors
$ ls /sys/bus/usb/devices/ | grep 2-
2-0:1.0
2-2
2-2:1.0
$ hexdump -C /sys/bus/usb/devices/2-2/descriptors
00000010 00 01 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 |....1...........|
00000040
Alas, the descriptors file doesn't always include _all_ the data sent
by the device. If the kernel sees an invalid descriptor it will
truncate the data in the file. (An invalid descriptor is one that is
less than 2 bytes long or that claims to be longer than the remaining
amount of data.)

In this case there was no warning about the config descriptor being too
short, so the device really did send 49 bytes. The descriptor shown
above is only 46 bytes (the first 18 bytes in the file are the device
descriptor and the remaining 46 are the config descriptor), so most
likely the unknown last 3 bytes contained a header with bLength set to
24, as indicated by the warning in the system log.

It could be that the 24 is wrong, or it could be that the 49 is wrong
(perhaps it ought to be 46 or perhaps it ought to be 46 + 24 = 70), or
maybe both are wrong. There's no way to tell from the information
given here.

Alan Stern
Xiaofan Chen
2012-10-29 03:14:25 UTC
Permalink
Post by Alan Stern
Post by sdaau
$ hexdump -C /sys/bus/usb/devices/2-2/descriptors
00000010 00 01 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 |....1...........|
00000040
Alas, the descriptors file doesn't always include _all_ the data sent
by the device. If the kernel sees an invalid descriptor it will
truncate the data in the file. (An invalid descriptor is one that is
less than 2 bytes long or that claims to be longer than the remaining
amount of data.)
In this case there was no warning about the config descriptor being too
short, so the device really did send 49 bytes. The descriptor shown
above is only *64* bytes (the first 18 bytes in the file are the device
descriptor and the remaining 46 are the config descriptor), so most
likely the unknown last 3 bytes contained a header with bLength set to
24, as indicated by the warning in the system log.
It could be that the 24 is wrong, or it could be that the 49 is wrong
(perhaps it ought to be 46 or perhaps it ought to be 46 + 24 = 70), or
maybe both are wrong. There's no way to tell from the information
given here.
Peter Stuge
2012-10-29 05:18:28 UTC
Permalink
Post by Alan Stern
It could be that the 24 is wrong, or it could be that the 49 is wrong
(perhaps it ought to be 46 or perhaps it ought to be 46 + 24 = 70), or
maybe both are wrong. There's no way to tell from the information
given here.
Xiaofan Chen
2012-10-29 13:44:51 UTC
Permalink
Post by Alan Stern
It could be that the 24 is wrong, or it could be that the 49 is wrong
(perhaps it ought to be 46 or perhaps it ought to be 46 + 24 = 70), or
maybe both are wrong. There's no way to tell from the information
given here.
Peter Stuge
2012-10-29 14:11:42 UTC
Permalink
It should be 46.
There's no way to be certain. There could be another altsetting
for the interface, or some class-specific descriptor.
I do not agree with you here. If there are those things,
lsusb (old version anyway) should be able to parse them.
I'm sure it can parse them but it never sees that data if it is
there, since libusb-0.1 uses wTotalLength to determine how many
bytes of the descriptor to transfer.


//Peter
Alan Stern
2012-10-29 14:53:25 UTC
Permalink
Post by Alan Stern
It could be that the 24 is wrong, or it could be that the 49 is wrong
(perhaps it ought to be 46 or perhaps it ought to be 46 + 24 = 70), or
maybe both are wrong. There's no way to tell from the information
given here.
sdaau
2012-10-29 19:57:21 UTC
Permalink
The fact is, we don't know what the device is supposed to be sending.
All we know is what it does send (and we don't even know all of that,
because the last three bytes are not shown).
This reminds me - I've taken UsbSnoop logs from this device's connection to a Windows XP (the "replug"); and I believe the complete descriptor is there; I've taken the liberty to concatenate the data (as I see it; the relevant logs are pasted below):

00000000: 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02
00000010: 00 01 09 02 31 00 01 01 00 c0 01 09 02 31 00 01
00000020: 01 00 c0 01 09 04 00 00 04 dc a1 b5 00 07 05 84
00000030: 02 40 00 00 07 05 03 02 40 00 00 07 05 86 02 40
00000040: 00 00 07 05 05 02 40 00 00 18 03 49

... and we can compare to the output of hexdump earlier:

$ hexdump -C /sys/bus/usb/devices/2-2/descriptors
00000000 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02 |***@........|
00000010 00 01 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 |....1...........|
00000020 dc a1 b5 00 07 05 84 02 40 00 00 07 05 03 02 40 |***@......@|
00000030 00 00 07 05 86 02 40 00 00 07 05 05 02 40 00 00 |***@......@..|
00000040

I tried comparing these in `meld` - and interestingly, it seems Linux may be missing some bytes occuring in the middle of the Windows XP data, in addition to the last "00 18 03 49"? Then again, I may not be reading those logs correctly..
libusb-0.1 always sends a GET_DESCRIPTOR control request to retrieve
the descriptor data from the device, while libusb-1.0 tries to avoid
communicating with the device as far as possible to avoid waking it
up from a power saving state. libusb-1.0 instead reads data cached by
the kernel.
If libusb-1.0 by default doesn't send this GET_DESCRIPTOR; and if this GET_DESCRIPTOR is what makes libusb-0.1 read the config correctly - then could I somehow force sending of a GET_DESCRIPTOR from my user space application (so as to enable it to read the endpoints properly)?

Cheers!


PS: Relevant UsbSnoop log entries:

[161 ms] >>> URB 1 going down >>>
-- URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE:
TransferBufferLength = 00000012
TransferBuffer = 89810da8
TransferBufferMDL = 00000000
Index = 00000000
DescriptorType = 00000001 (USB_DEVICE_DESCRIPTOR_TYPE)
LanguageId = 00000000
[171 ms] UsbSnoop - MyInternalIOCTLCompletion(b4e1d126) : fido=00000000, Irp=88cd3538, Context=89606f80, IRQL=2
[171 ms] <<< URB 1 coming back <<<
-- URB_FUNCTION_CONTROL_TRANSFER:
PipeHandle = 88d46888
TransferFlags = 0000000b (USBD_TRANSFER_DIRECTION_IN, USBD_SHORT_TRANSFER_OK)
TransferBufferLength = 00000012
TransferBuffer = 89810da8
TransferBufferMDL = 89706670
00000000: 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02
00000010: 00 01
UrbLink = 00000000
SetupPacket =
00000000: 80 06 00 01 00 00 12 00
[171 ms] UsbSnoop - FilterDispatchAny(b4e1cfd2) : IRP_MJ_INTERNAL_DEVICE_CONTROL
[171 ms] UsbSnoop - FdoHookDispatchInternalIoctl(b4e1d1ea) : fdo=8991c668, Irp=88cd3538, IRQL=0
[171 ms] >>> URB 2 going down >>>
-- URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE:
TransferBufferLength = 00000009
TransferBuffer = 89210bf0
TransferBufferMDL = 00000000
Index = 00000000
DescriptorType = 00000002 (USB_CONFIGURATION_DESCRIPTOR_TYPE)
LanguageId = 00000000
[181 ms] UsbSnoop - MyInternalIOCTLCompletion(b4e1d126) : fido=00000000, Irp=88cd3538, Context=89606f80, IRQL=2
[181 ms] <<< URB 2 coming back <<<
-- URB_FUNCTION_CONTROL_TRANSFER:
PipeHandle = 88d46888
TransferFlags = 0000000b (USBD_TRANSFER_DIRECTION_IN, USBD_SHORT_TRANSFER_OK)
TransferBufferLength = 00000009
TransferBuffer = 89210bf0
TransferBufferMDL = 89706670
00000000: 09 02 31 00 01 01 00 c0 01
UrbLink = 00000000
SetupPacket =
00000000: 80 06 00 02 00 00 09 00
[181 ms] UsbSnoop - FilterDispatchAny(b4e1cfd2) : IRP_MJ_INTERNAL_DEVICE_CONTROL
[181 ms] UsbSnoop - FdoHookDispatchInternalIoctl(b4e1d1ea) : fdo=8991c668, Irp=88cd3538, IRQL=0
[181 ms] >>> URB 3 going down >>>
-- URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE:
TransferBufferLength = 00000031
TransferBuffer = 8953a860
TransferBufferMDL = 00000000
Index = 00000000
DescriptorType = 00000002 (USB_CONFIGURATION_DESCRIPTOR_TYPE)
LanguageId = 00000000
[191 ms] UsbSnoop - MyInternalIOCTLCompletion(b4e1d126) : fido=00000000, Irp=88cd3538, Context=89606f80, IRQL=2
[191 ms] <<< URB 3 coming back <<<
-- URB_FUNCTION_CONTROL_TRANSFER:
PipeHandle = 88d46888
TransferFlags = 0000000b (USBD_TRANSFER_DIRECTION_IN, USBD_SHORT_TRANSFER_OK)
TransferBufferLength = 00000031
TransferBuffer = 8953a860
TransferBufferMDL = 89706670
00000000: 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 dc a1
00000010: b5 00 07 05 84 02 40 00 00 07 05 03 02 40 00 00
00000020: 07 05 86 02 40 00 00 07 05 05 02 40 00 00 18 03
00000030: 49
UrbLink = 00000000
SetupPacket =
00000000: 80 06 00 02 00 00 31 00
[191 ms] UsbSnoop - FilterDispatchAny(b4e1cfd2) : IRP_MJ_INTERNAL_DEVICE_CONTROL
[191 ms] UsbSnoop - FdoHookDispatchInternalIoctl(b4e1d1ea) : fdo=8991c668, Irp=88cd3538, IRQL=0
[191 ms] >>> URB 4 going down >>>
-- URB_FUNCTION_SELECT_CONFIGURATION:
ConfigurationDescriptor = 0x8953a860 (configure)
ConfigurationDescriptor : bLength = 9
ConfigurationDescriptor : bDescriptorType = 0x00000002
ConfigurationDescriptor : wTotalLength = 0x00000031
ConfigurationDescriptor : bNumInterfaces = 0x00000001
ConfigurationDescriptor : bConfigurationValue = 0x00000001
ConfigurationDescriptor : iConfiguration = 0x00000000
ConfigurationDescriptor : bmAttributes = 0x000000c0
ConfigurationDescriptor : MaxPower = 0x00000001
ConfigurationHandle = 0x00000000
Interface[0]: Length = 96
Interface[0]: InterfaceNumber = 0
Interface[0]: AlternateSetting = 0
[244 ms] UsbSnoop - MyInternalIOCTLCompletion(b4e1d126) : fido=00000000, Irp=88cd3538, Context=89606f80, IRQL=0
[244 ms] <<< URB 4 coming back <<<
-- URB_FUNCTION_SELECT_CONFIGURATION:
ConfigurationDescriptor = 0x8953a860 (configure)
ConfigurationDescriptor : bLength = 9
ConfigurationDescriptor : bDescriptorType = 0x00000002
ConfigurationDescriptor : wTotalLength = 0x00000031
ConfigurationDescriptor : bNumInterfaces = 0x00000001
ConfigurationDescriptor : bConfigurationValue = 0x00000001
ConfigurationDescriptor : iConfiguration = 0x00000000
ConfigurationDescriptor : bmAttributes = 0x000000c0
ConfigurationDescriptor : MaxPower = 0x00000001
ConfigurationHandle = 0x88cd9290
Interface[0]: Length = 96
Interface[0]: InterfaceNumber = 0
Interface[0]: AlternateSetting = 0
Interface[0]: Class = 0x000000dc
Interface[0]: SubClass = 0x000000a1
Interface[0]: Protocol = 0x000000b5
Interface[0]: InterfaceHandle = 0x88c90cc0
Interface[0]: NumberOfPipes = 4
Interface[0]: Pipes[0] : MaximumPacketSize = 0x00000040
Interface[0]: Pipes[0] : EndpointAddress = 0x00000084
Interface[0]: Pipes[0] : Interval = 0x00000000
Interface[0]: Pipes[0] : PipeType = 0x00000002 (UsbdPipeTypeBulk)
Interface[0]: Pipes[0] : PipeHandle = 0x88c90cdc
Interface[0]: Pipes[0] : MaxTransferSize = 0x00001000
Interface[0]: Pipes[0] : PipeFlags = 0x00000000
Interface[0]: Pipes[1] : MaximumPacketSize = 0x00000040
Interface[0]: Pipes[1] : EndpointAddress = 0x00000003
Interface[0]: Pipes[1] : Interval = 0x00000000
Interface[0]: Pipes[1] : PipeType = 0x00000002 (UsbdPipeTypeBulk)
Interface[0]: Pipes[1] : PipeHandle = 0x88c90cfc
Interface[0]: Pipes[1] : MaxTransferSize = 0x00001000
Interface[0]: Pipes[1] : PipeFlags = 0x00000000
Interface[0]: Pipes[2] : MaximumPacketSize = 0x00000040
Interface[0]: Pipes[2] : EndpointAddress = 0x00000086
Interface[0]: Pipes[2] : Interval = 0x00000000
Interface[0]: Pipes[2] : PipeType = 0x00000002 (UsbdPipeTypeBulk)
Interface[0]: Pipes[2] : PipeHandle = 0x88c90d1c
Interface[0]: Pipes[2] : MaxTransferSize = 0x00001000
Interface[0]: Pipes[2] : PipeFlags = 0x00000000
Interface[0]: Pipes[3] : MaximumPacketSize = 0x00000040
Interface[0]: Pipes[3] : EndpointAddress = 0x00000005
Interface[0]: Pipes[3] : Interval = 0x00000000
Interface[0]: Pipes[3] : PipeType = 0x00000002 (UsbdPipeTypeBulk)
Interface[0]: Pipes[3] : PipeHandle = 0x88c90d3c
Interface[0]: Pipes[3] : MaxTransferSize = 0x00001000
Interface[0]: Pipes[3] : PipeFlags = 0x00000000
Tim Roberts
2012-10-29 20:28:00 UTC
Permalink
Post by sdaau
00000000: 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02
00000010: 00 01 09 02 31 00 01 01 00 c0 01 09 02 31 00 01
00000020: 01 00 c0 01 09 04 00 00 04 dc a1 b5 00 07 05 84
00000030: 02 40 00 00 07 05 03 02 40 00 00 07 05 86 02 40
00000040: 00 00 07 05 05 02 40 00 00 18 03 49...
$ hexdump -C /sys/bus/usb/devices/2-2/descriptors
00000010 00 01 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 |....1...........|
00000040
I tried comparing these in `meld` - and interestingly, it seems Linux may be missing some bytes occuring in the middle of the Windows XP data, in addition to the last "00 18 03 49"? Then again, I may not be reading those logs correctly..
Well, isn't that interesting? That first hex dump is simply wrong.
The configuration descriptor header is duplicated (09 02 31 00 01 01 00
c0). That is a violation of the USB spec. This device is broken. It
is unreasonable to expect either operating system to do the Right Thing
with this.

It's interesting that Linux has elided the second configuration
descriptor header. I suppose one could add a "quirks" entry to allow
the kernel to fix this, but that would be a generous gesture, not a
required behavior.
--
Tim Roberts, ***@probo.com
Providenza & Boekelheide, Inc.
Peter Stuge
2012-10-29 20:47:49 UTC
Permalink
Post by sdaau
This reminds me - I've taken UsbSnoop logs from this device's
connection to a Windows XP (the "replug"); and I believe the
complete descriptor is there; I've taken the liberty to concatenate
Thanks for including the logs. Unfortunately your concatenation
doesn't correspond to the descriptors file on Linux, but all the
data was available in the logs.
Post by sdaau
If libusb-1.0 by default doesn't send this GET_DESCRIPTOR; and if
this GET_DESCRIPTOR is what makes libusb-0.1 read the config
correctly - then could I somehow force sending of a GET_DESCRIPTOR
from my user space application (so as to enable it to read the
endpoints properly)?
You could use something like:

libusb_get_descriptor(devh, LIBUSB_DT_CONFIG, 0, buffer, 46);

And parse the data structures yourself, but I would prefer to make
libusb cope with this broken descriptor.
Post by sdaau
[171 ms] <<< URB 1 coming back <<<
..
Post by sdaau
00000000: 12 01 10 01 00 00 00 40 ec f4 38 ee 00 01 01 02
00000010: 00 01
..
Post by sdaau
[181 ms] <<< URB 2 coming back <<<
..
Post by sdaau
00000000: 09 02 31 00 01 01 00 c0 01
..
Post by sdaau
[191 ms] <<< URB 3 coming back <<<
..
Post by sdaau
00000000: 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 dc a1
00000010: b5 00 07 05 84 02 40 00 00 07 05 03 02 40 00 00
00000020: 07 05 86 02 40 00 00 07 05 05 02 40 00 00 18 03
00000030: 49
URB 2 reads only the 9 bytes of the configuration descriptor.

URB 3 re-reads the configuration descriptor, this time along with all
following descriptors included in the (reportedly) 49 bytes.

USB is a packet transport, not a character device-like serial port or
stream transport, so it's important to pay attention to the various
fields in each transfer. Simple concatenation can easily create
confusion.

The three last bytes are 18 03 49, which is the beginning of a
24-byte ((24-2)/2 = 11 character) long string descriptor and the
first byte of which is 0x49, ie. half of the character 'I' (capital i).

This is clearly a firmware error. String descriptors must not
be counted in wTotalLength and must not be sent as part of data
following the configuration descriptor.
Post by sdaau
The configuration descriptor header is duplicated (09 02 31 00 01 01 00
c0).
The duplication was manual, but nevertheless the device is in
violation of the spec.


//Peter
Tim Roberts
2012-10-29 22:07:18 UTC
Permalink
Post by Peter Stuge
Post by Tim Roberts
The configuration descriptor header is duplicated (09 02 31 00 01 01 00
c0).
The duplication was manual, but nevertheless the device is in
violation of the spec.
I'm embarrassed that I did not realize that, given how common the
pattern is. I **assumed** it was a single transfer.
--
Tim Roberts, ***@probo.com
Providenza & Boekelheide, Inc.
Peter Stuge
2012-10-30 00:11:41 UTC
Permalink
I would prefer to make libusb cope with this broken descriptor.
Post by sdaau
[191 ms] <<< URB 3 coming back <<<
..
Post by sdaau
00000000: 09 02 31 00 01 01 00 c0 01 09 04 00 00 04 dc a1
00000010: b5 00 07 05 84 02 40 00 00 07 05 03 02 40 00 00
00000020: 07 05 86 02 40 00 00 07 05 05 02 40 00 00 18 03
00000030: 49
So how do we do that?

Given all 49 bytes, we can parse the bytes one descriptor at a time
and arrive at 18 03 49 knowing a few things:

* we expect 3 more bytes of data
* 3 bytes is too short to be an interface or endpoint descriptor,
but might *not* be too short for some vendor- or class-specific
descriptor which does belong with the config descriptor

Step 2: we read one more byte, the length 24. We learn that:

* wTotalLength is wrong and we will be unable to return a complete,
coherent descriptor to the caller since the device provides somehow
broken descriptors. one of:
a) wTotalLength is too small and should count this descriptor
b) wTotalLength is too large and should *not* count this descriptor
c) the length 24 is incorrect and should really have been 3

Step 3: we read another byte, the descriptor type 3. We learn that:

* this is a string descriptor, which must not be counted in
wTotalLength, so the error is b)

sysfs takes us to Step 2 but stops us there, so in case we want to
look at remaining bytes we'll have to do a control transfer to get
them. We would be waking up the device to handle this corner(?) case.
That seems acceptable, but unfortunately the API documentation
clearly states that libusb_get_active_config_descriptor() is
non-blocking and does not send any requests. I don't want to
break that promise, even if only in a corner case. Hmm.

Given only 46 bytes we can of course return what bytes we have and
parse them as best as possible. This seems the better solution, and
for the case of error b) in Step 2 will result in a correct struct
libusb_config_descriptor, papering over the error. For error a) and
c) it may not give correct results, but we're not really able to do
much about that.

I like failing early, but I think the potential for convenience is
more important in this case.

sd, please apply the attached patch on top of libusb.git and try
running lsusb with that library, with LIBUSB_DEBUG=3 set in the
environment. Hopefully it will say a few warnings, but still work.


//Peter
sdaau
2012-10-30 07:21:24 UTC
Permalink
Post by Peter Stuge
Post by Tim Roberts
The configuration descriptor header is duplicated (09 02 31 00 01 01 00
c0).
The duplication was manual, but nevertheless the device is in
violation of the spec.
... Unfortunately your concatenation
doesn't correspond to the descriptors file on Linux, but all the
data was available in the logs.
Darn! I could have guessed just looking for "URB coming back" and copypasting the data wouldn't really work! :) Sorry about the confusion ...
Post by Peter Stuge
URB 3 re-reads the configuration descriptor, this time along with all
following descriptors included in the (reportedly) 49 bytes.
USB is a packet transport, not a character device-like serial port or
stream transport, so it's important to pay attention to the various
fields in each transfer.
Thanks for breaking this down, Peter - I'm indeed still working mostly under a mental model of a serial port, so it's good to know when that is not applicable anymore.

Btw, is this "re-reading", same as a USB packet "retransmission"? While I'm aware USB can do retransmission - I haven't observed one in the logs yet: I was kinda assuming that either retransmissions wouldn't be listed in an UsbSnoop.log; or if they do get listed, they would have some obvious flag like RETRANSMIT = 0x01 or something in the log (and I tried looking in the log again, and couldn't see any obvious flags).
Post by Peter Stuge
This is clearly a firmware error. [...]
Yup - as much as I can follow the problem, I'd agree.
Post by Peter Stuge
sd, please apply the attached patch on top of libusb.git and try
running lsusb with that library, with LIBUSB_DEBUG=3 set in the
environment. Hopefully it will say a few warnings, but still work.
Many thanks for looking into this!

I'm not 100% sure I applied everything correctly (I rename the git folder to libusb-1.0, so I had to do patch -p1); but my terminal log - and the response of `LIBUSB_DEBUG=3 ./lsusb` - are below. In the OP, the difference becomes obvious only when using `lsusb -v -d f4ec:ee38`: in which case libusb-0.1 produces the "long" listing (with endpoints data), and libusb-1.0 produces "short" listing.

It seems that even with the ignore_too_large_wtotallength.patch, lsusb/libusb-1.0 still produce just the "short" listing - but there is a ton of debug messages that will hopefully shed more light; hope to hear some commentary on them.

Cheers!


PS: terminal log from build and running:

$ wget "http://sf.net/mailarchive/attachment.php?list_name=libusb-devel&message_id=20121030001141.19084.qmail%40stuge.se&counter=1" -O ignore_too_large_wtotallength.patch
...
2012-10-30 07:11:31 (30,2 MB/s) - `ignore_too_large_wtotallength.patch' saved [1793/1793]

$ rm -rf libusb-1.0/
$ git clone http://git.libusb.org/libusb.git libusb-1.0
$ cd libusb-1.0/

libusb-1.0$ git log -n 1
commit 7634714aa696175b08016b6f2185a75a2f55a113
Author: Peter Stuge <***@stuge.se>
Date: Tue Oct 23 09:46:02 2012 +0200

libusb-1.0$ patch -p1 <../ignore_too_large_wtotallength.patch
patching file libusb/descriptor.c
patching file libusb/os/linux_usbfs.c

libusb-1.0$ ./autogen.sh # also runs ./configure
libusb-1.0$ make
libusb-1.0$ cd ..

$ cd usbutils-git/
usbutils-git$ sed -i "***@LIBUSB_CFLAGS = -I/usr/include/libusb-***@LIBUSB_CFLAGS = -I../libusb-1.0/libusb@" Makefile
usbutils-git$ make clean
usbutils-git$ make V=1 lsusb

# since I have to use `sudo`, the LD_PRELOAD (and thus LIBUSB_DEBUG) seems to be ignored in this case - there are no debug messages:

usbutils-git$ LD_PRELOAD=../libusb-1.0/libusb/.libs/libusb-1.0.so LIBUSB_DEBUG=3 sudo ./lsusb -v -d f4ec:ee38
./lsusb: cannot open "/usr/share/usb.ids", No such file or directory

Bus 002 Device 002: ID f4ec:ee38
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xf4ec
idProduct 0xee38
bcdDevice 1.00
iManufacturer 1 Siglent TechCo., Ltd.
iProduct 2 USB Digital Oscilloscope
iSerial 0
bNumConfigurations 1
Couldn't get configuration descriptor 0, some information will be missing
Couldn't get configuration descriptor 0, some information will be missing
Device Status: 0x0001
Self Powered

# so go into su mode first:

usbutils-git$ sudo su
usbutils-git# LD_PRELOAD=../libusb-1.0/libusb/.libs/libusb-1.0.so LIBUSB_DEBUG=3 ./lsusb --version
lsusb (usbutils) 006

usbutils-git# LD_PRELOAD=../libusb-1.0/libusb/.libs/libusb-1.0.so LIBUSB_DEBUG=3 ./lsusb -v -d f4ec:ee38

./lsusb: cannot open "/usr/share/usb.ids", No such file or directory
libusb: 0.000000 debug [libusb_init] libusb-1.0.9 git:1.0.9-28-g7634714
libusb: 0.000231 debug [find_usbfs_path] found usbfs at /dev/bus/usb
libusb: 0.000382 debug [op_init] bulk continuation flag supported
libusb: 0.000447 debug [op_init] zero length packet flag supported
libusb: 0.000588 debug [op_init] found usb devices in sysfs
libusb: 0.001064 debug [usbi_add_pollfd] add fd 3 events 1
libusb: 0.001184 debug [usbi_io_init] using timerfd for timeouts
libusb: 0.001242 debug [usbi_add_pollfd] add fd 5 events 1
libusb: 0.001305 debug [libusb_get_device_list]
libusb: 0.002233 debug [sysfs_scan_device] scan usb1
libusb: 0.002646 debug [sysfs_scan_device] bus=1 dev=1
libusb: 0.002694 debug [enumerate_device] busnum 1 devaddr 1 session_id 257
libusb: 0.002729 debug [enumerate_device] allocating new device for 1/1 (session 257)
libusb: 0.003051 debug [sysfs_scan_device] scan usb2
libusb: 0.003339 debug [sysfs_scan_device] bus=2 dev=1
libusb: 0.003382 debug [enumerate_device] busnum 2 devaddr 1 session_id 513
libusb: 0.003415 debug [enumerate_device] allocating new device for 2/1 (session 513)
libusb: 0.003640 debug [sysfs_scan_device] scan usb3
libusb: 0.003899 debug [sysfs_scan_device] bus=3 dev=1
libusb: 0.003939 debug [enumerate_device] busnum 3 devaddr 1 session_id 769
libusb: 0.003970 debug [enumerate_device] allocating new device for 3/1 (session 769)
libusb: 0.004212 debug [sysfs_scan_device] scan usb4
libusb: 0.004489 debug [sysfs_scan_device] bus=4 dev=1
libusb: 0.004534 debug [enumerate_device] busnum 4 devaddr 1 session_id 1025
libusb: 0.004572 debug [enumerate_device] allocating new device for 4/1 (session 1025)
libusb: 0.004791 debug [sysfs_scan_device] scan usb5
libusb: 0.005053 debug [sysfs_scan_device] bus=5 dev=1
libusb: 0.005099 debug [enumerate_device] busnum 5 devaddr 1 session_id 1281
libusb: 0.005131 debug [enumerate_device] allocating new device for 5/1 (session 1281)
libusb: 0.005336 debug [sysfs_scan_device] scan 1-4
libusb: 0.005733 debug [sysfs_scan_device] bus=1 dev=2
libusb: 0.005788 debug [enumerate_device] busnum 1 devaddr 2 session_id 258
libusb: 0.005824 debug [enumerate_device] allocating new device for 1/2 (session 258)
libusb: 0.006059 debug [sysfs_scan_device] scan 1-7
libusb: 0.006332 debug [sysfs_scan_device] bus=1 dev=3
libusb: 0.006374 debug [enumerate_device] busnum 1 devaddr 3 session_id 259
libusb: 0.006408 debug [enumerate_device] allocating new device for 1/3 (session 259)
libusb: 0.006643 debug [sysfs_scan_device] scan 1-7.2
libusb: 0.006915 debug [sysfs_scan_device] bus=1 dev=4
libusb: 0.006954 debug [enumerate_device] busnum 1 devaddr 4 session_id 260
libusb: 0.006984 debug [enumerate_device] allocating new device for 1/4 (session 260)
libusb: 0.007250 debug [sysfs_scan_device] scan 1-7.4
libusb: 0.007542 debug [sysfs_scan_device] bus=1 dev=5
libusb: 0.007586 debug [enumerate_device] busnum 1 devaddr 5 session_id 261
libusb: 0.007621 debug [enumerate_device] allocating new device for 1/5 (session 261)
libusb: 0.007845 debug [discovered_devs_append] need to increase capacity
libusb: 0.007906 debug [sysfs_scan_device] scan 2-2
libusb: 0.008183 debug [sysfs_scan_device] bus=2 dev=2
libusb: 0.008226 debug [enumerate_device] busnum 2 devaddr 2 session_id 514
libusb: 0.008259 debug [enumerate_device] allocating new device for 2/2 (session 514)
libusb: 0.008546 debug [libusb_get_device_descriptor]
libusb: 0.008652 debug [libusb_get_device_descriptor]
libusb: 0.008731 debug [libusb_get_device_descriptor]
libusb: 0.008817 debug [libusb_get_device_descriptor]
libusb: 0.008902 debug [libusb_get_device_descriptor]
libusb: 0.008986 debug [libusb_get_device_descriptor]
libusb: 0.009072 debug [libusb_get_device_descriptor]
libusb: 0.009150 debug [libusb_get_device_descriptor]
libusb: 0.009229 debug [libusb_get_device_descriptor]
libusb: 0.009310 debug [libusb_get_device_descriptor]

Bus 002 Device 002: ID f4ec:ee38
libusb: 0.009598 debug [libusb_open] open 2.2
libusb: 0.009644 debug [op_open] opening /dev/bus/usb/002/002
libusb: 0.009727 debug [usbi_add_pollfd] add fd 6 events 4
libusb: 0.009796 debug [libusb_get_device_descriptor]
libusb: 0.009943 debug [libusb_submit_transfer] arm timerfd for timeout in 1000ms (first in line)
libusb: 0.010003 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.010036 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.014621 debug [handle_events] poll() returned 1
libusb: 0.014691 debug [reap_for_handle] urb type=2 status=0 transferred=4
libusb: 0.014727 debug [handle_control_completion] handling completion status 0
libusb: 0.014762 debug [disarm_timerfd]
libusb: 0.014792 debug [usbi_handle_transfer_completion] transfer 0x8b07254 has callback 0xd01170
libusb: 0.014827 debug [ctrl_transfer_cb] actual_length=4
libusb: 0.014923 debug [libusb_submit_transfer] arm timerfd for timeout in 1000ms (first in line)
libusb: 0.014975 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.015010 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.024857 debug [handle_events] poll() returned 1
libusb: 0.024930 debug [reap_for_handle] urb type=2 status=0 transferred=56
libusb: 0.024965 debug [handle_control_completion] handling completion status 0
libusb: 0.024994 debug [disarm_timerfd]
libusb: 0.025023 debug [usbi_handle_transfer_completion] transfer 0x8b07254 has callback 0xd01170
libusb: 0.025055 debug [ctrl_transfer_cb] actual_length=56
libusb: 0.025127 debug [libusb_submit_transfer] arm timerfd for timeout in 1000ms (first in line)
libusb: 0.025172 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.025203 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.034732 debug [handle_events] poll() returned 1
libusb: 0.034793 debug [reap_for_handle] urb type=2 status=0 transferred=4
libusb: 0.034823 debug [handle_control_completion] handling completion status 0
libusb: 0.034852 debug [disarm_timerfd]
libusb: 0.034877 debug [usbi_handle_transfer_completion] transfer 0x8b07254 has callback 0xd01170
libusb: 0.034906 debug [ctrl_transfer_cb] actual_length=4
libusb: 0.034962 debug [libusb_submit_transfer] arm timerfd for timeout in 1000ms (first in line)
libusb: 0.035000 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.035027 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.044809 debug [handle_events] poll() returned 1
libusb: 0.044884 debug [reap_for_handle] urb type=2 status=0 transferred=66
libusb: 0.044917 debug [handle_control_completion] handling completion status 0
libusb: 0.044952 debug [disarm_timerfd]
libusb: 0.044983 debug [usbi_handle_transfer_completion] transfer 0x8b07254 has callback 0xd01170
libusb: 0.045019 debug [ctrl_transfer_cb] actual_length=66
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xf4ec
idProduct 0xee38
bcdDevice 1.00
iManufacturer 1 Siglent TechCo., Ltd.
iProduct 2 USB Digital Oscilloscope
iSerial 0
bNumConfigurations 1
libusb: 0.045272 debug [libusb_get_config_descriptor] index 0
libusb: 0.045454 error [parse_endpoint] invalid descriptor length 0
libusb: 0.045490 error [libusb_get_config_descriptor] parse_configuration failed with error -1
Couldn't get configuration descriptor 0, some information will be missing
libusb: 0.045531 debug [libusb_get_config_descriptor] index 0
libusb: 0.045624 error [parse_endpoint] invalid descriptor length 0
libusb: 0.045661 error [libusb_get_config_descriptor] parse_configuration failed with error -1
Couldn't get configuration descriptor 0, some information will be missing
libusb: 0.045738 debug [libusb_submit_transfer] arm timerfd for timeout in 5000ms (first in line)
libusb: 0.045787 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.045824 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.053643 debug [handle_events] poll() returned 1
libusb: 0.053713 debug [reap_for_handle] urb type=2 status=-32 transferred=0
libusb: 0.053746 debug [handle_control_completion] handling completion status -32
libusb: 0.053778 debug [handle_control_completion] unsupported control request
libusb: 0.053810 debug [disarm_timerfd]
libusb: 0.053840 debug [usbi_handle_transfer_completion] transfer 0x8b072bc has callback 0xd01170
libusb: 0.053874 debug [ctrl_transfer_cb] actual_length=0
libusb: 0.053940 debug [libusb_submit_transfer] arm timerfd for timeout in 5000ms (first in line)
libusb: 0.053982 debug [libusb_handle_events_timeout_completed] doing our own event handling
libusb: 0.054010 debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb: 0.073512 debug [handle_events] poll() returned 1
libusb: 0.073604 debug [reap_for_handle] urb type=2 status=0 transferred=2
libusb: 0.073639 debug [handle_control_completion] handling completion status 0
libusb: 0.073675 debug [disarm_timerfd]
libusb: 0.073708 debug [usbi_handle_transfer_completion] transfer 0x8b072bc has callback 0xd01170
libusb: 0.073744 debug [ctrl_transfer_cb] actual_length=2
Device Status: 0x0001
Self Powered
libusb: 0.073833 debug [libusb_close]
libusb: 0.073882 debug [usbi_remove_pollfd] remove fd 6
libusb: 0.073972 debug [libusb_exit]
libusb: 0.074001 debug [usbi_remove_pollfd] remove fd 3
libusb: 0.074061 debug [usbi_remove_pollfd] remove fd 5
Tim Roberts
2012-10-30 16:10:43 UTC
Permalink
Post by sdaau
Post by Peter Stuge
USB is a packet transport, not a character device-like serial port or
stream transport, so it's important to pay attention to the various
fields in each transfer.
Btw, is this "re-reading", same as a USB packet "retransmission"? While I'm aware USB can do retransmission - I haven't observed one in the logs yet: I was kinda assuming that either retransmissions wouldn't be listed in an UsbSnoop.log; or if they do get listed, they would have some obvious flag like RETRANSMIT = 0x01 or something in the log (and I tried looking in the log again, and couldn't see any obvious flags).
No, this is very different. The issue is that a configuration
descriptor is of variable size. USB is a scheduled bus -- the entire
frame is all planned out in advance by the host controller driver, and
the list of transfers to perform are all sent to the hardware as a
bunch. The hardware then handles them autonomously. Variable-sized
transfers do not fit very well into that kind of a scheme. So, you
fetch the first few bytes of the configuration descriptor, which
includes the length field. Then, you allocate memory for the whole
descriptor, and make a second request to fetch the whole thing.

Retries are handled entirely by the hardware. They are invisible to
software. UsbSnoop is a software snooper, so it won't have a clue that
retries occurred. Unless you have a bad cable or a poor quality
connector, retries are rare.
--
Tim Roberts, ***@probo.com
Providenza & Boekelheide, Inc.
Loading...