Dear USB Experts,

I have a Net2280 PCI card and I'm trying to get the gadgetfs user-mode 
test program from http://www.linux-usb.org/gadget/usb.c to work.  
There's a second Linux box at the other end of the USB cable and both 
ends are running 2.6.19.  I have encountered a problem which I think 
could be a bug in the net2280 driver - though I suppose it's more likely 
that I just don't understand it properly yet.

The test program sends descriptors to gadgetfs.  The two ends CONNECT.  
The host asks for descriptors, and those that the kernel knows about 
itself are sent OK.  Then the host asks for a string descriptor.  
This is the responsibility of the test program.  Gadgetfs delegates 
this request to userspace.

>From here on the exact behaviour varies from one run to the next.  
I think it is sensitive to how quickly the test program returns the 
string descriptor data.  Certainly running the test program under 
strace slows it down enough to change the behaviour.  However, much 
of the time I believe that the Net2280 chip generates an interrupt 
saying "ep0 IN fifo empty, data required" before the test program 
has provided the string data for it to send.

As I understand it, at this point the driver should NOT write 
anything to the fifo and the hardware should NAK.   Eventually the 
test program would supply the string descriptor data and this 
would be returned to the host.  But this doesn't seem to be what 
happens.  It looks as if the hardware returns a ZLP immediately.  
The host isn't satisfied with this, and looking at the host-end 
code it retries a few times, then tries again asking for only 2 
bytes (there's a comment about broken devices), and eventually 
gives up.

I think that the ZLP is coming from this code in net2280.c, 
function handle_ep_small:

        if (unlikely (ep->num == 0)) {
                if (ep->is_in) {
..
                        /* reply to extra IN data tokens with a zlp */
                        } else if (t & (1 << DATA_IN_TOKEN_INTERRUPT)) {
..
                                } else if (!req && !ep->stopped) {
                                        write_fifo (ep, NULL);


If I correctly understand what is going on, the comment isn't 
consistent with how this code is actually reached: as well as 
possible "extra" IN data tokens, it is being reached for IN data
tokens that arrive before the data is ready.

Some debug traces follow. These aren't all from the same run 
so don't try to aligning the timestamps. First, here's what the 
host reports in syslog.  Note the string descriptor read failure.

Dec 20 14:18:12 egypt kernel: usb 4-4: new high speed USB device using ehci_hcd 
and address 16
Dec 20 14:18:12 egypt kernel: ehci_hcd 0000:00:10.3: port 4 high speed
Dec 20 14:18:12 egypt kernel: ehci_hcd 0000:00:10.3: GetStatus port 4 status 
001005 POWER sig=se0 PE CONNECT
Dec 20 14:18:12 egypt kernel: usb 4-4: string descriptor 0 read error: -22
Dec 20 14:18:12 egypt last message repeated 2 times

Here's a corresponding usbmon output, note the ZLPs returned 
quickly to the string descriptor read requests.

d934e3e0 3364486262 S Ci:007:00 s 80 06 0100 0000 0012 18 <
d934e3e0 3364488382 C Ci:007:00 0 18 = 12010002 ff000040 2505a4a4 00010102 0301
d934e3e0 3364488401 S Ci:007:00 s 80 06 0200 0000 0009 9 <
d934e3e0 3364488506 C Ci:007:00 0 9 = 09022700 010304c0 01
d934e3e0 3364488517 S Ci:007:00 s 80 06 0200 0000 0027 39 <
d934e3e0 3364488632 C Ci:007:00 0 39 = 09022700 010304c0 01090400 0003ff00 
00050705 87020002 00070503 02000201
d934e3e0 3364488656 S Ci:007:00 s 80 06 0300 0000 00ff 255 <
d934e3e0 3364488757 C Ci:007:00 0 0
d934e3e0 3364488766 S Ci:007:00 s 80 06 0300 0000 00ff 255 <
d934e3e0 3364488881 C Ci:007:00 0 0
d934e3e0 3364488890 S Ci:007:00 s 80 06 0300 0000 00ff 255 <
d934e3e0 3364489006 C Ci:007:00 0 0
d934e3e0 3364489016 S Ci:007:00 s 80 06 0300 0000 0002 2 <
d934e3e0 3364489131 C Ci:007:00 0 0
d934e3e0 3364489140 S Ci:007:00 s 80 06 0300 0000 0002 2 <
d934e3e0 3364489256 C Ci:007:00 0 0
d934e3e0 3364489265 S Ci:007:00 s 80 06 0300 0000 0002 2 <
d934e3e0 3364489382 C Ci:007:00 0 0
d934e3e0 3364489406 S Ci:007:00 s 80 06 0300 0000 00ff 255 <
d934e3e0 3364489507 C Ci:007:00 0 0
d934e3e0 3364489518 S Ci:007:00 s 80 06 0300 0000 00ff 255 <

There is more of the same before it eventually gives up.

On the machine with the net2280 card I have added more debug 
to both the of the modules.  It starts with connection and 
the descriptors that the kernel knows about are read OK:

Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: high speed
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0100 i0000 
l0012ep_cfg 00040480
Dec 20 14:21:00 haiti kernel: gadgetfs: connected
Dec 20 14:21:00 haiti kernel: gadgetfs: ev 1, next 1
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 queue req cafe9180, len 
18 buf cb5ad90e
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=18 
req->actual=0
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 18 
bytes (short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01080001, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 00040425, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=18 
req->actual=18
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01020002, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01000002, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0200 i0000 
l0009ep_cfg 00040480
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 queue req cafe9180, len 
9 buf cb5ad8e7
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=9 
req->actual=0
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 9 bytes 
(short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 000c0425, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=9 
req->actual=9
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01020002, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01000002, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0200 i0000 
l0027ep_cfg 00040480
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 queue req cafe9180, len 
39 buf cb5ad8e7
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=39 
req->actual=0
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 39 
bytes (short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 000c0425, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write_fifo req->length=39 
req->actual=39
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01020002, 
req cafe9180
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01000002, 
req 00000000

Now a request for a string descriptor is sent:

Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0300 i0000 
l00ffep_cfg 00040480
Dec 20 14:21:00 haiti kernel: gadgetfs: delegate req80.06 v0300 i0000 l255
Dec 20 14:21:00 haiti kernel: gadgetfs: ev 3, next 2

The test program is still thinking about this when an interrupt arrives:

Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 00080401, 
req 00000000

0x00080401 = DATA_IN_TOKEN_INTERRUPT | FIFO_EMPTY | USB_IN_NAK_SENT
I think it should continue to send NAKs, but it follows the path
described above and sends a ZLP.

Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: calling write_fifo with a 
NULL req
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 000c0425, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: calling write_fifo with a 
NULL req
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01020002, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01000002, 
req 00000000

Now the host retries.

Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0300 i0000 
l00ffep_cfg 00040480
Dec 20 14:21:00 haiti kernel: gadgetfs: delegate req80.06 v0300 i0000 l255
Dec 20 14:21:00 haiti kernel: gadgetfs: discard old event 3
Dec 20 14:21:00 haiti kernel: gadgetfs: ev 3, next 2
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 00080401, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: calling write_fifo with a 
NULL req
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 000c0425, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: calling write_fifo with a 
NULL req
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: write ep0 fifo (IN) 0 bytes 
(short) req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01020002, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: ep0 ack ep_stat 01000002, 
req 00000000
Dec 20 14:21:00 haiti kernel: net2280 0000:00:08.0: setup 80.06 v0300 i0000 
l00ffep_cfg 00040480

etc. etc.

Do let me know if there is any more debug I can supply.

Any thoughts anyone?  What I'd really like to know is: what path 
should it take when it gets an interrupt when it is still waiting 
for data from gadgetfs / userland?

Cheers,

Phil.



-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys - and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
linux-usb-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel

Reply via email to