Cascoda / ca821x-posix

Library for posix systems to connect the ca821x-api to an available interface (usb/kernel driver)
BSD 3-Clause "New" or "Revised" License
0 stars 0 forks source link

USB fragment out of order #11

Open HarryMorris opened 6 years ago

HarryMorris commented 6 years ago

Making an issue here just to record my findings.

Using the example app with 2 stm32-p152 boards (100 msdu_length, 0us delay) I regularly see the program fail an assertion:

|----||----|----|----|----|---|---|---|---||----|----|----|----|---|---|---|---|
|----||--------------NODE 00--------------||--------------NODE 01--------------|
|----||------------ShAddr 0001------------||------------ShAddr 0002------------|
|TIME||Tx  |Srcd|Rx  |AckR|Err|eRx|eTx|Rst||Tx  |Srcd|Rx  |AckR|Err|eRx|eTx|Rst|
|   0||   1|   0|   1|   1|  0|  0|  0|  0||   1|   1|   0|   1|  0|  0|  0|  0|
|   1||  61|  61|  61|  61|  0|  0|  0|  0||  61|  61|  61|  61|  0|  0|  0|  0|
|   2|| 120| 119| 121| 121|  0|  0|  0|  0|| 121| 121| 119| 120|  0|  0|  0|  0|
|   3|| 179| 178| 181| 181|  0|  0|  0|  0|| 181| 181| 178| 179|  0|  0|  0|  0|
|   4|| 239| 239| 241| 241|  0|  0|  0|  0|| 241| 241| 239| 239|  0|  0|  0|  0|
|   5|| 298| 298| 301| 301|  0|  0|  0|  0|| 301| 301| 298| 298|  0|  0|  0|  0|
|   6|| 370| 369| 315| 315|  0|  0|  0|  0|| 315| 315| 369| 370|  0|  0|  0|  0|
|   7|| 443| 442| 315| 315|  0|  0|  0|  0|| 315| 315| 442| 443|  0|  0|  0|  0|
|   8|| 517| 516| 315| 315|  0|  0|  0|  0|| 315| 315| 516| 517|  0|  0|  0|  0|
|   9|| 590| 590| 315| 315|  0|  0|  0|  0|| 315| 315| 590| 590|  0|  0|  0|  0|
|  10|| 665| 664| 315| 315|  0|  0|  0|  0|| 315| 315| 664| 665|  0|  0|  0|  0|
|  11|| 739| 739| 315| 315|  0|  0|  0|  0|| 315| 315| 739| 739|  0|  0|  0|  0|
|  12|| 813| 813| 315| 315|  0|  0|  0|  0|| 315| 315| 813| 813|  0|  0|  0|  0|
|  13|| 888| 888| 315| 315|  0|  0|  0|  0|| 315| 315| 888| 888|  0|  0|  0|  0|
|  14|| 962| 961| 315| 315|  0|  0|  0|  0|| 315| 315| 961| 962|  0|  0|  0|  0|
|  15||1035|1035| 315| 315|  0|  0|  0|  0|| 315| 315|1035|1035|  0|  0|  0|  0|
|  16||1109|1109| 315| 315|  0|  0|  0|  0|| 315| 315|1109|1109|  0|  0|  0|  0|
|  17||1182|1182| 315| 315|  0|  0|  0|  0|| 315| 315|1182|1182|  0|  0|  0|  0|
|  18||1256|1256| 315| 315|  0|  0|  0|  0|| 315| 315|1256|1256|  0|  0|  0|  0|
|  19||1332|1331| 315| 315|  0|  0|  0|  0|| 315| 315|1331|1332|  0|  0|  0|  0|
|----||----|----|----|----|---|---|---|---||----|----|----|----|---|---|---|---|
Digest of statistics:
Node 0:
        received 0 repeated frames
        missed 0 packets (of which 0 were acked!)
        received 0 unknown payloads
        encountered 0 Channel Access Failures
        sent 0 packets that weren't acknowledged (but 0 made it through anyway)
Node 1:
        received 0 repeated frames
        missed 0 packets (of which 0 were acked!)
        received 0 unknown payloads
        encountered 0 Channel Access Failures
        sent 0 packets that weren't acknowledged (but 0 made it through anyway)
|----||----|----|----|----|---|---|---|---||----|----|----|----|---|---|---|---|
|----||--------------NODE 00--------------||--------------NODE 01--------------|
|----||------------ShAddr 0001------------||------------ShAddr 0002------------|
|TIME||Tx  |Srcd|Rx  |AckR|Err|eRx|eTx|Rst||Tx  |Srcd|Rx  |AckR|Err|eRx|eTx|Rst|
|  20||1407|1407| 315| 315|  0|  0|  0|  0|| 315| 315|1407|1407|  0|  0|  0|  0|
|  21||1482|1481| 315| 315|  0|  0|  0|  0|| 315| 315|1481|1482|  0|  0|  0|  0|
|  22||1555|1555| 315| 315|  0|  0|  0|  0|| 315| 315|1555|1555|  0|  0|  0|  0|
|  23||1630|1629| 315| 315|  0|  0|  0|  0|| 315| 315|1629|1630|  0|  0|  0|  0|
|  24||1704|1704| 315| 315|  0|  0|  0|  0|| 315| 315|1704|1704|  0|  0|  0|  0|
|  25||1779|1779| 315| 315|  0|  0|  0|  0|| 315| 315|1779|1779|  0|  0|  0|  0|
|  26||1853|1853| 315| 315|  0|  0|  0|  0|| 315| 315|1853|1853|  0|  0|  0|  0|
|  27||1929|1929| 315| 315|  0|  0|  0|  0|| 315| 315|1929|1929|  0|  0|  0|  0|
|  28||2004|2003| 315| 315|  0|  0|  0|  0|| 315| 315|2003|2004|  0|  0|  0|  0|
|  29||2078|2077| 315| 315|  0|  0|  0|  0|| 315| 315|2077|2078|  0|  0|  0|  0|
|  30||2153|2152| 315| 315|  0|  0|  0|  0|| 315| 315|2152|2153|  0|  0|  0|  0|
|  31||2226|2226| 315| 315|  0|  0|  0|  0|| 315| 315|2226|2226|  0|  0|  0|  0|
|  32||2299|2299| 315| 315|  0|  0|  0|  0|| 315| 315|2299|2299|  0|  0|  0|  0|
|  33||2373|2373| 315| 315|  0|  0|  0|  0|| 315| 315|2373|2373|  0|  0|  0|  0|
|  34||2448|2448| 315| 315|  0|  0|  0|  0|| 315| 315|2448|2448|  0|  0|  0|  0|
|  35||2522|2522| 315| 315|  0|  0|  0|  0|| 315| 315|2522|2522|  0|  0|  0|  0|
|  36||2596|2595| 315| 315|  0|  0|  0|  0|| 315| 315|2595|2596|  0|  0|  0|  0|
|  37||2669|2669| 315| 315|  0|  0|  0|  0|| 315| 315|2669|2669|  0|  0|  0|  0|
|  38||2743|2743| 315| 315|  0|  0|  0|  0|| 315| 315|2743|2743|  0|  0|  0|  0|
|  39||2818|2817| 315| 315|  0|  0|  0|  0|| 315| 315|2817|2818|  0|  0|  0|  0|
|----||----|----|----|----|---|---|---|---||----|----|----|----|---|---|---|---|
Digest of statistics:
Node 0:
        received 0 repeated frames
        missed 0 packets (of which 0 were acked!)
        received 0 unknown payloads
        encountered 0 Channel Access Failures
        sent 0 packets that weren't acknowledged (but 0 made it through anyway)
Node 1:
        received 0 repeated frames
        missed 0 packets (of which 0 were acked!)
        received 0 unknown payloads
        encountered 0 Channel Access Failures
        sent 0 packets that weren't acknowledged (but 0 made it through anyway)
|----||----|----|----|----|---|---|---|---||----|----|----|----|---|---|---|---|
|----||--------------NODE 00--------------||--------------NODE 01--------------|
|----||------------ShAddr 0001------------|*offset == 0, frag_in[0] == 3f, frag_in[1] == 00
app: usb-exchange/usb_exchange.c:130: assemble_frags: Assertion `(is_first) == (*offset == 0)' failed.
HarryMorris commented 6 years ago

After capturing the USB traffic using tshark (terminal wireshark) the captures do not show any out of order fragments, either at 6s when the tx stalls or at the end. What I do see is that all fragments of the last data request around 6s are successfully transmitted as far as the host is concerned. This implies that either the ST board is dropping one of these fragments, or not transmitting the accompanying data confirm successfully. This still does not explain the error from the host side at the end of the test however.

HarryMorris commented 6 years ago

After debugging the ST's USB activity, I have not seen the tx or rx failing due to the queues being full. Theoretically a fragment from host->slave could be lost if there is no space in the queue, but I have not seen it happen when this failure occurs.