libusb / libusb

A cross-platform library to access USB devices
https://libusb.info
GNU Lesser General Public License v2.1
5.32k stars 1.93k forks source link

libusb cannot recover after device unplug on Windows #297

Open ecejeff opened 7 years ago

ecejeff commented 7 years ago

I've got a device with 6 concurrent bulk transfers to the same endpoint. Sometimes when unplugging the device, libusb gets into a state where it cannot recover. On a fast computer (like my development PC), this happens maybe 10% of the time. On a slow computer it's closer to 100%. Tested on various systems and it definitely follows this trend.

Tested on Windows 7 64-bit and Windows XP 32-bit.

Seems to be an issue where the file descriptors and transfers get out of sync. Seems like a race condition to me.

Here's the beginning of the relevant log portion, where we can see a couple of successful transfers full of data. Everything is going great...

...
[43.002000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.506613s
[43.002000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.002000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.002000] [00001afc] libusb: debug [handle_events] poll() 7 fds with timeout in 100ms
[43.100000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.100000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[43.100000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 1
[43.100000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 0, size 22720
[43.100000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783D14 has callback 0F6F2EF0
[43.100000] [00001afc] libusb: debug [libusb_submit_transfer] transfer 00783D14
[43.100000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 83 with interface 0
[43.100000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] reading 22720 bytes
[43.100000] [00001afc] libusb: debug [usbi_add_pollfd] add fd 1 events 1
[43.101000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.505906s
[43.101000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.101000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.101000] [00001afc] libusb: debug [handle_events] poll() 7 fds with timeout in 100ms
[43.199000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.199000] [00001afc] libusb: debug [windows_handle_events] checking fd 2 with revents = 0001
[43.199000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 2
[43.199000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 0, size 22720
[43.199000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783C8C has callback 0F6F2EF0
[43.199000] [00001afc] libusb: debug [libusb_submit_transfer] transfer 00783C8C
[43.199000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 83 with interface 0
[43.199000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] reading 22720 bytes
[43.199000] [00001afc] libusb: debug [usbi_add_pollfd] add fd 2 events 1

At this point libusb realizes the device is gone, and calls 4 of the 6 callbacks with a stall error code. The remaining 2 transfers time out, and libusb tries to call AbortPipe, which fails (because the device is gone?).

[43.199000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.505905s
[43.199000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.199000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.199000] [00001afc] libusb: debug [handle_events] poll() 7 fds with timeout in 100ms
[43.231000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.232000] [00001afc] libusb: debug [windows_handle_events] checking fd 3 with revents = 0001
[43.232000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 3
[43.232000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 31, size 7104
[43.232000] [00001afc] libusb: debug [windows_transfer_callback] detected endpoint stall
[43.232000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783F34 has callback 0F6F2EF0
[43.232000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783F34
[43.232000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.571308s
[43.233000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.233000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.233000] [00001afc] libusb: debug [handle_events] poll() 6 fds with timeout in 100ms
[43.235000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.235000] [00001afc] libusb: debug [windows_handle_events] checking fd 4 with revents = 0001
[43.235000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 4
[43.235000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 31, size 0
[43.235000] [00001afc] libusb: debug [windows_transfer_callback] detected endpoint stall
[43.235000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783EAC has callback 0F6F2EF0
[43.235000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783EAC
[43.236000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.667623s
[43.236000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.236000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.236000] [00001afc] libusb: debug [handle_events] poll() 5 fds with timeout in 100ms
[43.236000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.236000] [00001afc] libusb: debug [windows_handle_events] checking fd 5 with revents = 0001
[43.236000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 5
[43.236000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 31, size 0
[43.236000] [00001afc] libusb: debug [windows_transfer_callback] detected endpoint stall
[43.236000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783E24 has callback 0F6F2EF0
[43.236000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783E24
[43.236000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.764705s
[43.236000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.236000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.236000] [00001afc] libusb: debug [handle_events] poll() 4 fds with timeout in 100ms
[43.238000] [00001afc] libusb: debug [handle_events] poll() returned 1
[43.238000] [00001afc] libusb: debug [windows_handle_events] checking fd 6 with revents = 0001
[43.238000] [00001afc] libusb: debug [usbi_remove_pollfd] remove fd 6
[43.238000] [00001afc] libusb: debug [windows_transfer_callback] handling I/O completion with errcode 31, size 0
[43.238000] [00001afc] libusb: debug [windows_transfer_callback] detected endpoint stall
[43.238000] [00001afc] libusb: debug [usbi_handle_transfer_completion] transfer 00783D9C has callback 0F6F2EF0
[43.238000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783D9C
[43.238000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.861276s
[43.239000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.239000] [00001afc] libusb: debug [handle_events] poll fds modified, reallocating
[43.239000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.339000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.339000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.761128s
[43.339000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.339000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.439000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.439000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.660725s
[43.439000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.439000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.539000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.539000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.561030s
[43.539000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.539000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.639000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.639000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.460627s
[43.639000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.639000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.739000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.739000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.360735s
[43.739000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.739000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.839000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.839000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.260588s
[43.839000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.839000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[43.939000] [00001afc] libusb: debug [handle_events] poll() returned 0
[43.939000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.160440s
[43.939000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[43.939000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[44.039000] [00001afc] libusb: debug [handle_events] poll() returned 0
[44.039000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.060548s
[44.039000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[44.039000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 61ms
[44.100000] [00001afc] libusb: debug [handle_events] poll() returned 0
[44.100000] [00001afc] libusb: debug [libusb_cancel_transfer] transfer 00783D14
[44.100000] [00001afc] libusb: debug [winusbx_abort_transfers] will use interface 0
[44.100000] [00001afc] libusb: error [winusbx_abort_transfers] AbortPipe failed: [22] The device does not recognize the command.
[44.100000] [00001afc] libusb: debug [libusb_cancel_transfer] cancel transfer failed error -4
[44.100000] [00001afc] libusb: warning [handle_timeout] async cancel failed -4 errno=0
[44.100000] [00001afc] libusb: debug [libusb_get_next_timeout] next timeout in 0.098359s
[44.101000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[44.101000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 99ms
[44.200000] [00001afc] libusb: debug [handle_events] poll() returned 0
[44.200000] [00001afc] libusb: debug [libusb_cancel_transfer] transfer 00783C8C
[44.200000] [00001afc] libusb: debug [winusbx_abort_transfers] will use interface 0
[44.200000] [00001afc] libusb: error [winusbx_abort_transfers] AbortPipe failed: [22] The device does not recognize the command.
[44.200000] [00001afc] libusb: debug [libusb_cancel_transfer] cancel transfer failed error -4
[44.200000] [00001afc] libusb: warning [handle_timeout] async cancel failed -4 errno=0
[44.200000] [00001afc] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
[44.200000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[44.200000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[44.300000] [00001afc] libusb: debug [handle_events] poll() returned 0
[44.300000] [00001afc] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
[44.300000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[44.300000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[44.400000] [00001afc] libusb: debug [handle_events] poll() returned 0
[44.400000] [00001afc] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
[44.400000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[44.400000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[44.500000] [00001afc] libusb: debug [handle_events] poll() returned 0
...

Repetitive parts of the log have been trimmed while I plug in the new device.

The new device is connected and then libusb gets into a state where it cannot recover. Complaining could not find a matching transfer for fd 1:

...
[50.606000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.606000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.706000] [00001afc] libusb: debug [handle_events] poll() returned 0
[50.706000] [00001afc] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
[50.706000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.706000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.806000] [00001afc] libusb: debug [handle_events] poll() returned 0
[50.807000] [00001afc] libusb: debug [libusb_alloc_transfer] transfer 00783D9C
[50.807000] [00001afc] libusb: debug [libusb_submit_transfer] transfer 00783D9C
[50.807000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 02 with interface 0
[50.807000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] writing 4 bytes
[50.807000] [00001afc] libusb: error [winusbx_submit_bulk_transfer] ReadPipe/WritePipe failed: [22] The device does not recognize the command.
[50.807000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783D9C
[50.808000] [00001afc] libusb: debug [libusb_alloc_transfer] transfer 00783D9C
[50.808000] [00001afc] libusb: debug [libusb_submit_transfer] transfer 00783D9C
[50.808000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] matched endpoint 02 with interface 0
[50.808000] [00001afc] libusb: debug [winusbx_submit_bulk_transfer] writing 4 bytes
[50.808000] [00001afc] libusb: error [winusbx_submit_bulk_transfer] ReadPipe/WritePipe failed: [22] The device does not recognize the command.
[50.808000] [00001afc] libusb: debug [libusb_free_transfer] transfer 00783D9C
[50.808000] [00001afc] libusb: debug [libusb_cancel_transfer] transfer 00783D14
[50.808000] [00001afc] libusb: debug [libusb_cancel_transfer] transfer 00783C8C
[50.808000] [00001afc] libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by OS; no timeout!
[50.808000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.808000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 10ms
[50.818000] [00001afc] libusb: debug [handle_events] poll() returned 0
[50.818000] [00001afc] libusb: debug [libusb_release_interface] interface 0
[50.818000] [00001afc] libusb: debug [libusb_close] 
[50.818000] [00001afc] libusb: debug [do_close] Removed transfer 00783D14 from the in-flight list because device handle 00786108 closed
[50.818000] [00001afc] libusb: debug [do_close] Removed transfer 00783C8C from the in-flight list because device handle 00786108 closed
[50.818000] [00001afc] libusb: debug [libusb_get_device_list] 
[50.820000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [1E7]
[50.820000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [272] (2.0)
[50.827000] [00001afc] libusb: debug [get_api_type] driver(s): ausb3hub
[50.827000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.827000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [33D]
[50.828000] [00001afc] libusb: debug [get_api_type] driver(s): iusb3hub
[50.828000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.828000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [24C] (2.1)
[50.829000] [00001afc] libusb: debug [get_api_type] driver(s): iusb3hub
[50.829000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.829000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [3ED]
[50.830000] [00001afc] libusb: debug [get_api_type] driver(s): iusb3hub
[50.830000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.830000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [240]
[50.831000] [00001afc] libusb: debug [get_api_type] driver(s): iusb3hub
[50.831000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.831000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [2F6] (2.5)
[50.831000] [00001afc] libusb: debug [get_api_type] driver(s): iusb3hub
[50.831000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.831000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [88] (2.8)
[50.832000] [00001afc] libusb: debug [get_api_type] driver(s): ausb3hub
[50.832000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.832000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [252]
[50.894000] [00001afc] libusb: debug [get_api_type] driver(s): ausb3hub
[50.894000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.894000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [12C]
[50.895000] [00001afc] libusb: debug [get_api_type] driver(s): ausb3hub
[50.895000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.895000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [11F]
[50.896000] [00001afc] libusb: debug [get_api_type] driver(s): ausb3hub
[50.896000] [00001afc] libusb: debug [get_api_type] matched driver name against HUB API
[50.896000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [3B2]
[50.904000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [B9]
[50.904000] [00001afc] libusb: debug [init_device] got bus number from ancestor #3
[50.909000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.909000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[50.909000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 16, depth: 1, port: 4): '\\.\USB#VID_03EB&PID_2105#7&129AFCD5&0&4'
[50.909000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [37A]
[50.909000] [00001afc] libusb: debug [init_device] got bus number from ancestor #2
[50.909000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.909000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 2466 bytes)
[50.909000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 10, depth: 1, port: 2): '\\.\USB#VID_046D&PID_0825#197F4800'
[50.911000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [2D5]
[50.911000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.911000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 34 bytes)
[50.911000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 15, depth: 1, port: 3): '\\.\USB#VID_046D&PID_C069#7&129AFCD5&0&3'
[50.912000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [E9]
[50.912000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.912000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 34 bytes)
[50.912000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 14, depth: 1, port: 2): '\\.\USB#VID_046D&PID_C626#7&129AFCD5&0&2'
[50.912000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [89]
[50.912000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.912000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 59 bytes)
[50.912000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 6, depth: 1, port: 14): '\\.\USB#VID_04D9&PID_0169#5&26670DD9&0&14'
[50.914000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [16C]
[50.914000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.914000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 32 bytes)
[50.914000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 3, depth: 1, port: 5): '\\.\USB#VID_04F9&PID_0042#G3N255112'
[50.914000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [202]
[50.914000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.914000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 32 bytes)
[50.914000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 11, depth: 1, port: 3): '\\.\USB#VID_04F9&PID_2042#000L3Z895492'
[50.915000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [12D]
[50.915000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.915000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 118 bytes)
[50.915000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 13, depth: 1, port: 1): '\\.\USB#VID_0556&PID_0001#7&129AFCD5&0&1'
[50.915000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [3ED] (2.0)
[50.916000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.916000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 41 bytes)
[50.916000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 4, depth: 1, port: 6): '\\.\USB#VID_05E3&PID_0610#5&26670DD9&0&6'
[50.916000] [00001afc] libusb: debug [discovered_devs_append] need to increase capacity
[50.916000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [240] (2.0)
[50.916000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.916000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 41 bytes)
[50.916000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 9, depth: 2, port: 1): '\\.\USB#VID_05E3&PID_0610#6&2067702B&0&1'
[50.917000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [19A]
[50.917000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.917000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 218 bytes)
[50.917000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 2, depth: 1, port: 4): '\\.\USB#VID_0A5C&PID_21E8#000272C5C8D0'
[50.917000] [00001afc] libusb: debug [windows_get_device_list] allocating new device for session [18]
[50.917000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.917000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 32 bytes)
[50.917000] [00001afc] libusb: debug [init_device] (bus: 2, addr: 7, depth: 2, port: 3): '\\.\USB#VID_1366&PID_0101#000059101755'
[50.918000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [2F6] (2.5)
[50.919000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [88] (2.8)
[50.920000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [252] (0.0)
[50.920000] [00001afc] libusb: debug [init_device] got bus number from ancestor #2
[50.920000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.920000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 31 bytes)
[50.920000] [00001afc] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 4): '\\.\USB#VID_2109&PID_0812#8&28DAD054&0&4'
[50.920000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [12C] (0.0)
[50.921000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.921000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 31 bytes)
[50.921000] [00001afc] libusb: debug [init_device] (bus: 1, addr: 5, depth: 2, port: 4): '\\.\USB#VID_2109&PID_0812#9&25338BFC&0&4'
[50.921000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [11F] (0.0)
[50.921000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.921000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[50.921000] [00001afc] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 2): '\\.\USB#VID_2109&PID_2812#8&28DAD054&0&2'
[50.921000] [00001afc] libusb: debug [discovered_devs_append] need to increase capacity
[50.922000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [3B2] (0.0)
[50.922000] [00001afc] libusb: debug [init_device] found 1 configurations (active conf: 1)
[50.922000] [00001afc] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 25 bytes)
[50.922000] [00001afc] libusb: debug [init_device] (bus: 1, addr: 4, depth: 2, port: 4): '\\.\USB#VID_2109&PID_2812#9&21FB44EC&0&4'
[50.923000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [24C] (2.1)
[50.923000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [33D] (1.0)
[50.923000] [00001afc] libusb: debug [init_device] (bus: 1, addr: 1, depth: 0, port: 0): '\\.\IARUSB3#ROOT_HUB30#7&37BA513A&0'
[50.931000] [00001afc] libusb: debug [get_api_type] driver(s): atmelwindrvr
[50.932000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [B9] (2.16)
[50.932000] [00001afc] libusb: debug [get_api_type] driver(s): usbccgp
[50.933000] [00001afc] libusb: debug [get_api_type] matched driver name against Composite API
[50.933000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [37A] (2.10)
[50.933000] [00001afc] libusb: debug [get_api_type] driver(s): HidUsb
[50.934000] [00001afc] libusb: debug [get_api_type] lower filter driver(s): LUsbFilt
[50.934000] [00001afc] libusb: debug [get_api_type] matched driver name against HID API
[50.934000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [2D5] (2.15)
[50.934000] [00001afc] libusb: debug [get_api_type] driver(s): HidUsb
[50.935000] [00001afc] libusb: debug [get_api_type] matched driver name against HID API
[50.935000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [E9] (2.14)
[50.935000] [00001afc] libusb: debug [get_api_type] driver(s): usbccgp
[50.935000] [00001afc] libusb: debug [get_api_type] matched driver name against Composite API
[50.935000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [89] (2.6)
[50.936000] [00001afc] libusb: debug [get_api_type] driver(s): usbprint
[50.936000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [16C] (2.3)
[50.937000] [00001afc] libusb: debug [get_api_type] driver(s): usbprint
[50.937000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [202] (2.11)
[50.938000] [00001afc] libusb: debug [get_api_type] driver(s): usbccgp
[50.939000] [00001afc] libusb: debug [get_api_type] matched driver name against Composite API
[50.939000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [12D] (2.13)
[50.939000] [00001afc] libusb: debug [get_api_type] driver(s): BTHUSB
[50.940000] [00001afc] libusb: debug [get_api_type] lower filter driver(s): bcbtums;btwampfl
[50.940000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [19A] (2.2)
[50.941000] [00001afc] libusb: debug [get_api_type] driver(s): jlink
[50.941000] [00001afc] libusb: debug [windows_get_device_list] found existing device for session [18] (2.7)
[50.946000] [00001afc] libusb: debug [windows_get_device_list] unlisted ancestor for '\\.\HID#3DXKMJ_HIDMINI&COL01#1&2D595CA7&0&0000' (non USB HID, newly connected, etc.) - ignoring
[50.946000] [00001afc] libusb: debug [windows_get_device_list] unlisted ancestor for '\\.\HID#3DXKMJ_HIDMINI&COL02#1&2D595CA7&0&0001' (non USB HID, newly connected, etc.) - ignoring
[50.947000] [00001afc] libusb: debug [windows_get_device_list] unlisted ancestor for '\\.\HID#3DXKMJ_HIDMINI&COL03#1&2D595CA7&0&0002' (non USB HID, newly connected, etc.) - ignoring
[50.947000] [00001afc] libusb: debug [windows_get_device_list] setting HID interface for [2D5]:
[50.947000] [00001afc] libusb: debug [set_hid_interface] interface[0] = \\.\HID#VID_046D&PID_C069#8&3A718219&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[50.947000] [00001afc] libusb: debug [windows_get_device_list] setting HID interface for [E9]:
[50.947000] [00001afc] libusb: debug [set_hid_interface] interface[0] = \\.\HID#VID_046D&PID_C626#8&24B176AC&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[50.947000] [00001afc] libusb: debug [windows_get_device_list] setting composite interface for [89]:
[50.947000] [00001afc] libusb: debug [set_composite_interface] interface[0] = \\.\HID#VID_04D9&PID_0169&MI_00#7&8AA589D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[50.947000] [00001afc] libusb: debug [windows_get_device_list] setting composite interface for [89]:
[50.947000] [00001afc] libusb: debug [set_composite_interface] interface[1] = \\.\HID#VID_04D9&PID_0169&MI_01&COL01#7&2C81965F&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[50.947000] [00001afc] libusb: debug [windows_get_device_list] setting composite interface for [89]:
[50.947000] [00001afc] libusb: debug [set_composite_interface] interface[1] already set - ignoring HID collection: \\.\HID#VID_04D9&PID_0169&MI_01&COL02#7&2C81965F&0&0001
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_get_device_descriptor] 
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.16
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.10
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.15
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.14
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.6
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.3
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.11
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.13
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.9
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.4
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.2
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 2.7
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.5
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.3
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.4
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.2
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.1
[50.948000] [00001afc] libusb: debug [libusb_unref_device] destroy device 1.0
[50.949000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.949000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.949000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.949000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.949000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.949000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.949000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.949000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.949000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.949000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.949000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.949000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.949000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.949000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.949000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.949000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.949000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.949000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.949000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.949000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.949000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.950000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.950000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.950000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.950000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.950000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.950000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.950000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.950000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.950000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.950000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.950000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.950000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.950000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.950000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.950000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.950000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.950000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.950000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.950000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.950000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.950000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
[50.950000] [00001afc] libusb: debug [libusb_get_next_timeout] no URBs, no timeout!
[50.950000] [00001afc] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[50.950000] [00001afc] libusb: debug [handle_events] poll() 3 fds with timeout in 100ms
[50.950000] [00001afc] libusb: debug [handle_events] poll() returned 2
[50.950000] [00001afc] libusb: debug [windows_handle_events] checking fd 1 with revents = 0001
[50.950000] [00001afc] libusb: error [windows_handle_events] could not find a matching transfer for fd 1
[50.950000] [00001afc] libusb: error [handle_events] backend handle_events failed with error -5
...

This pattern repeats forever and the program never collects more data.

ecejeff commented 7 years ago

By the way, I don't get timeout callbacks for the 2 transfers that "time out". I only get error callbacks on the 4 that "stalled".

brendanbates89 commented 7 years ago

From a cursory glance at the source code (and I am not well versed on libusb): it appears to me that the two transfers must never get removed from the flying transfers list, which means they refer to stale file descriptors. In the windows_handle_events method, all flying transfers are looped through and matched to file descriptors - this is where a failure on reconnect occurs. I wonder if after the AbortPipe operation fails, the transfers should somehow find their way to the usbi_handle_transfer_cancellation function so that they are removed from the flying transfers list. I could be completely wrong on this however.

mcuee commented 7 years ago

In any case, libusb Windows does not support hotplug as of now.

mcuee commented 7 years ago

Close this for now. Will reopen this if things still happen after the hotplug feature is implemented.

brendanbates89 commented 7 years ago

I have no idea if this is related to hotplug or not, but I figure I'll comment our "fix" anyways: the patch is here. Again, I have no idea if this is the proper fix or not, but to sum it up: During AbortPipe, something bad would happen to trigger a "no device" error. This would cause the usbi_handle_transfer_cancellation to never get called, so the transfer is actually left hanging in that state. Another transfer would then attempt to use the transfer fd, which was never cleaned up. So, when the "no device" error from AbortPipe happens, a list of these bad transfers is maintained and then the usbi_handle_transfer_cancellation is called on each bad transfer. This has solved most of our problems, though I am not sure if it's really the best way to fix this.

ecejeff commented 7 years ago

I don't see how hotplug (callbacks on new devices and devices leaving) is related to this bug in any way.

dickens commented 4 years ago

With all the recent changes to how Windows handles transfers and events, I'd like to know if this is still an issue. Can anyone on this thread confirm?

ecejeff commented 4 years ago

Using the latest git I now get a different error when unplugging one of two devices now:

libusb: error [windows_iocp_thread] GetQueuedCompletionStatus failed: [31] A device attached to the system is not functioning.
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2
libusb: warning [handle_timeout] async cancel failed -5 errno=2

And the other device becomes hung as well.

ecejeff commented 4 years ago

Here's a more detailed log (not the same run, but the same effect).

libusb_debug_log.txt

dickens commented 4 years ago

Thanks for the quick feedback! I just pushed a commit (37e8b1334e59485e1d4735f5f67b31eba37ae5c9) to address an issue pointed out by your log. Can you try again?

ecejeff commented 4 years ago

It fixed the unplugging issue, but I've uncovered another in the process of testing the fix. It happens during tear down.

C:\Libraries\Asphodel_Win64_b727e2c1d314c36642ae0b3571db0676e5aa66a5>asphodel_streaming.exe
Found 2 devices!
Enabling 2 streams from UVB687
Enabling 3 streams from WMRP2147
Press any key to stop data collection...
Disabling 2 streams from UVB687
Disabling 3 streams from WMRP2147
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: warning [do_close] A cancellation for an in-flight transfer hasn't completed but closing the device handle
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: warning [do_close] A cancellation for an in-flight transfer hasn't completed but closing the device handle
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: warning [do_close] A cancellation for an in-flight transfer hasn't completed but closing the device handle
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: warning [do_close] A cancellation for an in-flight transfer hasn't completed but closing the device handle
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: warning [do_close] A cancellation for an in-flight transfer hasn't completed but closing the device handle

I then get a segfault (the windows equivalent rather). Here's the exception:

Unhandled exception at 0x000007FEDD5A0988 (libusb-1.0.dll) in asphodel_streaming.exe: 0xC0000005: Access violation reading location 0x0000000000000040. occurred

Here' the backtrace:

libusb-1.0.dll!windows_handle_transfer_completion(usbi_transfer * itransfer) Line 763
    at C:\Libraries\libusb\libusb\os\windows_common.c(763)
libusb-1.0.dll!handle_event_trigger(libusb_context * ctx) Line 2083
    at C:\Libraries\libusb\libusb\io.c(2083)
libusb-1.0.dll!handle_events(libusb_context * ctx, timeval * tv) Line 2192
    at C:\Libraries\libusb\libusb\io.c(2192)
libusb-1.0.dll!libusb_handle_events_timeout_completed(libusb_context * ctx, timeval * tv, int * completed) Line 2293
    at C:\Libraries\libusb\libusb\io.c(2293)
Asphodel64.dll!usb_poll_device(AsphodelDevice_t * device, int milliseconds, int * completed) Line 2432
    at c:\codebuild\tmp\output\src570898187\src\bitbucket.org\suprocktech\asphodel\src\asphodel_usb.c(2432)

I've seen similar warnings on older versions, but never a segfault. I understand this may be an artifact of my code, but is there an easy way for the library to guard against this?

dickens commented 4 years ago

Closing a device while there are outstanding transfers is 100% an application error. Handling this gracefully has been discussed in #540, #610 and #703.

mcuee commented 3 years ago

I will close this and please refer to #703.

mcuee commented 2 years ago

I will still keep this open since the issue keeps popping up.

mcuee commented 1 year ago

Relevant info: 1) https://github.com/libusb/libusb/issues/703 2) https://github.com/libusb/libusb/issues/182 3) https://github.com/libusb/libusb/issues/297 4) https://github.com/libusb/libusb/issues/540 5) https://github.com/libusb/libusb/issues/610

ijprest-haptx commented 1 month ago

We've experienced something similar on device disconnects. In particular, we get the error [winusbx_submit_bulk_transfer] ReadPipe/WritePipe failed: [22] The device does not recognize the command message, which corresponds to Win32's ERROR_BAD_COMMAND.

We're currently experimenting with this small patch, which just translates ERROR_BAD_COMMAND (and a couple other errors, for good measure) into LIBUSB_ERROR_NO_DEVICE inside the *do_bulk_transfer functions: https://github.com/libusb/libusb/commit/9e0349e9cb1908c42d62a78358b601d656f2de56. Initial tests show that it solves the problem in our case, and there is precedent elsewhere in libusb for converting these specific Win32 errors into LIBUSB_ERROR_NO_DEVICE.

We're happy to upstream this change, if you want it. Let me know...