Hello everyone,
I am experiencing problems when trying to run osmotrx with a b205mini and I connect another USB device to a different port on the machine. When I do this, osmotrx crashes instantly. Also, when I have the other device already plugged in when I start osmotrx, it takes ~20 seconds to crash.
Sometimes it just crashes without giving a reason, like here:
DLGLOBAL NOTICE Setting SCHED_RR priority 18 (cpu_sched_vty.c:471) DLGLOBAL NOTICE Setting SCHED_RR priority 18 (cpu_sched_vty.c:471) DLGLOBAL NOTICE Available via telnet 127.0.0.1 4237 (telnet_interface.c:88) DLCTRL NOTICE CTRL at 127.0.0.1 4236 (control_if.c:1024) [INFO] [UHD] linux; GNU C++ version 11.2.0; Boost_107400; UHD_4.1.0.5-3 DMAIN NOTICE -- Transceiver active with 1 channel(s) (osmo-trx.cpp:621) DLSTATS NOTICE Stats timer expire_count=7: We missed 6 timers (stats.c:169) DLGLOBAL NOTICE Stats timer expire_count=31: We missed 30 timers (rate_ctr.c:350) DTRXCTRL NOTICE Changing TSC from 0 to 7 (Transceiver.cpp:1032) DTRXCTRL NOTICE [chan=0] switching to TRXD version 1 (Transceiver.cpp:1059) DMAIN NOTICE Starting the transceiver (Transceiver.cpp:287) LLDTRXCLK NOTICE Sending CLOCK indications (Transceiver.cpp:1198) UDDEV ERROR No packet received, implementation timed-out (UHDDevice.cpp:782) DDEV FATAL UHD: Receive timed out (UHDDevice.cpp:786) DMAIN FATAL Receive error 0 (radioInterface.cpp:340) DTRXDUL FATAL Something went wrong in thread RxLower, requesting stop (Transceiver.cpp:1359) DMAIN NOTICE Shutting down transceiver... (osmo-trx.cpp:588) DMAIN NOTICE Stopping the transceiver (Transceiver.cpp:345) terminate called without an active exception Aborted
And sometimes it reports an USB error and shows the talloc report:
DMAIN NOTICE -- Transceiver active with 1 channel(s) (osmo-trx.cpp:621) DLSTATS NOTICE Stats timer expire_count=6: We missed 5 timers (stats.c:169) DLGLOBAL NOTICE Stats timer expire_count=26: We missed 25 timers (rate_ctr.c:350) DTRXCTRL NOTICE Changing TSC from 0 to 7 (Transceiver.cpp:1032) DTRXCTRL NOTICE [chan=0] switching to TRXD version 1 (Transceiver.cpp:1059) DMAIN NOTICE Starting the transceiver (Transceiver.cpp:287) DTRXCLK NOTICE Sending CLOCK indications (Transceiver.cpp:1198) LLUterminate called after throwing an instance of 'uhd::io_error' what(): EnvironmentError: IOError: usb rx6 transfer status: LIBUSB_TRANSFER_OVERFLOW signal 6 received talloc report on 'OsmoTRX' (total 8531 bytes in 29 blocks) rate_ctr.c:233 contains 1160 bytes in 1 blocks (ref 0) 0x559c72388720 trx_rate_ctr.cpp:343 contains 8 bytes in 1 blocks (ref 0) 0x559c723886b0 trx_rate_ctr.cpp:342 contains 40 bytes in 1 blocks (ref 0) 0x559c72389540 trx_rate_ctr.cpp:341 contains 32 bytes in 1 blocks (ref 0) 0x559c723895d0 telnet_connection contains 1 bytes in 1 blocks (ref 0) 0x559c723893d0 struct sched_vty_opts contains 72 bytes in 1 blocks (ref 0) 0x559c723489f0 logging contains 6197 bytes in 13 blocks (ref 0) 0x559c722c5d10 struct trx_ctx contains 1021 bytes in 8 blocks (ref 0) 0x559c722a0e80 msgb contains 0 bytes in 1 blocks (ref 0) 0x559c722c3ac0 full talloc report on 'OsmoTRX' (total 8531 bytes in 29 blocks) rate_ctr.c:233 contains 1160 bytes in 1 blocks (ref 0) 0x559c72388720 trx_rate_ctr.cpp:343 contains 8 bytes in 1 blocks (ref 0) 0x559c723886b0 trx_rate_ctr.cpp:342 contains 40 bytes in 1 blocks (ref 0) 0x559c72389540 trx_rate_ctr.cpp:341 contains 32 bytes in 1 blocks (ref 0) 0x559c723895d0 telnet_connection contains 1 bytes in 1 blocks (ref 0) 0x559c723893d0 struct sched_vty_opts contains 72 bytes in 1 blocks (ref 0) 0x559c723489f0 logging contains 6197 bytes in 13 blocks (ref 0) 0x559c722c5d10 vty_logp_doc_str contains 1377 bytes in 1 blocks (ref 0) 0x559c7231c040 vty_logp_cmd_str contains 260 bytes in 1 blocks (ref 0) 0x559c7231ba00 vty_log_level_doc_str contains 1170 bytes in 1 blocks (ref 0) 0x559c722ff430 vty_log_level_cmd_str contains 236 bytes in 1 blocks (ref 0) 0x559c722ff2d0 vty_log_level_doc_str contains 1305 bytes in 1 blocks (ref 0) 0x559c722fc610 vty_log_level_cmd_str contains 257 bytes in 1 blocks (ref 0) 0x559c722fc4a0 struct log_target contains 330 bytes in 3 blocks (ref 0) 0x559c7220c550 struct osmo_wqueue contains 96 bytes in 1 blocks (ref 0) 0x7ff689ff4090 struct log_category contains 74 bytes in 1 blocks (ref 0) 0x559c722c6290 struct log_info contains 1261 bytes in 3 blocks (ref 0) 0x559c722ac370 uint8_t contains 37 bytes in 1 blocks (ref 0) 0x559c722c6350 struct log_info_cat contains 1184 bytes in 1 blocks (ref 0) 0x559c722c5d80 struct trx_ctx contains 1021 bytes in 8 blocks (ref 0) 0x559c722a0e80 127.0.0.1 contains 10 bytes in 1 blocks (ref 0) 0x559c722c5c20 127.0.0.1 contains 10 bytes in 1 blocks (ref 0) 0x559c722c5ba0 struct cmd_element contains 122 bytes in 2 blocks (ref 0) 0x559c72369030 logging level lms (debug|info|notice|error|fatal) contains 50 bytes in 1 blocks (ref 0) 0x559c7236c1a0 utils.c:386 contains 405 bytes in 1 blocks (ref 0) 0x559c7225e5b0 utils.c:386 contains 65 bytes in 1 blocks (ref 0) 0x559c723524f0 contains 1 bytes in 1 blocks (ref 0) msgb contains 0 bytes in 1 blocks (ref 0)
On the BTS side I see several messages of missed timers, but this is something I see also when I don't have the USB plugged in:
<0006> scheduler_trx.c:489 GSM clock started, waiting for clock indications <0006> scheduler_trx.c:578 GSM clock skew: old fn=0, new fn=2555007 <0006> scheduler_trx.c:428 FN timer expire_count=4: We missed 3 timers <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:428 FN timer expire_count=6: We missed 5 timers <0006> scheduler_trx.c:593 We were 1 FN faster than TRX, compensating <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:593 We were 1 FN faster than TRX, compensating <0006> scheduler_trx.c:606 We were 2 FN slower than TRX, compensated <0006> scheduler_trx.c:428 FN timer expire_count=7: We missed 6 timers <0006> scheduler_trx.c:593 We were 1 FN faster than TRX, compensating <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:593 We were 1 FN faster than TRX, compensating <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:428 FN timer expire_count=7: We missed 6 timers <0006> scheduler_trx.c:593 We were 1 FN faster than TRX, compensating <0006> scheduler_trx.c:606 We were 1 FN slower than TRX, compensated <0006> scheduler_trx.c:428 FN timer expire_count=7: We missed 6 timers <0006> scheduler_trx.c:435 No more clock from transceiver
Does anyone know if this is a software or hardware problem? I am thinking maybe it is related to the power supply of the USB port, but I have no idea. I really need to have both devices connected at the same time.
Any help or suggestion is appreciated,
Jonathan
Dear Jonathan,
without knowing the details, it may very well be that you are hitting resourec allocation limits on the USB bus. It is a shared bus, after all. Every additional device will require bandwidth; every endpoint on every device will need to be periodically polled according to its descriptors.
The USB host software (OHCI/UICH/EHCI) or USB host controller firmware (XHCI) are managing this, and with hard real time sensitive streaming of SDR samples, you cannot afford to significantly delay any of them.
It's best to use USB ports connected to other USB root hubs / controllers for your additional devices.
Hi Harald,
I've checked and my USB ports are distributed on only 2 root hubs. One root hub has 3 USB 3.2 ports, and the other only has an USB 4.0 port.
I've tried connecting one device to each root hub and it still fails. This is the output from dmesg:
[ 848.355290] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 849.478929] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci_hcd [ 849.499288] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 850.011175] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci_hcd [ 850.031369] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 850.114091] usb 4-1.2: usbfs: process 2896 (osmo-trx-uhd) did not claim interface 3 before use [ 851.382928] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci_hcd [ 851.403659] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 853.062801] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci_hcd [ 853.083287] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 854.274350] usb 3-1.2: new high-speed USB device number 5 using xhci_hcd [ 858.166299] usb 4-1.2: can't restore configuration #1 (error=-110) [ 858.167237] usb 4-1.2: USB disconnect, device number 3 [ 858.642435] usb 4-1.2: new SuperSpeed USB device number 4 using xhci_hcd [ 858.662942] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 858.663795] usb 4-1.2: New USB device found, idVendor=2500, idProduct=0022, bcdDevice= 0.00 [ 858.663804] usb 4-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 858.663810] usb 4-1.2: Product: Unknown [ 858.663814] usb 4-1.2: Manufacturer: Ettus Research LLC [ 858.663818] usb 4-1.2: SerialNumber: 32B170C [ 859.578386] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 859.598971] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 940.407651] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 940.428142] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 1026.744963] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 1026.765333] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 1027.816836] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 1027.837274] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 1032.872714] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 1032.893202] usb 4-1.2: LPM exit latency is zeroed, disabling LPM. [ 1055.046967] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci_hcd [ 1055.067414] usb 4-1.2: LPM exit latency is zeroed, disabling LPM.
And this is the output of lsusb -t:
/: Bus 10.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 10000M /: Bus 09.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M /: Bus 08.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 10000M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M |__ Port 1: Dev 4, If 0, Class=Vendor Specific Class, Driver=r8152, 5000M |__ Port 2: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, 5000M /: Bus 07.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 2: Dev 3, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 3: Dev 5, If 0, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 1, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 2, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 3, Class=Human Interface Device, Driver=usbhid, 12M |__ Port 3: Dev 4, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/0p, 5000M /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/2p, 10000M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/2p, 10000M |__ Port 2: Dev 4, If 0, Class=Vendor Specific Class, Driver=, 5000M |__ Port 2: Dev 4, If 1, Class=Vendor Specific Class, Driver=, 5000M |__ Port 2: Dev 4, If 2, Class=Vendor Specific Class, Driver=, 5000M |__ Port 2: Dev 4, If 3, Class=Vendor Specific Class, Driver=, 5000M |__ Port 2: Dev 4, If 4, Class=Vendor Specific Class, Driver=, 5000M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/3p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M |__ Port 3: Dev 4, If 0, Class=Wireless, Driver=btusb, 12M |__ Port 3: Dev 4, If 1, Class=Wireless, Driver=btusb, 12M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/2p, 10000M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M
Where the USRP is on Bus 04 Dev 04 and the other device on Bus 07 Dev 04
-
Harald Welte -
JPichel