Overrun when doing sync meta transfers TX and RX
Posted: Thu Dec 07, 2017 12:28 pm
Hi there,
I am working on a SDR program that requires using both RX and TX at specific timestamps. In testing the program, sometimes I get overruns and discontinued timestamps on RX.
I reproduced the bug with a small program by modifying the sync_rxtx.c (in order to reduce the clutter) and, yes, I am able to see the same overrun behaviour.
Looking at dmesg I see that the USB device is reset due to LPM from time to time. I correlate the messages with the moments when the reset occurs but I am not sure about that.
One strange thing is that the overrun occurs when I create the timestam for TX based on the one from RX like this:
meta_tx.timestamp = meta_rx.timestamp + 10000;
but it does not occur when I create it like this:
meta_tx.timestamp += 10000;
I am using Ubuntu 16.04.3 with kernel 4.10.
Is there something I am missing, is there something I need to do?
output from console:
.........
TX actual_count: 0, timestamp: 81667826
RX actual_count: 10000, timestamp: 81667826
TX actual_count: 0, timestamp: 81677826
RX actual_count: 10000, timestamp: 81677826
TX actual_count: 0, timestamp: 81687826
RX actual_count: 10000, timestamp: 81687826
TX actual_count: 0, timestamp: 81697826
RX actual_count: 10000, timestamp: 81697826
TX actual_count: 0, timestamp: 81707826
RX actual_count: 10000, timestamp: 81707826
TX actual_count: 0, timestamp: 81717826
RX actual_count: 10000, timestamp: 81717826
TX actual_count: 0, timestamp: 81727826
RX actual_count: 10000, timestamp: 81727826
TX actual_count: 0, timestamp: 81737826
RX overrun, count: 8792, timestamp: 81737826
RX actual_count: 8792, timestamp: 81737826
TX actual_count: 0, timestamp: 81747826
RX actual_count: 10000, timestamp: 81747646
Closing the device...
dmesg:
[70124.812673] usb 1-4: Product: bladeRF
[70124.812676] usb 1-4: Manufacturer: Nuand
[70124.812678] usb 1-4: SerialNumber: 9eeeeecf610343cba827a9889dcc9c23
[70135.899122] usb 1-4: reset high-speed USB device number 5 using xhci_hcd
[70189.999920] usb 1-4: USB disconnect, device number 5
[70266.959216] usb 2-2: new SuperSpeed USB device number 9 using xhci_hcd
[70266.979724] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70266.980198] usb 2-2: New USB device found, idVendor=2cf0, idProduct=5246
[70266.980203] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[70266.980207] usb 2-2: Product: bladeRF
[70266.980210] usb 2-2: Manufacturer: Nuand
[70266.980213] usb 2-2: SerialNumber: 9eeeeecf610343cba827a9889dcc9c23
[70276.919235] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70276.939527] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70317.299166] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70317.319220] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70376.383426] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70376.403448] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70821.463588] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70821.483728] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70869.671442] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70869.691695] usb 2-2: LPM exit latency is zeroed, disabling LPM.
Link to download the sync_rxtx.c
https://we.tl/ZUJuq92pOy
Thanks
I am working on a SDR program that requires using both RX and TX at specific timestamps. In testing the program, sometimes I get overruns and discontinued timestamps on RX.
I reproduced the bug with a small program by modifying the sync_rxtx.c (in order to reduce the clutter) and, yes, I am able to see the same overrun behaviour.
Looking at dmesg I see that the USB device is reset due to LPM from time to time. I correlate the messages with the moments when the reset occurs but I am not sure about that.
One strange thing is that the overrun occurs when I create the timestam for TX based on the one from RX like this:
meta_tx.timestamp = meta_rx.timestamp + 10000;
but it does not occur when I create it like this:
meta_tx.timestamp += 10000;
I am using Ubuntu 16.04.3 with kernel 4.10.
Is there something I am missing, is there something I need to do?
output from console:
.........
TX actual_count: 0, timestamp: 81667826
RX actual_count: 10000, timestamp: 81667826
TX actual_count: 0, timestamp: 81677826
RX actual_count: 10000, timestamp: 81677826
TX actual_count: 0, timestamp: 81687826
RX actual_count: 10000, timestamp: 81687826
TX actual_count: 0, timestamp: 81697826
RX actual_count: 10000, timestamp: 81697826
TX actual_count: 0, timestamp: 81707826
RX actual_count: 10000, timestamp: 81707826
TX actual_count: 0, timestamp: 81717826
RX actual_count: 10000, timestamp: 81717826
TX actual_count: 0, timestamp: 81727826
RX actual_count: 10000, timestamp: 81727826
TX actual_count: 0, timestamp: 81737826
RX overrun, count: 8792, timestamp: 81737826
RX actual_count: 8792, timestamp: 81737826
TX actual_count: 0, timestamp: 81747826
RX actual_count: 10000, timestamp: 81747646
Closing the device...
dmesg:
[70124.812673] usb 1-4: Product: bladeRF
[70124.812676] usb 1-4: Manufacturer: Nuand
[70124.812678] usb 1-4: SerialNumber: 9eeeeecf610343cba827a9889dcc9c23
[70135.899122] usb 1-4: reset high-speed USB device number 5 using xhci_hcd
[70189.999920] usb 1-4: USB disconnect, device number 5
[70266.959216] usb 2-2: new SuperSpeed USB device number 9 using xhci_hcd
[70266.979724] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70266.980198] usb 2-2: New USB device found, idVendor=2cf0, idProduct=5246
[70266.980203] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[70266.980207] usb 2-2: Product: bladeRF
[70266.980210] usb 2-2: Manufacturer: Nuand
[70266.980213] usb 2-2: SerialNumber: 9eeeeecf610343cba827a9889dcc9c23
[70276.919235] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70276.939527] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70317.299166] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70317.319220] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70376.383426] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70376.403448] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70821.463588] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70821.483728] usb 2-2: LPM exit latency is zeroed, disabling LPM.
[70869.671442] usb 2-2: reset SuperSpeed USB device number 9 using xhci_hcd
[70869.691695] usb 2-2: LPM exit latency is zeroed, disabling LPM.
Link to download the sync_rxtx.c
https://we.tl/ZUJuq92pOy
Thanks