libusb
libusb copied to clipboard
Windows: Freezing in Kernel with libusb-win32
And does this mean that, even if a given device is "officially" using libusb0 (i.e. libusb0.sys, libusb0.dll reported by Device Manager), then in the end all functions of winusb_interface are backed by libusbK implementation and none of libusb0 code will be called?
I am having this understanding based on this code snippet from windows_winsub.c, funciton winusbx_init, line 2505:
// NB: The below for loop works because the sub_api value for WinUSB
// is a higher value than that of libusbK and libusb0
for (; sub_api < SUB_API_WINUSB; sub_api++) {
libusbK_Set(sub_api, AbortPipe, true);
libusbK_Set(sub_api, ControlTransfer, true);
libusbK_Set(sub_api, FlushPipe, true);
libusbK_Set(sub_api, Free, true);
libusbK_Set(sub_api, GetAssociatedInterface, true);
libusbK_Set(sub_api, Initialize, true);
libusbK_Set(sub_api, ReadPipe, true);
libusbK_Set(sub_api, ResetPipe, true);
libusbK_Set(sub_api, SetCurrentAlternateSetting, true);
libusbK_Set(sub_api, SetPipePolicy, true);
libusbK_Set(sub_api, WritePipe, true);
//etc.
sub_api
takes value from 0 to 1, i.e. SUB_API_LIBUBSK
and SUB_API_LIBUSB0
, meanig that function pointers corresponding to libusb0 are actually pointing to libusbK.
Thank you in advance for your help understanding this. Best regards.
libusb0.dll (libusb-win32 API) library is not used. libusbK.dll will talk to libusb0.sys directly through IOCTLs. libusbK.sys (KMDF based) supports all the IOCTLs from libusb0.sys (WDM based). https://github.com/mcuee/libusbk/blob/master/libusbK/src/drv_api.h
Does the following Wiki FAQ entry answer your question? https://github.com/libusb/libusb/wiki/FAQ#user-content-libusbwin32_libusbK_and_libusb_project_what_about_openusb
- WinUSB.sys kernel driver from Microsoft, through WinUSB.dll from Microsoft (if libusbK.dll is not present), or through libusbK.dll from libusbK project if libusbK.dll is present. libusb-1.0.dll --> WinUSB.dll --> WinUSB.sys (if libusbK.dll is not present) libusb-1.0.dll --> libusbK.dll --> WinUSB.dll --> WinUSB.sys
Edit --> Wiki updated. For libusb 1.0.24 onwards, it is alway use the following scheme, regardless of the presence of libusbK.dll. libusb-1.0.dll --> WinUSB.dll --> WinUSB.sys
-
libusbK.sys kernel driver from libusbK project, through libusbK.dll libusb-1.0.dll --> libusbK.dll --> libusbK.sys
-
libusb0.sys kernel driver from libusb-win32 project, through libusbK.dll from libusbK project libusb-1.0.dll --> libusbK.dll --> libusb0.sys
Hello, thank you for your prompt response. Sorry that I missed the Wiki FAQ. Yes I got my answers, thank you.
The reason behind it is that I have an issue with libusb_clear_halt: when called to a libusb0.sys device, it sometimes freeze completely, making the whole process unkillable. I am trying to understand where in the call it freezes exactly and started by looking at libusb sources.
But then I guess I shall have a look a libusbK so start with.
Just wondering what is the version of libusb0.sys are you using? You may want to try the latest 1.2.7.3 release if you are still using the older libusb0.sys 1.2.6.0 version.
Does the problem occure if you switch to WinUSB driver or libusbK.sys driver? If you suspect libusbK.dll issue, you may want to remove libusbK.dll and use WinUSB driver to try it out.
Another thing, some devices may choke at libusb_clear_halt
due to FW bugs (eg: USB data toggle) problem and may need libusb_reset
to go back to the normal state.
Hello @mcuee : I am using 1.2.7.3 indeed. And this behavior is happening with plain physical Windows (in case you wonder if I am on virtual machine, since I posted PR #1202 .
I still need to test with switching drivers indeed, though it is currently not an option to use them for real, beside for testing.
And yes: I am pretty sure that there is some bugs in the device FW. Right before I get a freezing clear_halt I can see failed ControlTransfer (out), that should not happen.
What I see is that as soon as I have a failed ControlTransfer, the next clear_halt will freeze for ever.
My problem is that I currently don't have access to the FW, so fixing the bug is not an option. I am writing complicated code to detect the failure condition and try a way to reset the device withtout freezing or causing other issues on the software side.
However, I feel like having a function that can freeze so hard that it prevent even Task Manager from killing its calling process, with no way of cancelling it, is not something that is desirable in general.
I don't understand why clear_halt could not return with an error if it can not do its task in a reasonable amount of time. And I didn't test yet, but I am pretty sure (based on what I observed so far) that reset_device would freeze as well.
Did I miss something in the API that could either let me specify a timeout for those functions, or let me call another function to cancel them?
Interesting. However buggy the device is, this shouldn't freeze the program or the machine if a timeout* is given.
There are some parts in libusb0.sys, especially the error paths, that I am unsure about. Do you have the WDK so that you can build and test patched drivers? Can you reproduce this in a VM (would be nice for such tests)?
*) if not in the high-level API, there should be some timeout /somewhere/. libusb0.sys uses the timeout specified in the IOCTL, also for clear_feature.
Thank you for your interest in my issue. "However buggy the device is, this shouldn't freeze the program": yes, that's my point, I am happy that we agree.
As for now I am working on finding a workaround at the application level, that's the priority.
But in parallel I will swap drivers to better understand who is responsible for this behavior, and in the end decide whether I could try to fix it or rather change driver for good. I should be able to build patched libusb0.sys versions if it happens that this code is where the freeze occurs.
For reference: my device is made of a FX3 connected to a Zynq. The issue happen when the Zynq is power-cycled while the FX3 is kept alive. It occurs with a probabily of 1/5 approximately, so there is probably some dependency of the exact timing of the events.
Also, I just noticed that I have the same issue with various devices when I hiibernate my computer, remove the devices, then wake it up: it seems that some part of the library / driver do not realize what just happened and go on with the tasks they were doing. If I call clear_halt at this point, it will freeze 100% of the times.
I am wondering whether the "freezes" I experience are somehow related to what is described in https://github.com/libusb/libusb/pull/1127 . I will try with the code proposed in this PR as well.
@sonatique
Any updates on this issue? Thanks.
@mcuee : Regarding the "freeze": I should soon be able to reproduce it and study it more in depth. I'll keep you posted
@mcuee : So I have been able to reproduce a similar issue, quite easily actually.
I made a while(1){...}
loop issuing libusb_control_transfer
of type Out|Vendor|Device to a previously open device. The detail of the transfer doesn't really matter but it corresponds to a command that is supported by the physical device (FX2).
In this loop I also print the return value if < 0.
I start the program, I can see that control transfer out are correctly transmitted and received, then I simply disconnect the USB cable (physically).
The behavior that occurs depends on the driver used. With libusb0.sys 1.2.7.3, the next transfer will fail with error code LIBUSB_ERROR_IO, but the next one will completely freeze the program.
Since I am launching my program from Visual Studio I can break. I see that the program is stuck in the call at line 3157 of windows_winusb.c
if (!WinUSBX[sub_api].ControlTransfer(winusb_handle, *setup ...
and I can see that it is somewhere in libusbK.dll.
From there I have an unkillable process that will stay there until I reboot the OS.
Using kernel debugger I can see that it is frozen somewhere within libusb0:
0: kd> !process 0 7 sam3u_benchmark.exe
PROCESS ffffb38cbaec2080
SessionId: 1 Cid: 6adc Peb: e03fc78000 ParentCid: 5924
DirBase: 6b7b63002 ObjectTable: ffff9d02c8118cc0 HandleCount: 2.
Image: sam3u_benchmark.exe
VadRoot ffffb38cbaddf300 Vads 53 Clone 0 Private 324. Modified 259. Locked 0.
DeviceMap ffff9d02a64ea090
Token ffff9d02c9093060
ElapsedTime 01:14:28.309
UserTime 00:00:00.046
KernelTime 00:00:00.046
QuotaPoolUsage[PagedPool] 107520
QuotaPoolUsage[NonPagedPool] 7456
Working Set Sizes (now,min,max) (1532, 50, 345) (6128KB, 200KB, 1380KB)
PeakWorkingSetSize 1885
VirtualSize 4183 Mb
PeakVirtualSize 4188 Mb
PageFaultCount 2017
MemoryPriority BACKGROUND
BasePriority 8
CommitCharge 535
THREAD ffffb38cbaac1080 Cid 6adc.4274 Teb: 000000e03fc79000 Win32Thread: ffffb38cbadd08f0 WAIT: (Executive) KernelMode Non-Alertable
ffffae0f7001b5f0 NotificationEvent
IRP List:
ffffb38cba1b6a20: (0006,0508) Flags: 00060030 Mdl: 00000000
Not impersonating
DeviceMap ffff9d02a64ea090
Owning Process ffffb38cbaec2080 Image: sam3u_benchmark.exe
Attached Process N/A Image: N/A
Wait Start TickCount 402061
Context Switch Count 7847 IdealProcessor: 2
UserTime 00:00:00.250
KernelTime 00:00:00.078
Win32 Start Address 0x00007ff6c81234f4
Stack Init ffffae0f7001bc90 Current ffffae0f7001b1d0
Base ffffae0f7001c000 Limit ffffae0f70016000 Call 0000000000000000
Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
Child-SP RetAddr : Args to Child : Call Site
ffffae0f`7001b210 fffff802`4fc1bca0 : 00000000`00000008 00000000`ffffffff 00000000`00000000 ffffb38c`a9187158 : nt!KiSwapContext+0x76
ffffae0f`7001b350 fffff802`4fc1b1cf : 00000801`000005fd 00000000`00000000 ffffae0f`7001b510 00000000`00000000 : nt!KiSwapThread+0x500
ffffae0f`7001b400 fffff802`4fc1aa73 : ffffae0f`00000000 00000000`00000000 00000000`00000300 ffffb38c`baac11c0 : nt!KiCommitThreadWait+0x14f
ffffae0f`7001b4a0 fffff802`8e363f2a : ffffae0f`7001b5f0 00000000`00000000 ffffae0f`7001b600 00000000`00000000 : nt!KeWaitForSingleObject+0x233
ffffae0f`7001b590 fffff802`8e36713e : 001f0003`ffff0000 fffff802`8e369b50 ffffae0f`7001b7e0 00000000`00000000 : libusb0+0x3f2a
ffffae0f`7001b620 fffff802`8e362bc0 : ffffb38c`ba8ce1a0 00000000`00000000 ffffb38c`ba8ce1a0 ffffb38c`9bfeca00 : libusb0+0x713e
ffffae0f`7001b720 fffff802`8e3614b9 : 00000000`00000002 ffffb38c`ba1b6a20 00000000`00000000 00000000`00000000 : libusb0+0x2bc0
ffffae0f`7001b7d0 fffff802`4fc10665 : ffffb38c`b9034500 00000000`00000000 ffffae0f`20206f49 00000000`00000020 : libusb0+0x14b9
ffffae0f`7001b800 fffff802`50000fec : 00000000`00000002 00000000`00000000 ffffb38c`b9034500 ffffb38c`baec2080 : nt!IofCallDriver+0x55
ffffae0f`7001b840 fffff802`50000c41 : ffffb38c`ba1b6e98 ffffae0f`7001bb80 00000000`00040005 ffffb38c`ba1b6e98 : nt!IopSynchronousServiceTail+0x34c
ffffae0f`7001b8e0 fffff802`4fffffb6 : 00000000`00000000 00000000`000002fc 00000000`00000000 000000e0`3feff890 : nt!IopXxxControlFile+0xc71
ffffae0f`7001ba20 fffff802`4fe105f8 : ffffb38c`baac1080 000000e0`3feff7b8 ffffae0f`7001baa8 00000000`00000000 : nt!NtDeviceIoControlFile+0x56
ffffae0f`7001ba90 00007ffc`d950cf34 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KiSystemServiceCopyEnd+0x28 (TrapFrame @ ffffae0f`7001bb00)
000000e0`3feff788 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : 0x00007ffc`d950cf34
0: kd> !processirps ffffb38cbaec2080
**** PROCESS ffffb38cbaec2080 (Image: sam3u_benchmar) ****
Checking threads for IRPs.
Thread ffffb38cbaac1080:
IRP ffffb38cba1b6a20 - Owned by \Driver\libusb0 for device libusb00001 (ffffb38cba8ce050)
Checking file objects for IRPs.
I tried to have a look at libusb-win32 source code, but so far I didn't understand exactly what is the issue, and I doubt I will.
Using Zadig to replace driver by either WinUSB or libusbK and trying the same experiment result in no freeze at all: after I unplugged the USB cable, libusb_control_transfer
simply returns LIBUSB_ERROR_NOT_FOUND .
So, it is not exactly the issue with libusb_clear_halt
, but it shows that there is a problem with libusb0.sys, I guess
I think this also shows that there is no real problem with libsub-1.0 itself.
I am wondering whether this https://github.com/libusb/libusb/pull/1018 may help, I will give it a try
I don't think 1018 will help for the kernel hang, but it is in any case appreciated if you test that PR. I notice your kernel dump is stuck in KeWaitForSingleObject() which is called from the libusb.sys parts that I mentioned above. From looking at the code I had a suspicion that the IRP locking is not done properly and there is a chance of races or deadlocks. I started working on some patches (based on the MS documentation) but haven't been able to test them myself. I could compile it with the WDK but didn't figure out the installation part. I can push this to an experimental libusb.sys PR and hope someone can look at it or test it.
@tormodvolden : thank you. I can try to build a patched libusb0.sys and try again, or better just try to replace mine with your built libusb0.sys. I'll do this soon.
@tormodvolden : would you mind attaching a built libusb0.sys containing your latest patch somewhere? Thanks in advance!
@dontech Please help to look at this issue and https://github.com/mcuee/libusb-win32/pull/38, when you got the time. Thanks.
I don't think 1018 will help for the kernel hang, but it is in any case appreciated if you test that PR....
Ok, no, it doesn't help with kernel hang, but I get 2 control transfer fails (with ERROR_IO) before the freeze ;-)
I was hoping that the windows_force_sync_completion
that you added in case of failure could help putting the driver back on track. Maybe it does a little bit but not enough
Apart from this I see no difference under normal behavior in between master and your PR. I guess this is good..
@sonatique : This should be the patched libusb.sys. I also included the other build artifacts (from running make_all.bat in libusb/ddk_make in a "Windows Win7 x64 Free Build Environment" window).
I have done minimal testing of the patched libusb.sys with xusb just to see that it works and doesn't BSOD (copied the file into system32/drivers in a Recovery Command Line window and rebooted with "Disable driver signature enforcement").
@tormodvolden : so I tested your patched libusb0.sys by replacing my current one with yours (and of course rebooting with disabled driver signature enforcement). I then repeated the exact same procedure as described above: instead of kernal hang now I get:
- at the instant when I disconnect the cable: ERROR_IO once (like before)
- then ERROR_NO_DEVICE 5 times
- then OK again.
So very good improvement since no hang at all, but still strange behavior I think: While 1 and 2 seems OK to me, perfectly making sens with respect to the situation, I am puzzled by the fact that calls resume to returning OK when there is no longer a cable connected to any devices. Worse is that the returned value is 8, i.e. the expected written byte count of my request (that I correctly get as well before disconnecting).
I thank you very much for this attempt, and for sure it goes into the right direction, but I think it is not usable as is since it could fool the application into thinking everything is fine when there are no longer any device attached.
Anyway this "disable driver signature enforcement" thing makes me think we are doomed: we cannot any longer use driver that we built ourselves (I am yes we could use them but not distribute them, etc.), so basically we are stuck with staying with driver we built before the change in requirements made by MS, or switch to using WinUSB.... This basically makes any futur special driver development meaningless, expect maybe for niche/hobby things. What do you think?
Thanks for testing this. I am very glad that the hang went away. I also wonder why "then OK again" happens. Can you please attach debug logs?
This is still with PR 1018 applied, right?
I wish I could provide a debug build of libusb0.sys so that we can see driver debug output with DebugView but I haven't figured out what to do in in the ddk_build folder to enable this. Maybe @dontech can help.
For signed libusb0.sys driver updates, this is still possible because dontech has the appropriate certifications to sign it.
Here is a debug build, I gave it version number 1.2.7.101. The size is larger, however I don't see anything in DebugView from it. (Built in CMD.exe window with CMD /C make.cmd "arch=x64" "outdir=.\x64" "DEBUGMODE=true" "app=driver"
)
libusb0_sys_PR38_dbg.zip
EDIT: Seems to work fine with DebugView.
New snapshots: https://sourceforge.net/projects/libusb-win32/files/libusb-win32-snapshots/20230920/
@tormodvolden : OK here are some results with your debug build (was tricky because of the overwhelming amount of log produced by the very fast looping). Yes my last message was still with 1018 applied, you were right. I test with and without it. My procedure is as follow: I start with libusb debug log disabled but DebugView enabled I start the vendor request write loop and remove the cable as promptly as possible (after 50-150 loops). In my program when I ses the first non-OK error returned, I enable libusb debug logging. I then allow 5 non-error returns, then exit the loop (otherwise it will loop forever) Basically what we see is that the driver correctly report 1 or 2 failed requests (I guess this is during the removal of the cable) then says " SURPRISE_REMOVAL" and basically doesn't do anything anymore after it (which is correct I guess). However libusb-1.0 happily continues to return "8 bytes written" forever after a few error messages. The behavior is slightly different with or with PR 1018 applied, but not fundamentally. I think that while you definitively fixed something in the driver (congratulation!) this also shows an issue in libusb-1.0 that shall be fixed sooner or later.
Here are some logs:
Current master, commit 6bf2db6 (without PR 1018)
Output from my modified sam3u_benchmark (a few printf and libusb-1.0 debug-level logs): (each initial dot represent a successful write request before cable removal, debug logs enable after first error, you can see 5 times "Write Success: 8" after cable removal that shouldn't be there in my opinion)
................................................................................................................................Write Error: LIBUSB_ERROR_IO
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 8.419228] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B6ED0
[ 8.419306] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.419374] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.419484] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.419585] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.419694] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.419798] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.419901] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.420005] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.420090] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.420174] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.420256] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.420331] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.420406] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.420488] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.420496] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.420555] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.420635] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.420759] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.420811] [00005030] libusb: warning [winusbx_submit_control_transfer] ControlTransfer failed: [433] A device which does not exist was specified.
[ 8.420826] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.420888] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.420954] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.421014] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.421132] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.421195] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B6ED0
Write Error: LIBUSB_ERROR_IO
[ 8.421305] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B6250
[ 8.421365] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.421431] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.421543] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.421607] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.421671] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.421735] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.421799] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.421863] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.421926] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.421990] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.422054] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.422117] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.422181] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.425566] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.425574] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.425672] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.425773] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.426573] [00005030] libusb: warning [winusbx_submit_control_transfer] ControlTransfer failed: [433] A device which does not exist was specified.
[ 8.427751] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.427038] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.429355] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.429386] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.433532] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.435055] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.436228] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B6250
Write Error: LIBUSB_ERROR_IO
[ 8.439056] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B6A20
[ 8.441373] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.442644] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.443847] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.444156] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.444519] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.444877] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.445235] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.445601] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.445958] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.446318] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.446676] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.447036] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.447397] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.459424] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.459447] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.463051] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.471193] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.471303] [00005030] libusb: debug [windows_force_sync_completion] transfer 000001C8A73B6A20, length 8
[ 8.472865] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.472948] [00005030] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 8.473046] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.473123] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 8.473197] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.475256] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.476195] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF6E0 for handle 000001C8A73AC060
[ 8.479137] [0000022c] libusb: debug [windows_iocp_thread] transfer 000001C8A73B6A20 completed, length 8
[ 8.479878] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 8.480743] [00005030] libusb: debug [handle_event_trigger] event triggered
[ 8.483541] [00005030] libusb: debug [windows_handle_transfer_completion] handling transfer 000001C8A73B6A20 completion with errcode 0, length 8
[ 8.484122] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.485335] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.496615] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.497406] [00005030] libusb: debug [usbi_handle_transfer_completion] transfer 000001C8A73B6A20 has callback 00007FF6B735E0A0
[ 8.498418] [00005030] libusb: debug [sync_transfer_cb] actual_length=8
[ 8.499575] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B6A20
Write success: 8
[ 8.505085] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B6570
[ 8.505702] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.506494] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.509794] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.510684] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.513465] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.514106] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.515212] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.517959] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.522047] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.523008] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.527624] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.528107] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.529032] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.532296] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.540188] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.532327] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.543112] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.541467] [00005030] libusb: debug [windows_force_sync_completion] transfer 000001C8A73B6570, length 8
[ 8.543970] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.547244] [00005030] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 8.548309] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.557011] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.553902] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 8.557975] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.560364] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF6E0 for handle 000001C8A73AC060
[ 8.563082] [0000022c] libusb: debug [windows_iocp_thread] transfer 000001C8A73B6570 completed, length 8
[ 8.567223] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 8.567849] [00005030] libusb: debug [handle_event_trigger] event triggered
[ 8.568779] [00005030] libusb: debug [windows_handle_transfer_completion] handling transfer 000001C8A73B6570 completion with errcode 0, length 8
[ 8.573575] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.575026] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.577640] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.579673] [00005030] libusb: debug [usbi_handle_transfer_completion] transfer 000001C8A73B6570 has callback 00007FF6B735E0A0
[ 8.583736] [00005030] libusb: debug [sync_transfer_cb] actual_length=8
[ 8.585581] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B6570
Write success: 8
[ 8.589452] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B6700
[ 8.592970] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.598861] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.600418] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.603804] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.604639] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.607109] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.608704] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.615445] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.616793] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.620379] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.621306] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.624464] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.627409] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.631611] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.631619] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.632847] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.633705] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.637117] [00005030] libusb: debug [windows_force_sync_completion] transfer 000001C8A73B6700, length 8
[ 8.637897] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.641652] [00005030] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 8.649680] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.653124] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.652045] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 8.654108] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.661444] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF6E0 for handle 000001C8A73AC060
[ 8.662706] [0000022c] libusb: debug [windows_iocp_thread] transfer 000001C8A73B6700 completed, length 8
[ 8.665566] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 8.666599] [00005030] libusb: debug [handle_event_trigger] event triggered
[ 8.669646] [00005030] libusb: debug [windows_handle_transfer_completion] handling transfer 000001C8A73B6700 completion with errcode 0, length 8
[ 8.671557] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.674588] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.679727] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.681142] [00005030] libusb: debug [usbi_handle_transfer_completion] transfer 000001C8A73B6700 has callback 00007FF6B735E0A0
[ 8.684371] [00005030] libusb: debug [sync_transfer_cb] actual_length=8
[ 8.685385] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B6700
Write success: 8
[ 8.689750] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B60C0
[ 8.691778] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.695974] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.696581] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.699721] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.700513] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.704694] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.711344] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.711453] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.712531] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.713372] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.716377] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.717335] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.720377] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.725171] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.726596] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.725197] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.728993] [00005030] libusb: debug [windows_force_sync_completion] transfer 000001C8A73B60C0, length 8
[ 8.732260] [00005030] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 8.729756] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.733253] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 8.739764] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.744699] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.745605] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.747951] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.749491] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF6E0 for handle 000001C8A73AC060
[ 8.757539] [0000022c] libusb: debug [windows_iocp_thread] transfer 000001C8A73B60C0 completed, length 8
[ 8.759295] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 8.762304] [00005030] libusb: debug [handle_event_trigger] event triggered
[ 8.763414] [00005030] libusb: debug [windows_handle_transfer_completion] handling transfer 000001C8A73B60C0 completion with errcode 0, length 8
[ 8.766538] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.772771] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.774109] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.776988] [00005030] libusb: debug [usbi_handle_transfer_completion] transfer 000001C8A73B60C0 has callback 00007FF6B735E0A0
[ 8.777873] [00005030] libusb: debug [sync_transfer_cb] actual_length=8
[ 8.781585] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B60C0
Write success: 8
[ 8.788513] [00005030] libusb: debug [libusb_submit_transfer] transfer 000001C8A73B60C0
[ 8.789714] [00005030] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 8.790733] [00005030] libusb: debug [libusb_claim_interface] interface 0
[ 8.793009] [00005030] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 8.795397] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 8.797804] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 8.804794] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 8.806287] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 8.809378] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 8.810180] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 8.813881] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 8.819853] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 8.822366] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 8.825645] [00005030] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 8.826503] [00005030] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 8.826536] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.829273] [00005030] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 8.833415] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.838664] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.834144] [00005030] libusb: debug [windows_force_sync_completion] transfer 000001C8A73B60C0, length 8
[ 8.840119] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.840219] [00005030] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 8.843145] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF3B0 for handle 000001C8A73AC060
[ 8.845239] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 8.849923] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF490 for handle 000001C8A73AC060
[ 8.854244] [0000022c] libusb: debug [windows_iocp_thread] ignoring overlapped 000000570ADDF6E0 for handle 000001C8A73AC060
[ 8.854991] [0000022c] libusb: debug [windows_iocp_thread] transfer 000001C8A73B60C0 completed, length 8
[ 8.858186] [00005030] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 8.859808] [00005030] libusb: debug [handle_event_trigger] event triggered
[ 8.860879] [00005030] libusb: debug [windows_handle_transfer_completion] handling transfer 000001C8A73B60C0 completion with errcode 0, length 8
[ 8.866586] [00005030] libusb: debug [libusb_release_interface] interface 0
[ 8.868117] [00005030] libusb: debug [auto_release] auto-released interface 0
[ 8.868201] [00005030] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 8.871375] [00005030] libusb: debug [usbi_handle_transfer_completion] transfer 000001C8A73B60C0 has callback 00007FF6B735E0A0
[ 8.872444] [00005030] libusb: debug [sync_transfer_cb] actual_length=8
[ 8.875452] [00005030] libusb: debug [libusb_free_transfer] transfer 000001C8A73B60C0
Write success: 8
[ 8.883051] [00005030] libusb: debug [libusb_release_interface] interface 2
[ 8.884022] [00005030] libusb: debug [libusb_close]
[ 8.886817] [00005030] libusb: debug [libusb_unref_device] destroy device 1.21
[ 8.887928] [00005030] libusb: debug [libusb_unref_device] destroy device 1.0
[ 8.890850] [00005030] libusb: debug [libusb_exit] destroying default context
[ 8.893641] [0000022c] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 8.906918] [00005030] libusb: debug [usbi_remove_event_source] remove HANDLE 000000000000009C
[ 8.907080] [00005030] libusb: debug [usbi_remove_event_source] remove HANDLE 0000000000000098
Done
Corresponding libusb0.sys driver debug log: N times this: (1 for every successful transfer before cable removal)
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = 00000000h
libusb0-sys:[vendor_class_request] 8 bytes transmitted
then:
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = C0000001h
libusb0-sys:err [vendor_class_request] request failed: status: 0xc0000001, urb-status: 0xc0000011
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = C000000Eh
libusb0-sys:err [vendor_class_request] request failed: status: 0xc000000e, urb-status: 0x80000300
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = C000000Eh
libusb0-sys:err [vendor_class_request] request failed: status: 0xc000000e, urb-status: 0x80000300
libusb0-sys:[dispatch_pnp] IRP_MN_SURPRISE_REMOVAL: is-filter=N usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[set_filter_interface_key] updated interface registry with LUsb0 direct-access symbolic link. id=-1
libusb0-sys:[dispatch_pnp] IRP_MN_REMOVE_DEVICE: is-filter=N usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[dispatch_pnp] deleting device #1 usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[unload] [unloading-driver] v1.2.7.101
With PR 1018 commits (3) applied on top of current master (commit 6bf2db6)
my program output:
............................................Write Error: LIBUSB_ERROR_PIPE
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 6.517168] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26570
[ 6.517247] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.517315] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.517427] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.517511] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.517599] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.517685] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.517772] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.517857] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.517933] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.518008] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.518072] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.518136] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.518200] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.518283] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.518290] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.518347] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.518428] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.518553] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.518623] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.518690] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.518717] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26570, length 8
[ 6.518760] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF380 for handle 000001EBBEC1C060
[ 6.518825] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.518890] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26570 completed, length 8
[ 6.518954] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.519081] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.519142] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.519199] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26570 completion with errcode 0, length 8
[ 6.519274] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.519332] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.519390] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.519451] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26570 has callback 00007FF70EF6E0A0
[ 6.519518] [00003850] libusb: debug [sync_transfer_cb] actual_length=8
[ 6.519575] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26570
Write success: 8
[ 6.519686] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26BB0
[ 6.519745] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.519811] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.519922] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.519984] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.520048] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.520112] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.520176] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.520253] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.520702] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.521072] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.521506] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.521874] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.522250] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.522629] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.522652] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.523020] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.523418] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.523918] [00003850] libusb: debug [winusbx_submit_control_transfer] ControlTransfer returned: [433] A device which does not exist was specified.
[ 6.524195] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.524591] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26BB0, length 0
[ 6.524981] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.525546] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.535056] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.536982] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.538079] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26BB0 completed, length 0
[ 6.539649] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.540836] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.542121] [00003850] libusb: debug [windows_handle_transfer_completion] GetOverlappedResult true, but Internal not reset
[ 6.543681] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26BB0 completion with errcode 433, length 0
[ 6.544052] [00003850] libusb: debug [windows_handle_transfer_completion] detected device removed
[ 6.544438] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.544809] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.545180] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.545541] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26BB0 has callback 00007FF70EF6E0A0
[ 6.545899] [00003850] libusb: debug [sync_transfer_cb] actual_length=0
[ 6.546256] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26BB0
Write Error: LIBUSB_ERROR_NO_DEVICE
[ 6.546973] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26A20
[ 6.547329] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.547691] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.548102] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.548414] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.548765] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.549128] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.549487] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.549846] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.550208] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.550567] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.550929] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.551288] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.551680] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.552093] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.552100] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.552483] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.552879] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.553677] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.553266] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26A20, length 8
[ 6.554092] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.554494] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.554887] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.555281] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.555660] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.556454] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF380 for handle 000001EBBEC1C060
[ 6.557156] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26A20 completed, length 8
[ 6.560304] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.561059] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.561612] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26A20 completion with errcode 0, length 8
[ 6.562004] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.562407] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.562755] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.563111] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26A20 has callback 00007FF70EF6E0A0
[ 6.563467] [00003850] libusb: debug [sync_transfer_cb] actual_length=8
[ 6.563817] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26A20
Write success: 8
[ 6.564539] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26890
[ 6.564888] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.565263] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.565668] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.565971] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.566340] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.566703] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.567060] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.567415] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.567768] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.568128] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.568518] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.568871] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.569245] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.569615] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.569955] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.569631] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.570349] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26890, length 8
[ 6.570692] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.571047] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.571404] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.571758] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.572112] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.572843] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.573246] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.573626] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF380 for handle 000001EBBEC1C060
[ 6.574009] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26890 completed, length 8
[ 6.574636] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.577322] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.628121] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26890 completion with errcode 0, length 8
[ 6.630763] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.631749] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.632711] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.633696] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26890 has callback 00007FF70EF6E0A0
[ 6.634680] [00003850] libusb: debug [sync_transfer_cb] actual_length=8
[ 6.635659] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26890
Write success: 8
[ 6.638079] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26250
[ 6.638267] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.643045] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.650627] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.652873] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.656719] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.663164] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.665659] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.672003] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.673027] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.675388] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.678462] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.679655] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.681568] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.682379] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.682402] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.685302] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.687470] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.693397] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26250, length 8
[ 6.697093] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.697974] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.694806] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.707621] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.709260] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.712007] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.712559] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF380 for handle 000001EBBEC1C060
[ 6.713466] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26250 completed, length 8
[ 6.716522] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.720847] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.721757] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26250 completion with errcode 0, length 8
[ 6.726026] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.727340] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.730707] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.732219] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26250 has callback 00007FF70EF6E0A0
[ 6.733249] [00003850] libusb: debug [sync_transfer_cb] actual_length=8
[ 6.739814] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26250
Write success: 8
[ 6.744496] [00003850] libusb: debug [libusb_submit_transfer] transfer 000001EBBEC26700
[ 6.747847] [00003850] libusb: debug [add_to_flying_list] arm timer for timeout in 1000ms (first in line)
[ 6.754674] [00003850] libusb: debug [libusb_claim_interface] interface 0
[ 6.755693] [00003850] libusb: debug [winusbx_claim_interface] claimed interface 0
[ 6.756695] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 01 to interface 0
[ 6.757921] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 81 to interface 0
[ 6.758702] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 02 to interface 0
[ 6.759673] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 82 to interface 0
[ 6.763133] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 04 to interface 0
[ 6.770820] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 84 to interface 0
[ 6.771367] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 06 to interface 0
[ 6.772461] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 86 to interface 0
[ 6.775258] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 08 to interface 0
[ 6.776078] [00003850] libusb: debug [windows_assign_endpoints] (re)assigned endpoint 88 to interface 0
[ 6.777180] [00003850] libusb: debug [auto_claim] auto-claimed interface 0 for control request
[ 6.780525] [00003850] libusb: debug [winusbx_submit_control_transfer] will use interface 0
[ 6.777203] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.781416] [00003850] libusb: debug [windows_force_sync_completion] transfer 000001EBBEC26700, length 8
[ 6.785266] [00003850] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 6.782356] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.789323] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() for 2 HANDLEs with timeout in 60000ms
[ 6.790875] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.797809] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.801010] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF050 for handle 000001EBBEC1C060
[ 6.805666] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF130 for handle 000001EBBEC1C060
[ 6.807316] [00005d64] libusb: debug [windows_iocp_thread] ignoring overlapped 0000008742CFF380 for handle 000001EBBEC1C060
[ 6.810022] [00005d64] libusb: debug [windows_iocp_thread] transfer 000001EBBEC26700 completed, length 8
[ 6.811182] [00003850] libusb: debug [usbi_wait_for_events] WaitForMultipleObjects() returned 0
[ 6.813847] [00003850] libusb: debug [handle_event_trigger] event triggered
[ 6.814729] [00003850] libusb: debug [windows_handle_transfer_completion] handling transfer 000001EBBEC26700 completion with errcode 0, length 8
[ 6.817569] [00003850] libusb: debug [libusb_release_interface] interface 0
[ 6.824278] [00003850] libusb: debug [auto_release] auto-released interface 0
[ 6.827328] [00003850] libusb: debug [arm_timer_for_next_timeout] no timeouts, disarming timer
[ 6.827931] [00003850] libusb: debug [usbi_handle_transfer_completion] transfer 000001EBBEC26700 has callback 00007FF70EF6E0A0
[ 6.828740] [00003850] libusb: debug [sync_transfer_cb] actual_length=8
[ 6.830738] [00003850] libusb: debug [libusb_free_transfer] transfer 000001EBBEC26700
Write success: 8
[ 6.835323] [00003850] libusb: debug [libusb_release_interface] interface 2
[ 6.835970] [00003850] libusb: debug [libusb_close]
[ 6.836863] [00003850] libusb: debug [libusb_unref_device] destroy device 1.17
[ 6.840537] [00003850] libusb: debug [libusb_unref_device] destroy device 1.0
[ 6.841437] [00003850] libusb: debug [libusb_exit] destroying default context
[ 6.844722] [00005d64] libusb: debug [windows_iocp_thread] I/O completion thread exiting
[ 6.852441] [00003850] libusb: debug [usbi_remove_event_source] remove HANDLE 00000000000000A0
[ 6.852551] [00003850] libusb: debug [usbi_remove_event_source] remove HANDLE 000000000000009C
Done
Corresponding libusb0.sys driver debug log: N times this: (1 for every successful transfer before cable removal)
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = 00000000h
libusb0-sys:[vendor_class_request] 8 bytes transmitted
then:
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = C0000001h
libusb0-sys:err [vendor_class_request] request failed: status: 0xc0000001, urb-status: 0xc0000011
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = 00000000h
libusb0-sys:[vendor_class_request] 8 bytes transmitted
libusb0-sys:[get_descriptor] buffer size: 9 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[get_descriptor] buffer size: 88 type: 0002 recipient: 0000 index: 0000 language id: 0000 timeout: 0
libusb0-sys:[vendor_class_request] type: vendor
libusb0-sys:[vendor_class_request] recipient: device
libusb0-sys:[vendor_class_request] request: 0xf3
libusb0-sys:[vendor_class_request] value: 0x03e8
libusb0-sys:[vendor_class_request] index: 0x0024
libusb0-sys:[vendor_class_request] size: 8
libusb0-sys:[vendor_class_request] direction: out
libusb0-sys:[vendor_class_request] timeout: 1000
libusb0-sys:dbg [call_usbd_ex] status = C000000Eh
libusb0-sys:err [vendor_class_request] request failed: status: 0xc000000e, urb-status: 0x80000300
libusb0-sys:[dispatch_pnp] IRP_MN_SURPRISE_REMOVAL: is-filter=N usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[set_filter_interface_key] updated interface registry with LUsb0 direct-access symbolic link. id=-1
libusb0-sys:[dispatch_pnp] IRP_MN_REMOVE_DEVICE: is-filter=N usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[dispatch_pnp] deleting device #2 usb\vid_1500&pid_0008&rev_0100
libusb0-sys:[unload] [unloading-driver] v1.2.7.101
@tormodvolden @dontech : I just tried with 1.2.7.4 snapshot of libusb0.sys driver (thanks for it) and got the same results (minus the driver logs obviously)
@tormodvolden : I retested exactly the same with libusbK and WinUSB drivers, and (as previously mentionned) I get a completely, and in my opinion correct, behavior: After cable removal I only get error codes returned (ERROR_NO_DEVICE, then ERROR_NOT_FOUND) when I attempt to write control requests. So, I don't know what to think: it seems that libusb-1.0 correctly returns an error code when the driver correctly does what it is supposed to do, but with your hang-corrected libusb0.sys, the behavior of libusb is wrong, while the driver itself seems to correctly stop doing anything after cable removal. Maybe libusb0.sys misses a status that libusb-1.0 will understand...
As of now, I would say that unfortunately current libusb-1.0 is not usable with libusb0.sys:: with version <= 1.2.7.3 we get a kernel hang and with >= 1.2.7.4 we incorrectly get OK status for write request that can not physically be completed successfully...
What do you think? Are there any reasonably possible improvements?
Thank you anyway, this at least gave me some precious indications.
EDIT: Could the "return success after cable removal problem" caused by libusbK.dll? And not by libusb-1.0 nor libusb0.sys? Given the results this is what seems to be the most probable to me... I don't understand why the "removal during transfer" would end-up in a different state than "removal while idle" except if there is a bug in libusbK.dll in the specific code that interact with libusb0.sys
@dontech : side question: any plan to compile libusb0.sys for ARM64, by luck?
@dontech : side question: any plan to compile libusb0.sys for ARM64, by luck?
You can add your comments here.
- https://github.com/mcuee/libusb-win32/issues/29
Related issue:
- https://github.com/mcuee/libusb-win32/issues/30
Thanks for the informative debug logs. Surely there is still something wrong with error propagation.
Could the "return success after cable removal problem" caused by libusbK.dll? And not by libusb-1.0 nor libusb0.sys?
In theory yes, but it could also be remaining bugs in libusb.sys or libusb-1.0. Is there a debug version of libusbK.dll that reports something in DebugView? EDIT: There is -debug.7z here https://sourceforge.net/projects/libusbk/files/libusbK-release/3.1.0.0/
There is also this in the log with PR 1018: [ 6.542121] [00003850] libusb: debug [windows_handle_transfer_completion] GetOverlappedResult true, but Internal not reset This is something I need to look closer at, because it breaks some of my assumptions.
Another oddity in the PR 1018 libusb0-sys output is that there is a successful transfer after the first failing one. I don't know if this is a coincidence that could also happen without 1018.
I just tried with 1.2.7.4 snapshot of libusb0.sys driver (thanks for it) and got the same results (minus the driver logs obviously)
libusb-win32-bin-debug-1.2.7.4.zip should give you driver debug output.
It seems from the debug logs, if I have correlated the libusb and kernel logs correctly, that there is a good match between the kernel call_usbd_ex() status and the libusb transfer status as long as the driver is loaded. As soon as the PNP management unloads the driver, the false transfer success appears. I am not sure what happens with device objects and ioctl's and so forth in this case, it is possible that this needs special care by the library/DLL ("Whenever a client opens a handle to a pnp device, it should register for pnp notification and close the handle when the system notifies the device is being removed" [1]).
We can see that the unload routine is being called, but it is also not clear from the log whether the driver is successfully unloaded ("The fact that unload-routine is called doesn't mean the driver unload is successful" [1]). This can maybe be checked through other means.
[1] https://techcommunity.microsoft.com/t5/microsoft-usb-blog/why-doesn-t-my-driver-unload/ba-p/270680
@dontech : side question: any plan to compile libusb0.sys for ARM64, by luck?
Yes. I can probably get it to compile, but I don't currently have a windows device to compile with.
And yes, we also need to port to new SDK first, as the current one does not support ARM at all.