On Sun, 3 Dec 2006, Jon Senior wrote: > >-----Original Message----- > >Try using the usbmon facility. Instructions are in the kernel source > >file > >Documentation/usb/usbmon.txt. > > OK. I have enabled usbmon and produced a log file of the following procedure > > mount > cp (device -> pc) > umount > > I'll see if I can make head or tail of what's going on, but right now it's a > few hundred K of meaningless gibberish to me! > > The log file is at www.hoovesofdestiny.co.uk/usb_out.txt for anyone who > fancies having a go at working it out.
Here's a quick analysis of a typical READ command from the log. I have removed some extraneous information and added line numbers and decimal points to the timestamps (second column) so they will be easier to read. 1. 1185.281980 S Bo:002:01 -115 31 = 55534243 2. 1185.282022 C Bo:002:01 0 31 > 3. 1185.282180 S Bi:002:02 -115 20480 < 4. 1185.282184 S Bi:002:02 -115 4096 < 5. 1185.282187 S Bi:002:02 -115 8192 < 6. 1185.282189 S Bi:002:02 -115 65536 < 7. 1185.282193 S Bi:002:02 -115 24576 < 8. 1185.332172 C Bi:002:02 0 20480 = feedbdff 9. 1185.332175 C Bi:002:02 0 4096 = 343955dc 10. 1185.432171 C Bi:002:02 0 8192 = fffbe200 11. 1185.513403 C Bi:002:02 0 65536 = 5a4a5295cb 12. 1185.513406 C Bi:002:02 0 24576 = d24235b8e1 13. 1185.513414 S Bi:002:02 -115 13 < 14. 1185.513526 C Bi:002:02 0 13 = 55534253 15. 1185.513585 S Bo:002:01 -115 31 = 55534243 This was a READ transfer of 120 KB. (The last line is actually the start of the next READ command.) As you can see, the entire operation took just about 232 milliseconds. That averages out to 517 KB/s -- a little on the slow side for full speed but not too bad. Extremely slow for a high-speed connection, though. Lines 1 & 2 are the computer sending the READ command to the drive and the drive acknowledging it. Line 3-7 are the computer requesting the data in five chunks, and lines 8-12 are the data being sent back by the drive. Line 13 is the computer requesting the final status and line 14 is the drive sending the final status. (Line 15 is the next READ command getting sent to the drive.) By looking at the time stamps, you can see that the computer does everything very quickly. The delays occur when the drive needs to read the data and send it back. Just for comparison, at the maximum possible high-speed transfer rate it would require no more than 2.4 ms to send that much data over USB (not counting the time it takes the drive to read the data initially). We can see that the first two blocks (containing 24 KB) don't get sent until 50 ms have elapsed. The next block of 8 KB takes 100 (!) ms more, and the last two blocks (containing 88 KB) take 81 ms, thus accounting for virtually all of the 231 ms delay. In other words, the time-consuming parts of this data transfer consisted entirely of the computer waiting for the drive to send data. Transferring the command and the status took practically no time by comparison. This does make it look like the bottleneck is in the drive, not the computer. However I wouldn't put it past the VIA controller to be slowing things down. Those timestamps indicate when the computer learns that the transfers have completed, which obviously doesn't happen until the controller tells it. VIA hardware is known to have a number of funky problems. Alan Stern ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys - and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ Linux-usb-users@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-users
