Bug 231782

Summary: a USB frame from an interrupt endpoint may be missed
Product: Base System Reporter: Ludovic Rousseau <ludovic.rousseau+freebsd>
Component: usbAssignee: freebsd-usb (Nobody) <usb>
Status: Open ---    
Severity: Affects Many People CC: 0mp, b.altendorf, emaste, hselasky
Priority: --- Keywords: needs-patch
Version: 10.4-STABLE   
Hardware: Any   
OS: Any   
Attachments:
Description Flags
lshal(1) output
none
sudo lsusb -v
none
sudo usbconfig dump_curr_config_desc
none
sudo usbconfig dump_device_desc none

Description Ludovic Rousseau 2018-09-28 13:42:31 UTC
Hello,
I have another issue.

I can reproduce it easily using 1 USB device and 2 threads using the same libUSB context.
I know a sequence to always reproduce the problem but I have no idea where the problem comes from. Maybe it is not in libUSB but in a lower layer.

The USB interrupt end point is used to wait for an event from the USB device. In my case then event is a card removal from the smart card reader. In that case 2 bytes are sent on the interrupt end point.

I note that in a given condition the event is *never* received by my application.
I also see *no* log activity from libUSB. So maybe libUSB does not receive the USB frame.

When this happens I have 1 thread waiting in libusb_handle_events_completed() (waiting on the interrupt end point) and the other thread is not doing any libUSB activity.

The card removal event is not received. But the card insertion event (also 2 bytes sent on the interrupt end point) has no problem and is received by libUSB and my program.
It looks like in some cases a USB frame is lost.

I can send you libUSB logs if you want. But I was not able to find any problem in them. I was also not able to find why in some cases I have the problem and why in other cases my program works fine.

Is there an equivalent of the Linux usbmon kernel facility to see all the USB activity in FreeBSD?
https://www.kernel.org/doc/Documentation/usb/usbmon.txt

Thanks
Comment 1 Hans Petter Selasky freebsd_committer 2018-09-28 13:53:56 UTC
Hi,

In FreeBSD there is "usbdump -i usbusX -f Y -s 65536 -vvv" where X.Y are the numbers after ugen.

If you are using BULK, unless you clear-halt the endpoint after cancelling, one packet may get lost due to incorrect data-toggle values at the USB wire level.

--HPS
Comment 2 Ludovic Rousseau 2018-09-29 13:37:15 UTC
I do not always reproduce the problem. I do not yet know what is needed to make the problem to happen. After that it is easy to reproduce but sometimes I get a normal execution again with no problem. Strange.

For this issue I do not use libusb_cancel_transfer(). No transfer is cancelled here.

I used usbdump to dump the USB traffic.
I can reproduce the problem even when usbdump is running. Good.

When I have the issue *nothing* is logged by usbdump. The USB frame that should be received is not dumped. And then libUSB does not see it either.

I do not have a USB hardware analyser to confirm the USB frame is really travelling on the USB bus. Since I do not have the issue on GNU/Linux and I have the problem on FreeBSD 10.4 with, at least, 3 different models of USB smart card reader I guess the problem is not in the USB devices.

The missing frame is something like:
15:01:49.961874 usbus0.2 DONE-INTR-EP=00000083,SPD=FULL,NFR=1,SLEN=4,IVAL=16,ERR=0
 frame[0] READ 2 bytes
 0000  50 02 -- -- -- -- -- --  -- -- -- -- -- -- -- --  |P.              |
 flags 0x16 <SHORT_XFER_OK|SHORT_FRAMES_OK|PROXY_BUFFER|0>
 status 0xcb821 <OPEN|STARTED|SHORT_FRAMES_OK|SHORT_XFER_OK|BDMA_ENABLE|BDMA_SETUP|CAN_CANCEL_IMMED|DOING_CALLBACK|0>

It looks like the problem is not in libUSB but in a lower layer.

It looks like the problem happens more often when using a USB3 port (blue connector) than a USB2 port.
I will join the results of lshal for USB related parts.

How can I help debug this issue?
Comment 3 Ludovic Rousseau 2018-09-29 13:39:01 UTC
Created attachment 197594 [details]
lshal(1) output
Comment 4 Hans Petter Selasky freebsd_committer 2018-09-30 15:53:45 UTC
Could you also dump the USB descriptors of such a device?

Which USB controller is the device connected to? Did you try using a USB HUB in between?

--HPS
Comment 5 Ludovic Rousseau 2018-09-30 19:24:10 UTC
I do not use a USB HUB. I have 8 USB ports available on the computer. I tried with 4 of them (2 are USB 2, 2 are USB 3 according to the logos on the chassis)

How do I dump the USB descriptor on FreeBSD?
Comment 6 Hans Petter Selasky freebsd_committer 2018-09-30 21:01:01 UTC
You can use lsusb from usb-utils in ports or man usbconfig.

--HPS
Comment 7 Ludovic Rousseau 2018-10-01 16:39:19 UTC
I attach the results of:
- sudo lsusb -v
- sudo usbconfig dump_device_desc
- sudo usbconfig dump_curr_config_desc

With 2 smart card readers connected.
I was able to reproduce the problem on the 2 readers.
Comment 8 Ludovic Rousseau 2018-10-01 16:39:55 UTC
Created attachment 197684 [details]
sudo lsusb -v
Comment 9 Ludovic Rousseau 2018-10-01 16:40:25 UTC
Created attachment 197685 [details]
sudo usbconfig dump_curr_config_desc
Comment 10 Ludovic Rousseau 2018-10-01 16:40:54 UTC
Created attachment 197686 [details]
sudo usbconfig dump_device_desc
Comment 11 Hans Petter Selasky freebsd_committer 2018-10-03 08:06:47 UTC
It might be some timing issue in the USB firmware of the device. Do you by chance have access to a USB wire analyzer like the Beagle one? Or maybe you can compare the timestamps of the traffic to/from the device with Linux.

--HPS
Comment 12 Hans Petter Selasky freebsd_committer 2018-10-03 08:07:27 UTC
Try to put a usleep(10000) between commands.
Comment 13 Ludovic Rousseau 2018-10-03 14:03:52 UTC
I do not have a USB wire analyzer.

I don't think the problem is time related. When I have the problem there is no USB traffic.
I do not have to remove the smart card at a precise time. Just after a specific sequence. I have not yet found what is specific in the sequence.