Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

windows: hotplug implementation #1406

Open
wants to merge 4 commits into
base: master
Choose a base branch
from

Conversation

sonatique
Copy link
Contributor

@sonatique sonatique commented Dec 28, 2023

Hotplug implementation for Windows.

The idea is to use WM_DEVICECHANGE message to trigger a re-enumeration, then figure out which device(s) have been removed or added and trigger corresponding changes in ctx internal device list as well as relevant hotplug events.

I tried to minimize changes on existing code, basically reusing well tested main windows_winusb and windows_usbdk "get_device_list" implementation. I had to do small changes though, but without putting this code at risk, I think.

I tried to avoid re-enumerating on WM_DEVICECHANGE notifications, but didn't figure out how to get all required information about the triggering device. And anyway, all my attempts were actually doing a full enumeration, and I realized I was writing "get_device_list" again, but without taking all subtleties into account, so I reverted using existing code as much as possible.

As far as I can tell this approach works well, hotplugtest works as expected and I didn't see any issue so far.

Note that I used the approach of having a "hidden window" and a message pump in a dedicated thread. I tried to somehow mimic how it is done for linux, but dealing with Windows API. I understand having a "hidden Windows" might sound weird but in the end I didn't find any major drawback and we probably can consider this an implementation detail.

Now that I have a working solution as a reference, I will explore whether CM_Register_Notification could be used to improve code and avoid the hidden window, as suggested here: #86 (comment)

I am totally OK to consider this PR only as a basis for discussion toward the optimal solution, but I thought it would worth publishing it since it could already be useful as is.

Beside providing hotplug events, this implementation avoid fully enumerating devices at system level every time user calls "libusb_get_device_list" since we're reusing ctx internal device list. I think that this alone should provide some desired improvements.

I had a hard time trying to comply with both coding style of Windows C and existing libusb-1.0 code for the Windows backend. I took some liberty in the new windows_hotplug.c file.

Let me know how all this works for you, I greatly welcome feedback regarding the code itself or any issue you may report when testing this code on your system. Thank you in advance!

@whitequark
Copy link

Thanks for working on this code! I have some applications which would benefit from hotplug notifications, but I'm not sure when I'll be able to test them.

I gave the diff a quick look. One obvious issue is that you have a mixture of tabs and spaces that makes it a bit hard to read.

I do want to encourage you to look into using CM_Register_Notification. While I cannot give you any specific situation where I know this would cause a problem, it seems like not having a message pump at all would let everyone involved to convince themselves that the approach is sound more easily, which means the change would probably get accepted earlier.

@mcuee mcuee added enhancement New features windows labels Dec 29, 2023
@mcuee
Copy link
Member

mcuee commented Dec 29, 2023

Thanks a lot for working on this long outstanding feature for libusb Windows. I will for sure test this PR.

@xhwang-China
Copy link

excellent, As #86 (comment) suggests,it works well in my Project. as you‘ve said, i took a lot of tests too, it passed.

@sonatique
Copy link
Contributor Author

sonatique commented Dec 29, 2023

@whitequark

One obvious issue is that you have a mixture of tabs and spaces that makes it a bit hard to read.

Oups, sorry, I didn't notice this, thanks for reporting. I will correct this asap.
EDIT: done.

While I cannot give you any specific situation where I know this would cause a problem ...

This is interesting: do you have any idea why people would be so reluctant in having a Windows message pump somewhere in the code? I mean, the basic mechanism used for linux udev hotplug is not fundamentally different: there is a background thread waiting on some event to unblock, and then doing a switch on something and doing the actual hotplug sutff. With udev we also need some "hidden" objects (file descriptor and event) and a thread for "pumping messages".
Moreover, I didn't have to link with additional Windows library or even include files, so I think I didn't increase the dependency toward Windows core components very much (if that is somehow an issue), while udev is a dependency by itself..

Anyway, I will look at CM_Register_Notification, but so far I didn't manage to make it work.

@yume-chan
Copy link
Contributor

yume-chan commented Dec 29, 2023

I found node-usb is using CM_Register_Notification for detecting device changes (and libusb for actually communicate with the device): https://github.com/node-usb/node-usb/blob/master/src/hotplug/windows.cc

One issue it may have is that these events are delivered pretty early, and the device may not be ready for reading. node-usb has an arbitrary 500ms delay, but in my test, sometimes it still can't read serial number or other string descriptors after the delay.

@sonatique
Copy link
Contributor Author

One obvious issue is that you have a mixture of tabs and spaces that makes it a bit hard to read.

@mcuee @tormodvolden @whitequark : I need to use tabs (no spaces) right? I didn't find this coding requirement in any document.

@sonatique sonatique force-pushed the windows-hotplug branch 2 times, most recently from cbfe18c to 8726a33 Compare December 29, 2023 13:41
@mcuee
Copy link
Member

mcuee commented Dec 29, 2023

The first test seems to be in the positive direction. Not so sure about the Entity not found error though.

 MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/hotplugtest.exe
Device attached: 03eb:2177
Error opening device: Entity not found
Device detached: 03eb:2177

Detail debug log: two devices still referenced

Debug log for hotplugtest.exe
MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/hotplugtest.exe
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000925] [00004380] libusb: debug [libusb_init_context] created default context
[ 0.001146] [00004380] libusb: debug [libusb_init_context] libusb v1.0.27.11855-rc1
[ 0.001280] [00004380] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000dc events 0
[ 0.001397] [00004380] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.001504] [00004380] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000e0 events 0
[ 0.001617] [00004380] libusb: debug [get_windows_version] Windows 11 64-bit
[ 0.001672] [00004380] libusb: debug [htab_create] using 1021 entries hash table
[ 0.002979] [00004380] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.003248] [00004380] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.005040] [00004380] libusb: info [windows_init] UsbDk backend is not available
[ 0.005220] [000010fc] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.005259] [00003480] libusb: debug [windows_event_thread_main] windows event thread entering
[ 0.008639] [00003480] libusb: error [windows_event_thread_main] GetMessage failed with error 0: The operation completed successfully.
[ 0.008745] [00003480] libusb: error [windows_event_thread_main] DispatchMessage failed with error 0: The operation completed successfully.
[ 0.014741] [00004380] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[ 0.014940] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 0.015044] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [5]
[ 0.015166] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.015236] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [6]
[ 0.015352] [00004380] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&12C539F&0&0' bus number 1
[ 0.015413] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.015480] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [7]
[ 0.015589] [00004380] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' bus number 2
[ 0.015646] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 0.015715] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [8]
[ 0.016076] [00004380] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[ 0.016240] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.016368] [00004380] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.016442] [00004380] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.016490] [00004380] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.016536] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [20]
[ 0.016675] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.016795] [00004380] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.016867] [00004380] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.016915] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [41]
[ 0.017074] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.017192] [00004380] libusb: debug [get_api_type] driver(s): HidUsb
[ 0.017257] [00004380] libusb: debug [get_api_type] matched driver name against HID API
[ 0.017303] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [6A]
[ 0.017360] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.017477] [00004380] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.017541] [00004380] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.017586] [00004380] libusb: debug [winusb_get_device_list] allocating new device for session [6B]
[ 0.017688] [00004380] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[ 0.017901] [00004380] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[ 0.017972] [00004380] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[ 0.018187] [00004380] libusb: debug [winusb_get_device_list] ENUM pass GEN
[ 0.018690] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 0.018861] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.018935] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [5]
[ 0.019047] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.019111] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 31 bytes)
[ 0.019174] [00004380] libusb: debug [init_device] (bus: 2, addr: 1, depth: 1, port: 2): 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.019235] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.019343] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.019411] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [41]
[ 0.019510] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.019566] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.019619] [00004380] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 10): 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.019670] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.019763] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.019815] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [6A]
[ 0.019895] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.019947] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 34 bytes)
[ 0.019997] [00004380] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 3): 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020047] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.020148] [00004380] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.020199] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [6B]
[ 0.020277] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_04F2&PID_B6DD\0001'
[ 0.020332] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 512 bytes)
[ 0.020384] [00004380] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 5): 'USB\VID_04F2&PID_B6DD\0001'
[ 0.020435] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.020533] [00004380] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.020583] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [20]
[ 0.020661] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.020714] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[ 0.020765] [00004380] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 7): 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.020815] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.020905] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.021032] [00004380] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&12C539F&0&0' reports 16 ports
[ 0.021119] [00004380] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.021169] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[ 0.021261] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[ 0.021317] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 0.021404] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.021455] [00004380] libusb: debug [winusb_get_device_list] found existing device for session [8]
[ 0.021534] [00004380] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.021585] [00004380] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 41 bytes)
[ 0.021643] [00004380] libusb: debug [init_device] (bus: 1, addr: 1, depth: 1, port: 2): 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.021694] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.021782] [00004380] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.021901] [00004380] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' reports 5 ports
[ 0.021960] [00004380] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.022082] [00004380] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.022283] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[ 0.022346] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.022417] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[ 0.022467] [00004380] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[ 0.022512] [00004380] libusb: debug [set_hid_interface] interface[0] = \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.022575] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[ 0.022710] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[ 0.022786] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[ 0.022842] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.022908] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[ 0.022968] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.023034] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[ 0.023091] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.023157] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[ 0.023216] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.023284] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[ 0.023344] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.023410] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[ 0.023469] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.023532] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[ 0.023587] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.023653] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[ 0.023712] [00004380] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.023776] [00004380] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[ 0.023824] [00004380] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[ 0.023870] [00004380] libusb: debug [set_hid_interface] interface[1] = \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.024023] [00004380] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.024386] [00004380] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.024564] [00004380] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.024691] [00004380] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.024764] [00004380] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.024812] [00004380] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.025336] [00004380] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 000001da407614d0 with handle 1
[ 0.025425] [00004380] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 000001da3eb9bac0 with handle 2
[ 0.025473] [00004380] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.025519] [00004380] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.025566] [00004380] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[10.837395] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[10.838087] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[10.838261] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [5]
[10.838351] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[10.838484] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6]
[10.838698] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[10.838869] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [7]
[10.839060] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[10.839264] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [8]
[10.839845] [00003480] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[10.842197] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[10.842518] [00003480] libusb: debug [get_api_type] driver(s): WUDFRd
[10.842662] [00003480] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[10.842756] [00003480] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[10.842834] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [20]
[10.843032] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[10.843228] [00003480] libusb: debug [get_api_type] driver(s): BTHUSB
[10.843348] [00003480] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[10.843432] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [41]
[10.843663] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[10.843858] [00003480] libusb: debug [get_api_type] driver(s): HidUsb
[10.844006] [00003480] libusb: debug [get_api_type] matched driver name against HID API
[10.844156] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6A]
[10.844257] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[10.844534] [00003480] libusb: debug [get_api_type] driver(s): usbccgp
[10.844751] [00003480] libusb: debug [get_api_type] matched driver name against Composite API
[10.844951] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6B]
[10.845176] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[10.845523] [00003480] libusb: debug [get_api_type] driver(s): usbccgp
[10.845842] [00003480] libusb: debug [get_api_type] matched driver name against Composite API
[10.846060] [00003480] libusb: debug [winusb_get_device_list] allocating new device for session [87]
[10.846242] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[10.846521] [00003480] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[10.846651] [00003480] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[10.846919] [00003480] libusb: debug [winusb_get_device_list] ENUM pass GEN
[10.847474] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[10.847687] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[10.847799] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [5]
[10.847933] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[10.848129] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[10.848391] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [41]
[10.848647] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[10.848892] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[10.849010] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6A]
[10.849172] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[10.849387] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[10.849501] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6B]
[10.849584] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_00\7&315E345F&4&0000
[10.849684] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[10.849743] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[10.849844] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[10.849896] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [20]
[10.849976] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001
[10.850066] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001'
[10.850129] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[10.850241] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[10.850376] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[10.850470] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[10.850529] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[10.850618] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[10.850672] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [8]
[10.850750] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[10.850863] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
[10.850937] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [87]
[10.851066] [00003480] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_03EB&PID_2177\BUR200973052'
[10.851151] [00003480] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 107 bytes)
[10.851270] [00003480] libusb: debug [init_device] (bus: 1, addr: 7, depth: 2, port: 2): 'USB\VID_03EB&PID_2177\BUR200973052'
[10.851379] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[10.851534] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[10.851797] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[10.852185] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[10.852314] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[10.852479] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[10.852565] [00003480] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[10.852644] [00003480] libusb: debug [set_hid_interface] interface[0] already set to \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[10.852737] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[10.852886] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[10.852987] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[10.853059] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[10.853135] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[10.853209] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[10.853296] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[10.853385] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[10.853465] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[10.853536] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[10.853617] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[10.853686] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[10.853810] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[10.853907] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[10.854006] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[10.854090] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[10.854181] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[10.854254] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[10.854326] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[10.854388] [00003480] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[10.854444] [00003480] libusb: debug [set_hid_interface] interface[1] already set to \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[10.854628] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[10.855170] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[10.855764] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[10.855912] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[10.856151] [00003480] libusb: debug [get_api_type] driver(s): WUDFRd
[10.856239] [00003480] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[10.856289] [00003480] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[10.856585] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
[10.857217] [00004380] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[10.857272] [00004380] libusb: debug [handle_event_trigger] event triggered
[10.857337] [00004380] libusb: debug [handle_event_trigger] hotplug message received
[10.857440] [00004380] libusb: debug [libusb_get_device_descriptor]
Device attached: 03eb:2177
[10.858796] [00004380] libusb: debug [libusb_open] open 1.7
[10.858882] [00004380] libusb: debug [libusb_open] open 1.7 returns -5
Error opening device: Entity not found
[10.860587] [00004380] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[10.860641] [00004380] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[20.100051] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[20.100195] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[20.100381] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [5]
[20.100480] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[20.100564] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6]
[20.100639] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[20.100723] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [7]
[20.100792] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[20.100920] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [8]
[20.101284] [00003480] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[20.101445] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[20.101600] [00003480] libusb: debug [get_api_type] driver(s): WUDFRd
[20.101688] [00003480] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[20.101737] [00003480] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[20.101781] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [20]
[20.101921] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[20.102038] [00003480] libusb: debug [get_api_type] driver(s): BTHUSB
[20.102110] [00003480] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[20.102158] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [41]
[20.102315] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[20.102428] [00003480] libusb: debug [get_api_type] driver(s): HidUsb
[20.102492] [00003480] libusb: debug [get_api_type] matched driver name against HID API
[20.102537] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6A]
[20.102591] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[20.102703] [00003480] libusb: debug [get_api_type] driver(s): usbccgp
[20.102770] [00003480] libusb: debug [get_api_type] matched driver name against Composite API
[20.102874] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6B]
[20.102969] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[20.103200] [00003480] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[20.103268] [00003480] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[20.103557] [00003480] libusb: debug [winusb_get_device_list] ENUM pass GEN
[20.104022] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[20.104125] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[20.104178] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [5]
[20.104253] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[20.104344] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[20.104436] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [41]
[20.104510] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[20.104597] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[20.104646] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6A]
[20.104720] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[20.104811] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[20.104866] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [6B]
[20.104940] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[20.105031] [00003480] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[20.105079] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [20]
[20.105152] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[20.105236] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[20.105352] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[20.105444] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[20.105562] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[20.105657] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[20.105706] [00003480] libusb: debug [winusb_get_device_list] found existing device for session [8]
[20.105778] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[20.105860] [00003480] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[20.106013] [00003480] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[20.106226] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[20.106284] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[20.106354] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[20.106402] [00003480] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[20.106447] [00003480] libusb: debug [set_hid_interface] interface[0] already set to \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[20.106522] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[20.106658] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[20.106732] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[20.106786] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[20.106850] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[20.106907] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[20.106970] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[20.107026] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[20.107096] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[20.107152] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[20.107216] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[20.107274] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[20.107338] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[20.107395] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[20.107460] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[20.107512] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[20.107575] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[20.107631] [00003480] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[20.107696] [00003480] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[20.107745] [00003480] libusb: debug [winusb_get_device_list] setting HID interface for [6A]:
[20.107789] [00003480] libusb: debug [set_hid_interface] interface[1] already set to \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[20.107950] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[20.108316] [00003480] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[20.108535] [00003480] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[20.108651] [00003480] libusb: debug [get_api_type] driver(s): WUDFRd
[20.108722] [00003480] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[20.108768] [00003480] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[20.109394] [00004380] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[20.109536] [00004380] libusb: debug [handle_event_trigger] event triggered
[20.109593] [00004380] libusb: debug [handle_event_trigger] hotplug message received
[20.109639] [00004380] libusb: debug [libusb_get_device_descriptor]
Device detached: 03eb:2177
[20.111113] [00004380] libusb: debug [libusb_unref_device] destroy device 1.7
[20.111173] [00004380] libusb: debug [libusb_exit] destroying default context
[20.111239] [00004380] libusb: debug [libusb_unref_device] destroy device 1.3
[20.111314] [00004380] libusb: debug [libusb_unref_device] destroy device 1.2
[20.111374] [00004380] libusb: debug [libusb_unref_device] destroy device 1.5
[20.111434] [00004380] libusb: debug [libusb_unref_device] destroy device 1.4
[20.111492] [00004380] libusb: debug [libusb_unref_device] destroy device 1.1
[20.111547] [00004380] libusb: debug [libusb_unref_device] destroy device 2.1
[20.111619] [000010fc] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[20.113255] [00003480] libusb: debug [windows_event_thread_main] windows event thread exiting
[20.113536] [00004380] libusb: error [windows_stop_event_monitor] SendMessage failed with error 0: The operation completed successfully.
[20.114062] [00004380] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000e0
[20.114144] [00004380] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000dc
[20.114289] [00004380] libusb: warning [libusb_exit] device 2.0 still referenced
[20.114368] [00004380] libusb: warning [libusb_exit] device 1.0 still referenced

More about the device (Microchip PICKit 4) which is a USB Composite Device

Debug log for xusb example using Microchip PICKit 4
MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/xusb.exe 03eb:2177
Using libusb v1.0.27.11855

[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000168] [00002d60] libusb: debug [libusb_init_context] created default context
[ 0.000257] [00002d60] libusb: debug [libusb_init_context] libusb v1.0.27.11855-rc1
[ 0.000324] [00002d60] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000d8 events 0
[ 0.000378] [00002d60] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.000426] [00002d60] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000dc events 0
[ 0.000482] [00002d60] libusb: debug [get_windows_version] Windows 11 64-bit
[ 0.000528] [00002d60] libusb: debug [htab_create] using 1021 entries hash table
[ 0.001873] [00002d60] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.002146] [00002d60] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.003898] [00002d60] libusb: info [windows_init] UsbDk backend is not available
[ 0.004165] [00001110] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.004260] [00004ba8] libusb: debug [windows_event_thread_main] windows event thread entering
[ 0.007563] [00004ba8] libusb: error [windows_event_thread_main] GetMessage failed with error 0: The operation completed successfully.
[ 0.007676] [00004ba8] libusb: error [windows_event_thread_main] DispatchMessage failed with error 0: The operation completed successfully.
[ 0.015217] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[ 0.015383] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 0.015487] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [5]
[ 0.015618] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.015691] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [6]
[ 0.015826] [00002d60] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&12C539F&0&0' bus number 1
[ 0.015884] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.015954] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [7]
[ 0.016078] [00002d60] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' bus number 2
[ 0.016136] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 0.016206] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [8]
[ 0.016583] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[ 0.016746] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.016876] [00002d60] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.016954] [00002d60] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.017003] [00002d60] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.017048] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [21]
[ 0.017188] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.017308] [00002d60] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.017385] [00002d60] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.017433] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [42]
[ 0.017607] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.017729] [00002d60] libusb: debug [get_api_type] driver(s): HidUsb
[ 0.017797] [00002d60] libusb: debug [get_api_type] matched driver name against HID API
[ 0.017843] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [6C]
[ 0.017901] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.018018] [00002d60] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.018086] [00002d60] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.018131] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [6D]
[ 0.018188] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[ 0.018313] [00002d60] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.018381] [00002d60] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.018426] [00002d60] libusb: debug [winusb_get_device_list] allocating new device for session [6E]
[ 0.018521] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[ 0.018737] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[ 0.018807] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[ 0.019025] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass GEN
[ 0.019518] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 0.019656] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.019718] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [5]
[ 0.019821] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.019876] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 31 bytes)
[ 0.019930] [00002d60] libusb: debug [init_device] (bus: 2, addr: 1, depth: 1, port: 2): 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 0.019981] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.020075] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020126] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [42]
[ 0.020228] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020319] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.020400] [00002d60] libusb: debug [init_device] (bus: 1, addr: 5, depth: 1, port: 10): 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020456] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.020564] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020624] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [6C]
[ 0.020712] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020767] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 34 bytes)
[ 0.020822] [00002d60] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 3): 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020873] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.020984] [00002d60] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.021035] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [6D]
[ 0.021178] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_04F2&PID_B6DD\0001'
[ 0.021245] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 512 bytes)
[ 0.021317] [00002d60] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 5): 'USB\VID_04F2&PID_B6DD\0001'
[ 0.021391] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_00\7&315E345F&4&0000
[ 0.021550] [00002d60] libusb: debug [winusb_get_device_list] extra GUID: {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[ 0.021628] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.021785] [00002d60] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.021854] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [21]
[ 0.021973] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.022049] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[ 0.022122] [00002d60] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 7): 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.022176] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001
[ 0.022276] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001'
[ 0.022340] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.022433] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.022580] [00002d60] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&12C539F&0&0' reports 16 ports
[ 0.022673] [00002d60] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.022724] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[ 0.022819] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[ 0.022878] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 0.022970] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.023028] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [8]
[ 0.023111] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.023163] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 41 bytes)
[ 0.023214] [00002d60] libusb: debug [init_device] (bus: 1, addr: 1, depth: 1, port: 2): 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 0.023264] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[ 0.023363] [00002d60] libusb: debug [winusb_get_device_list] extra GUID: {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
[ 0.023414] [00002d60] libusb: debug [winusb_get_device_list] found existing device for session [6E]
[ 0.023499] [00002d60] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_03EB&PID_2177\BUR200973052'
[ 0.023552] [00002d60] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 107 bytes)
[ 0.023602] [00002d60] libusb: debug [init_device] (bus: 1, addr: 8, depth: 2, port: 2): 'USB\VID_03EB&PID_2177\BUR200973052'
[ 0.023653] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.023743] [00002d60] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.023875] [00002d60] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' reports 5 ports
[ 0.023936] [00002d60] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.024072] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.024282] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[ 0.024348] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.024418] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[ 0.024469] [00002d60] libusb: debug [winusb_get_device_list] setting HID interface for [6C]:
[ 0.024514] [00002d60] libusb: debug [set_hid_interface] interface[0] = \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.024576] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[ 0.024715] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[ 0.024791] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[ 0.024846] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.024911] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[ 0.024970] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.025035] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[ 0.025094] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.025161] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[ 0.025219] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.025283] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[ 0.025342] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.025409] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[ 0.025467] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.025532] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[ 0.025587] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.025651] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[ 0.025709] [00002d60] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.025773] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_03EB&PID_2177&MI_00\7&6090BDD&0&0000
[ 0.025826] [00002d60] libusb: debug [winusb_get_device_list] setting composite interface for [6E]:
[ 0.025871] [00002d60] libusb: debug [set_composite_interface] interface[0] = \\?\HID#VID_03EB&PID_2177&MI_00#7&6090BDD&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.025936] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[ 0.025985] [00002d60] libusb: debug [winusb_get_device_list] setting HID interface for [6C]:
[ 0.026030] [00002d60] libusb: debug [set_hid_interface] interface[1] = \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.026189] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.026563] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass EXT {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[ 0.026959] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.027138] [00002d60] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.027273] [00002d60] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.027351] [00002d60] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.027399] [00002d60] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.027689] [00002d60] libusb: debug [winusb_get_device_list] ENUM pass EXT {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
Opening device 03EB:2177...
[ 0.029314] [00002d60] libusb: debug [libusb_get_device_list]
[ 0.029363] [00002d60] libusb: debug [libusb_get_device_descriptor]
[ 0.029408] [00002d60] libusb: debug [libusb_open] open 1.8
[ 0.029569] [00002d60] libusb: debug [hid_open] set maximum input buffer size to 512
[ 0.029632] [00002d60] libusb: debug [hid_open] 1 HID input report value(s) found
[ 0.029679] [00002d60] libusb: debug [hid_open]   Report ID: 0x00
[ 0.029724] [00002d60] libusb: debug [hid_open] 1 HID output report value(s) found
[ 0.029770] [00002d60] libusb: debug [hid_open]   Report ID: 0x00
[ 0.029815] [00002d60] libusb: debug [hid_open] 1 HID feature report value(s) found
[ 0.029860] [00002d60] libusb: debug [hid_open]   Report ID: 0x00

Reading device descriptor:
[ 0.031466] [00002d60] libusb: debug [libusb_get_device_descriptor]
            length: 18
      device class: 239
               S/N: 3
           VID:PID: 03EB:2177
         bcdDevice: 0100
   iMan:iProd:iSer: 1:2:3
          nb confs: 1

Reading BOS descriptor: [ 0.038526] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.038613] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.038684] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.038740] [00002d60] libusb: debug [libusb_claim_interface] interface 0
[ 0.038806] [00002d60] libusb: debug [hid_claim_interface] claimed interface 0
[ 0.038859] [00002d60] libusb: debug [parse_endpoint] skipping descriptor 0xb
[ 0.038915] [00002d60] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 0.038961] [00002d60] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 0.039009] [00002d60] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 0.039056] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.039102] [00002d60] libusb: warning [_hid_get_descriptor] unsupported
[ 0.039147] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.039193] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.039239] [00002d60] libusb: warning [_hid_get_descriptor] unsupported
[ 0.039285] [00002d60] libusb: error [composite_submit_control_transfer] no libusb supported interfaces to complete request
[ 0.039331] [00002d60] libusb: debug [libusb_release_interface] interface 0
[ 0.039376] [00002d60] libusb: debug [auto_release] auto-released interface 0
[ 0.039422] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.039469] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
[ 0.039516] [00002d60] libusb: error [libusb_get_bos_descriptor] failed to read BOS (-5)
no descriptor

Reading first configuration descriptor:
[ 0.041556] [00002d60] libusb: debug [libusb_get_config_descriptor] index 0
[ 0.041606] [00002d60] libusb: debug [parse_endpoint] skipping descriptor 0xb
              total length: 107
         descriptor length: 9
             nb interfaces: 3
              interface[0]: id = 0
interface[0].altsetting[0]: num endpoints = 2
   Class.SubClass.Protocol: 03.00.00
       endpoint[0].address: 81
           max packet size: 0040
          polling interval: 01
       endpoint[1].address: 02
           max packet size: 0040
          polling interval: 01
              interface[1]: id = 1
interface[1].altsetting[0]: num endpoints = 1
   Class.SubClass.Protocol: 02.02.00
       endpoint[0].address: 84
           max packet size: 0040
          polling interval: 10
              interface[2]: id = 2
interface[2].altsetting[0]: num endpoints = 2
   Class.SubClass.Protocol: 0A.00.00
       endpoint[0].address: 83
           max packet size: 0200
          polling interval: 00
       endpoint[1].address: 05
           max packet size: 0200
          polling interval: 00

Kernel driver attached for interface 0: [ 0.075181] [00002d60] libusb: debug [libusb_kernel_driver_active] interface 0
(not supported)

Claiming interface 0...
[ 0.076649] [00002d60] libusb: debug [libusb_claim_interface] interface 0
[ 0.076695] [00002d60] libusb: debug [hid_claim_interface] claimed interface 0
[ 0.076744] [00002d60] libusb: debug [parse_endpoint] skipping descriptor 0xb
[ 0.076791] [00002d60] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 0.076838] [00002d60] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0

Kernel driver attached for interface 1: [ 0.078283] [00002d60] libusb: debug [libusb_kernel_driver_active] interface 1
(not supported)

Claiming interface 1...
[ 0.079740] [00002d60] libusb: debug [libusb_claim_interface] interface 1
[ 0.079785] [00002d60] libusb: debug [composite_claim_interface] unsupported API call for 'claim_interface' (unrecognized device driver)
   Failed (error -12) Operation not supported or unimplemented on this platform

Kernel driver attached for interface 2: [ 0.084095] [00002d60] libusb: debug [libusb_kernel_driver_active] interface 2
(not supported)

Claiming interface 2...
[ 0.085557] [00002d60] libusb: debug [libusb_claim_interface] interface 2
[ 0.085602] [00002d60] libusb: debug [composite_claim_interface] unsupported API call for 'claim_interface' (unrecognized device driver)
   Failed (error -12) Operation not supported or unimplemented on this platform

Reading string descriptors:
[ 0.089880] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.089928] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.089977] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.090022] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.090068] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.090114] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 4
[ 0.090163] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.090305] [00002d60] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.090371] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.090169] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 4
[ 0.090492] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.090548] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.090596] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 4
[ 0.090645] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.090694] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.090740] [00002d60] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.090787] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
[ 0.090835] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.090881] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.090928] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.090974] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.091020] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.091065] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 68
[ 0.091113] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.091164] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.091118] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 68
[ 0.091273] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.091320] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.091366] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 68
[ 0.091411] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.091459] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.091505] [00002d60] libusb: debug [sync_transfer_cb] actual_length=68
[ 0.091551] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
   String (0x01): "Microchip Technology Incorporated"
[ 0.093438] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.093484] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.093530] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.093575] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.093620] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.093665] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 4
[ 0.093714] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.093764] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.093718] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 4
[ 0.093869] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.093916] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.093962] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 4
[ 0.094009] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.094055] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.094101] [00002d60] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.094147] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
[ 0.094193] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.094238] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.094284] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.094329] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.094375] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.094420] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 50
[ 0.094468] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.094517] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.094471] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 50
[ 0.094623] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.094674] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.094719] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 50
[ 0.094767] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.094814] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.094859] [00002d60] libusb: debug [sync_transfer_cb] actual_length=50
[ 0.094905] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
   String (0x02): "MPLAB PICkit 4 CMSIS-DAP"
[ 0.096484] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.096530] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.096576] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.096622] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.096667] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.096713] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 4
[ 0.096760] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.096809] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.096764] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 4
[ 0.096913] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.096960] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.097006] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 4
[ 0.097052] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.097098] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.097143] [00002d60] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.097189] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
[ 0.097235] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.097281] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.097326] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.097371] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.097416] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.097462] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 26
[ 0.097509] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.097558] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.097513] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 26
[ 0.097666] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.097714] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.097759] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 26
[ 0.097805] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.097851] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.097896] [00002d60] libusb: debug [sync_transfer_cb] actual_length=26
[ 0.097942] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
   String (0x03): "BUR200973052"

Reading OS string descriptor:[ 0.100143] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.100188] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.100254] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.100300] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.100351] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.100813] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.100889] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
 no descriptor

Reading interface association descriptors (IADs) for first configuration:
[ 0.104017] [00002d60] libusb: debug [libusb_get_interface_association_descriptors] IADs for config index 0
    nb IADs: 1
      IAD 0:
            bFirstInterface: 1
            bInterfaceCount: 2
             bFunctionClass: 02
          bFunctionSubClass: 02
          bFunctionProtocol: 00
[ 0.110803] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.110853] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.110902] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.110948] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.110993] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.111039] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 4
[ 0.111088] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.111143] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.111093] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 4
[ 0.111255] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.111304] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.111351] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 4
[ 0.111398] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.111445] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.111491] [00002d60] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.111537] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
[ 0.111584] [00002d60] libusb: debug [libusb_submit_transfer] transfer 00000191600a3f50
[ 0.111629] [00002d60] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 0.111676] [00002d60] libusb: debug [composite_submit_control_transfer] using interface 0
[ 0.111721] [00002d60] libusb: debug [hid_submit_control_transfer] will use interface 0
[ 0.111766] [00002d60] libusb: debug [_hid_get_descriptor] LIBUSB_DT_STRING
[ 0.112043] [00002d60] libusb: debug [windows_force_sync_completion] transfer 00000191600a3f50, length 52
[ 0.112092] [00002d60] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.112142] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 0.112096] [00001110] libusb: debug [windows_iocp_thread] transfer 00000191600a3f50 completed, length 52
[ 0.112250] [00002d60] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 0.112298] [00002d60] libusb: debug [handle_event_trigger] event triggered
[ 0.112344] [00002d60] libusb: debug [windows_handle_transfer_completion] handling transfer 00000191600a3f50 completion with errcode 0, length 52
[ 0.112389] [00002d60] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 0.112436] [00002d60] libusb: debug [usbi_handle_transfer_completion] transfer 00000191600a3f50 has callback 00007ff8776e9380
[ 0.112482] [00002d60] libusb: debug [sync_transfer_cb] actual_length=52
[ 0.112528] [00002d60] libusb: debug [libusb_free_transfer] transfer 00000191600a3f50
                  iFunction: 5 (PICkit 4 Virtual COM Port)

Releasing interface 0...
[ 0.115489] [00002d60] libusb: debug [libusb_release_interface] interface 0
Releasing interface 1...
[ 0.116393] [00002d60] libusb: debug [libusb_release_interface] interface 1
Releasing interface 2...
[ 0.117297] [00002d60] libusb: debug [libusb_release_interface] interface 2
Closing device...
[ 0.117961] [00002d60] libusb: debug [libusb_close]
[ 0.118024] [00002d60] libusb: debug [libusb_exit] destroying default context
[ 0.118070] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.8
[ 0.118117] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.3
[ 0.118164] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.2
[ 0.118210] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.5
[ 0.118257] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.4
[ 0.118303] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.1
[ 0.118349] [00002d60] libusb: debug [libusb_unref_device] destroy device 1.0
[ 0.118395] [00002d60] libusb: debug [libusb_unref_device] destroy device 2.1
[ 0.118440] [00002d60] libusb: debug [libusb_unref_device] destroy device 2.0
[ 0.118494] [00001110] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 0.119282] [00004ba8] libusb: debug [windows_event_thread_main] windows event thread exiting
[ 0.119474] [00002d60] libusb: error [windows_stop_event_monitor] SendMessage failed with error 0: The operation completed successfully.
[ 0.119832] [00002d60] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000dc
[ 0.119890] [00002d60] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000d8

@sonatique
Copy link
Contributor Author

@mcuee : macOS build has some intermittent "stress_test" failures that are obviously not related to my changes. Any idea?

@sonatique
Copy link
Contributor Author

sonatique commented Dec 29, 2023

Thanks for your tests @mcuee . I will have a look. One obvious issue on my side is this:
"[00004380] libusb: error [windows_stop_event_monitor] SendMessage failed with error 0: The operation completed successfully."
that I will correct by force push ASAP.

@mcuee
Copy link
Member

mcuee commented Dec 29, 2023

@mcuee : macOS build has some intermittent "stress_test" failures that are obviously not related to my changes. Any idea?

You can ignore that issue. It seems to be specific to the CI machine.

@mcuee
Copy link
Member

mcuee commented Dec 29, 2023

One obvious issue is that you have a mixture of tabs and spaces that makes it a bit hard to read.

@mcuee @tormodvolden @whitequark : I need to use tabs (no spaces) right? I didn't find this coding requirement in any document.

I think the general guideline is not to changing the coding style of existing codes. And I remember the original Windows source codes from @pbatard were using tab.

@sonatique
Copy link
Contributor Author

@whitequark @yume-chan : as far as I understand, using "CM_Register_Notification" requires to move to Universal (UWP) platform (https://learn.microsoft.com/fr-fr/windows/win32/api/cfgmgr32/nf-cfgmgr32-cm_register_notification) . I didn't manage to simply correctly include required header without this.
This means that we need to upgrade (recreate) both dll and static lib + probably all example and test projects. And obviously we would break some existing application by doing so. Do you have any pointer that would indicate the opposite?
If not, then I think that moving all of libusb-1.0 Windows implementation to UWP should be a well-tought move and a separate PR. After this is done, it shouldn't be a big change to modify some of the code in windows_hotplug.c for using CM_Register_Notification and get rid of the hWnd and thread.

If this PR gives good results as is I think we should keep it as it will enable hotplug without breaking anything.

Another option is to create a new UWP library with a different implementation for windows_hotplug.c, I could explore this possibility further if there is some interest for it.

By the way, I am not sure that CM_Register_Notification is not actually only hiding away some code very similar to what I did ;-)

@sonatique sonatique force-pushed the windows-hotplug branch 2 times, most recently from 02bd73a to 7502234 Compare December 29, 2023 16:07
@sonatique
Copy link
Contributor Author

Detail debug log: two devices still referenced

@mcuee : Would you mind testing again for this issue? I just forced push a fix and don't see it anymore on my side. Thanks!

@yume-chan
Copy link
Contributor

According to the documentation, CM_Register_Notification was added in Windows 8. Libusb still supports Windows Vista and sets its _WIN32_WINNT to _WIN32_WINNT_VISTA, so CM_Register_Notification is not visible.

<PreprocessorDefinitions>_WIN32_WINNT=_WIN32_WINNT_VISTA;_CRT_SECURE_NO_WARNINGS;%(PreprocessorDefinitions)</PreprocessorDefinitions>


If we want to use CM_Register_Notification (and only support hot plugging on Windows 8 and later), I think it should use the same dynamic loading pattern as here:

DLL_DECLARE_HANDLE(Cfgmgr32);
DLL_DECLARE_FUNC(WINAPI, CONFIGRET, CM_Get_Parent, (PDEVINST, DEVINST, ULONG));
DLL_DECLARE_FUNC(WINAPI, CONFIGRET, CM_Get_Child, (PDEVINST, DEVINST, ULONG));

DLL_GET_HANDLE(ctx, Cfgmgr32);
DLL_LOAD_FUNC(Cfgmgr32, CM_Get_Parent, true);
DLL_LOAD_FUNC(Cfgmgr32, CM_Get_Child, true);

It will require copy-pasting all related header definitions.

@whitequark
Copy link

whitequark commented Dec 30, 2023

By the way, I am not sure that CM_Register_Notification is not actually only hiding away some code very similar to what I did ;-)

@sonatique I have looked at the disassembly of CM_Register_Notification in Windows 10 Build 19045. It does not have a message pump. Rather, it opens the \Device\DeviceApi\CMNotify special file and uses the RtlSubscribeWnfStateChangeNotification function to retrieve the events. This seems all undocumented but if you search these names you can find some brief explanations of what these facilities are.

@whitequark
Copy link

whitequark commented Dec 30, 2023

Interestingly, RegisterDeviceNotificationW on the same version of Windows is implemented in sechost.dll, where it uses... CM_Register_Notification. So there's actually no reason whatsoever to have a window handle be used on Windows 10, it's just an artifact of the past, and either way you're using CM_Register_Notification in the end, potentially with some extra steps.

I don't have Vista DLLs on hand to check there.

@mcuee
Copy link
Member

mcuee commented Dec 30, 2023

Testing results of latest git push.

No more device still referenced warning messages. This is good.

Entity not found error message is still present when devices are attached. I am not so sure it is a real problem of this PR or just an existing issue which gets manifested by this PR.

  1. Detaching Microchip PICKit 4 from an external USB Type-C Hub is okay but not attaching due to the strange error message Entity not found. It might be the enumeration of the USB Composite Device takes a bit of time.
MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/hotplugtest.exe
Device detached: 03eb:2177 (detaching is good)
Device attached: 03eb:2177
Error opening device: Entity not found (attaching got this strange error code)

$ ./examples/hotplugtest.exe
Device attached: 03eb:2177
Error opening device: Entity not found (attaching got this strange error code)
Device detached: 03eb:2177 (detaching is okay)
  1. Similar results if I attach and detaching the external USB Type-C Hub (including Microchip PICKit 4)
MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/hotplugtest.exe
Device attached: 05e3:0612
Error opening device: Operation not supported or unimplemented on this platform
Device attached: 05e3:0610
Error opening device: Operation not supported or unimplemented on this platform
Device attached: 03eb:2177
Error opening device: Entity not found

$ ./examples/hotplugtest.exe
Device detached: 03eb:2177
Device detached: 05e3:0610

Debug message for the test cases of attaching the external USB Type-C Hub.

Debug message when detaching the external USB Type-C Hub which the Microchip PICKit 4 is connected to
MINGW64 /c/work/libusb/libusb_pr1406
$ ./examples/hotplugtest.exe
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000842] [00002658] libusb: debug [libusb_init_context] created default context
[ 0.001006] [00002658] libusb: debug [libusb_init_context] libusb v1.0.27.11855-rc1
[ 0.001330] [00002658] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000dc events 0
[ 0.001628] [00002658] libusb: debug [usbi_io_init] using timer for timeouts
[ 0.001851] [00002658] libusb: debug [usbi_add_event_source] add HANDLE 00000000000000e0 events 0
[ 0.002003] [00002658] libusb: debug [get_windows_version] Windows 11 64-bit
[ 0.002229] [00002658] libusb: debug [htab_create] using 1021 entries hash table
[ 0.003666] [00002658] libusb: info [winusbx_init] WinUSB DLL available (with isoch support)
[ 0.004028] [00002658] libusb: debug [winusbx_init] libusbK DLL found, version: 3.1.0.0
[ 0.005874] [00002658] libusb: info [windows_init] UsbDk backend is not available
[ 0.006184] [00004a78] libusb: debug [windows_iocp_thread] I/O completion thread started
[ 0.006270] [00003b80] libusb: debug [windows_event_thread_main] windows event thread entering
[ 0.015942] [00002658] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[ 0.016143] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.016300] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [5]
[ 0.016513] [00002658] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&12C539F&0&0' bus number 1
[ 0.016600] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.016727] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [6]
[ 0.017008] [00002658] libusb: debug [winusb_get_device_list] assigning Root Hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' bus number 2
[ 0.017415] [00002658] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[ 0.017662] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.017797] [00002658] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.017872] [00002658] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.017924] [00002658] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.017971] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [1E]
[ 0.018116] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.018234] [00002658] libusb: debug [get_api_type] driver(s): BTHUSB
[ 0.018310] [00002658] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 0.018358] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [3F]
[ 0.018521] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.018636] [00002658] libusb: debug [get_api_type] driver(s): HidUsb
[ 0.018703] [00002658] libusb: debug [get_api_type] matched driver name against HID API
[ 0.018753] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [68]
[ 0.018811] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.018926] [00002658] libusb: debug [get_api_type] driver(s): usbccgp
[ 0.018993] [00002658] libusb: debug [get_api_type] matched driver name against Composite API
[ 0.019043] [00002658] libusb: debug [winusb_get_device_list] allocating new device for session [69]
[ 0.019141] [00002658] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[ 0.019462] [00002658] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[ 0.019543] [00002658] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[ 0.019761] [00002658] libusb: debug [winusb_get_device_list] ENUM pass GEN
[ 0.020226] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 0.020375] [00002658] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020431] [00002658] libusb: debug [winusb_get_device_list] found existing device for session [3F]
[ 0.020533] [00002658] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020587] [00002658] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 200 bytes)
[ 0.020642] [00002658] libusb: debug [init_device] (bus: 1, addr: 2, depth: 1, port: 10): 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 0.020693] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 0.020783] [00002658] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020837] [00002658] libusb: debug [winusb_get_device_list] found existing device for session [68]
[ 0.020919] [00002658] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.020971] [00002658] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 34 bytes)
[ 0.021021] [00002658] libusb: debug [init_device] (bus: 1, addr: 13, depth: 1, port: 3): 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 0.021070] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 0.021164] [00002658] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.021212] [00002658] libusb: debug [winusb_get_device_list] found existing device for session [69]
[ 0.021314] [00002658] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_04F2&PID_B6DD\0001'
[ 0.021366] [00002658] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 512 bytes)
[ 0.021418] [00002658] libusb: debug [init_device] (bus: 1, addr: 3, depth: 1, port: 5): 'USB\VID_04F2&PID_B6DD\0001'
[ 0.021469] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.021573] [00002658] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.021622] [00002658] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 0.021701] [00002658] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.021754] [00002658] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 46 bytes)
[ 0.021804] [00002658] libusb: debug [init_device] (bus: 1, addr: 4, depth: 1, port: 7): 'USB\VID_1C7A&PID_0575\077E2F9A'
[ 0.021853] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 0.021937] [00002658] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.022060] [00002658] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&12C539F&0&0' reports 16 ports
[ 0.022145] [00002658] libusb: debug [init_device] (bus: 1, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 0.022195] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[ 0.022284] [00002658] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[ 0.022341] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 0.022424] [00002658] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.022545] [00002658] libusb: debug [init_root_hub] root hub 'USB\ROOT_HUB30\4&1A63DC7C&0&0' reports 5 ports
[ 0.022603] [00002658] libusb: debug [init_device] (bus: 2, addr: 0, depth: 0, port: 0): 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 0.022732] [00002658] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.022922] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[ 0.022986] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.023054] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[ 0.023104] [00002658] libusb: debug [winusb_get_device_list] setting HID interface for [68]:
[ 0.023153] [00002658] libusb: debug [set_hid_interface] interface[0] = \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.023218] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[ 0.023358] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[ 0.023434] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[ 0.023488] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.023552] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[ 0.023611] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.023677] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[ 0.023735] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.023799] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[ 0.023857] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 0.023922] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[ 0.023981] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 0.024045] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[ 0.024102] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 0.024165] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[ 0.024219] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.024290] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[ 0.024349] [00002658] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 0.024411] [00002658] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[ 0.024459] [00002658] libusb: debug [winusb_get_device_list] setting HID interface for [68]:
[ 0.024504] [00002658] libusb: debug [set_hid_interface] interface[1] = \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 0.024657] [00002658] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 0.025020] [00002658] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[ 0.025185] [00002658] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 0.025347] [00002658] libusb: debug [get_api_type] driver(s): WUDFRd
[ 0.025498] [00002658] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 0.025605] [00002658] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 0.026205] [00002658] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 00000269762eea10 with handle 1
[ 0.026349] [00002658] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 00000269762eef50 with handle 2
[ 0.026449] [00002658] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.026546] [00002658] libusb: debug [handle_events] event sources modified, reallocating event data
[ 0.026644] [00002658] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 5.313959] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass HUB {F18A0E88-C30C-11D0-8815-00A0C906BED8}
[ 5.314174] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 5.314400] [00003b80] libusb: debug [winusb_get_device_list] allocating new device for session [85]
[ 5.314539] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 5.314636] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [5]
[ 5.314699] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 5.314778] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [6]
[ 5.314837] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 5.314910] [00003b80] libusb: debug [winusb_get_device_list] allocating new device for session [86]
[ 5.315301] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass DEV {A5DCBF10-6530-11D2-901F-00C04FB951ED}
[ 5.315458] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 5.315616] [00003b80] libusb: debug [get_api_type] driver(s): WUDFRd
[ 5.315703] [00003b80] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 5.315774] [00003b80] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 5.315925] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 5.316096] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 5.316303] [00003b80] libusb: debug [get_api_type] driver(s): BTHUSB
[ 5.316409] [00003b80] libusb: debug [get_api_type] lower filter driver(s): ibtusb
[ 5.316738] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [3F]
[ 5.316974] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 5.317176] [00003b80] libusb: debug [get_api_type] driver(s): HidUsb
[ 5.317283] [00003b80] libusb: debug [get_api_type] matched driver name against HID API
[ 5.317367] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [68]
[ 5.317450] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 5.317681] [00003b80] libusb: debug [get_api_type] driver(s): usbccgp
[ 5.317813] [00003b80] libusb: debug [get_api_type] matched driver name against Composite API
[ 5.317872] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [69]
[ 5.317943] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[ 5.318159] [00003b80] libusb: debug [get_api_type] driver(s): usbccgp
[ 5.318248] [00003b80] libusb: debug [get_api_type] matched driver name against Composite API
[ 5.318304] [00003b80] libusb: debug [winusb_get_device_list] allocating new device for session [87]
[ 5.318440] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass HCD {3ABF6F2D-71C4-462A-8A92-1E6861E6AF27}
[ 5.318764] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_A0ED&SUBSYS_15451025&REV_20\3&11583659&0&A0
[ 5.320212] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing PCI\VEN_8086&DEV_9A13&SUBSYS_72708086&REV_01\3&11583659&0&68
[ 5.322513] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass GEN
[ 5.323121] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0612\5&1A00B1C&0&2
[ 5.323296] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 5.323396] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [85]
[ 5.323561] [00003b80] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 5.323666] [00003b80] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 31 bytes)
[ 5.323754] [00003b80] libusb: debug [init_device] (bus: 2, addr: 7, depth: 1, port: 2): 'USB\VID_05E3&PID_0612\5&1A00B1C&0&2'
[ 5.323834] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_8087&PID_0026\5&586B51A&0&10
[ 5.323986] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_8087&PID_0026\5&586B51A&0&10'
[ 5.324073] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [3F]
[ 5.324151] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1EA7&PID_0064\5&586B51A&0&3
[ 5.324355] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_1EA7&PID_0064\5&586B51A&0&3'
[ 5.324447] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [68]
[ 5.324533] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD\0001
[ 5.324780] [00003b80] libusb: debug [winusb_get_device_list] extra GUID: {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 5.324994] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [69]
[ 5.325202] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_00\7&315E345F&4&0000
[ 5.325488] [00003b80] libusb: debug [winusb_get_device_list] extra GUID: {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[ 5.325717] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 5.325997] [00003b80] libusb: debug [winusb_get_device_list] extra GUID: {20348E47-A897-468E-9D0E-56307802FC2A}
[ 5.326208] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [1E]
[ 5.326429] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001
[ 5.326557] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_03EB&PID_2177&MI_01\7&315E345F&4&0001'
[ 5.326625] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&12C539F&0&0
[ 5.326725] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&12C539F&0&0'
[ 5.326800] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000
[ 5.326896] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_04F2&PID_B6DD&MI_00\6&2F8D90E&0&0000'
[ 5.326958] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_05E3&PID_0610\5&586B51A&0&2
[ 5.327053] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 5.327109] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [86]
[ 5.327212] [00003b80] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 5.327273] [00003b80] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 41 bytes)
[ 5.327347] [00003b80] libusb: debug [init_device] (bus: 1, addr: 29, depth: 1, port: 2): 'USB\VID_05E3&PID_0610\5&586B51A&0&2'
[ 5.327423] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_03EB&PID_2177\BUR200973052
[ 5.327563] [00003b80] libusb: debug [winusb_get_device_list] extra GUID: {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
[ 5.327640] [00003b80] libusb: debug [winusb_get_device_list] found existing device for session [87]
[ 5.327851] [00003b80] libusb: debug [init_device] found 1 configurations (current config: 1) for device 'USB\VID_03EB&PID_2177\BUR200973052'
[ 5.327974] [00003b80] libusb: debug [cache_config_descriptors] cached config descriptor 0 (bConfigurationValue=1, 107 bytes)
[ 5.328106] [00003b80] libusb: debug [init_device] (bus: 1, addr: 30, depth: 2, port: 2): 'USB\VID_03EB&PID_2177\BUR200973052'
[ 5.328169] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\ROOT_HUB30\4&1A63DC7C&0&0
[ 5.328281] [00003b80] libusb: warning [get_guid] no DeviceInterfaceGUID registered for 'USB\ROOT_HUB30\4&1A63DC7C&0&0'
[ 5.328510] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass HID {4D1E55B2-F16F-11CF-88CB-001111000030}
[ 5.328780] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000
[ 5.328878] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL01\5&2F64DFEA&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 5.329013] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL02\6&1BDFD61D&0&0001
[ 5.329097] [00003b80] libusb: debug [winusb_get_device_list] setting HID interface for [68]:
[ 5.329173] [00003b80] libusb: debug [set_hid_interface] interface[0] already set to \\?\HID#VID_1EA7&PID_0064&COL02#6&1BDFD61D&0&0001#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 5.329271] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL01\9&3ABB00B2&0&0000
[ 5.329435] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\{00001812-0000-1000-8000-00805F9B34FB}_DEV_VID&02046D_PID&B021_REV&0007_FD9C982FF43F&COL02\9&3ABB00B2&0&0001
[ 5.329542] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\INTC816\3&D2322F2&0&0000
[ 5.329641] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\INTC816\3&D2322F2&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 5.329744] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001
[ 5.329848] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL02\5&2F64DFEA&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 5.329963] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002
[ 5.330059] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL03\5&2F64DFEA&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 5.330143] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003
[ 5.330221] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\SYNA7DAB&COL04\5&2F64DFEA&0&0003' (non USB HID, newly connected, etc.) - ignoring
[ 5.330301] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001
[ 5.330495] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL02\5&32CF90E6&0&0001' (non USB HID, newly connected, etc.) - ignoring
[ 5.330586] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002
[ 5.330663] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL03\5&32CF90E6&0&0002' (non USB HID, newly connected, etc.) - ignoring
[ 5.330732] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\10251229\3&9D5D338&0&0000
[ 5.330791] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\10251229\3&9D5D338&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 5.330857] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000
[ 5.330916] [00003b80] libusb: debug [winusb_get_device_list] unlisted ancestor for 'HID\CONVERTEDDEVICE&COL01\5&32CF90E6&0&0000' (non USB HID, newly connected, etc.) - ignoring
[ 5.330984] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing HID\VID_1EA7&PID_0064&COL01\6&1BDFD61D&0&0000
[ 5.331035] [00003b80] libusb: debug [winusb_get_device_list] setting HID interface for [68]:
[ 5.331082] [00003b80] libusb: debug [set_hid_interface] interface[1] already set to \\?\HID#VID_1EA7&PID_0064&COL01#6&1BDFD61D&0&0000#{4D1E55B2-F16F-11CF-88CB-001111000030}
[ 5.331254] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass EXT {16126A05-3179-4589-9DB8-952AFFD297D5}
[ 5.331640] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass EXT {D841CD8A-1E2B-37ED-271E-5700F86978DA}
[ 5.332053] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass EXT {20348E47-A897-468E-9D0E-56307802FC2A}
[ 5.332238] [00003b80] libusb: debug [winusb_get_device_list] ENUM processing USB\VID_1C7A&PID_0575\077E2F9A
[ 5.332429] [00003b80] libusb: debug [get_api_type] driver(s): WUDFRd
[ 5.332525] [00003b80] libusb: debug [get_api_type] lower filter driver(s): WinUsb
[ 5.332574] [00003b80] libusb: debug [get_api_type] matched lower filter driver name against WinUSB
[ 5.332864] [00003b80] libusb: debug [winusb_get_device_list] ENUM pass EXT {7FD43CF6-B517-CA1D-05C1-B7066E6953B3}
[ 5.333510] [00002658] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 5.333582] [00002658] libusb: debug [handle_event_trigger] event triggered
[ 5.333651] [00002658] libusb: debug [handle_event_trigger] hotplug message received
[ 5.333732] [00002658] libusb: debug [libusb_get_device_descriptor]
Device attached: 05e3:0612
[ 5.334964] [00002658] libusb: debug [libusb_open] open 2.7
[ 5.335030] [00002658] libusb: debug [winusb_open] unsupported API call for 'open' (unrecognized device driver)
[ 5.335093] [00002658] libusb: debug [libusb_open] open 2.7 returns -12
Error opening device: Operation not supported or unimplemented on this platform
[ 5.338703] [00002658] libusb: debug [libusb_get_device_descriptor]
Device attached: 05e3:0610
[ 5.339901] [00002658] libusb: debug [libusb_open] open 1.29
[ 5.339973] [00002658] libusb: debug [winusb_open] unsupported API call for 'open' (unrecognized device driver)
[ 5.340036] [00002658] libusb: debug [libusb_open] open 1.29 returns -12
Error opening device: Operation not supported or unimplemented on this platform
[ 5.343395] [00002658] libusb: debug [libusb_get_device_descriptor]
Device attached: 03eb:2177
[ 5.344533] [00002658] libusb: debug [libusb_open] open 1.30
[ 5.344601] [00002658] libusb: debug [libusb_open] open 1.30 returns -5
Error opening device: Entity not found
[ 5.346365] [00002658] libusb: debug [libusb_exit] destroying default context
[ 5.346437] [00002658] libusb: debug [libusb_unref_device] destroy device 1.30
[ 5.346500] [00002658] libusb: debug [libusb_unref_device] destroy device 1.29
[ 5.346554] [00002658] libusb: debug [libusb_unref_device] destroy device 2.7
[ 5.346608] [00002658] libusb: debug [libusb_unref_device] destroy device 1.3
[ 5.346669] [00002658] libusb: debug [libusb_unref_device] destroy device 1.13
[ 5.346726] [00002658] libusb: debug [libusb_unref_device] destroy device 1.2
[ 5.346805] [00002658] libusb: debug [libusb_unref_device] destroy device 1.4
[ 5.346870] [00002658] libusb: debug [libusb_unref_device] destroy device 2.0
[ 5.346932] [00002658] libusb: debug [libusb_unref_device] destroy device 1.0
[ 5.347002] [00004a78] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 5.348766] [00003b80] libusb: debug [windows_event_thread_main] windows event thread exiting
[ 5.349553] [00002658] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000e0
[ 5.349656] [00002658] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000dc

@sonatique
Copy link
Contributor Author

@yume-chan

If we want to use CM_Register_Notification (and only support hot plugging on Windows 8 and later) ...

Thanks a lot for all this information. I think that the decision of whether support Windows 8+ or not is not to be taken by me.

@whitequark : thanks a lot as well for these interesting facts. May I ask how you did manage to have a clear disassembly of CM_Register_Notification? I am not really experienced with disassemmbling C/C++ binaries, thanks in advance.

Now, trying to get a bigger picture: what are the known drawbacks of using the message pump in the way I did it? Or, put the other way round: what benefits could we expect from moving to CM_Register_Notification? Thanks!

@sonatique
Copy link
Contributor Author

@mcuee : thanks for reporting; I will try to reproduce. I this point I am not sure whether I introduced a problem or not. I mean: hotplug test code tries to open whatever device triggers hotplug events. Some of them may not be "open-able" at all
For the "entity not found" : it might be a different story, but the thing is that, as you saw in the code, I basically only added some Windows event handling to trigger a re-enumeration of all devices using only slightly modified "winXX_get_device_list".
What I mean is that if we now get an "entity not found" when trying to access a device returned by this enumeration, we could probably reproduce this with master.

Anyway I will either try to fix it or commit some additional tests for you to run, if you're OK.

@sonatique
Copy link
Contributor Author

Hello again @tormodvolden,

I am back at looking at the "hotplug_poll" issue. And seeking for some advices about how to solve it.

Let me try to explain better (...)The user program will then see no change in the list, probably carry on and patiently wait for a new event. Only when a second event arrives, it will see the device change that triggered the first event.

For solving it, my base concern is that I want to avoid fully enumerating the device list every time the user call libusb_get_device_list , i.e. I don't want hotplug_poll to be implemented with simply calling windows_refresh_device_list_for_all_ctx. As said previously this would defeat one of the nice benefit of having hotplug implemented.

So, I am thinking about what you wrote. Say the user application registered its own device plug/unplug detection (ignoring LIBUSB_CAP_HAS_HOTPLUG). Since it is decoupled from libusb hotplug event loop, it may receive its event well before libusb event loop realize something happened. I am just paraphrasing what you wrote, for now.

When the user call libusb_get_device_list, libusb doesn't even have the idea that something changed and it doesn't know whether the user is calling because he's pretty sure something change, or just like this, to routinely get the list.

So: how could I implement hoplug_poll?
I could wait for the next internal event to occur/terminate, then go on and return the updated list. If the call to libusb_get_device_list is indeed resulting from the user (correctly) detecting some device changes before libusb, libusb own mechanism will trigger sooner or later, update the list and un-block the call.

But if the call to libusb_get_device_list result from the user just wanting to get the list (e.g. the initial get for populating its own list), then then call may block until the next device change occurs, which might be... never.

I had a look at linux implementation: hotplug_poll is checking for pending events and processing them, like they would have been processed from libusb event thread. This is all good as long as we supposed that the user own device change detection is based on the same mechanism. Otherwise, it may detect a device change from whatever origin, calllibusb_get_device_list` but there could not yet be any event to see from libusb perspective and the result would be the same issue you described.

As far as my knowledge goes, there is no such "event register" to poll under Windows, we need to register a callback. This means that in order to mimic what Linux does, I would have to recreate such "event register" internally. But this register won't be in sync with whatever mechanism the user is using, and there would therefore be no guarantee that a call to libusb_get_device_list will not hit the issue.

The only thing I can think of for now is to add a (bool) parameter to libusb_get_device_list to indicate the user wants to force refresh: when the user calls it from its own device change detection event, it shall ask for a forced refresh, otherwise not. But I am not liking it very much. Especially since, in order to have "pre-hotplug" implementation to work without code change with the now hotplug-enabled new libusb, the "force refresh" parameter should be "true" by default, killing the purpose of hotplug.

What I can do otherwise is implement hotplug_poll in way that if it sees that there is a current refresh list ongoing but not terminated (it means the user call was issues very shortly after libusb event loop detected the change) then it waits for it to be terminated, then returns the updated list. This could probably mitigate some of the issue occurrences, but not all obviously since it won't solve the case where the user call happens before.

Can you think of something better? What shall I do in your opinion? I am sorry I don't have the magical solution you may have expected.

Thanks!

@sonatique
Copy link
Contributor Author

Or maybe we we could do, in order to preserve compatibility with pre-hotplug Windows client implementation, is to implement an additional mechanism to disable/enable hotplug support at runtime and have it disabled by default on Windows. With this in place, existing implementation updating their libsub-1.0 to the newer hotplug-capable version would not see a difference since hotplug would be disabled. Implementation wanting to benefit from new hotplug should enable it.

This is doable, but of course add a layer of complexity and maintenance. It is more a "political" decision than a "technical" one.

So far I don't have better ideas / input. @tormodvolden : any thought?

@sonatique
Copy link
Contributor Author

hollo @sonatique : this feature help me a lot, thanks. but recently I have an issue on windows hotplug. if I restart (use pnputil or devcon.exe to Disconnect / Connect a USB device "softly".) a USB device, i can't get the ARRIVED or LEFT event. I restart a device like this: pnputil /restart-device "USB\VID_22B8&PID_2E82\ZY223LQ5DP"

libusb did receive both the DBT_DEVICEREMOVECOMPLETE and DBT_DEVICEARRIVAL events after restart device. but the device "USB\VID_22B8&PID_2E82\ZY223LQ5DP" hotplug_status not changed to LEFT.

Hello @anqiren ,
Sorry for coming back this late to you regarding the mentioned issue.

I identified the cause, which is actually quite trivial, but not easy to fix with how I implemented things and what Windows gives us to actually implement anything at all.

When you do the pnputil /restart-device, the device is indeed quickly removed and re-added to the system. But by the time the hotplug event thread receive the "DBT_DEVICEREMOVECOMPLETE" notification, the device is actually back online already.

So when this event is processed, enumerating all now-present devices in order to find which one left (the difference with respect to the previous list), it does not find any, all devices are there. So no device is triggering an hotplug event, nothing happens.

The same happens when we receive the "DBT_DEVICEARRIVAL": the implementation cannot detect the new device since when comparing with the previous list, nothing changed.

So yes, you won't get LEFT / ARRIVAL events in this case. The implementation is made such that there is a sort of implicit time window or "grace period" within which devices can be quickly removed and re-added (or added then removed) without triggering any visible libusb-1.0 hotplug events.

From the point of view where hotplug events are actually used only to trigger refreshes of the current device list, this is OK: "macroscopically" it is OK to say that nothing changed, but I understand that "microscopically" this doesn't look right and might cause issues to implementations relying on a 1:1 relationship in between low level events and libusb-1.0 events.

When receiving DBT events we could check in the DEV_BROADCAST_DEVICEINTERFACE structure for the name of the device that triggered the system event and use this for triggering a libusb event on the correct device object.

I decided not to do this when I worked on the hotplug feature because the name of the device (as far as I could understand) only reflect VID / PID / SerialNumber, but doesn't provide a unique ID per device instance.

Therefore if there are more than one device on the system with same VID/PID/SerialNumber, it won't be possible to find with certainty which libusb-1.0 device object to trigger the event for.

Libusb-1.0 can identify each device instance specifically but this level of details is not available at the Windows event level.

Of course, when there is only one device with a given VID/PID/SerialNumber plugged at a time, then we could search for the name in the current libusub-1.0 device list and trigger events for it. But this won't work as soon as there are more than one.

So, I decided to no implement this at all.

Now, if the community prefer another approach, I could work on using the device name in the Windows event to match a device in the libusb-1.0 list and triggering events when there is one and only one with certainty. That would probably solve most real cases, but I don't know. I don't really like the idea that resulting events would depend on the number and type of devices plugged.

What do you think @anqiren ? Or @mcuee or @tormodvolden ?

Does anyone figured out a way to get a sort of per device unique id from Windows events?

Thanks!

@sonatique
Copy link
Contributor Author

@anqiren , well, actually, after I wrote my previous message, I found evidence that dbcc_name could actually be unique.
I will investigate more and see whether I have a way to use this to find the good device in libusb-1.0 current device list.

…dbcc_name

for finding corresponding device in current context list and triggering LEFT
or ARRIVED event.
(No longer set LEFT / ARRIVED status during re-enumeration.)
@sonatique
Copy link
Contributor Author

@anqiren I think I found a simple way to achieve a better implementation that nonetheless fix your issue, but also simplify existing code (and potentially add robustness).

The assumption is that Windows will do what is necessary to create a unique name per device even when more than one devices have equal VID, PID, SerialName.

I will try to find a correct way to verify this assumption, unless someone can validate it for me.

@anqiren Could you please test my latest commit on this PR ("hotplug implementation: use PDEV_BROADCAST_DEVICEINTERFACE->dbcc_name (...)" and let me known whether everything works for you?

@tormodvolden @mcuee @fabiensanglard @xhwang-China @whitequark and all: what do you think?
Would you mind to retest with the latest commit and let me know whether everything still works for you?

Thanks

@whitequark
Copy link

@sonatique Happy to test with the Glasgow Interface Explorer which uses hotplug functionality to detect the FX2 re-enumerating. Do you happen to have a prebuilt libusb-1.0.dll I can use?

@sonatique
Copy link
Contributor Author

@whitequark here you go: (release X64 dll, had to zip it for being able to attach it here):
libusb-1.0.zip
Thank you!

@mcuee
Copy link
Member

mcuee commented Jun 19, 2024

Yes I will carry out the tests again.
Initial test under Windows 10 seems to be good (with the Dell Docking Station).

@mcuee
Copy link
Member

mcuee commented Jun 24, 2024

More test results: using Cypress FX2LP (downloading the Cystream FW to remunerate as a new device and then start hotplugtest example, then reset the board, and download the FW again). Looks okay.

$ ./examples/hotplugtest.exe
Device detached: 04b4:00f1
Device attached: 04b4:8613
Device detached: 04b4:8613
Device attached: 04b4:00f1

I also checked other test cases and verified that there are no devices ref/unref related issues.

whitequark added a commit to whitequark/glasgow that referenced this pull request Jun 26, 2024
Now that libusb will support hotplug events on Windows shortly (see
libusb/libusb#1406), the hotplug wait path will get exercised.
Currently it does not wait for long enough; it takes about 5.5 s on
a representative Windows desktop machine used for testing.

This commit raises re-enumeration timeout to 10.0 s, and ensure that
the timeout is respected no matter how many hotplug events are received.
The higher fixed timeout on older libusb on Windows isn't disruptive,
and with the next libusb release will become irrelevant for most.
whitequark added a commit to whitequark/glasgow that referenced this pull request Jun 26, 2024
Now that libusb will support hotplug events on Windows shortly (see
libusb/libusb#1406), the hotplug wait path will get exercised.
Currently it does not wait for long enough; it takes about 5.5 s on
a representative Windows desktop machine used for testing.

This commit raises re-enumeration timeout to 10.0 s, and ensure that
the timeout is respected no matter how many hotplug events are received.
The higher fixed timeout on older libusb on Windows isn't disruptive,
and with the next libusb release will become irrelevant for most.
@whitequark
Copy link

@whitequark here you go: (release X64 dll, had to zip it for being able to attach it here):

Verified that everything works with the Glasgow Interface Explorer. I had to raise the timeout I've had a little (see GlasgowEmbedded/glasgow#601), it turns out 5 s isn't quite enough. Otherwise the existing Linux developed code worked perfectly.

github-merge-queue bot pushed a commit to GlasgowEmbedded/glasgow that referenced this pull request Jun 26, 2024
Now that libusb will support hotplug events on Windows shortly (see
libusb/libusb#1406), the hotplug wait path will get exercised.
Currently it does not wait for long enough; it takes about 5.5 s on
a representative Windows desktop machine used for testing.

This commit raises re-enumeration timeout to 10.0 s, and ensure that
the timeout is respected no matter how many hotplug events are received.
The higher fixed timeout on older libusb on Windows isn't disruptive,
and with the next libusb release will become irrelevant for most.
@oleavr
Copy link

oleavr commented Jun 27, 2024

Awesome work! We (@hsorbo and I) just took this for a spin in Frida, and noticed an edge-case when modeswitching an iDevice. Turns out DBT_DEVICEARRIVAL may happen before the system has finished identifying the drivers to be used. A known workaround is to defer arrival handling until after a subsequent DBT_DEVNODES_CHANGED. This doesn't seem to be very reliable though, as an unrelated DBT_DEVICEREMOVECOMPLETE happening around the same time would also trigger DBT_DEVNODES_CHANGED. Plus, there might be more than one DBT_DEVNODES_CHANGED emitted per arrived device. We took a stab at a workaround and figured we should share it here in case it's helpful.

@pgorgon-hem
Copy link

@whitequark here you go: (release X64 dll, had to zip it for being able to attach it here): libusb-1.0.zip Thank you!

Hello everyone!

I have tested attached dll in our environment. It works properly with "single driver" device, but it doesn't work correctly with composite devices. I just can't open a composite device when it is detected by hotplug. After a start of an application, it works correctly. I suppose it is the same issue as @oleavr mentioned.

A year ago, I developed my own implementation of hotplug, based on version 1.0.26. It uses some very old code + a lot of my rework. You can find the code here. I'm sorry for not creating PR, but I didn't have time to manage it that time. What is important, it works in both situations i.e. for single driver device and composite device. Maybe it can help you or I can help with this anyhow.

Regarding the issue, I have found in my code, that I implemented it using the fact, that WM_DEVICECHANGE event provides an information what has changed. When it provides information that usb device was attached, my code creates usb device. Then it receives events about setup of each interface of composite device, so it configures interfaces on corresponding events. It also doesn't refresh all the devices, (I'm worry it can be slow in some situations), but only adds or removes what arrives in the event. Unfortunately, when hotplug event occures, interfaces can be not set up yet, but this is how Windows works and maybe it is not an issue. On the other hand, we don't know whether an interface receives an event or not, so we can't wait for it (e.g. It doesn't receive an event when driver is not installed, or it is disabled).

If you wish, you can test my implementation by using this file:
libusb-1.0-hem-hotplug.zip

@sonatique
Copy link
Contributor Author

sonatique commented Jul 4, 2024

@pgorgon-hem : interesting, thank you! I am looking at your code.

Note that the reason for reusing the big enumeration loop in my implementation was to try to maximize backward compatibility + not re-inventing the wheel or copy/pasting/re-writing a lot of code in another hotplug-specific function, given that we still need the big enumeration to create the starting point state.

However from your message it seems that I missed some way to extract more information about the device triggering the event, that is interesting. I'll try to extract this from your code, or find another way to fix the issue, thanks,

@pgorgon-hem
Copy link

@pgorgon-hem : interesting, thank you! I am looking at your code.

Note that the reason for reusing the big enumeration loop in my implementation was to try to maximize backward compatibility + not re-inventing the wheel or copy/pasting/re-writing a lot of code in another hotplug-specific function, given that we still need the big enumeration to create the starting point state.

However from your message it seems that I missed some way to extract more information about the device triggering the event, that is interesting. I'll try to extract this from your code, or find another way to fix the issue, thanks,

I'm aware of that we need starting point, and this is why I left original function and called it during init. Host devices are detected only there, and I suppose it is correct. To make all of this work I had to import a few more functions from Windows API, there was some specific need to convert 2 different handles as I remember.

I can make PR of my code for reference. Then it is easier to see what has changed. What do you think? I really would like to contribute, but I don't want to compete with you in PRs.

PS. I also slightly changed behavior of devices which are disabled or have no driver, because they are not operational. I know that it is different than on linux, but on linux you don't need driver to communicate with a device, so I think it is just platform specific thing.

PS2. I was thinking about the compatibility issue. Maybe it is good idea to make it configurable in runtime? I did it in compile time but doing it in the same way for runtime seams only a little more work. Another idea is creating 3rd windows port, which could share the same code, but have different behavior. Then we still need some mechanism to tell the core library whether hotplug is supported or not, but switching is almost done then. And what is more important it gives us a little more space for slightly changing some behaviors and give users choice if they want to stay with current implementation or go into next. After some time, it would be even possible to change the default driver.

PS3. Maybe it would be a good idea to refactor winusb_get_device_list function, because it is very unclear how it works, which slows down development.

@DoubleSpicy
Copy link

Hi @sonatique I'm trying to setup a test envrionment on windows 11 by building this branch.
Running hotplugtest throws Hotplug capabilities are not supported on this platform, are there any special care required when building the project on visual studio?

OS Name : Microsoft Windows 11 Pro
OS Version : 10.0.22631 N/A Build 22631

P.S. stress_mt would also throw LIBUSB_ERROR_NOT_SUPPORTED

@sonatique
Copy link
Contributor Author

sonatique commented Jul 8, 2024

(..) I'm trying to setup a test envrionment on windows 11 by building this branch. Running hotplugtest throws Hotplug capabilities are not supported on this platform, are there any special care required when building the project on visual studio?

Hello @DoubleSpicy,
I am not aware of such problem, compilation and run from Visual Studio should be quite straightforward and probllem-free.
DId you load solution libusb.sln from MSVC folder? Did you double checked that you git pulled my branch?
Which build configuration are you using? Debug, Debug-MT, Release, Release-MT?
Are you running in debug mode (using "F5") or in release?
Could you put a break on line 119 of hotplugtest.c if (!libusb_has_capability (LIBUSB_CAP_HAS_HOTPLUG)) { then "step into" with the debugger and tell me if usbi_backend.get_device_list is indeed not null (it is null when hotplug IS supported). If it is not null, it would be interesting to understand who set it to a value, given I think that in my branch it is not assigned anywhere....
Thank you in advance for your reply.

@DoubleSpicy
Copy link

DoubleSpicy commented Jul 8, 2024

@sonatique I was too sleepy last night, simply didn't checkout the branch, some simple tests by unplugging my joysticks (both XInput and DirectInput) looks good.

I will see more possibilities in terms of joystick.

P.S. @oleavr I also found similar issue when writing some joystick hooks recently, raw input events sent out to another thread would occasionally be reordered, probably is a general behavior for all windows event message queues.
For example WM_INPUT_DEVICE_CHANGE with GIDC_REMOVAL may come earlier than WM_INPUT when unplugging a joystick

@fabiensanglard
Copy link

fabiensanglard commented Jul 18, 2024

@tormodvolden @mcuee @fabiensanglard @xhwang-China @whitequark and all: what do you think?
Would you mind to retest with the latest commit and let me know whether everything still works for you?

I re-tested Android adb with this PR and it works like a charm.

@tormodvolden @mcuee: What about me merge this PR as-is and keep on working on edge-cases in later PRs? My reason for this suggestiong are:

  • This PR has been ongoing for six months, and I am concerned it is going to end up in limbo (like several previous attempts).
  • In its current state it does not break anything. It actually brings hot-plug to most Windows users while leaving others (composite) at the same level of features.
  • Having Windows hotplug merged would give us access to users using libusb HEAD and allow further tests before the next release.

@whitequark
Copy link

I would very much like to see the PR merged, personally. I realize there are some minor issues but I feel that this is a "perfect is the enemy of good" case.

@mcuee
Copy link
Member

mcuee commented Jul 18, 2024

@tormodvolden @mcuee: What about me merge this PR as-is and keep on working on edge-cases in later PRs? My reason for this suggestiong are:

  • This PR has been ongoing for six months, and I am concerned it is going to end up in limbo (like several previous attempts).
  • In its current state it does not break anything. It actually brings hot-plug to most Windows users while leaving others (composite) at the same level of features.
  • Having Windows hotplug merged would give us access to users using libusb HEAD and allow further tests before the next release.

I will support your recommendation. But then @tormodvolden will have the say since I am not touching the codes (mainly on testing and support side).

@hjelmn
Copy link
Member

hjelmn commented Jul 19, 2024

My personal (and professional) opinions about Windows aside... I see no reason not to merge this and deal with issues as they come up. Having developers use this will help shake out the remaining bugs.

@tormodvolden
Copy link
Contributor

I have expressed my concerns e.g. in #1406 (comment) and to repeat some of it: This is not an opt-in feature, the new hotplug code will be used by all programs and users. We must therefore assure there are no significant regressions. I would prefer to avoid any opt-in switch as discussed in #1406 (comment) in particular if it adds APIs that we need to carry. I have mentioned the missing hotplug_poll and suggested a possible failure pattern. And I have not seen reports of testing the new library code on an old application doing its own hotplug reenumeration, that would have reassured me in this regard. If anyone wants to help this getting merged, that would be a good way to contribute.

(That said I believe it is common in the Windows world to bundle library copies with each application so end users won't see their application break because of a system libusb update. So I am a little less afraid of regressions on this platform that only affects a small number of applications.)

Is the issue seen by @anqiren confirmed as resolved in the latest revision?

There are recently some new ideas from @pgorgon-hem and @sonatique and I am curious where that discussion is going.

@fabiensanglard
Copy link

fabiensanglard commented Jul 22, 2024

And I have not seen reports of testing the new library code on an old application doing its own hotplug reenumeration, that would have reassured me in this regard. If anyone wants to help this getting merged, that would be a good way to contribute.

I confirm this scenario works (at least on adb). With this PR, the capability test libusb_has_capability(LIBUSB_CAP_HAS_HOTPLUG) disables our in-house hotplug in favor of the new "built-in" one.

@tormodvolden
Copy link
Contributor

That means your application has already been prepared for using libusb's hotplug and does the right thing. The scenario I am interested in is an unmodified Windows application always doing its own hotplug detection, unaware of what libusb's new capabilities are.

@pgorgon-hem
Copy link

That means your application has already been prepared for using libusb's hotplug and does the right thing. The scenario I am interested in is an unmodified Windows application always doing its own hotplug detection, unaware of what libusb's new capabilities are.

I think this is exactly the case, when we break compatibility with composite devices. App switches to new hotplug implementation, because libusb_has_capability(LIBUSB_CAP_HAS_HOTPLUG) == true, but then newly detected composite device can't be open.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet