[libusb] libusb hangs when transfering data via libuhd to a USRP radio

[Paul T. <pa...@gm...>]

Hey there libusb-devel,

I've got an OS specific question about OpenBSD. I've reached out to a few
specific individuals off-list, and yesterday I posted to the OpenBSD ports
mailing list (<ZCHKm9h7YYQiE4Uc@nysos>[1]) with details. I do not believe I'm
going to get a reply -- I don't think there are libusb experts lurking there.

I've built libusb from git, all logs are from a build of libusb at
fcf0c710ef5911ae37fbbf1b39d48a89f6f14e8a on an OpenBSD snapshot build of the
next release, and a -current OpenBSD kernel with extra USB debugging enabled
for ugen (to help with debugging), which makes me feel better about posting
here -- since it's not the ports version, it's the upstream libusb git repo
that I'm working against.

I've been trying to get libuhd to build, which uses libusb to communicate with
USRP devices connected over USB. The libuhd code works on Linux (tested on my
Debian sid system) without issues, but not OpenBSD. I've tracked down the
offending line to 'libusb_submit_transfer', specifically, 'obsd_submit_transfer'
which leads to '_sync_gen_transfer' doing a read() that never completes. The
read is on a file descriptor to a ugen device, but I don't know what behaviors
exist in the interaction between ugen and libusb -- or even how ugen behaves.

I do not know the OpenBSD usb stack nearly at all, so I've -- unsurprisingly --
hit a wall very quickly. I've only found one other post about OpenBSD's libusb
read blocking, which is <201...@ul...>[2], where Christian
was doing the same thing with a different library, but also transfering IQ data
to/from a software defined radio. I saw the followup, and have done what was
asked -- tried the latest libusb, but I have not emailed tech@, I emailed
ports@ instead, since this has more of a nexus there until I find a smoking
gun. Since the rtl-sdr (and librtlsdr) works (transfering IQ in async mode and
everything), I'm inclined to think the bug may lie outside the OpenBSD src tree.

What's funny is libuhd *can* communicate with the radio -- it can open the
radio, load firmware to the FPGA, and fetch information from the device
such as serial number - it's just the IQ transfer that's hanging.

Here's a snippit of the debug output - including a tail for the kernel ugen
printf's in the background (interleaved with stderr). I'll attach full
logs to this email.

/
> [ 0.718964] [00042c96] libusb: debug [libusb_claim_interface] interface 4
> [ 0.719026] [00042c96] libusb: debug [libusb_submit_transfer] transfer 0x2ea487360
> [ 0.719043] [00042c96] libusb: debug [obsd_submit_transfer]
> [ 0.719054] [00042c96] libusb: debug [_access_endpoint] endpoint 8 mode 0
> [ 0.729511] [00042c96] libusb: debug [_errno_to_libusb] error: Operation timed out (60)
> [ 0.729531] [00042c96] libusb: debug [libusb_free_transfer] transfer 0x2ea487360
> [ 0.730553] [00042c96] libusb: debug [libusb_submit_transfer] transfer 0x2ea487460
> [ 0.730569] [00042c96] libusb: debug [obsd_submit_transfer]
> [ 0.730580] [00042c96] libusb: debug [_access_endpoint] endpoint 8 mode 0
> Mar 27 20:04:40 ourea /bsd: ugenopen: flag=3, mode=8192, unit=0 endpt=8
> Mar 27 20:04:40 ourea /bsd: ugenopen: flag=1, mode=8192, unit=0 endpt=8
> Mar 27 20:04:40 ourea /bsd: ugenopen: sc=0xffff8000001be000, endpt=8, dir=1, sce=0xffff8000001bf7c0
> Mar 27 20:04:40 ourea /bsd: ugen_clear_iface_eps: clear interface eps
> Mar 27 20:04:40 ourea /bsd: ugenioctl: cmd=80045572
> Mar 27 20:04:40 ourea /bsd: ugenioctl: cmd=80045571
> Mar 27 20:04:40 ourea /bsd: ugen0: ugenread: 8
> Mar 27 20:04:40 ourea /bsd: ugenread: start transfer 512 bytes
> Mar 27 20:04:40 ourea /bsd: ugenioctl: cmd=80045572
> Mar 27 20:04:40 ourea /bsd: ugenioctl: cmd=80045571
> Mar 27 20:04:40 ourea /bsd: ugen0: ugenread: 8
> Mar 27 20:04:40 ourea /bsd: ugenread: start transfer 1024 bytes
> [ 0.824716] [0003af1b] libusb: debug [usbi_wait_for_events] poll() returned 0
> [ 0.824746] [0003af1b] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
> [ 0.824761] [0003af1b] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
\

At which point we now enter our poll loop waiting for the event to fire in order
to callback the transfer.

/
> [ 0.824774] [0003af1b] libusb: debug [usbi_wait_for_events] poll() 1 fds with timeout in 100ms
> [ 0.934674] [0003af1b] libusb: debug [usbi_wait_for_events] poll() returned 0
> [ 0.934702] [0003af1b] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
> [ 0.934716] [0003af1b] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
> [ 0.934727] [0003af1b] libusb: debug [usbi_wait_for_events] poll() 1 fds with timeout in 100ms
> [ 1.044719] [0003af1b] libusb: debug [usbi_wait_for_events] poll() returned 0
> [ 1.044746] [0003af1b] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
> [ 1.044763] [0003af1b] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
 ...
> [ 1.924783] [0003af1b] libusb: debug [usbi_wait_for_events] poll() 1 fds with timeout in 100ms
> [ 2.034700] [0003af1b] libusb: debug [usbi_wait_for_events] poll() returned 0
> [ 2.034731] [0003af1b] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
> [ 2.034744] [0003af1b] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
> [ 2.034757] [0003af1b] libusb: debug [usbi_wait_for_events] poll() 1 fds with timeout in 100ms
> ^C
> Mar 27 20:04:42 ourea /bsd: ugenclose: flag=3, mode=8192, unit=0, endpt=0
> Mar 27 20:04:42 ourea /bsd: ugenclose: close control
> Mar 27 20:04:42 ourea /bsd: ugenclose: flag=1, mode=8192, unit=0, endpt=8
> Mar 27 20:04:42 ourea /bsd: ugenclose: endpt=8 dir=1 sce=0xffff8000001bf7c0
\

Does this happen to sound like anything anyone here knows about? Any chance
there's a promising lead out there for me? I'd love to get this working.

Thank you very much!
  paultag

[1]: https://marc.info/?t=167993667800007&r=1&w=2
[2]: https://marc.info/?l=libusb-devel&m=144466221830349

-- 
:wq