none
WinUSB_ReadPipe returns ERROR_IO_PENDING and WinUSB_GetOverlappedResult returns Error code 31 RRS feed

  • Question

  • I am using a device for measurement purpose.I have an Application which uses this device and sends commands to get the data from the device.All works fine till here,I send command and get response and notifications from device.

     But after sometime WinUSB_ReadPipe returns ERROR_IO_PENDING and WinUSB_GetOverlappedResult returns  Error code 31(a device attached to the system is not functioning properly)and all the communication stops .To again start the communication I have to manually reset(switch off and on again) the device.

    Device uses WinUSB as its device driver on Win7 64 bit and this problem is occuring only in win7 not in WinXP(which uses custom device driver).And operations are done in Admin mode.

    Any helpful comments are welcome

    Thanks in Advance.

    • Edited by Vipin1_44 Thursday, March 28, 2013 9:41 AM
    Thursday, March 28, 2013 9:29 AM

Answers

  • Looks like your device is not compliant with the basic on the wire transfer protocol.

    d -- This posting is provided "AS IS" with no warranties, and confers no rights.

    Tuesday, April 2, 2013 3:41 AM

All replies

  • Hi,

    I did some debug tracing for winusb  and I am providing logs below.I am not able to figure out what "Transfer was terminated by a short packet" means and how to handle it.

    My application stopped working after this log.

    Can you tell what could be the problem and possible solution.

    Thanks in advance.

    [0]1120.0F70::04/01/2013-16:04:35.403 - IOCTL_WINUSB_READ_PIPE
    [0]1120.0F70::04/01/2013-16:04:35.403 - PIPE130: (000109dd) The read has been added to the read queue
    [0]1120.0F70::04/01/2013-16:04:35.403 - PIPE130: (000109dd) The read for 256 bytes is being handled
    [0]1120.0F70::04/01/2013-16:04:35.403 - PIPE130: (000109dd) Reading 256 bytes from the device
    [0]08B8.12F8::04/01/2013-16:04:35.404 - PIPE130: (000109dd) Read request for 256 bytes has completed with 256 bytes
    [0]1120.0F70::04/01/2013-16:04:35.406 - IOCTL_WINUSB_READ_PIPE
    [0]1120.0F70::04/01/2013-16:04:35.406 - PIPE130: (000109de) The read has been added to the read queue
    [0]1120.0F70::04/01/2013-16:04:35.406 - PIPE130: (000109de) The read for 256 bytes is being handled
    [0]1120.0F70::04/01/2013-16:04:35.406 - PIPE130: (000109de) Reading 256 bytes from the device
    [0]08B8.0220::04/01/2013-16:04:35.407 - PIPE130: (000109de) Read request for 256 bytes has completed with 256 bytes
    [1]1120.0F70::04/01/2013-16:04:35.409 - IOCTL_WINUSB_READ_PIPE
    [1]1120.0F70::04/01/2013-16:04:35.409 - PIPE130: (000109df) The read has been added to the read queue
    [1]1120.0F70::04/01/2013-16:04:35.409 - PIPE130: (000109df) The read for 256 bytes is being handled
    [1]1120.0F70::04/01/2013-16:04:35.409 - PIPE130: (000109df) Reading 256 bytes from the device
    [0]08B8.0220::04/01/2013-16:04:35.409 - PIPE130: (000109df) Transfer was terminated by a short packet
    [0]08B8.0220::04/01/2013-16:04:35.409 - PIPE130: (000109df) Read request for 256 bytes has completed with 19 bytes
    [0]1120.0F70::04/01/2013-16:04:35.413 - IOCTL_WINUSB_READ_PIPE
    [0]1120.0F70::04/01/2013-16:04:35.413 - PIPE130: (000109e0) The read has been added to the read queue
    [0]1120.0F70::04/01/2013-16:04:35.413 - PIPE130: (000109e0) The read for 256 bytes is being handled
    [0]1120.0F70::04/01/2013-16:04:35.413 - PIPE130: (000109e0) Reading 256 bytes from the device
    [0]0000.0000::04/01/2013-16:04:35.500 - PIPE130: (000109e0) Request failed with status 0xc0000001(STATUS_UNSUCCESSFUL)
    [0]0000.0000::04/01/2013-16:04:35.500 - PIPE130: (000109e0) Read request for 256 bytes has completed with 0 bytes
    [2]1120.1214::04/01/2013-16:04:37.152 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:37.152 - PIPE2: (000109e1) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:37.152 - PIPE2: (000109e1) The write is being handled
    [2]1120.1214::04/01/2013-16:04:37.152 - PIPE2: (000109e1) Writing 10 bytes to the device
    [0]1120.0E00::04/01/2013-16:04:37.152 - PIPE2: (000109e1) Write request for 10 bytes has completed
    [2]1120.1214::04/01/2013-16:04:40.158 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:40.158 - PIPE2: (000109e2) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:40.158 - PIPE2: (000109e2) The write is being handled
    [2]1120.1214::04/01/2013-16:04:40.158 - PIPE2: (000109e2) Writing 10 bytes to the device
    [0]1120.1190::04/01/2013-16:04:40.158 - PIPE2: (000109e2) Write request for 10 bytes has completed
    [0]1120.0F70::04/01/2013-16:04:40.501 - IOCTL_WINUSB_READ_PIPE
    [0]1120.0F70::04/01/2013-16:04:40.501 - PIPE130: (000109e3) The read has been added to the read queue
    [0]1120.0F70::04/01/2013-16:04:40.501 - PIPE130: (000109e3) The read for 256 bytes is being handled
    [0]1120.0F70::04/01/2013-16:04:40.501 - PIPE130: (000109e3) Reading 256 bytes from the device
    [2]1120.1214::04/01/2013-16:04:43.162 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:43.162 - PIPE2: (000109e4) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:43.162 - PIPE2: (000109e4) The write is being handled
    [2]1120.1214::04/01/2013-16:04:43.162 - PIPE2: (000109e4) Writing 9 bytes to the device
    [0]0000.0000::04/01/2013-16:04:43.162 - PIPE2: (000109e4) Write request for 9 bytes has completed
    [2]1120.1214::04/01/2013-16:04:46.169 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:46.169 - PIPE2: (000109e5) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:46.169 - PIPE2: (000109e5) The write is being handled
    [2]1120.1214::04/01/2013-16:04:46.169 - PIPE2: (000109e5) Writing 10 bytes to the device
    [0]0000.0000::04/01/2013-16:04:46.170 - PIPE2: (000109e5) Write request for 10 bytes has completed
    [2]1120.1214::04/01/2013-16:04:49.175 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:49.175 - PIPE2: (000109e6) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:49.175 - PIPE2: (000109e6) The write is being handled
    [2]1120.1214::04/01/2013-16:04:49.175 - PIPE2: (000109e6) Writing 10 bytes to the device
    [0]0000.0000::04/01/2013-16:04:49.176 - PIPE2: (000109e6) Write request for 10 bytes has completed
    [2]1120.1214::04/01/2013-16:04:52.179 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:52.179 - PIPE2: (000109e7) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:52.179 - PIPE2: (000109e7) The write is being handled
    [2]1120.1214::04/01/2013-16:04:52.179 - PIPE2: (000109e7) Writing 9 bytes to the
    [0]0000.0000::04/01/2013-16:04:52.179 - PIPE2: (000109e7) Write request for 9 bytes has completed
    [2]1120.1214::04/01/2013-16:04:55.336 - IOCTL_WINUSB_WRITE_PIPE
    [2]1120.1214::04/01/2013-16:04:55.336 - PIPE2: (000109e8) The write has been added to the write queue
    [2]1120.1214::04/01/2013-16:04:55.336 - PIPE2: (000109e8) The write is being handled
    [2]1120.1214::04/01/2013-16:04:55.336 - PIPE2: (000109e8) Writing 10 bytes to the device
    [0]0DA0.133C::04/01/2013-16:04:55.336 - PIPE2: (000109e8) Write request for 10 bytes has completed
    [0]1120.0F70::04/01/2013-16:04:55.919 - Enter: WinUSB_CancelRead
    [0]1120.0F70::04/01/2013-16:04:55.919 - Exit: WinUSB_CancelRead
    [0]0DA0.0E84::04/01/2013-16:04:55.919 - PIPE130: (000109e3) Request failed with status 0xc0000120(STATUS_CANCELLED)
    [0]0DA0.0E84::04/01/2013-16:04:55.919 - PIPE130: (000109e3) Read request for 256 bytes has completed with 0 bytes
    [3]1120.07CC::04/01/2013-16:04:55.957 - Purging pipe: xFFFFFA8009FA2BE0 pipe queue: x0000057FF530BFD8
    [3]1120.07CC::04/01/2013-16:04:55.957 - Purging pipe: xFFFFFA800820F680 pipe queue: x0000057FF530B3A8
    [3]1120.07CC::04/01/2013-16:04:55.957 - Purging pipe: xFFFFFA800820F680 pipe raw io queue: x0000057FF530B778
    [3]1120.07CC::04/01/2013-16:04:55.957 - Enter: WinUSB_InitControlPipe
    [3]1120.07CC::04/01/2013-16:04:55.957 - Exit: WinUSB_InitControlPipe (STATUS_SUCCESS)


    • Edited by Vipin1_44 Monday, April 1, 2013 12:50 PM
    Monday, April 1, 2013 12:46 PM
  • Looks like your device is not compliant with the basic on the wire transfer protocol.

    d -- This posting is provided "AS IS" with no warranties, and confers no rights.

    Tuesday, April 2, 2013 3:41 AM
  • Hi,

    My device was working fine for nearly 2 hours and then I got error_gen_failure meaning device is not functioning properly. These logs are of last 2 minutes. After manual reset device, it is again working fine.

    Frequency of this problem is more in win7 which uses WinUSB.

    Frequency of this problem is less in WinXP which uses custom driver.

    Tuesday, April 2, 2013 12:29 PM
  • but no matter which driver, the problem still exists. I would say the increase in frequency has everything to do with the fact that the win7 usb core stack is much more strict about compliance than the XP core was. as such, on win7, your firmware issues show up more often and if you used your own driver, you would see the same relative frequency that you do with winusb. end of story: fix your device.

    d -- This posting is provided "AS IS" with no warranties, and confers no rights.

    Tuesday, April 2, 2013 4:48 PM
  • "Short packet" means the device returned a packet containing less bytes than the endpoint's MaxPacketSize. This is not an error unless your specific device is never expected to return a short packet.

    The error is this line: 

    [0]0000.0000::04/01/2013-16:04:35.500 - PIPE130: (000109e0) Request failed with status 0xc0000001(STATUS_UNSUCCESSFUL)

    Unfortunately, this line dosen't contain the USBD status code. You will need to take a USB ETW trace or a bus analyzer trace to dig into what happened at the bus level.

    As Doron said, I would expect a custom driver to encounter the same bus error that WinUSB is encountering here.

    Tuesday, April 2, 2013 7:04 PM