On Sat, 2009-02-28 at 12:36 -0500, Alan Stern wrote:
> On Sat, 28 Feb 2009, Chris Frey wrote:
>
> > There were two issues confusing the debugging process. One was that the
> > timeout appeared to be 1ms in gdb, but this was just a stack anomaly...
> > stepping a bit farther changed gdb's results... probably due to using
> > -O2 for the build.
> >
> > The other issue was a timeout in libusb's usb_bulk_read() function.
> > This depended on:
> >
> > - a fairly modern tool chain (e.g. Debian Lenny or Ubuntu Jaunty)
> > - a 2.6.28 kernel or higher (2.6.27 never shows this issue)
> >
> > My setup is a Debian Etch system running 2.6.28.7, and a Debian Lenny
> > system running in a QEMU VM. btool (compiled with g++ 4.1.2 on Etch)
> > runs fine on 2.6.28.7 and 2.6.28.4 on the bare Etch system. But if I run
> > btool in the VM Lenny system using 2.6.28.4, compiled with g++ 4.3.2,
> > I get a timeout. Adding a delay doesn't seem to help.
>
> You've got so many variables here, it's hard to keep things straight:
>
> Distribution (Etch vs. Lenny),
>
> Kernel (2.6.28.4 vs. 2.6.28.7),
>
> Environment (bare vs. VM),
>
> Compiler (4.1.2 vs. 4.3.2).
>
> Maybe other things as well. The cardinal rule of debugging is to vary
> only one ingredient at a time.
>
I'm varying one ingredient in my testing ;-). I only began
experimenting with this set of tools once I had already completed an
upgrade to Ubuntu Jaunty. So far I have varied only the Kernel (works
under 2.6.27.x with same libc, same libusb, same libboost-*, and same
libbarry) and did not work with 2.6.28.x kernel with all those same
variables.
libusb as discussed calls the REAPURBNDELAY function as part of it's
SUBMITURB processing. I'm still seeing the timeouts, however my
BlackBerry doesn't get lost with the 100uSec sleep after the Clear Halts
and things proceed normally now. Here's another strace (abbreviated)
showing the 100uSec sleeps and some selected parts.
I don't know if the timeout is from the device, from the libusb
processing, but I still venture that it was introduced by some Kernel
change between 2.6.27 and 2.6.28 and I think Chris is on the right track
to find where it occurs. But ultimately I'll bet that we'll either have
to ignore the timeout (if it's not affecting the overall device/connect
process) or make code changes to eliminate the REAPURBNDELAY functions
in libusb.
log segments follow:
First, see effect of inserting the sleeps
-------------------------------------
13:52:33.456174 open("/dev/bus/usb/007/005", O_RDWR) = 3
13:52:33.456324 ioctl(3, USBDEVFS_CONTROL, 0xbfcb961c) = 1
13:52:33.456650 ioctl(3, USBDEVFS_CLAIMINTERFACE, 0xbfcb9634) = 0
13:52:33.456766 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfcb9644) = 0
-----------sleep 1----------------V
13:52:33.457116 nanosleep({0, 100000000}, NULL) = 0
13:52:33.557517 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfcb9644) = 0
-----------sleep 2----------------V
13:52:33.557904 nanosleep({0, 100000000}, NULL) = 0
13:52:33.658313 gettimeofday({1235847153, 658378}, NULL) = 0
13:52:33.658447 ioctl(3, USBDEVFS_SUBMITURB, 0xbfcb94e4) = 0
-----------still times out--------------------------------------V
13:52:33.658562 ioctl(3, USBDEVFS_REAPURBNDELAY, 0xbfcb9528) = -1 EAGAIN
(Resource temporarily unavailable)
13:52:33.658706 select(4, NULL, [3], NULL, {0, 1000}) = 1 (out [3], left
{0, 992})
13:52:33.660212 gettimeofday({1235847153, 660264}, NULL) = 0
-----------But recovers on first retry-------------------------V
13:52:33.660330 ioctl(3, USBDEVFS_REAPURBNDELAY, 0xbfcb9528) = 0
13:52:33.660439 futex(0x9af4964, FUTEX_WAIT_PRIVATE, 1, NULL) = 0
13:52:33.714335 futex(0x9af4948, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
13:52:33.714458 futex(0x9af4948, FUTEX_WAKE_PRIVATE, 1) = 0
13:52:33.714565 futex(0x9af4964, FUTEX_WAIT_PRIVATE, 3, NULL) = 0
13:52:33.714944 futex(0x9af4948, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
13:52:33.715048 futex(0x9af4948, FUTEX_WAKE_PRIVATE, 1) = 0
13:52:33.715221 gettimeofday({1235847153, 715263}, NULL) = 0
13:52:33.715326 ioctl(3, USBDEVFS_SUBMITURB, 0xbfcb9454) = 0
-----------------time out---------------------------------------V
13:52:33.715423 ioctl(3, USBDEVFS_REAPURBNDELAY, 0xbfcb9498) = -1 EAGAIN
(Resource temporarily unavailable)
13:52:33.715534 select(4, NULL, [3], NULL, {0, 1000}) = 1 (out [3], left
{0, 990})
13:52:33.715673 gettimeofday({1235847153, 715708}, NULL) = 0
------------------ recover ------------------------------------v
13:52:33.715769 ioctl(3, USBDEVFS_REAPURBNDELAY, 0xbfcb9498) = 0
I'll boot 2.6.27x and repeat.
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
