512 bytes missing

[Felipe Balbi-3]

Hi,

I have a pair of applications using libusb to test my controller
driver and gadget driver. For some weird reasons libusb seems
to be missing 512 bytes after a few iterations of the test
application.

Here's the relevant part of the debug messages:

libusb:debug [bulk_transfer_cb] actual_length=2560
do_read:  7168 / 37648 bytes done, missing 30480 bytes
libusb_fill_bulk_transfer: filling bulk ep 82 length 30480
libusb_submit_transfer: submitting bulk ep 82 length 30480
libusb:debug [submit_bulk_transfer] need 2 urbs for new transfer with
length 30480
libusb:debug [libusb_get_next_timeout] next timeout in 0.999985s
libusb:debug [handle_events] poll() 2 fds with timeout in 1000ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=3 status=0 transferred=0
libusb:debug [handle_bulk_completion] handling completion status 0 of
bulk urb 1/2, actual 0
libusb:debug [handle_bulk_completion] short transfer 0/16384 --> complete!
libusb:debug [libusb_get_next_timeout] next timeout in 0.999727s
libusb:debug [handle_events] poll() 2 fds with timeout in 1000ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=3 status=-2 transferred=0
libusb:debug [handle_bulk_completion] handling completion status -2 of
bulk urb 2/2, actual 0
libusb:debug [handle_bulk_completion] abnormal reap: urb status -2
libusb:debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
libusb:debug [usbi_handle_transfer_completion]
usbi_handle_transfer_completion: actual_length 0

libusb:debug [bulk_transfer_cb] actual_length=0
do_read:  7168 / 37648 bytes done, missing 30480 bytes
libusb_fill_bulk_transfer: filling bulk ep 82 length 30480
libusb_submit_transfer: submitting bulk ep 82 length 30480
libusb:debug [submit_bulk_transfer] need 2 urbs for new transfer with
length 30480
libusb:debug [libusb_get_next_timeout] next timeout in 0.999990s
libusb:debug [handle_events] poll() 2 fds with timeout in 1000ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=3 status=0 transferred=512
libusb:debug [handle_bulk_completion] handling completion status 0 of
bulk urb 1/2, actual 0
libusb:debug [handle_bulk_completion] short transfer 512/16384 --> complete!
libusb:debug [libusb_get_next_timeout] next timeout in 0.999564s
libusb:debug [handle_events] poll() 2 fds with timeout in 1000ms
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=3 status=-2 transferred=1024
libusb:debug [handle_bulk_completion] handling completion status -2 of
bulk urb 2/2, actual 512
libusb:debug [handle_bulk_completion] abnormal reap: urb status -2
libusb:debug [handle_bulk_completion] received 1024 bytes of surplus data
libusb:debug [handle_bulk_completion] moving surplus data from offset
16384 to offset 512
libusb:debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
libusb:debug [usbi_handle_transfer_completion]
usbi_handle_transfer_completion: actual_length 1536

See that on the first block, libusb_bulk_transfer() gets zero bytes.
Why is the urb returning with
-ENOENT ?

What is this "received XXXX bytes of surplus data" ?

The pair of applications can be found in [1] client and [2] server

[1] http://gitorious.org/usb/usb-tools/blobs/serial/serialc.c
[2] http://gitorious.org/usb/usb-tools/blobs/serial/seriald.c

BTW, I'm pretty much sure the problem is on host side because seriald
already read()
and write() the correct total amount of data. From gadget driver logs, I see the
complete block reaches the gadget driver so tty isn't loosing anything and from
sniffer, I see the entire block reached host side.

My pc is running 2.6.29-1-686-bigmem (quite old but I have NVIDIA card and
I didn't spend time to get nouveau running, sorry)

--
Best Regards,

Felipe Balbi
felipebalbi@...

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[David Moore]

On Fri, 2009-11-06 at 12:45 +0200, Felipe Balbi wrote:
> Hi,
>
> I have a pair of applications using libusb to test my controller
> driver and gadget driver. For some weird reasons libusb seems
> to be missing 512 bytes after a few iterations of the test
> application.

> See that on the first block, libusb_bulk_transfer() gets zero bytes.

That probably means the urb received a packet of zero bytes.  Since that
is a short packet, it cancels the remaining urbs.

> Why is the urb returning with
> -ENOENT ?

The second urb got canceled when the first got the short packet.  The -2
indicates that the callback is happening only in response to being
canceled.

However, the libusb transfer is still "successful", it just has a size
of 0.

>
> What is this "received XXXX bytes of surplus data" ?
>

That's a bug in libusb and the kernel where the second urb got canceled,
but the cancel did not happen until after some data had already been
transferred into the urb.  As a result, even though there was a short
packet, the data got "smushed" together into a single transfer.

This bug has been fixed with libusb 1.0.4 or later and kernel 2.6.32-rc1
or later (you need both).

Alternatively, you can work around the bug by limiting your libusb
transfer size to 16k or less.

-David


------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Felipe Balbi-3]

Hi,

On Sat, Nov 7, 2009 at 6:44 AM, David Moore <dcm@...> wrote:
>> See that on the first block, libusb_bulk_transfer() gets zero bytes.
>
> That probably means the urb received a packet of zero bytes.  Since that
> is a short packet, it cancels the remaining urbs.

sure, I see the 0-length packets on the usb sniffer, but I also see
the actual data going through

>> Why is the urb returning with
>> -ENOENT ?
>
> The second urb got canceled when the first got the short packet.  The -2
> indicates that the callback is happening only in response to being
> canceled.

and this is probably why libusb doesn't see my extra packet coming since
the urb got cancelled, could it be ?

> However, the libusb transfer is still "successful", it just has a size
> of 0.

Still if you look at my application, I already know the size of the transfer
so I:

        while (done < bytes) {
                ret = libusb_bulk_transfer(serial->udevh, serial->eprx,
                                serial->rxbuf + done, bytes - done,
                                &transferred, TIMEOUT);
                if (ret < 0) {
                        DBG("%s: failed receiving %d/%d bytes\n",
__func__, done, bytes);
                        goto err;
                }
                done += transferred;
        }

(simplified version of the actual code).

Then shouldn't it mean that the host pc application would still fill
urbs until I reach
the total size of the transfers represented by "bytes" variable ?

> That's a bug in libusb and the kernel where the second urb got canceled,
> but the cancel did not happen until after some data had already been
> transferred into the urb.  As a result, even though there was a short
> packet, the data got "smushed" together into a single transfer.
>
> This bug has been fixed with libusb 1.0.4 or later and kernel 2.6.32-rc1
> or later (you need both).

I was expecting to hear that. I remember a discussion with Alan Stern
regarding adding a new ioctl to usbfs which sounded somehow related
to my problem.

I'll upgrade my kernel on monday and see if the problem persists. I'm guessing
not.

--
Best Regards,

Felipe Balbi
felipebalbi@...

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Daniel Drake]

Felipe Balbi wrote:
> and this is probably why libusb doesn't see my extra packet coming since
> the urb got cancelled, could it be ?

No - if the host accepts it then it should go all the way to libusb.
As a first step I would suggest looking at usbmon output and figuring
out if the missing 512 bytes is being seen there or not.

If you can see it there, then you can try and figure out into which URB
it fell into in libusb, and where libusb missed that.

Yes, upgrading to the new bits might help, but you may have found a
wider bug in libusb which would be good to solve and understand in any
event.

And to answer your other question about filling urbs - no, libusb will
(attempt to) terminate any incoming transfer as soon as it sees an
incomplete packet.

Daniel


------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Hans Petter Selasky]

On Saturday 07 November 2009 18:29:36 Daniel Drake wrote:
> if the host accepts it then it should go all the way to libusb.

If the data-toggle value is wrong, then the host will ack the packet and
silently drop it.

--HPS

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Tim Roberts]

Felipe Balbi wrote:

> Hi,
>
> On Sat, Nov 7, 2009 at 6:44 AM, David Moore <dcm@...> wrote:
>  
>>> See that on the first block, libusb_bulk_transfer() gets zero bytes.
>>>      
>> That probably means the urb received a packet of zero bytes.  Since that
>> is a short packet, it cancels the remaining urbs.
>>    
>
> sure, I see the 0-length packets on the usb sniffer, but I also see
> the actual data going through
>  

Except in very peculiar circumstances, this is a bad design choice in
your hardware.  A zero-length packet has a very specific meaning in USB
-- it means this whole "transfer" should be abruptly terminated.  If the
device merely has nothing to send, the proper response is for the device
to send a NAK.  The transfer will continue and the host will retry until
the request completes.

--
Tim Roberts, timr@...
Providenza & Boekelheide, Inc.


------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Felipe Balbi-3]

Hi,

On Mon, Nov 9, 2009 at 8:17 PM, Tim Roberts <timr@...> wrote:

> Felipe Balbi wrote:
>> Hi,
>>
>> On Sat, Nov 7, 2009 at 6:44 AM, David Moore <dcm@...> wrote:
>>
>>>> See that on the first block, libusb_bulk_transfer() gets zero bytes.
>>>>
>>> That probably means the urb received a packet of zero bytes.  Since that
>>> is a short packet, it cancels the remaining urbs.
>>>
>>
>> sure, I see the 0-length packets on the usb sniffer, but I also see
>> the actual data going through
>>
>
> Except in very peculiar circumstances, this is a bad design choice in
> your hardware.  A zero-length packet has a very specific meaning in USB
> -- it means this whole "transfer" should be abruptly terminated.  If the
> device merely has nothing to send, the proper response is for the device
> to send a NAK.  The transfer will continue and the host will retry until
> the request completes.

What I meant is:

1. host requests to read e.g. 64k
2. device has 32k ready so...
3. device sends 32k
4. device sends 0-length packet
5. host notes that the transfer is still not complete so,
6. host kicks more bulk transfers
7. device has 32k ready
8. device sends 32k
9. device sends 0-length packet
10. host is happy, transfer finishes...

This is behavior to protocols like acm and obex when built
on top of usb.

--
Best Regards,

Felipe Balbi
felipebalbi@...

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Tim Roberts]

Felipe Balbi wrote:

> What I meant is:
>
> 1. host requests to read e.g. 64k
> 2. device has 32k ready so...
> 3. device sends 32k
> 4. device sends 0-length packet
> 5. host notes that the transfer is still not complete so,
> 6. host kicks more bulk transfers
> 7. device has 32k ready
> 8. device sends 32k
> 9. device sends 0-length packet
> 10. host is happy, transfer finishes...
>
> This is behavior to protocols like acm and obex when built
> on top of usb.
>  

If the transfer was not complete, why did the device send a 0-length
packet in step 4?

I'm mostly arguing out of thin air, here.  I know there are specs that
read this way, but it's certainly NOT the kind of design one should use
if one is interesting in maximum throughput.

--
Tim Roberts, timr@...
Providenza & Boekelheide, Inc.


------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel

[Peter Stuge-4]

Felipe Balbi wrote:

> 1. host requests to read e.g. 64k
> 2. device has 32k ready so...
> 3. device sends 32k
> 4. device sends 0-length packet
> 5. host notes that the transfer is still not complete so,
> 6. host kicks more bulk transfers
> 7. device has 32k ready
> 8. device sends 32k
> 9. device sends 0-length packet
> 10. host is happy, transfer finishes...

The suggested alternative would be:

1. host requests to read e.g. 64k
2. device has 32k ready so...
3. device sends 32k
4. device has no more data so sends NAK
5. device has another 32k ready
6. device sends 32k
7. host is happy, transfer finishes...


Tim Roberts wrote:
> it's certainly NOT the kind of design one should use if one is
> interesting in maximum throughput.

Or minimum power consumption.

The 0-byte packet must involve every layer from the wire until the
application. It might even cause the host to wake up from sleep -
even though there is no data! NAKing could (at least in theory)
allow only the HC to be powered.

With the suggested alternative using NAKs each transfer is always
complete and valid data.


//Peter

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
_______________________________________________
Libusb-devel mailing list
Libusb-devel@...
https://lists.sourceforge.net/lists/listinfo/libusb-devel