Sunday 25 July 2010

Weekly report - Week 9

As expected, it wasn't a very productive week...

Status:
  • Tested my MUSB modification when double-buffering is enabled. It seems to cause a lot of packet losses with isochronous transfers, so I'm wondering if my patch is breaking something.
  • Added recipes for libpcap 1.1.1 and tcpdump 4.1.1 in OpenEmbedded. Commits: libpcap, and tcpdump.
  • These versions are able to capture USB traffic in a format that is compatible with wireshark.
  • Added an all-in-one capture script: sniff. See the script here, and updated instructions.

Plans:
  • Investigate the MSP430 Launchpad problem.
  • Choose the FIFO size for each of the endpoints from the device descriptors: right now, I have 2 extra FIFO modes, 6, and 7, used respectively for the webcam, and the headset. When that is done, we will have some fully automatic sniffing solution.
  • MUSB related: try to find out what is going wrong when double-buffering is enabled, and experiment with high-bandwidth transfers.

Risks:
  • Lack of time... This week will be the last week I will be able to work full-time on this project.

Monday 19 July 2010

Weekly report - Week 8

Status:
  • Managed to fix the bug with short ISO packets in the MUSB driver (see Friday's post).
  • Retested the proxy driver with the devices I have. I did some more thorough Bluetooth testing, including file transfers (table here).
Plans:
  • Test with a few more devices, before leaving Switzerland.
  • The MSP430 Launchpad doesn't work with the proxy (it seems a bit fragile, even when connected directly to my PC, I suspect a driver problem): investigate this.
  • It would be good to add support for high-bandwidth endpoints in the MUSB driver, and test it with the proxy (I don't own any device requiring this at the moment).
  • Test packet capture with libpcap on the BeagleBoard (to get wireshark-compatible capture files).
Risks:
  • I'll be on a plane for most of Wednesday and Thursday (and jet-lagged after that...), so don't expect too much out of this week...

Friday 16 July 2010

MUSB isochronous transfers fixed (hopefully)

So, it took a while, but I think I managed to fix the MUSB bug, the relevant commit is here.

The MUSB DMA supports 2 different transfer modes: mode-0 transfers packets one at a time, requiring CPU intervention to reload the next packet, while mode-1 is able to transfer multiple packets, before triggering an interrupt.

For every mode-0 transfer, or for the last mode-1 packet, the packet in the FIFO must be manually flushed, that is, MUSB_TXCSR_TXPKTRDY must be set. This was somehow done in musb_g_tx (musb_gadget.c:513), but incorrectly. Using the procedure described on the wiki, with a packet size of 4 (parameter -x 4), I got the following usbmon output:
S Zi:2:120:1 -115:1024:0 1 -18:0:512 512 <
C Zi:2:120:1 0:1024:5584:0 1 0:0:512 512 = de010203 de050607 de090a0b de0d0e0f de111213 de151617 de19
1a1b de1d1e1f
S Zi:2:120:1 -115:1024:5584 1 -18:0:512 512 <
C Zi:2:120:1 0:1024:6608:0 1 0:0:4 4 = df010203
S Zi:2:120:1 -115:1024:6608 1 -18:0:512 512 <
C Zi:2:120:1 0:1024:7632:0 1 0:0:4 4 = df010203
S Zi:2:120:1 -115:1024:7632 1 -18:0:512 512 <
C Zi:2:120:1 0:1024:464:0 1 0:0:4 4 = df010203
S Zi:2:120:1 -115:1024:464 1 -18:0:512 512 <
...
The first packet is 512 bytes, which is normal, and then same data was repeated again and again: df is supposed to be incremented, that is, the next packets should contain e0010203, e1010203. I tried commenting out
if (csr & MUSB_TXCSR_TXPKTRDY)
return;
as recommend by Ajay, with the same result...

I then realized that the following lines (which, BTW, do not necessarily send a zero packet, they simply ask the MUSB controller to fetch the next packet from the FIFO):
DBG(4, "sending zero pkt\n");
musb_writew(epio, MUSB_TXCSR, MUSB_TXCSR_MODE
| MUSB_TXCSR_TXPKTRDY);
were clearing all flags from MUSB_TXCSR (including things like MUSB_TXCSR_ISO or >MUSB_TXCSR_DMAEN). So I replaced these with:
DBG(4, "sending zero pkt\n");
musb_writew(epio, MUSB_TXCSR, csr
| MUSB_TXCSR_TXPKTRDY);
where csr is the current value of MUSB_TXCSR. I'm not sure if some other flags must be cleared, but at least, it works for my test case...

And the output looks better:
S Zi:2:125:1 -115:1024:0 1 -18:0:512 512 <
C Zi:2:125:1 0:1024:2608:0 1 0:0:512 512 = de010203 de050607 de090a0b de0d0e0f de111213 de151617 de191a1b de1d1e1f
S Zi:2:125:1 -115:1024:2608 1 -18:0:512 512 <
C Zi:2:125:1 0:1024:3632:0 1 0:0:12 12 = df010203 e0010203 e1010203
S Zi:2:125:1 -115:1024:3632 1 -18:0:512 512 <
C Zi:2:125:1 0:1024:4656:0 1 0:0:12 12 = e2010203 e3010203 e4010203
S Zi:2:125:1 -115:1024:4656 1 -18:0:512 512 <
C Zi:2:125:1 0:1024:5680:0 1 0:0:4 4 = e5010203
S Zi:2:125:1 -115:1024:5680 1 -18:0:512 512 <
C Zi:2:125:1 0:1024:6704:0 1 0:0:4 4 = e6010203
...
Except that 3 requests were merged into one packet (twice), which is not supposed to happen, I suppose: If the gadget driver sends a short request to the gadget controller, it probably means that it wants a short packet to be transmitted.

In any case, a bigger problem appeared, if the driver sent packets of 5 bytes, instead of 4 bytes:
S Zi:2:009:1 -115:8:0 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4568:0 1 0:0:512 512 = de010203 de050607 de090a0b de0d0e0f de111213 de151617 de191a1b de1d1e1f
S Zi:2:009:1 -115:8:4568 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4576:0 1 0:0:15 15 = df010203 e0010203 e1010203 de0d0e
S Zi:2:009:1 -115:8:4576 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4584:0 1 0:0:10 10 = e1e20203 e3010203 e301
S Zi:2:009:1 -115:8:4584 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4592:0 1 0:0:15 15 = e4010203 e5010203 e6010203 e60102
S Zi:2:009:1 -115:8:4592 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4600:0 1 0:0:5 5 = e7010203 e7
S Zi:2:009:1 -115:8:4600 1 -18:0:512 512 <
C Zi:2:009:1 0:8:4608:0 1 0:0:5 5 = e8010203 e8
...
The second packet data is badly corrupted, it should be df010203 04e00102 0304e101 020304. It seems like the DMA engine is not able to properly write unaligned data to the FIFO.

After seeing that problem (added to the fact that requests should not be merged together in the first place), I realized that MUSB_TXCSR_TXPKTRDY was probably not set at the right place in the code: it should be set right after the DMA finishes copying the data to the FIFO.

This happens in musbhsdma.c, function dma_controller_irq. And the code was already there, it's just that, for some reasons, it was only enabled for the host mode, and not the peripheral mode (if (devctl & MUSB_DEVCTL_HM), line 533). I enabled that code path, with a fix for DMA mode 0: it is useless to clear MUSB_TXCSR_DMAMODE in that case, and MUSB_TXCSR_DMAENAB may need to be cleared before clearing MUSB_TXCSR_DMAMODE, but the flag needs to be set again, otherwise this confuses the driver...

Then, I disabled the code setting MUSB_TXCSR_TXPKTRDY in musb_g_tx, and replaced it with another piece of code that forces the packet to be sent, by setting MUSB_TXCSR_FLUSHFIFO, and, it seems to work!
S Zi:2:016:1 -115:8:0 1 -18:0:512 512 <
C Zi:2:016:1 0:8:1328:0 1 0:0:512 512 = de010203 de050607 de090a0b de0d0e0f de111213 de151617 de191a1b de1d1e1f
S Zi:2:016:1 -115:8:1328 1 -18:0:512 512 <
C Zi:2:016:1 0:8:1336:0 1 0:0:5 5 = df010203 df
S Zi:2:016:1 -115:8:1336 1 -18:0:512 512 <
C Zi:2:016:1 0:8:1344:0 1 0:0:5 5 = e0010203 e0
S Zi:2:016:1 -115:8:1344 1 -18:0:512 512 <
C Zi:2:016:1 0:8:1352:0 1 0:0:5 5 = e1010203 e1
...


Long story short, the webcam works, even with DMA enabled... And g_ether still works (i.e., I didn't break everything else)...

The latest code is available here: the kernel is now based on a 2.6.34 tree.

Monday 12 July 2010

Weekly report - Week 7

Status:
  • Switched to a more recent kernel, based on 2.6.34, to make sure I have the latest bug fixes, as recommended by Ajay.
  • I shifted focus towards debugging the MUSB driver, and particularly the code path used when DMA is used. It could be possible to debug the MUSB driver using my proxy driver, connecting the webcam, but the transfer rate and packet sizes are rather unpredictable, making it hard to reproduce problems.
  • My first idea was to program a Cypress FX2 to stream isochronous packets, connect the FX2 to the BeagleBoard, with my proxy driver. I tried to find some ready-made test firmwares, without much success: none of these tested isochronous transfers, and most of them were written for the Cypress EZ-USB chip (i.e., a (incompatible) predecessor to the FX2).
  • Since the problem lies in the MUSB driver, I don't really need to use my proxy driver. I found a testing gadgetfs driver, which supports isochronous transfers. I could then hack the driver to force it to send short packets, triggering the MUSB bug (some instructions can be found here).

Plans:
  • Continue debugging the MUSB driver with short isochronous packets. If I cannot find a solution after a few days, I'll report the problem to the linux-usb list.
  • High-throughput endpoints are not supported in the MUSB driver, that's something I could try to implement.

Risks:
  • Debugging the MUSB driver is a bit difficult: since isochronous are delay sensitive, displaying some debugging messages causes packet losses.

Monday 5 July 2010

Weekly report - Week 6

Status:
  • Mostly worked on the webcam, I got isochronous transfers to work, after identifying a bug in the MUSB driver (related to the DMA controller). See last Friday's post.
Plans:
  • Attempt to fix the MUSB driver with isochronous endpoints, disabling the DMA works, but hurts the performance...
  • Program a Cypress FX2 with a high-speed, high-bandwidth endpoint (the MUSB does not seems to handle that, so it would be good to fix it as well). Maybe the FX2 can be used for bulk bandwidth tests too.
Risks:
  • Lack of available documentation about MUSB.

Friday 2 July 2010

Isochronous transfers - Webcam

These past 2 weeks, I focused on getting a USB webcam to work, and particularly the 2 isochronous endpoints, used for audio and video coming from the webcam. This is a full speed device, and its descriptor is below (I trimmed it a bit):

Bus 002 Device 061: ID 046d:08da Logitech, Inc. QuickCam Messanger
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 0 (Defined at Interface level)
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 8
idVendor 0x046d Logitech, Inc.
idProduct 0x08da QuickCam Messanger
bcdDevice 1.00
iManufacturer 0
iProduct 0
iSerial 0
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 336
bNumInterfaces 3
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xa0
(Bus Powered)
Remote Wakeup
MaxPower 100mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 255 Vendor Specific Class
bInterfaceSubClass 255 Vendor Specific Subclass
bInterfaceProtocol 255 Vendor Specific Protocol
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0000 1x 0 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0008 1x 8 bytes
bInterval 10
Interface Descriptor: ...
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 6
bNumEndpoints 2
bInterfaceClass 255 Vendor Specific Class
bInterfaceSubClass 255 Vendor Specific Subclass
bInterfaceProtocol 255 Vendor Specific Protocol
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0300 1x 768 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0008 1x 8 bytes
bInterval 10
Interface Descriptor: ...
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
...
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 0
bNumEndpoints 0
bInterfaceClass 1 Audio
bInterfaceSubClass 2 Streaming
bInterfaceProtocol 0
iInterface 0
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 1
bNumEndpoints 1
bInterfaceClass 1 Audio
bInterfaceSubClass 2 Streaming
bInterfaceProtocol 0
iInterface 0
AudioStreaming Interface Descriptor: ....
AudioStreaming Interface Descriptor: ....
Endpoint Descriptor:
bLength 9
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0010 1x 16 bytes
bInterval 1
bRefresh 0
bSynchAddress 0
AudioControl Endpoint Descriptor: ....
Device Status: 0x0000
(Bus Powered)

Audio comes through EP3, and video through EP1.

The first thing to note is that isochronous endpoints are not allowed to be part of the default configuration for a device, so, to support these transfers, the SET_INTERFACE command has to be supported. For example, when a video player is launched, the alternate setting 6 is selected for interface 0, allowing packets of up to 768 bytes on EP1 IN.

When I tried with audio playback, URBs could not be submitted to the device, with error -28, i.e. ENOSPC, which has something to do with a problem in USB bandwidth allocation. The kernel configuration CONFIG_USB_EHCI_TT_NEWSCHED is meant to help with that kind of problems, and it does, no more -28 errors, and audio worked. I realised much later that the same problem happens when I connect the webcam to my PC, through the same USB hub I normally use with the BeagleBoard, so this is probably a hub problem. The webcam works fine with another USB hub on my PC, but that USB hub refuses to work with the BeagleBoard, so I need to find a better supported USB hub.

The next problem was about the packet size used for EP1, 768 bytes is more than the FIFO size (512 bytes) in the default endpoint configurations (fifo_mode=5, see here, __initdata mode_5_cfg). I simply created a new configuration, with an EP1 FIFO size of 1024 bytes (fifo_mode=6).

And then, nothing. When I started a video player, some packets were received properly from the webcam. The proxy driver would then submit a request to the MUSB controller, and, then, the request completion handler was only called for the first request, and never for any subsequent packet. After a few hours of debugging, I found that the MUSB driver sends a zero-length packet after sending a packet smaller than the maximum size (see musb_gadget.c, around line 520). This may make sense for bulk transfers (and I have doubts...), but not for isochronous transfers. Furthermore, sending that packet seemed to stall the endpoint, and no further requests would be processed. I tried a quick hack (around line 503), and avoid sending a zero-length packet, but transfers were still not working.

After seeing the line testing #ifdef CONFIG_USB_INVENTRA_DMA around there, I started wondering about that DMA engine, and disabled it (use_dma=0 parameter to musb_hdrc), and the webcam video started to work.

Now, the question is, why did it work with audio, but not video? The answer is quite simple, audio packets are always filled: Each packet contains exactly 16 bytes, as can be seen in the following usbmon line:

ffff88006e576100 2368995185 C Zi:6:075:3 0:1:831804651:0 1 0:0:16 16 =
6aff81ff 65ff6fff 7fff6fff 9dff86ff

(The interesting bit is 0:0:16, the 3rd number indicates that the packet contains 16 bytes. Other packets are similar, just with different payload and timestamps.)

However, for the webcam, the packet size is variable:

ffff880080052000 2351992862 C Zi:6:075:1 0:1:831787618:0 32 0:0:250
0:768:292 0:1536:338 0:2304:362 0:3072:254 6807 = ...

Here, the first packet contains 250 bytes, the second one 292, then 338, etc., triggering the MUSB/DMA bug.

Finally, you can try the latest version by using the instructions found here, and the branch stable-20100702 (here).