On Thu, 1 Jun 2006, Vivek Dharmadhikari wrote: > Alan > > I used usbmon to gain more visibility and i see some interesting points > in it. I am reproducing a small and relevent portion of usbmon log > below. Note that the test comprises of writing about 12Mbytes of data to > 2.0 external USB hard disk. > > 1 810c73e0 1314291816 C Bi:002:01 0 13 D 5 > 2 810c73e0 1314296816 C Bo:002:02 0 31 D 6 > 3 810c73e0 1314302816 C Bo:002:02 0 31 D 7 > 4 810c73e0 1314309816 S Bo:002:02 -150 31 D > 3 > 5 810c73e0 1314312816 C Bi:002:01 0 13 D 6 > 6 81485200 1314318816 C Bo:002:02 0 512 D 5 > 7 810c73e0 1314323816 C Bi:002:01 0 13 D 8 > 8 81485200 1314331816 C Bo:002:02 0 512 D 5 > 9 810c73e0 1314336816 C Bi:002:01 0 13 D 30001 > 10 81485200 1344337816 C Bo:002:02 -131 0 0 > 11 810c73e0 1344337816 S Co:002:00 -150 0 1 > 12 810c73e0 1344338816 C Co:002:00 0 0 > 6001 > 13 810c73e0 1350339816 S Co:002:00 -150 0 1 > 14 810c73e0 1350340816 C Co:002:00 0 0 0 > 15 810c73e0 1350340816 S Co:002:00 -150 0 1 > 16 810c73e0 1350341816 C Co:002:00 0 0 0 > 17 810c73e0 1350341816 S Bo:002:02 -150 31 D > 1 > 18 810c73e0 1350342816 C Bo:002:02 0 31 D 0 > 19 810c73e0 1350342816 S Bi:002:01 -150 13 D > 539 > 20 810c73e0 1350881816 C Bi:002:01 -32 0 3 > 21 810c73e0 1350884816 S Co:002:00 -150 0 1 > 22 810c73e0 1350885816 C Co:002:00 0 0 6 > 23 810c73e0 1350891816 S Bi:002:01 -150 13 D > 1 > 24 810c73e0 1350892816 C Bi:002:01 0 13 D 1 > 25 810c73e0 1350893816 S Co:002:00 -150 0 1 > 26 810c73e0 1350894816 C Co:002:00 0 0 > 6000
Apparently you are using an old kernel version. With more recent versions (like 2.6.17-rc5), usbmon provides a lot more information. Also it looks like either usbmon has dropped a lot of lines or you have edited them out of the log. > The rightmost column above is difference between timestamp in > milliseconds. As you see, the difference in timestamp for the first 7 > samples looks ok. However there is big jump of about 30 seconds in > timestamp between sample #8 and #9. Similarly the timestamp difference > between sample #25 and #26 is about 6 seconds. I see many such random > jump in the timestamp in the usbmon log that i captured for the entire > data transfer. The net result is that the copy operation takes long time > to complete. > > Now my questions are > > 1. What could possibly be the reason behind the abrupt jump in the time > stamp values ? The 30-second jump occurs because the device has crashed and isn't sending any response. The kernel waits for 30 seconds before aborting the command. The 6-second jump is probably part of the device-reset sequence. > 2. Are there any error codes in usbmon log that i should grep for in > order to gain more visibility ? No. For better visibility you should upgrade to a more recent kernel. > 3. Is this a known issue in 2.6.12 series kernel and is there any fix > for the same ? The problem is more likely to be in your device than in the kernel. Nevertheless, the only available fix is to upgrade to a newer kernel. Alan Stern _______________________________________________ linux-usb-devel@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
