WinUSB not responding properly to 0 byte packets

NTDEV
1

I have a device that attaches using the WinUSB driver and exposes a 16 byte Bulk in and a 16 byte Bulk out endpoint. The size of the messages, sent or received could be any arbitrary length (up to 64 bytes), but I don’t have enough RAM on my ?C to build to 64 byte buffers, consequently I have exchange all messages in 16 byte increments. This was first coded as:
success = WinUsb_ReadPipe(myDevInfo.winUsbHandle, _
pipeID, _
buffer, _
bytesToRead, _
bytesRead, _
IntPtr.Zero)

Where buffer is a byte array of size 64, and bytesToRead is ‘64’. Read pipe policies are set to IGNORE_SHORT_PACKETS = False, and Timeout = 2000 (2s). Attempting to receiving a 16 byte message resulted in an error 121=semaphore timeout. Using Don Miller’s WinUSB trace provider I generated the following trace:

[1]0F80.0CDC::06/09/2010-16:04:33.296 - IOCTL_WINUSB_WRITE_PIPE
[1]0F80.0CDC::06/09/2010-16:04:33.296 - PIPE1: (00000010) The write has been added to the write queue
[1]0F80.0CDC::06/09/2010-16:04:33.296 - PIPE1: (00000010) The write is being handled
[1]0F80.0CDC::06/09/2010-16:04:33.296 - PIPE1: (00000010) Writing 5 bytes to the device
[1]0F80.04F0::06/09/2010-16:04:33.296 - IOCTL_WINUSB_READ_PIPE
[1]0F80.04F0::06/09/2010-16:04:33.296 - PIPE129: (00000011) The read has been added to the read queue
[1]0F80.04F0::06/09/2010-16:04:33.296 - PIPE129: (00000011) The read for 64 bytes is being handled
[1]0F80.04F0::06/09/2010-16:04:33.296 - PIPE129: (00000011) Reading 64 bytes from the device
[1]0F80.0CDC::06/09/2010-16:04:43.780 - IOCTL_WINUSB_WRITE_PIPE
[1]0F80.0CDC::06/09/2010-16:04:43.780 - PIPE1: (00000012) The write has been added to the write queue
[1]0F80.0CDC::06/09/2010-16:04:43.780 - PIPE1: (00000012) The write is being handled
[1]0F80.0CDC::06/09/2010-16:04:43.780 - PIPE1: (00000012) Writing 15 bytes to the device
[1]0F80.0CDC::06/09/2010-16:04:48.061 - IOCTL_WINUSB_WRITE_PIPE
[1]0F80.0CDC::06/09/2010-16:04:48.061 - PIPE1: (00000014) The write has been added to the write queue
[1]0F80.0CDC::06/09/2010-16:04:48.061 - PIPE1: (00000014) The write is being handled
[1]0F80.0CDC::06/09/2010-16:04:48.061 - PIPE1: (00000014) Writing 16 bytes to the device
[1]0004.0180::06/09/2010-16:04:50.061 - PIPE129: (00000015) Request failed with status 0xc00000b5(STATUS_IO_TIMEOUT)
[1]0004.0180::06/09/2010-16:04:50.061 - PIPE129: (00000015) Read request for 64 bytes has completed with 16 bytes
[0]0000.0000::06/09/2010-16:04:33.296 - PIPE1: (00000010) Write request for 5 bytes has completed
[0]0F80.0CDC::06/09/2010-16:04:33.311 - PIPE129: (00000011) Transfer was terminated by a short packet
[0]0F80.0CDC::06/09/2010-16:04:33.311 - PIPE129: (00000011) Read request for 64 bytes has completed with 5 bytes
[0]0000.0000::06/09/2010-16:04:43.780 - PIPE1: (00000012) Write request for 15 bytes has completed
[0]0F80.04F0::06/09/2010-16:04:43.780 - IOCTL_WINUSB_READ_PIPE
[0]0F80.04F0::06/09/2010-16:04:43.780 - PIPE129: (00000013) The read has been added to the read queue
[0]0F80.04F0::06/09/2010-16:04:43.780 - PIPE129: (00000013) The read for 64 bytes is being handled
[0]0F80.04F0::06/09/2010-16:04:43.780 - PIPE129: (00000013) Reading 64 bytes from the device
[0]0F80.0CDC::06/09/2010-16:04:43.780 - PIPE129: (00000013) Transfer was terminated by a short packet
[0]0F80.0CDC::06/09/2010-16:04:43.780 - PIPE129: (00000013) Read request for 64 bytes has completed with 15 bytes
[0]0000.0000::06/09/2010-16:04:48.061 - PIPE1: (00000014) Sending a zero length packet to terminate the transfer
[0]0000.0000::06/09/2010-16:04:48.061 - PIPE1: (00000014) Writing 0 bytes to the device
[0]0000.0000::06/09/2010-16:04:48.061 - PIPE1: (00000014) Write request for 16 bytes has completed
[0]0F80.04F0::06/09/2010-16:04:48.061 - IOCTL_WINUSB_READ_PIPE
[0]0F80.04F0::06/09/2010-16:04:48.061 - PIPE129: (00000015) The read has been added to the read queue
[0]0F80.04F0::06/09/2010-16:04:48.061 - PIPE129: (00000015) The read for 64 bytes is being handled
[0]0F80.04F0::06/09/2010-16:04:48.061 - PIPE129: (00000015) Reading 64 bytes from the device
[0]0F80.04F0::06/09/2010-16:04:51.343 - Purging pipe: x85677110 pipe queue: x7ACB9FE8
[0]0F80.04F0::06/09/2010-16:04:51.343 - Purging pipe: x856BDD48 pipe queue: x7A914BA8
[0]0F80.04F0::06/09/2010-16:04:51.358 - Enter: WinUSB_InitControlPipe
[0]0F80.04F0::06/09/2010-16:04:51.358 - Exit: WinUSB_InitControlPipe (STATUS_SUCCESS)

Transaction 15 ends in a timout error, but 16 bytes were recieved. Clearly WinUSB_readpipe cannot handle a message that is shorter than the requested number of bytes *and* equal to the endpoint size. Whether or not a 0 byte frame is sent after the endpoint sized message.

So, I recoded to break the message up into endpoint sized message, *or smaller*:

If bytesToRead > myDevInfo.bulkInPipeSize Then

For i As UInt32 = 0 To bytesToRead Step myDevInfo.bulkInPipeSize
success = WinUsb_ReadPipe(myDevInfo.winUsbHandle, _
pipeID, _
FractionalBuffer, _
myDevInfo.bulkInPipeSize, _
BytesReadNow, _
IntPtr.Zero)

If success Then

System.Buffer.BlockCopy(FractionalBuffer, 0, buffer, CType(i, Integer), CType(BytesReadNow, Integer))
bytesRead = bytesRead + BytesReadNow

If BytesReadNow < myDevInfo.bulkInPipeSize Then
Exit For
End If
Else
Exit For
End If

Next

End If

The endpoint policies are the same, and FractionalBuffer is defined as myDevInfo.bulkInPipeSize (16). The fact that the Visual Studio 2008 doesn’t provide a way to append arrays was a shock, but I was able to make the buffer.blockmove work.
This also fails a 16 byte message with an error 121=semaphore timeout. The WinUSB trace provider produced the following file:

1]17C4.1160::06/11/2010-09:33:23.611 - Create succeeded
[1]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[1]17C4.1160::06/11/2010-09:33:23.627 - IOCTL_WINUSB_GET_DESCRIPTOR
[1]17C4.1160::06/11/2010-09:33:23.627 - IOCTL_WINUSB_QUERY_DEVICE_INFORMATION
[1]17C4.1160::06/11/2010-09:33:33.064 - IOCTL_WINUSB_WRITE_PIPE
[1]17C4.1160::06/11/2010-09:33:33.064 - PIPE1: (0000000f) The write has been added to the write queue
[1]17C4.1160::06/11/2010-09:33:33.064 - PIPE1: (0000000f) The write is being handled
[1]17C4.1160::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Writing 16 bytes to the device
[1]17C4.07D4::06/11/2010-09:33:33.080 - IOCTL_WINUSB_READ_PIPE
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000010) The read has been added to the read queue
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000010) The read for 16 bytes is being handled
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000010) Reading 16 bytes from the device
[1]17C4.07D4::06/11/2010-09:33:33.080 - IOCTL_WINUSB_READ_PIPE
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000011) The read has been added to the read queue
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000011) The read for 16 bytes is being handled
[1]17C4.07D4::06/11/2010-09:33:33.080 - PIPE129: (00000011) Reading 16 bytes from the device
[1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Request failed with status 0xc00000b5(STATUS_IO_TIMEOUT)
[1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Read request for 16 bytes has completed with 0 bytes
[1]17C4.07D4::06/11/2010-09:33:36.018 - Purging pipe: x853807E8 pipe queue: x7AC4DB48
[1]17C4.07D4::06/11/2010-09:33:36.018 - Purging pipe: x851B8230 pipe queue: x7AC43FE8
[1]17C4.07D4::06/11/2010-09:33:36.018 - Enter: WinUSB_InitControlPipe
[1]17C4.07D4::06/11/2010-09:33:36.018 - Exit: WinUSB_InitControlPipe (STATUS_SUCCESS)
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_VERSION_EXCHANGE
[0]17C4.1160::06/11/2010-09:33:23.611 - Enter: WinUSB_ExchangeVersion
[0]17C4.1160::06/11/2010-09:33:23.611 - Exit: WinUSB_ExchangeVersion (STATUS_SUCCESS)
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_RESET_DEFAULTS
[0]17C4.1160::06/11/2010-09:33:23.611 - Enter: WinUSB_InitControlPipe
[0]17C4.1160::06/11/2010-09:33:23.611 - Exit: WinUSB_InitControlPipe (STATUS_SUCCESS)
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_SET_PIPE_POLICY
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_SET_PIPE_POLICY
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_SET_PIPE_POLICY
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_SET_PIPE_POLICY
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[0]17C4.1160::06/11/2010-09:33:23.611 - IOCTL_WINUSB_GET_DESCRIPTOR
[0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Sending a zero length packet to terminate the transfer
[0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Writing 0 bytes to the device
[0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Write request for 16 bytes has completed
[0]17C4.1160::06/11/2010-09:33:33.080 - PIPE129: (00000010) Read request for 16 bytes has completed with 16 bytes

Transaction 11 fails due to a timeout, but the bytes received was 0. Since my code is looking for a *succesful* message size of < 16 to terminate assembling the complete message, my code fails.

This appears to be a bug in WinUSB (?), whereby a 0 length message is *not* recognized as a short packet (1- 15 is however), and so WinUSB_readpipe returns a fail, when it should return a success?
Actually, WinUSB_readpipe should implement the algorithm in my second set of code, and automagically assemble the message from 16 byte or less pieces. But, I’ve coded around that in my application (Whither array.append??). However, I cannot code around the fact that a legitimate 0 lenght packet read causes WinUSB_readpipe to fail???
There will be those here who ask why not just request the number of bytes that equals the message size? As I explained the message size can be any arbitrary size up to 64 bytes, which I don’t know, a priori. There will those who ask why not make the endpoint size 64 bytes? As I explained my device doesn’t have those kind of resources.
So, either I’ve missed something in the pipe policies, or returning ‘fail’ for a legitimate 0 packet transaction is a bug. I’m open to being wrong (it wouldn’t be the first time. Today even), but I honestly don’t see how make this happen if WinUSB_readpipe is going to call this a failure?

2

In the case where the amount of data transferred on the bus is less
than the requested transfer size *and* the amount of data transferred
is an exact multiple of the endpoint MaxPacketSize *and* the transfer
is not terminated on the bus with a zero length data packet then no
driver (WinUSB or otherwise) can handle that condition and magically
detect that the transfer has ended, without resorting to some sort of
transfer timeout mechanism.

If the transfer is terminated on the bus with a zero length data
packet then that should complete the transfer request. If that is not
happening in the case of your usage of WinUSB I am not sure what is
happening there.

-Glen

3

Glen:
My device is currently in debug mode, it just echoes the packets sent by the host. The following trace entry shows the 0 byte packet being sent to the device:

[0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Sending a zero length packet to terminate the transfer [0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Writing 0 bytes to the device

I can trap, in my device code, showing that the 0 byte transfer is being echoed. In addition the actual error line in the trace:

[1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Request failed with status 0xc00000b5(STATUS_IO_TIMEOUT) [1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Read request for 16 bytes has completed with 0 bytes

Shows that the 0 byte packet was received. The problem is that the read only completed with the timeout, and so report ‘fail’. This is in itself a violation of the USB spec., and is causing me heartache as well.
I believe that WinUSB should report a succesful read for legitimate 0 byte packets?

4

On 6/12/2010 3:29 PM, xxxxx@earthlink.net wrote:

Glen:
My device is currently in debug mode, it just echoes the packets sent by the host. The following trace entry shows the 0 byte packet being sent to the device:

[0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Sending a zero length packet to terminate the transfer [0]0000.0000::06/11/2010-09:33:33.064 - PIPE1: (0000000f) Writing 0 bytes to the device

I can trap, in my device code, showing that the 0 byte transfer is being echoed.

How is it being echoed? May I ask which USB microcontroller you are
using? The FX2, for example, requires special register setup in order
to send a zero-length packet. Remember, there is a BIG difference
between “sending nothing” and “sending a zero-length packet”. A
zero-length packet is a complete USB response that happens to carry no
payload.

In addition the actual error line in the trace:

[1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Request failed with status 0xc00000b5(STATUS_IO_TIMEOUT) [1]0004.0188::06/11/2010-09:33:35.080 - PIPE129: (00000011) Read request for 16 bytes has completed with 0 bytes

Shows that the 0 byte packet was received.

No, it doesn’t. Think about it for a moment – you would get that exact
same message if your device had simply not responded at all.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

5

Tim:
Yes, I concede your point, if my device had not responded, it would result in a timeout with 0 bytes received.
I’m using a PIC18F2458 and the CCS USB stack:

#ifdef DEBUG // Debug mode just echos data back over the USB link
if((CurrentChar <= ReceiveSize) && !(0xFF == ReceiveSize))// While there’s data in the input buffer…
{
if (!(0 == ReceiveSize))
{
For (CurrentChar = 0;CurrentChar <= ReceiveSize;CurrentChar++)
{
oBuff[CurrentChar] = iBuff[CurrentChar];// Move data that came in to output buffer
}
}
CurrentChar = 0;
SendSize = ReceiveSize;
ReceiveSize = 0xFF;

If (0 == SendSize)
sendstatus = usb_put_packet(1,oBuff,(int16)0,USB_DTS_TOGGLE);// Echo incoming data
else
sendstatus = usb_put_packet(1,oBuff,(int16)SendSize,USB_DTS_TOGGLE);// Echo incoming data

SendSize = 0xFF;
}
else
{
if (usb_kbhit(1)&& (0xFF == ReceiveSize)) // Endpoint 1 receive has data, and buffer empty?
ReceiveSize = usb_get_packet(1, iBuff, USB_EP1_RX_SIZE);// Read 16 byte packet from Endpoint 1 receive
}
#endif

I can trap in the debugger on:

sendstatus = usb_put_packet(1,oBuff,(int16)0,USB_DTS_TOGGLE);// Echo incoming data

and I only execute this line if I send a endpoint buffer sized message (16 bytes) with the out endpoint policy set to “SHORT_PACKET_TERMINATE = TRUE”, since the default is not to send 0 byte packets when the message size equals the endpoint size (?? as I said before this is a violation of the USB spec.).

I don’t have access to a USB hardware buss sniffer, so I can’t prove that my device sent the 0 byte packet, but I’m pretty convinced it is as the DATA0/1 toggled.

The best answer is that I screwed up, as I can fix that immediately. But from the threadbare dox on the pipepolicies I can’t figure out what I could have done wrong?
By-the-bye, a quick search of the web will turn many references to a SEMAPHORE_TIMEOUT (error code 121) with WinUSB, it seems to be the number one problem people encounter (?).

Perhaps, I’m not supposed to toggle DTS on the 0 byte packet? But WinUSB trace didn’t complain about a link layer error, it just timed out?

ghb

6

On 6/14/2010 1:27 PM, xxxxx@earthlink.net wrote:

Tim:
Yes, I concede your point, if my device had not responded, it would result in a timeout with 0 bytes received.
I’m using a PIC18F2458 and the CCS USB stack:
…
If (0 == SendSize)
sendstatus = usb_put_packet(1,oBuff,(int16)0,USB_DTS_TOGGLE);// Echo incoming data
else
sendstatus = usb_put_packet(1,oBuff,(int16)SendSize,USB_DTS_TOGGLE);// Echo incoming data

Are you confident that usb_put_packet, when handed a length of 0,
actually commits a packet to the bus? I’m not familiar with the CCS
stack; I’ve done PIC 18F4550 stuff, but I used Microchip’s stack.

(Actually, I found a version of pic18_usb.c on the web that looks like
it should actually commit a packet.)

sendstatus = usb_put_packet(1,oBuff,(int16)0,USB_DTS_TOGGLE);// Echo incoming data

and I only execute this line if I send a endpoint buffer sized message (16 bytes) with the out endpoint policy set to “SHORT_PACKET_TERMINATE = TRUE”, since the default is not to send 0 byte packets when the message size equals the endpoint size (?? as I said before this is a violation of the USB spec.).

No, it is NOT. I know the point you are trying to make here, but the
whole zero-length packet thing is just a convention of convenience.
There is nothing illegal about sending a full packet without following
it up with a zero-length packet. The ZLP is a useful convention if you
need to send messages of variable sizes, but it’s not the only way to
implement that.

Perhaps, I’m not supposed to toggle DTS on the 0 byte packet? But WinUSB trace didn’t complain about a link layer error, it just timed out?

Well, I’ve just about exhausted my clues. Glen says it should work, and
Glen would know.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

7

I went back and read what I said, which is this:

When I said that I was saying that based only on how I thought (and still think) it should would. I haven’t actually had time yet to go examine the WinUSB code and try to experimentally verify with a device that what I said matches reality.

In the meantime, if a USBPORT ETW trace is captured while the ZLP is sent to the device and should be echoed back by the device that could provide some additional debugging information.

-Glen

8

Tim:
I pretty confident, but without a buss sniff not 100%, that a 0 byte packet is being echoed. I’ve spoken to the author of the USB stack at CCS and he assures me that the 0 byte packet will be sent as advertised. Previous experience indicates he is always right about his code.

I know that section 5.8.3 of the spec says that I can terminate after receiving the the ‘expected’ amount of data. But I don’t know how much data to expect, other than it is less than or equal to 64 bytes. Therefore I need an end of data flag.

On a more general level, whether the channel is USB, RS232, I2C, etc. it is unwise to use byte counts to terminate a transaction. If either party disagrees on the byte count, the channel will hang. It is much more robust to use a semaphore, and keep sending or receiving data until the semaphore turns red. This way the error floats to the protocol layer, and the link layer isn’t broken.

Finally, the point is moot. I need the WinUSB driver to recognize a 0 byte packet with valid DTS, EOP and CRC as a *succesful* transaction. It is a succesful transaction, merits of its existence aside, and so should report a succesful, 0 byte transaction.

Glen:
Both the traces I posted had 0 bytes sent by the host (when the message size was 16) and this is in the trace.
In the second trace I had to break the receipt into 16 byte packets (instead of one 64 byte packet) because I thought that WinUSB wasn’t doing this (?). But if the real issue was the 0 byte packet, then perhaps that was wasted effort. In any event, 0 byte packets were sent, and theoretically echoed by the device?
The USB spec says that DTS is not supposed to toggle is an error occurrs, it is possible that there is something wrong with the 0 byte packet and the host is requesting resends until timeout. Since the device won’t change the contents of the packet or the DTS, if the first one was wrong so are the rest. But I can’t see this in the trace output and I don’t have access to a USB buss analyzer, so…
If you have suggestions, gbarbehenn-at-linear.com
ghb