I am running the HCT Universal USB tests on a new full speed USB device.
I am seeing what seem to be random failures in three tests: USB Device
Control test, USB Device Enumeration, and USB Descriptor. At the point
of each failure I see three unexplained transactions captured on the USB
analyzer. I don't know if the transactions are the cause of the failure or
an effect of the failure.
For a run of the USB Enumeration test:
Looking at the analyzer output I see a regular pattern of the test:
Reset
High Speed detection handshake
SetAddress
GetDescriptor - device descriptor
GetDescriptor - configuration, interface, and endpoint descriptors
I see the addresses go through 1 to 4 complete cycles (1 to 127 skipping 2)
and the test will fail with "Device with ID 138A/0001 was not found in
tree" for assertion 9.21.11. The failure will always occur after the
second GetDescriptor.
At the point of the failure there will be three incomplete transactions (or
one transaction and two retries). All three will be attempts at the same
operation with no ACK or NAK response The request will be to device 127
Endpoint 0,
bmRequestType.Recipient= 31,
bmRequestType.Type =3
bmRequestType.Direction = 1 (DEVICE TO HOST)
bRequest= 0xFF
mValue= 0x4441
wIndex= 0x5244
wLength=0
The host will send the Setup and Data0 packets from this transaction and
there is no ACK or NAK
The three consecutive transactions will be identical. (The USB analyzer for
this capture is located between the device and the hub.)
The end of the trace is included below.
(Other failures may show the same or different values for wValue and wIndex.)
Does anyone recognize this transaction?
Is it the cause or an effect of the failure?
Ed
==========================================================================
Reset duration<16.1 milliseconds> time<6.177 649 083>
HighSpeedHandshake status time<6.187 657 933>
StartOfFrame frameNumber<155> speed time<6.194 752 200>
errors<non_consecutive>
Packet id frame<155> crc5<0x0E> speed time<6.194 752 200>
ConsecutiveSof count<390> time<6.195 752 316>
Container title device<0 (6)> endpoint<0> status speed
time<6.585 691 150>
Transaction type device<0 (6)> endpoint<0> status speed
time<6.585 691 150>
Packet id devAddr<0> epNum<0> crc5<0x02> speed
time<6.585 691 150>
Packet id length<8> data<00 05 06 00 00 00 00 00> crc16<0x92EA>
speed time<6.585 694 383>
Packet id speed time<6.585 703 116>
Transaction type device<0 (6)> endpoint<0> status speed
time<6.646 695 866>
Packet id devAddr<0> epNum<0> crc5<0x02> speed time<6.646
695 866>
Packet id length<0> crc16<0x0000> speed time<6.646 699 266>
Packet id speed time<6.646 702 666>
ConsecutiveSof count<61> time<6.585 794 699>
ConsecutiveSof count<63> time<6.646 801 333>
Container title device<6> endpoint<0> status
speed time<6.709 704 450>
Transaction type device<6> endpoint<0> status speed
time<6.709 704 450>
Packet id devAddr<6> epNum<0> crc5<0x12> speed
time<6.709 704 450>
Packet id length<8> data<80 06 00 01 00 00 12 00> crc16<0xF4E0>
speed time<6.709 707 683>
Packet id speed time<6.709 716 449>
Transaction type device<6> endpoint<0> status speed
time<6.771 709 450>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.771
709 450>
Packet id length<8> data<12 01 10 01 FF FF FF 08> crc16<0xA350>
speed time<6.771 712 900>
Packet id speed time<6.771 721 999>
Transaction type device<6> endpoint<0> status speed
time<6.771 732 566>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.771
732 566>
Packet id speed time<6.771 736 016>
Transaction type device<6> endpoint<0> status speed
time<6.771 818 100>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.771
818 100>
Packet id length<8> data<8A 13 01 00 08 02 00 00> crc16<0x5BB7>
speed time<6.771 821 566>
Packet id speed time<6.771 830 333>
ConsecutiveTransaction count<2> time<6.771 842 900>
Transaction type device<6> endpoint<0> status speed
time<6.771 876 566>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.771
876 566>
Packet id length<2> data<00 01> crc16<0x8F3F> speed
time<6.771 880 033>
Packet id speed time<6.771 884 866>
Transaction type device<6> endpoint<0> status speed
time<6.833 716 633>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.833
716 633>
Packet id length<0> crc16<0x0000> speed time<6.833 719 866>
Packet id speed time<6.833 723 283>
ConsecutiveSof count<62> time<6.709 808 166>
StartOfFrame frameNumber<732> speed time<6.771 814 783>
Packet id frame<732> crc5<0x00> speed time<6.771 814 783>
ConsecutiveSof count<61> time<6.772 814 733>
ConsecutiveSof count<64> time<6.833 821 266>
Container title device<6> endpoint<0>
status speed time<6.897 724 749>
Transaction type device<6> endpoint<0> status speed
time<6.897 724 749>
Packet id devAddr<6> epNum<0> crc5<0x12> speed
time<6.897 724 749>
Packet id length<8> data<80 06 00 02 00 00 2E 00> crc16<0xF4B5>
speed time<6.897 727 983>
Packet id speed time<6.897 736 766>
Transaction type device<6> endpoint<0> status speed
time<6.959 729 583>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.959
729 583>
Packet id length<8> data<09 02 2E 00 01 01 00 80> crc16<0x8C0B>
speed time<6.959 732 949>
Packet id speed time<6.959 741 699>
Transaction type device<6> endpoint<0> status speed
time<6.959 752 849>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.959
752 849>
Packet id speed time<6.959 756 233>
Transaction type device<6> endpoint<0> status speed
time<6.959 838 233>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.959
838 233>
Packet id length<8> data<32 09 04 00 00 04 FF 00> crc16<0x8CA5>
speed time<6.959 841 616>
Packet id speed time<6.959 850 449>
ConsecutiveTransaction count<2> time<6.959 863 016>
Transaction type device<6> endpoint<0> status speed
time<6.959 896 699>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.959
896 699>
Packet id length<8> data<00 00 07 05 01 02 40 00> crc16<0xBFE3>
speed time<6.959 900 083>
Packet id speed time<6.959 908 916>
ConsecutiveTransaction count<2> time<6.959 920 000>
Transaction type device<6> endpoint<0> status speed
time<6.959 953 766>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.959
953 766>
Packet id length<8> data<00 07 05 81 02 40 00 00> crc16<0x13F5>
speed time<6.959 957 150>
Packet id speed time<6.959 965 983>
ConsecutiveTransaction count<2> time<6.959 983 716>
Transaction type device<6> endpoint<0> status speed
time<6.960 017 483>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.960
017 483>
Packet id length<8> data<07 05 82 02 40 00 00 07> crc16<0xF298>
speed time<6.960 020 866>
Packet id speed time<6.960 029 616>
ConsecutiveTransaction count<2> time<6.960 040 783>
Transaction type device<6> endpoint<0> status speed
time<6.960 074 800>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<6.960
074 800>
Packet id length<6> data<05 83 03 01 00 05> crc16<0xE82B>
speed time<6.960 078 183>
Packet id speed time<6.960 085 599>
Transaction type device<6> endpoint<0> status speed
time<7.021 736 099>
Packet id devAddr<6> epNum<0> crc5<0x12> speed time<7.021
736 099>
Packet id length<0> crc16<0x0000> speed time<7.021 739 333>
Packet id speed time<7.021 742 733>
ConsecutiveSof count<62> time<6.897 828 216>
StartOfFrame frameNumber<920> speed time<6.959 834 916>
Packet id frame<920> crc5<0x09> speed time<6.959 834 916>
ConsecutiveSof count<61> time<6.960 834 500>
ConsecutiveSof count<187> time<7.021 841 066>
Reset duration<16.1 milliseconds> time<7.208 758 883>
HighSpeedHandshake status time<7.218 767 733>
StartOfFrame frameNumber<1,186> speed time<7.225 861 916>
errors<non_consecutive>
Packet id frame<1,186> crc5<0x06> speed time<7.225 861 916>
ConsecutiveSof count<390> time<7.226 862 016>
Container title device<0 (7)> endpoint<0> status speed
time<7.616 800 783>
Transaction type device<0 (7)> endpoint<0> status speed
time<7.616 800 783>
Packet id devAddr<0> epNum<0> crc5<0x02> speed
time<7.616 800 783>
Packet id length<8> data<00 05 07 00 00 00 00 00> crc16<0x43EB>
speed time<7.616 804 016>
Packet id speed time<7.616 812 783>
Transaction type device<0 (7)> endpoint<0> status speed
time<7.677 805 566>
Packet id devAddr<0> epNum<0> crc5<0x02> speed time<7.677
805 566>
Packet id length<0> crc16<0x0000> speed time<7.677 809 016>
Packet id speed time<7.677 812 450>
ConsecutiveSof count<61> time<7.616 904 416>
ConsecutiveSof count<64> time<7.677 910 949>
Container title device<7> endpoint<0> status
speed time<7.741 814 183>
Transaction type device<7> endpoint<0> status speed
time<7.741 814 183>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed
time<7.741 814 183>
Packet id length<8> data<80 06 00 01 00 00 12 00> crc16<0xF4E0>
speed time<7.741 817 416>
Packet id speed time<7.741 826 166>
Transaction type device<7> endpoint<0> status speed
time<7.802 819 066>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed time<7.802
819 066>
Packet id length<8> data<12 01 10 01 FF FF FF 08> crc16<0xA350>
speed time<7.802 822 500>
Packet id speed time<7.802 831 616>
Transaction type device<7> endpoint<0> status speed
time<7.802 842 433>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed time<7.802
842 433>
Packet id speed time<7.802 845 866>
Transaction type device<7> endpoint<0> status speed
time<7.802 927 733>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed time<7.802
927 733>
Packet id length<8> data<8A 13 01 00 08 02 00 00> crc16<0x5BB7>
speed time<7.802 931 166>
Packet id speed time<7.802 939 933>
ConsecutiveTransaction count<2> time<7.802 952 583>
Transaction type device<7> endpoint<0> status speed
time<7.802 986 283>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed time<7.802
986 283>
Packet id length<2> data<00 01> crc16<0x8F3F> speed
time<7.802 989 700>
Packet id speed time<7.802 994 499>
Transaction type device<7> endpoint<0> status speed
time<7.865 826 116>
Packet id devAddr<7> epNum<0> crc5<0x0D> speed time<7.865
826 116>
Packet id length<0> crc16<0x0000> speed time<7.865 829 449>
Packet id speed time<7.865 832 899>
ConsecutiveSof count<61> time<7.741 917 899>
StartOfFrame frameNumber<1,763> speed time<7.802 924 416>
Packet id frame<1,763> crc5<0x18> speed time<7.802 924 416>
ConsecutiveSof count<62> time<7.803 924 366>
ConsecutiveSof count<64> time<7.865 931 083>
Container title device<7> endpoint<0></non_consecutive></non_consecutive>