Re: MX25 USB timeout on ID 0951:1665 Kingston Technology Digital DataTraveler SE9 64GB

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Peter

On Mon, Dec 25, 2017 at 1:56 AM, Peter Chen <peter.chen@xxxxxxx> wrote:
>
>> > On Thu, Nov 16, 2017 at 10:20 AM, Peter Chen <peter.chen@xxxxxxx> wrote:
>> >>
>> >>> >
>> >>> > All USB registers, including USB transceiver, USB non-core, and USB core.
>> >>>
>> >>> I need to have some time to go to the platform again. It will be possible this
>> weekend.
>> >>> Have you any idea to restrict the debug apart register dump?
>> >>>
>> >>
>> >> I am afraid I don't have since imx25 is too old, I have little directly experiences on
>> it.
>> >>
>> >
>> > I have done some testing on top. I can not easily dump registers on
>> > the 2.6.31. I have recompile the old kernel and re-instrumented it.
>> > Well I don't find any important thing.
>> >
>> > The old kernel was using ehci_fsl.c basecode and the new one use
>> > chipidea. Let's say that some changes are in USB_CTRL usbmisc
>> > controller initialization but even play with those bits I did not find
>> > any failure on that side. I will continue on difference. Hope that
>> > some other have some idea ;).
>>
>> I have used a usb hardware tracer. What I can say that basically after the reset the
>> device try to go in HIGH SPEED mode but the controller can only manage full speed
>> even is an ehci.
>>
>> I have tried the errata to set PFSC bit but is even set from the dts if we force the
>> FULL SPEED mode.

The big difference I found is the way that they schedule request in
periodic schedule introduce
by 3ca9aebac2ebb8f56d2d097636b8c568320a9f87 from v3.10

What I will try to do is to go to 3.18 that I know that already was
not working. Revert couple of change
in usb that make ehci registers register difference and test again

This is the controller status after insert the key

bus platform, device ci_hdrc.1
EHCI Host Controller
EHCI 1.00, rh state running
structural params 0x00010011
capability params 0x00000006
status ce088 PPCE Async Periodic Recl FLR
command 0010075 (park)=0 ithresh=1 IAAD Async Periodic period=512 RUN
intrenable 37 IAA FATAL PCD ERR INT
uframe 2f78
port:1 status e1001805 112  STALL POWER sig=j PE CONNECT
irq normal 572 err 0 iaa 202 (lost 0)
complete 572 unlink 20

In csv you can find capture from 2.6.x and 4.1x kernel. I have the dump
of registers too but they just let me undestand about the periodic scheduling
and a bit different init of USBMISC part

Michael


>>
>>
>> Michael
>>
>
> Michael, it may have some trick things for imx25, I highly recommend compare the registers
> between work model and non-work model. You may use 'memtool' which at unit_tests folder
> which should be in Freescale released rootfs to dump registers.
>
> Peter
# Total Phase Data Center(tm) v6.73,,,,,,,,,,
# (c) 2005-2017 Total Phase, Inc.,,,,,,,,,
# www.totalphase.com,,,,,,,,,,
#,,,,,,,,,,
# sab dic 23 12:32:23 2017,,,,,,,,,,
#,,,,,,,,,,
# Level,Sp,Index,m:s.ms.us,Dur,Len,Err,Dev,Ep,Record,Summary
0,,0,0:00.000.000,,,,,,Capture started (Aggregate),[sab 23 dic 2017 12:25:53 CET]
0,,1,0:00.000.000,,,,,,<Host connected>,
0,,2,0:14.426.485,,,,,,<Host connected>,
0,FS,3,0:14.492.643,,,,,,<Full-speed>,
0,FS,4,0:14.495.643,154.327.583 ms,,,,,<Suspend>,
0,FS,5,0:14.649.971,198.450 us,,,,,<Reset> / <Chirp J> / <Tiny J>,
0,FS,6,0:14.650.169,1.020.733 ms,,,,,<Chirp K>,
0,FS,7,0:14.651.190,16 ns,,,,,<Reset> / <Chirp J> / <Tiny J>,
0,HS,8,0:14.651.190,,,U,,,<High-speed>,
0,HS,9,0:14.651.436,1.092.316 ms,,U,,,<Reset> / <Target disconnected>,
0,FS,10,0:14.652.528,,,,,,<Full-speed>,
0,FS,11,0:14.653.526,11.002.833 ms,,,,,[12 SOF],[Frames: 772 - 783] 
0,FS,12,0:14.665.174,10.500 us,8 B,I,2,0,SETUP txn,A3 00 00 00 02 00 04 00
1,FS,13,0:14.665.174,2.083 us,3 B,,2,0,   SETUP packet,2D 02 A8
1,FS,14,0:14.665.177,7.416 us,11 B,,2,0,   DATA0 packet,C3 A3 00 00 00 02 00 04 00 F6 E1
0,FS,15,0:14.665.202,5.166 us,0 B,I,2,0,OUT txn,
1,FS,16,0:14.665.202,2.083 us,3 B,,2,0,   OUT packet,E1 02 A8
1,FS,17,0:14.665.205,2.083 us,3 B,,2,0,   DATA1 packet,4B 00 00
0,FS,18,0:14.665.527,2.083 us,,,,,[1 SOF],[Frame: 784] 
0,FS,19,0:14.665.773,10.500 us,8 B,I,2,0,SETUP txn,23 01 14 00 02 00 00 00
0,FS,22,0:14.666.527,152.012.083 ms,,,,,[153 SOF],[Frames: 785 - 937] 
0,FS,23,0:14.741.535,12.583 us,8 B,,0,0,SETUP txn,80 06 00 01 00 00 40 00
0,FS,27,0:14.741.551,77.352.833 ms,,,0,0,[11201 IN-NAK],
0,FS,28,0:14.818.906,2.083 us,,!,0,0,[1 ORPHANED],
1,FS,29,0:14.818.906,2.083 us,,U,0,0,   [1 IN],
0,FS,30,0:14.665.190,605.583 us,,,2,0,[2 ORPHANED],
0,FS,32,0:14.778.538,2.083 us,,,2,1,[1 ORPHANED],
0,FS,34,0:14.821.908,247.002.300 ms,,T,,,<Suspend>,
0,,35,5:15.724.049,,,,,,Capture stopped,[sab 23 dic 2017 12:31:09 CET]
# Total Phase Data Center(tm) v6.73,,,,,,,,,,
# (c) 2005-2017 Total Phase, Inc.,,,,,,,,,
# www.totalphase.com,,,,,,,,,,
#,,,,,,,,,,
# dom gen 14 09:55:11 2018,,,,,,,,,,
#,,,,,,,,,,
# Level,Sp,Index,m:s.ms.us,Dur,Len,Err,Dev,Ep,Record,Summary
0,,0,0:00.000.000,,,,,,Capture started (Aggregate),[dom 14 gen 2018 09:53:44 CET]
0,,1,0:00.000.000,,,,,,<Host connected>,
0,HS,2,0:11.434.932,,,,,,<High-speed>,
0,HS,3,0:11.434.947,183 ns,8 B,C,,,CORRUPTED packet,B3 F0 05 63 79 83 AC FB
0,HS,4,0:11.434.947,66 ns,1 B,,,,CORRUPTED packet,E6
0,HS,5,0:11.436.298,1.533 us,,U,,,<Reset> / <Chirp K> / <Tiny K>,
0,HS,6,0:11.436.299,65.523.750 ms,,,,,<Reset> / <Target disconnected>,
0,FS,7,0:11.501.823,,,,,,<Full-speed>,
0,FS,8,0:11.504.823,210.221.216 ms,,,,,<Suspend>,
0,FS,9,0:11.715.044,198.150 us,,,,,<Reset> / <Chirp J> / <Tiny J>,
0,FS,10,0:11.715.243,1.020.533 ms,,,,,<Chirp K>,
0,FS,11,0:11.716.263,16 ns,,,,,<Reset> / <Chirp J> / <Tiny J>,
0,HS,12,0:11.716.263,,,U,,,<High-speed>,
0,HS,13,0:11.716.263,11.889.316 ms,,,,,<Reset> / <Target disconnected>,
0,FS,14,0:11.728.152,,,,,,<Full-speed>,
0,FS,15,0:11.730.622,3.002.333 ms,,,,,[4 SOF],[Frames: 814 - 817] 
0,FS,16,0:11.734.428,10.500 us,8 B,I,2,0,SETUP txn,A3 00 00 00 02 00 04 00
0,FS,19,0:11.734.456,5.250 us,0 B,I,2,0,OUT txn,
0,FS,22,0:11.734.623,59.006.000 ms,,,,,[60 SOF],[Frames: 818 - 877] 
0,FS,23,0:11.794.356,10.500 us,8 B,I,2,0,SETUP txn,23 01 14 00 02 00 00 00
0,FS,26,0:11.794.626,6.002.500 ms,,,,,[7 SOF],[Frames: 878 - 884] 
0,FS,27,0:11.800.956,12.583 us,8 B,,0,0,SETUP txn,80 06 00 01 00 00 40 00
0,FS,31,0:11.800.973,96.104.416 ms,,,0,0,[13743 IN-NAK],
0,FS,32,0:11.897.079,9.833 us,,!,0,0,[2 ORPHANED],
0,FS,34,0:11.801.627,96.008.333 ms,,,,,[97 SOF],[Frames: 885 - 981] 
0,FS,35,0:11.897.095,1.149.750 ms,18 B,!,0,0,IN txn   [166 POLL],12 01 00 02 00 00 00 40 51 09 65 16 00 02 01 02 03 01
0,FS,40,0:11.898.248,7.250 us,0 B,I,0,0,OUT txn,
0,FS,44,0:11.898.633,2.083 us,,,,,[1 SOF],[Frame: 982] 
0,FS,45,0:11.899.125,10.583 us,8 B,I,2,0,SETUP txn,23 03 04 00 02 00 00 00
0,FS,48,0:11.734.444,59.935.166 ms,,,2,0,[2 ORPHANED],
0,FS,50,0:11.813.631,2.083 us,,,2,1,[1 ORPHANED],
0,FS,52,0:11.899.136,2.650 us,,,,,<Reset> / <Target disconnected>,
0,FS,53,0:11.899.139,80.216 us,,,,,<Reset> / <Chirp J> / <Tiny J>,
0,FS,54,0:11.899.219,1.023.916 ms,,,,,<Chirp K>,
0,HS,55,0:11.900.243,,,U,,,<High-speed>,
0,HS,56,0:11.900.243,1.500 us,1 B,B,,,CORRUPTED packet,FF
0,HS,57,0:11.900.245,1.092.316 ms,,U,,,<Reset> / <Target disconnected>,
0,FS,58,0:11.901.337,,,,,,<Full-speed>,
0,FS,59,0:11.901.338,7.416 us,11 B,I,,,DATA0 packet,C3 A3 00 00 00 02 00 04 00 F6 E1
0,FS,60,0:11.901.363,5.166 us,0 B,I,2,0,OUT txn,
0,FS,63,0:11.901.527,59.005.916 ms,,,,,[60 SOF],[Frames: 998 - 1057] 
0,FS,64,0:11.961.257,10.500 us,8 B,I,2,0,SETUP txn,23 01 14 00 02 00 00 00
0,FS,67,0:11.961.531,2.083 us,,,,,[1 SOF],[Frame: 1058] 
0,FS,68,0:11.961.778,24.416 us,0 B,,0,0,Set Address,Address=04
0,FS,77,0:11.962.531,29.004.000 ms,,,,,[30 SOF],[Frames: 1059 - 1088] 
0,FS,78,0:11.991.178,1.186.000 ms,18 B,,4,0,Get Device Descriptor,Index=0 Length=18
0,FS,92,0:11.992.533,1.002.166 ms,,,,,[2 SOF],[Frames: 1089 - 1090] 
0,FS,93,0:11.992.779,1.330.916 ms,10 B,,4,0,Get Device Qualifier Descriptor,Index=0 Length=10
0,FS,107,0:11.994.533,7.002.500 ms,,,,,[8 SOF],[Frames: 1091 - 1098] 
0,FS,108,0:12.000.616,1.000.000 ms,9 B,,4,0,Get Configuration Descriptor,Index=0 Length=9
0,FS,122,0:12.002.534,1.002.166 ms,,,,,[2 SOF],[Frames: 1099 - 1100] 
0,FS,123,0:12.002.780,1.030.833 ms,32 B,,4,0,Get Configuration Descriptor,Index=0 Length=32
0,FS,137,0:12.004.534,1.002.166 ms,,,,,[2 SOF],[Frames: 1101 - 1102] 
0,FS,138,0:12.004.782,991.000 us,4 B,,4,0,Get String Descriptor,Index=0 Length=255
0,FS,152,0:12.006.534,1.002.166 ms,,,,,[2 SOF],[Frames: 1103 - 1104] 
0,FS,153,0:12.006.780,1.033.666 ms,34 B,,4,0,Get String Descriptor,Index=2 Length=255
0,FS,167,0:12.008.534,1.002.166 ms,,,,,[2 SOF],[Frames: 1105 - 1106] 
0,FS,168,0:12.008.780,1.012.000 ms,18 B,,4,0,Get String Descriptor,Index=1 Length=255
0,FS,182,0:12.010.534,1.002.083 ms,,,,,[2 SOF],[Frames: 1107 - 1108] 
0,FS,183,0:12.010.781,1.059.000 ms,50 B,,4,0,Get String Descriptor,Index=3 Length=255
0,FS,197,0:12.012.534,18.003.250 ms,,,,,[19 SOF],[Frames: 1109 - 1127] 
0,FS,198,0:12.030.946,416.416 us,0 B,,4,0,Set Configuration,Configuration=1
0,FS,208,0:12.031.536,30.004.000 ms,,,,,[31 SOF],[Frames: 1128 - 1158] 
0,FS,209,0:12.061.783,10.500 us,8 B,I,2,0,SETUP txn,A3 00 00 00 02 00 04 00
0,FS,212,0:12.061.813,5.250 us,0 B,I,2,0,OUT txn,
0,FS,215,0:11.901.351,160.459.083 ms,,,2,0,[3 ORPHANED],[Periodic Timeout]
0,FS,217,0:11.928.532,1.920.127.250 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,220,0:12.062.538,1.999.132.416 s,,,,,[2000 SOF],[Frames: 1159 - 1110] [Periodic Timeout]
0,FS,221,0:13.976.665,1.920.127.250 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,223,0:14.062.668,1.999.132.416 s,,,,,[2000 SOF],[Frames: 1111 - 1062] [Periodic Timeout]
0,FS,224,0:16.062.798,999.067.250 ms,,,,,[1000 SOF],[Frames: 1063 - 14] 
0,FS,225,0:17.061.867,435.500 us,1 B,,4,0,Get Max LUN,Max LUN = 0
0,FS,239,0:17.062.864,3.002.250 ms,,,,,[4 SOF],[Frames: 15 - 18] 
0,FS,240,0:17.063.948,2.103.416 ms,36 B,,4,2,Inquiry [0],Passed
0,FS,256,0:17.066.864,26.003.750 ms,,,,,[27 SOF],[Frames: 19 - 45] 
0,FS,257,0:17.092.453,687.416 us,,,4,2,Test Unit Ready [0],Passed
0,FS,268,0:17.093.866,3.002.250 ms,,,,,[4 SOF],[Frames: 46 - 49] 
0,FS,269,0:17.094.534,2.679.750 ms,8 B,,4,2,Read Capacity [0],Passed
0,FS,286,0:17.097.866,9.002.666 ms,,,,,[10 SOF],[Frames: 50 - 59] 
0,FS,287,0:17.105.121,2.020.250 ms,36 B,,4,2,Mode Sense [0],Passed
0,FS,304,0:17.107.866,10.002.750 ms,,,,,[11 SOF],[Frames: 60 - 70] 
0,FS,305,0:17.117.702,453.666 us,,,4,2,Test Unit Ready [0],Passed
0,FS,316,0:17.118.867,1.002.083 ms,,,,,[2 SOF],[Frames: 71 - 72] 
0,FS,317,0:17.119.535,599.166 us,,,4,2,Prevent Allow Medium Removal [0],Removal Prohibited (Failed)
0,FS,328,0:17.120.867,2.002.250 ms,,,,,[3 SOF],[Frames: 73 - 75] 
0,FS,329,0:17.121.122,2.013.166 ms,18 B,,4,2,Request Sense [0],Sense Key = Illegal Request (Passed)
0,FS,345,0:17.123.867,7.002.583 ms,,,,,[8 SOF],[Frames: 76 - 83] 
0,FS,346,0:17.129.872,1.288.750 ms,,,4,2,Test Unit Ready [0],Passed
0,FS,357,0:17.131.868,3.002.250 ms,,,,,[4 SOF],[Frames: 84 - 87] 
0,FS,358,0:17.132.537,2.682.166 ms,8 B,,4,2,Read Capacity [0],Passed
0,FS,375,0:17.135.868,3.002.250 ms,,,,,[4 SOF],[Frames: 88 - 91] 
0,FS,376,0:17.136.621,2.526.833 ms,36 B,,4,2,Mode Sense [0],Passed
0,FS,393,0:17.139.869,12.002.833 ms,,,,,[13 SOF],[Frames: 92 - 104] 
0,FS,394,0:17.146.285,5.860.250 ms,4096 B,,4,2,Read [0],LBA = 0 Length = 8 blocks (Passed)
0,FS,662,0:17.152.869,40.004.666 ms,,,,,[41 SOF],[Frames: 105 - 145] 
0,FS,663,0:17.192.119,1.096.166 ms,,,4,2,Test Unit Ready [0],Passed
0,FS,674,0:17.193.872,3.002.333 ms,,,,,[4 SOF],[Frames: 146 - 149] 
0,FS,675,0:17.194.541,2.601.416 ms,8 B,,4,2,Read Capacity [0],Passed
0,FS,692,0:17.197.872,3.002.333 ms,,,,,[4 SOF],[Frames: 150 - 153] 
0,FS,693,0:17.198.707,2.441.250 ms,36 B,,4,2,Mode Sense [0],Passed
0,FS,710,0:16.024.799,1.920.127.250 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,712,0:17.201.873,1.999.132.416 s,,,,,[2000 SOF],[Frames: 154 - 105] [Periodic Timeout]
0,FS,713,0:18.072.933,1.920.127.250 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,715,0:19.202.003,1.999.132.416 s,,,,,[2000 SOF],[Frames: 106 - 57] [Periodic Timeout]
0,FS,716,0:20.121.066,1.920.127.333 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,718,0:21.202.133,1.999.132.416 s,,,,,[2000 SOF],[Frames: 58 - 9] [Periodic Timeout]
0,FS,719,0:22.169.200,1.920.127.333 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,721,0:23.202.264,1.999.132.600 s,,,,,[2000 SOF],[Frames: 10 - 2009] [Periodic Timeout]
0,FS,722,0:24.217.333,1.920.127.333 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,724,0:25.202.394,1.999.132.516 s,,,,,[2000 SOF],[Frames: 2010 - 1961] [Periodic Timeout]
0,FS,725,0:26.265.467,1.920.127.333 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,727,0:27.202.525,1.999.132.500 s,,,,,[2000 SOF],[Frames: 1962 - 1913] [Periodic Timeout]
0,FS,728,0:28.313.600,1.920.127.416 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,730,0:29.202.655,1.999.132.500 s,,,,,[2000 SOF],[Frames: 1914 - 1865] [Periodic Timeout]
0,FS,731,0:30.361.734,1.920.127.416 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,733,0:31.202.786,1.999.132.583 s,,,,,[2000 SOF],[Frames: 1866 - 1817] [Periodic Timeout]
0,FS,734,0:32.409.868,1.920.127.416 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,736,0:33.202.916,1.999.132.583 s,,,,,[2000 SOF],[Frames: 1818 - 1769] [Periodic Timeout]
0,FS,737,0:34.458.001,1.920.127.416 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,739,0:35.203.047,1.999.132.583 s,,,,,[2000 SOF],[Frames: 1770 - 1721] [Periodic Timeout]
0,FS,740,0:36.506.135,1.920.127.500 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,742,0:37.203.177,1.999.132.666 s,,,,,[2000 SOF],[Frames: 1722 - 1673] [Periodic Timeout]
0,FS,743,0:38.554.269,1.920.127.500 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,745,0:39.203.308,1.999.132.666 s,,,,,[2000 SOF],[Frames: 1674 - 1625] [Periodic Timeout]
0,FS,746,0:40.602.403,1.920.127.500 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,748,0:41.203.439,1.999.132.666 s,,,,,[2000 SOF],[Frames: 1626 - 1577] [Periodic Timeout]
0,FS,749,0:42.650.536,1.920.127.500 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,751,0:43.203.569,1.999.132.766 s,,,,,[2000 SOF],[Frames: 1578 - 1529] [Periodic Timeout]
0,FS,752,0:44.698.670,1.920.127.500 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,754,0:45.203.700,1.999.132.766 s,,,,,[2000 SOF],[Frames: 1530 - 1481] [Periodic Timeout]
0,FS,755,0:46.746.804,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,757,0:47.203.831,1.999.132.750 s,,,,,[2000 SOF],[Frames: 1482 - 1433] [Periodic Timeout]
0,FS,758,0:48.794.938,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,760,0:49.203.961,1.999.132.750 s,,,,,[2000 SOF],[Frames: 1434 - 1385] [Periodic Timeout]
0,FS,761,0:50.843.072,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,763,0:51.204.092,1.999.132.750 s,,,,,[2000 SOF],[Frames: 1386 - 1337] [Periodic Timeout]
0,FS,764,0:52.891.206,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,766,0:53.204.223,1.999.132.750 s,,,,,[2000 SOF],[Frames: 1338 - 1289] [Periodic Timeout]
0,FS,767,0:54.939.339,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,769,0:55.204.354,1.999.132.833 s,,,,,[2000 SOF],[Frames: 1290 - 1241] [Periodic Timeout]
0,FS,770,0:56.987.473,1.920.127.583 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,772,0:57.204.484,1.999.132.833 s,,,,,[2000 SOF],[Frames: 1242 - 1193] [Periodic Timeout]
0,FS,773,0:59.035.607,1.920.127.666 s,,,2,1,[16 ORPHANED],[Periodic Timeout]
0,FS,775,0:59.204.615,1.999.132.833 s,,,,,[2000 SOF],[Frames: 1194 - 1145] [Periodic Timeout]
0,FS,776,1:01.204.746,764.052.183 ms,,,,,[765 SOF],[Frames: 1146 - 1910] 
0,FS,777,1:01.083.741,768.052.333 ms,,,2,1,[7 ORPHANED],
0,,779,1:01.968.796,,,,,,Capture stopped,[dom 14 gen 2018 09:54:47 CET]

[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux