sorry, I forgot to hit "reply all" -------------- Original message from Alan Stern <stern@xxxxxxxxxxxxxxxxxxx>: -------------- > On Wed, 13 May 2009, Dwayne Fontenot wrote: > > > I have gathered data from /sys/kernel/debug/ehci and it looks interesting. > > Does this tell us anything useful? > > Does it still look like a hardware bug? > > > ========================================================================== > > > > after insmod ruusb driver (36 interrupt URBs submitted): > > > > Intel HCD: > > > > [recsys@ws2 0000:00:1d.7]$ cat periodic > > size = 1024> 255: qh256-0001/f44cc080 (h18 ep1in [1/0] q1 p1) qh256-0001/f44cc400 (h31 ep1in [1/0] q1 p1) qh256-0001/f44cc680 (h32 ep1in [1/0] q1 p1) qh256-0001/f44ccc00 (h57 ep1in [1/0] q1 p1) qh256-0001/f44ccd00 (h58 ep1in [1/0] q1 p1) qh256-0001/f4415d80 (h83 ep1in [1/0] q1 p1) qh256-0001/f4415c00 (h25 ep1in [2/0] q1 p64) qh256-0001/f4415600 (h26 ep1in [2/0] q1 p64) qh256-0001/f4415680 (h27 ep1in [2/0] q1 p64) qh256-0001/f4415a00 (h28 ep1in [2/0] q1 p64) qh256-0001/f4415a80 (h29 ep1in [2/0] q1 p64) qh256-0001/f4415800 > (h30 ep1in [2/0] q1 p64) qh256-0001/f4415f00 (h45 ep1in [2/0] q1 p64) > qh256-0001/f4415c80 (h46 ep1in [2/0] q1 p64) qh256-0001/f4415e80 (h47 ep1in > [2/0] q1 p64) qh256-0001/f4415e00 (h48 ep1in [2/0] q1 p64) qh256-0001/f4415980 > (h49 ep1in [2/0] q1 p64) qh256-0001/f4415900 (h50 ep1in [2/0] q1 p64) > qh256-0001/f4415480 (h51 ep1in [2/0] q1 p64) qh256-0001/f4415380 (h52 ep1in > [2/0] q1 p64) qh256-0001/f6af3e80 (h53 ep1in [2/0] q1 p64) qh256-0001/f6af3d00 > (h54 ep1in [2/0] q1 p64) qh256-0001/f6af3b80 (h55 ep1in [2/0] q1 p64) > qh256-0001/f6af3b00 (h56 ep1in [2/0] q1 p64) qh256-0001/f6af3180 (h71 ep1in > [2/0] q1 p64) qh256-0001/f6af3100 (h72 ep1in [2/0] q1 p64) qh256-0001/f6af3c80 > (h73 ep1in [2/0] q1 p64) qh256-0001/f6af3d80 (h74 ep1in [2/0] q1 p64) > qh256-0001/f6af3a80 (h75 ep1in [2/0] q1 p64) qh256-0001/f6af3080 (h76 ep1in > [2/0] q1 p64) qh256-0001/f6af3000 (h77 ep1in [2/0] q1 p64) qh256-0001/f6af3280 > (h78 ep1in [2/0] q1 p64) qh256-0001/f6af3200 (h79 ep1in [2/0] q1 p64) > qh256-0001/f6af3c00 (h80 ep1in [2/0] q1 p64) qh256-0001/f6af3480 (h81 ep1in > [2/0] q1 p64) qh256-0001/f6af3400 (h82 ep1in [2/0] q1 p64) qh256-0001/f6af3700 > (h90 ep1in [2/0] q1 p64) qh256-0001/f6af3980 (h91 ep1in [2/0] q1 p64) > qh256-0001/f6af3900 (h92 ep1in [2/0] q1 p64) qh256-0001/f6af3680 (h93 ep1in > [2/0] q1 p64) qh256-0001/f6af3600 (h94 ep1in [2/0] q1 p64) qh256-0001/f6af3f00 > (h95 ep1in [2/0] q1 p64) > > 511: qh256-0001/f44cc080 ... qh256-0001/f44cc400 ... qh256-0001/f44cc680 ... > qh256-0001/f44ccc00 ... qh256-0001/f44ccd00 ... qh256-0001/f4415d80 ... > qh256-0001/f4415c00 ... qh256-0001/f4415600 ... qh256-0001/f4415680 ... > qh256-0001/f4415a00 ... qh256-0001/f4415a80 ... qh256-0001/f4415800 ... > qh256-0001/f4415f00 ... qh256-0001/f4415c80 ... qh256-0001/f4415e80 ... > qh256-0001/f4415e00 ... qh256-0001/f4415980 ... qh256-0001/f4415900 ... > qh256-0001/f4415480 ... qh256-0001/f4415380 ... qh256-0001/f6af3e80 ... > qh256-0001/f6af3d00 ... qh256-0001/f6af3b80 ... qh256-0001/f6af3b00 ... > qh256-0001/f6af3180 ... qh256-0001/f6af3100 ... qh256-0001/f6af3c80 ... > qh256-0001/f6af3d80 ... qh256-0001/f6af3a80 ... qh256-0001/f6af3080 ... > qh256-0001/f6af3000 ... qh256-0001/f6af3280 ... qh256-0001/f6af3200 ... > qh256-0001/f6af3c00 ... qh256-0001/f6af3480 ... qh256-0001/f6af3400 ... > qh256-0001/f6af3700 ... qh256-0001/f6af3980 ... qh256-0001/f6af3900 ... > qh256-0001/f6af3680 ... qh256-0001/f6af3600 ... qh256-0001/f6af3f00 > > 767: qh256-0001/f44cc080 ... qh256-0001/f44cc400 ... qh256-0001/f44cc680 ... > qh256-0001/f44ccc00 ... qh256-0001/f44ccd00 ... qh256-0001/f4415d80 ... > qh256-0001/f4415c00 ... qh256-0001/f4415600 ... qh256-0001/f4415680 ... > qh256-0001/f4415a00 ... qh256-0001/f4415a80 ... qh256-0001/f4415800 ... > qh256-0001/f4415f00 ... qh256-0001/f4415c80 ... qh256-0001/f4415e80 ... > qh256-0001/f4415e00 ... qh256-0001/f4415980 ... qh256-0001/f4415900 ... > qh256-0001/f4415480 ... qh256-0001/f4415380 ... qh256-0001/f6af3e80 ... > qh256-0001/f6af3d00 ... qh256-0001/f6af3b80 ... qh256-0001/f6af3b00 ... > qh256-0001/f6af3180 ... qh256-0001/f6af3100 ... qh256-0001/f6af3c80 ... > qh256-0001/f6af3d80 ... qh256-0001/f6af3a80 ... qh256-0001/f6af3080 ... > qh256-0001/f6af3000 ... qh256-0001/f6af3280 ... qh256-0001/f6af3200 ... > qh256-0001/f6af3c00 ... qh256-0001/f6af3480 ... qh256-0001/f6af3400 ... > qh256-0001/f6af3700 ... qh256-0001/f6af3980 ... qh256-0001/f6af3900 ... > qh256-0001/f6af3680 ... qh256-0001/f6af3600 ... qh256-0001/f6af3f00 > > 1023: qh256-0001/f44cc080 ... qh256-0001/f44cc400 ... qh256-0001/f44cc680 ... > qh256-0001/f44ccc00 ... qh256-0001/f44ccd00 ... qh256-0001/f4415d80 ... > qh256-0001/f4415c00 ... qh256-0001/f4415600 ... qh256-0001/f4415680 ... > qh256-0001/f4415a00 ... qh256-0001/f4415a80 ... qh256-0001/f4415800 ... > qh256-0001/f4415f00 ... qh256-0001/f4415c80 ... qh256-0001/f4415e80 ... > qh256-0001/f4415e00 ... qh256-0001/f4415980 ... qh256-0001/f4415900 ... > qh256-0001/f4415480 ... qh256-0001/f4415380 ... qh256-0001/f6af3e80 ... > qh256-0001/f6af3d00 ... qh256-0001/f6af3b80 ... qh256-0001/f6af3b00 ... > qh256-0001/f6af3180 ... qh256-0001/f6af3100 ... qh256-0001/f6af3c80 ... > qh256-0001/f6af3d80 ... qh256-0001/f6af3a80 ... qh256-0001/f6af3080 ... > qh256-0001/f6af3000 ... qh256-0001/f6af3280 ... qh256-0001/f6af3200 ... > qh256-0001/f6af3c00 ... qh256-0001/f6af3480 ... qh256-0001/f6af3400 ... > qh256-0001/f6af3700 ... qh256-0001/f6af3980 ... qh256-0001/f6af3900 ... > qh256-0001/f6af3680 ... qh256-0001/f6af3600 ... qh256-0001/f6af3f00 > > I had an idea. This information shows that all of your interrupt > transfers are queued for the same microframes. It might help to > stagger them. That sounds promising. I admit I cannot completely interpret the above; what part shows which microframe an interrupt transfer is queued for? > You should try changing your driver so that it delays by one > millisecond after submitting each of the initial interrupt URBs. Then > different URBs will be processed during different frames and the queue > depths will never get very big. The NEC controller might be able to > handle this with no problem. > > Alan Stern I configured CONFIG_PRINTK_TIME=y and ran the test again. The interrupt URB submissions look like this: [ 951.701316] usb 4-4.4.2: submitted intr urb for ru100 [ 951.702951] usb 4-4.4.3: submitted intr urb for ru101 [ 951.703770] usb 4-4.4.5: submitted intr urb for ru102 [ 951.704685] usb 4-4.4.6: submitted intr urb for ru103 [ 951.715441] usb 4-4.4.7: submitted intr urb for ru104 [ 951.719620] usb 4-3.1: submitted intr urb for ru105 [ 951.724040] usb 4-3.2: submitted intr urb for ru106 [ 951.728336] usb 4-3.3: submitted intr urb for ru107 [ 951.732626] usb 4-3.5: submitted intr urb for ru108 [ 951.733413] usb 4-3.6: submitted intr urb for ru109 [ 951.737141] usb 4-3.7: submitted intr urb for ru110 [ 951.743021] usb 4-3.4.1: submitted intr urb for ru111 [ 951.743848] usb 4-3.4.2: submitted intr urb for ru112 [ 951.746622] usb 4-3.4.3: submitted intr urb for ru113 [ 951.747401] usb 4-3.4.5: submitted intr urb for ru114 [ 951.748251] usb 4-3.4.6: submitted intr urb for ru115 [ 951.748995] usb 4-3.4.7: submitted intr urb for ru116 [ 951.749876] usb 4-2.1: submitted intr urb for ru117 [ 951.750622] usb 4-2.2: submitted intr urb for ru118 [ 951.751499] usb 4-2.3: submitted intr urb for ru119 [ 951.752372] usb 4-2.5: submitted intr urb for ru120 [ 951.753123] usb 4-2.6: submitted intr urb for ru121 [ 951.753874] usb 4-2.7: submitted intr urb for ru122 [ 951.754751] usb 4-5.1: submitted intr urb for ru123 [ 951.755499] usb 4-5.2: submitted intr urb for ru124 [ 951.756254] usb 4-5.3: submitted intr urb for ru125 [ 951.757030] usb 4-5.5: submitted intr urb for ru126 [ 951.757874] usb 4-5.6: submitted intr urb for ru127 [ 951.758749] usb 4-5.7: submitted intr urb for ru128 [ 951.759509] usb 4-4.1: submitted intr urb for ru129 [ 951.760383] usb 4-4.2: submitted intr urb for ru130 [ 951.761130] usb 4-4.3: submitted intr urb for ru131 [ 951.762009] usb 4-4.5: submitted intr urb for ru132 [ 951.762757] usb 4-4.6: submitted intr urb for ru133 [ 951.763634] usb 4-4.7: submitted intr urb for ru134 [ 951.764506] usb 4-4.4.1: submitted intr urb for ru135 The initial interrupt URB submissions are in the probe routine of the RU driver. It appears that they are already staggered over approx. 64 mS (?). The periodic schedule for the above looks like this (first six entries are the hubs): size = 256 255: qh256-0001/f68e5100 (h2 ep1in [1/0] q1 p1) qh256-0001/f68e5500 (h9 ep1in [1/0] q1 p1) qh256-0001/f68e5600 (h10 ep1in [1/0] q1 p1) qh256-0001/f68e5d00 (h23 ep1in [1/0] q1 p1) qh256-0001/f68e5e00 (h24 ep1in [1/0] q1 p1) qh256-0001/f543f580 (h37 ep1in [1/0] q1 p1) qh256-0001/f68e5980 (h44 ep1in [2/0] q1 p64) qh256-0001/f68e5780 (h45 ep1in [2/0] q1 p64) qh256-0001/f68e5700 (h46 ep1in [2/0] q1 p64) qh256-0001/f68e5680 (h47 ep1in [2/0] q1 p64) qh256-0001/f68e5900 (h48 ep1in [2/0] q1 p64) qh256-0001/f68e5880 (h49 ep1in [2/0] q1 p64) qh256-0001/f68e5800 (h50 ep1in [2/0] q1 p64) qh256-0001/f68e5400 (h51 ep1in [2/0] q1 p64) qh256-0001/f68e5380 (h52 ep1in [2/0] q1 p64) qh256-0001/f68e5300 (h53 ep1in [2/0] q1 p64) qh256-0001/f68e5280 (h54 ep1in [2/0] q1 p64) qh256-0001/f68e5200 (h55 ep1in [2/0] q1 p64) qh256-0001/f68e5180 (h56 ep1in [2/0] q1 p64) qh256-0001/f561c000 (h57 ep1in [2/0] q1 p64) qh256-0001/f561c080 (h58 ep1in [2/0] q1 p64) qh256-0001/f561c100 (h59 ep1in [2/0] q1 p64) qh256-0001/f561c180 (h60 ep1in [2/0] q1 p64) qh256-0001/f561c200 (h61 ep1in [2/0] q1 p64) qh256-0001/f561c280 (h62 ep1in [2/0] q1 p64) qh256-0001/f561c300 (h63 ep1in [2/0] q1 p64) qh256-0001/f561c380 (h64 ep1in [2/0] q1 p64) qh256-0001/f561c400 (h65 ep1in [2/0] q1 p64) qh256-0001/f561c480 (h66 ep1in [2/0] q1 p64) qh256-0001/f561c500 (h67 ep1in [2/0] q1 p64) qh256-0001/f561c580 (h68 ep1in [2/0] q1 p64) qh256-0001/f561c600 (h69 ep1in [2/0] q1 p64) qh256-0001/f561c680 (h70 ep1in [2/0] q1 p64) qh256-0001/f561c700 (h71 ep1in [2/0] q1 p64) qh256-0001/f561c780 (h72 ep1in [2/0] q1 p64) qh256-0001/f561c800 (h73 ep1in [2/0] q1 p64) qh256-0001/f561c880 (h74 ep1in [2/0] q1 p64) qh256-0001/f561c900 (h75 ep1in [2/0] q1 p64) qh256-0001/f561c980 (h76 ep1in [2/0] q1 p64) qh256-0001/f561ca00 (h77 ep1in [2/0] q1 p64) qh256-0001/f561ca80 (h78 ep1in [2/0] q1 p64) qh256-0001/f561cb00 (h79 ep1in [2/0] q1 p64) Maybe a USB scheduler bug is causing them to all be queued for the same microframe? Dwayne -- 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
