On Sat, 28 Feb 2009, Paul O'Keefe wrote:
> 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.
You mean, it didn't work before you added the sleeps, right? And now
it does work?
> libusb as discussed calls the REAPURBNDELAY function as part of it's
> SUBMITURB processing. I'm still seeing the timeouts,
What timeouts? There was only one timeout in your earlier usbmon log.
> 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)
Why do you call that a timeout? It isn't a timeout. It's a poll that
indicated the URB had not yet completed.
> 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
And that isn't a recovery. It shows libusb waiting until the URB _did_
complete and then reaping it.
> 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
Same here. This is all perfectly normal; there's nothing wrong.
Alan Stern
--
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
