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 3 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.

tormodvolden pushed a commit that referenced this pull request Mar 14, 2024
Remove all parents with a single child remaining in parent tree.

This ensures that no parents of the direct parent of the device being
considered are left in the list, when appearing before their child(ren)
in the processing order of the context device list cleaning.

References #1452
References #1406
tormodvolden pushed a commit that referenced this pull request Mar 14, 2024
This prevents concurrent access to the list by the event background
thread, which could still be processing a previous hotplug event and
having to modify the list.

Fixes #1366
Fixes #1445
Closes #1452
References #1406
@tormodvolden
Copy link
Contributor

I am probably not going to block this on the hotplug_poll() issue, but it is good if we are all aware of this potential issue, and can try to find a way to minimize it before next release. Other platforms like darwin and linux simply read events until there are no more pending events, suggesting everything has quieted down (maybe this also increases the chance for scheduling, so that the hotplug thread is more likely to get its work done). Can we do something similar on Windows?

It would also be great if all application developers who have their own event detection in combination with libusb_get_device_list() can verify that it still works with this PR applied. What I can imagine as possible symptoms is that the devices detection is intermittently lagging, with a plugged device only "showing up" (maybe with failing access) when it is unplugged again (supposing single devices being plugged).

@tormodvolden
Copy link
Contributor

tormodvolden commented Mar 14, 2024

well, as with anything multithreaded, he can miss the "very very last state change".

And (for a "legacy" application) this could typically be the exact state change that triggered their own event detection.

@sonatique
Copy link
Contributor Author

Hello @tormodvolden : sorry I didn't have time to reply or work on this but I am taking your concern seriously. I read your comments (including that one from 4 days ago) carefully and I think I understand the problem. I did not find an easy way to address it, but I am not desperate I can.

I just need some amount of free time to work on it.

@anqiren
Copy link

anqiren commented Mar 18, 2024

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.

@mcuee
Copy link
Member

mcuee commented Mar 19, 2024

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.

Interesting finding.

Let's see if @sonatique can identify the root cause or not.

But to me this may be a corner case we can deal with in the future.

@sonatique
Copy link
Contributor Author

Hello @anqiren , thank you for the feedback and for the issue report. I guess I'll have to test it to understand what is happening, I have to admit I didn't try this scenario.
Just to be sure I understand the case fully: your expectation is that when executing pnputil / restart-device, you get 2 libusb hotplug events, one saying the device left and then one saying the device arrived. Is this correct?

@anqiren
Copy link

anqiren commented Mar 19, 2024

Hello @anqiren , thank you for the feedback and for the issue report. I guess I'll have to test it to understand what is happening, I have to admit I didn't try this scenario. Just to be sure I understand the case fully: your expectation is that when executing pnputil / restart-device, you get 2 libusb hotplug events, one saying the device left and then one saying the device arrived. Is this correct?

yes, thanks for reply @sonatique, this is what i expected.
and i found that, when receive DBT_DEVICEREMOVECOMPLETE envent, winusb_get_device_list get the restarted device ( "USB\VID_22B8&PID_2E82\ZY223LQ5DP" in my case, an Android phone) in GEN_PASS, but not in HUB_PASS or DEV_PASS.
when receive DBT_DEVICEARRIVAL event, the restarted device is in DEV_PASS and GEN_PASS and the 'initialized' flag is false. Hope this helps.

@tormodvolden
Copy link
Contributor

About hotplug_poll(): If I understand correctly, the Linux implementation of it processes any pending hotplug events and updates the internal list of devices before libusb_get_device_list() returns the new list, all on the calling thread, whereas the macOS implementation of it waits for things to settle down while the hotplug thread is processing everything.

@tormodvolden
Copy link
Contributor

the restarted device is in DEV_PASS and GEN_PASS and the 'initialized' flag is false.

This reminds me about commit 4b732d9. Is it a possible challenge that we receive Windows events when the device appear, but we'd prefer to ignore it until it has been configured, for which we probably do not receive any event?

@FutureIsM
Copy link

@sonatique i think this is important for libusb, i see there is "This branch has conflicts that must be resolved", can you fix it ?

@tormodvolden
Copy link
Contributor

@sonatique i think this is important for libusb, i see there is "This branch has conflicts that must be resolved", can you fix it ?

This is just an automatic warning from GitHub, and in this case nothing to worry about. The "conflict" is trivial and in a code comment, no need to do anything.

@fabiensanglard
Copy link

no need to do anything.

Is there anything else I should do to get this PR merged? Who is in charge of merging from here?

@mcuee
Copy link
Member

mcuee commented May 7, 2024

no need to do anything.

Is there anything else I should do to get this PR merged? Who is in charge of merging from here?

You can carry out test and report the positive results.

As for merging, this PR is a big PR and @tormodvolden may need some time to review it before merging. As of now @tormodvolden and @hjelmn are the two main developer and committer for libusb project.

@nxpfrankli
Copy link
Contributor

I also tested it by https://github.com/nxp-imx/mfgtools and wait for merge into main line. Everything is good.

@tormodvolden
Copy link
Contributor

no need to do anything.

Is there anything else I should do to get this PR merged? Who is in charge of merging from here?

This was taking things out of context. I was referring to the merge conflict that someone was concerned about.

Yes, more testing is very welcome. Meanwhile we haven't heard from the submitter in almost two months, this is fine, but also means we are not rushing anything in their absence. There is a reported issue with pnputil, I don't know how important that is. There is the missing hotplug_poll, I also don't know how important that is. For the latter issue:

I would kindly ask anyone using a "home-made" hotplug scheme in their applications (calling libusb_get_device_list repeatedly) to test backwards-compatibility of this PR by using the new libusb but without making changes to the application. Especially watch out for issues with late or out-of-sync notification.

Mind also that with this PR, the new hotplug notification going on behind the scene is not an opt-in functionality. This will be used by everyone, with libusb_get_device_list() now running on top of it. So it is an important change. This has a performance impact, a good one for those who need updates often but have few real USB changes, but a bad one for those who need rare updates but has a lot of real USB changes on the machine since a full enumeration task will run all the time, although I am sure the latter use case is rare (and probably not something Windows deals well with anyway) so we can live with it. Also, a well-written multi-platform program will automatically switch to "proper" hotplug operation because the hotplug capability now will be reported. So this change needs a lot of testing before it can be released. Since many of us don't even use Windows, we are grateful if the community can help testing out and report their experience.

@sonatique
Copy link
Contributor Author

Hello @tormodvolden, @mcuee , et al.
I am sorry, life is such that I have not been able yet to look at the remaining potential issues : i) being sure hotplug_poll is correctly handled and ii) the "pnputil" issue (which might have a common cause).
The good news is that I should be able to get back on working on this, soon.
I'll keep you posted.

@fabiensanglard
Copy link

Is there anything else I should do to get this PR merged? Who is in charge of merging from here?

Apologies about the message, I thought I was replying on PR #1428 (for which I am the contributor and trying to get merged). I agree with everything you mentioned @tormodvolden. Sorry again about the confusion.

@fabiensanglard
Copy link

fabiensanglard commented May 31, 2024

I tested the latest patch again with adb. I did a little more advanced testing, in particular how hotplug behaved when laptop goes to sleep and power off the USB Host controllers.

Devices reconnect as expected after awakening. Everything is working well :) ! This is an awesome patch!

@tormodvolden and @hjelmn: Did you get a chance to look at it?

Depending on the devices or drivers, open() may return
 LIBUSB_ERROR_ACCESS
 LIBUSB_ERROR_NOT_FOUND
 LIBUSB_ERROR_NOT_SUPPORTED
for devices "out of reach" to libusb.
This fixes an issue where an error that occurred in thread #X will create a false
error message stating that thread #X+1 did not discover the correct number of devices
Implemented as is a three steps process:
1. We create a monitor on GUID_DEVINTERFACE_USB_DEVICE via a hidden window.
2. Upon notification of an event, we run the current windows backend to get
   the list of devices. This updates the hotplug status of each device to one
   of three values {UNCHANGED, ARRIVED, LEFT}.
3. According to the value, we generate events to libusb client via hotplug
   callbacks.
@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!

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