manuelbl / JavaDoesUSB

USB library for Java
MIT License
143 stars 11 forks source link

Issues with JavaDoesUSB in Windows 11 with USB 1.1 device #15

Closed aosocorro closed 1 year ago

aosocorro commented 1 year ago

Hi @manuelbl

First of all, great work! The library is amazing and it comes really useful when other USB libraries for Java are almost dead... kudos for that!

I am testing the library for an application which is using a USB 1.1 device on Mac & Windows, and I am finding some issues in the Windows 11 side (in Mac everything works smoothly):

JavaDoesUSB version: 0.5.1

  1. Only a specific version of WinUSB seem to work. When I configure the USB data interface of the device with Zadig, the tool shows the following screen, instructing me to downgrade WinUSB:

image

I guess this is caused because of the device implementing USB 1.1 (that is the reason WCID does not work with the dongle) ... do you think I am right?

  1. Once the USB driver is properly set, the application I am testing can be used. I am sending a command to the device with the following code (kotlin syntax):
    companion object {
        const val APP_INTERFACE = 4
        const val IN_ENDPOINT = 4
        const val OUT_ENDPOINT = 5
        const val COMMAND = "COMMAND"
    }
    device.get()?.apply {
                try {
                    open()
                    claimInterface(APP_INTERFACE) 
                    transferOut(OUT_ENDPOINT, COMMAND.toByteArray())
                } catch (t: Throwable) {
                    logger.error("Unable to execute USB operation ", t)
                } finally {
                    if (isOpen) {
                        if (getInterface(APP_INTERFACE).isClaimed) {
                            releaseInterface(APP_INTERFACE)
                        }
                        logger.debug { "Closing device..." }
                        close()
                    }
                }
            }

    The code is executed inside a process which is continuously running. As you can see it is pretty straightforward, but its behaviour is weird:

Do you think if this is related with the library or with the dongle specification? Would there be any procedure that could help me to debug the issue?

if you think that there is some work that could help with this, just let me know. I would be happy to help.

Again, great work!

Thanks, Alberto.

manuelbl commented 1 year ago

WinUSB version

From your screenshot, it looks as if WCID works as WinUSB is installed. Otherwise, no driver would be installed at all. Do I understand it correctly that it will not work without downgrading the driver?

Zadig shows the exact same information for the test device I'm using to test this library. It also offers to downgrade from the driver version 10.x (bundled with Windows) to version 6.1 (bundled with Zadig). I don't need to downgrade; it works with version 10.x.

I have seen other reports on the internet that a device works after the WinUSB driver has been downgraded from version 10.x to 6.x. But my suspicion is that it's not due to the driver but due to the install procedure and that it only affects certain composite devices.

I don't think that USB v1.1 vs USB 2.x makes any differences.

Claiming interface

When does the "Interface number 4 cannot be claimed" error occur? Immediately after plugging in the device? Does your code set a handler to be notified about connected device and immediately open it on notification?

The issue looks like a timing problem. The Java code is sometimes notified about a new device before all the information has been updated in the device registry. Mainly composite devices are affected. I have already identified such cases and usually handle them by retrying after a short delay. If this is another such case, I will try to modify the library such that the problem no longer occurs.

Can you support the analysis:

Is it correct that this is a third-party USB device (and not one you are involved in the implementation)?

manuelbl commented 1 year ago

And what error do you get or what happens if you run your code without downgrading the WinUSB driver?

aosocorro commented 1 year ago

Thanks for the quick answer @manuelbl. I add some clarifications:

manuelbl commented 1 year ago

Thank you very much fo the information.

In the meantime, I've figured out that the missing information leading to the "Interface number 4 cannot be claimed" error are queried when the device is plugged in, not when the device is opened by the software. So chances are that it is a timing error. My questions regarding whether the device is immediately opened after plug-in thus were misleading.

The fact that the bulk_transfer example always works could be due to the fact that it is only used with devices that have already been plugged in when the software starts and not at a later stage.

I will study it some more and likely publish an updated version. It will require JDK 21, which will be released early next week. I hope that's not a problem for you.

You wrote: "If WinUSB driver is not downgraded, the device does never work." What exactly happens? Is the device invisible? Does an error occur? If so, what error?

If I can, I would really like to get the library to the point where it just works if the device implements WCID or Microsoft OS 2.0 Descriptors. Zadig can be very helpful; but at the end of the day, it's still a workaround for hardware and/or software that wasn't implemented properly.

aosocorro commented 1 year ago

If WinUSB driver is not downgraded, the error is (again) : Interface number 4 cannot be claimed (non WinUSB device?) on every test. Downgrade of WinUSB is mandatory to make the device working.

Enumerate example return the same output I sent you in my previous post in that scenario.

Moving to JDK 21 is ok.

When do you expect to deliver a new release of the library?

aosocorro commented 1 year ago

@manuelbl I have seen there is a new version 0.6.0. Does it contain the fixes you mentioned in your previous comments? or should I wait for 0.6.1 version?

manuelbl commented 1 year ago

@aosocorro Version 0.6.0 contains fixes but I'm afraid it won't fully fix your problem as I cannot correctly reproduce it. Thus I would like to build a device with the same configuration as yours.

Can you run the enumerate example again and send me the output related to your device (using JDK 21 and library version 0.6.0). It now dumps the full device and configuration descriptors. That's the additional part I'm interested in.

Can you also run your software with the new version and try to trigger the problem again? The library now writes additional log information. I'm interested whether there is a difference in the log information when you plug in the device and it works correctly vs. when you plug it in and fails when claiming the interface.

Make sure you get the log information at DEBUG level. If you are using a logging library, make sure it also connects to System.Logger. Some libraries need an additional Maven package to do so.

aosocorro commented 1 year ago

@manuelbl This is the full output of the enumerate example for my device:

Device:
  VID: 0x248a
  PID: 0x881c
  Manufacturer:  CD
  Product name:  Merlyn Mind GO
  Serial number: RF427C
  Device class:    0x00 ((Defined at Interface level))
  Device subclass: 0x00
  Device protocol: 0x00

  Interface 0
    Interface class:    0x01 (Audio)
    Interface subclass: 0x01
    Interface protocol: 0x00

  Interface 1
    Interface class:    0x01 (Audio)
    Interface subclass: 0x02
    Interface protocol: 0x00

  Interface 1 (alternate 1)
    Interface class:    0x01 (Audio)
    Interface subclass: 0x02
    Interface protocol: 0x00

    Endpoint 7
        Direction: IN
        Transfer type: ISOCHRONOUS
        Packet size: 32 bytes

  Interface 2
    Interface class:    0x03 (Human Interface Device)
    Interface subclass: 0x01 (Keyboard)
    Interface protocol: 0x01 (Keyboard)

    Endpoint 1
        Direction: IN
        Transfer type: INTERRUPT
        Packet size: 8 bytes

  Interface 3
    Interface class:    0x03 (Human Interface Device)
    Interface subclass: 0x01 (Mouse)
    Interface protocol: 0x02 (Mouse)

    Endpoint 2
        Direction: IN
        Transfer type: INTERRUPT
        Packet size: 8 bytes

  Interface 4
    Interface class:    0xfe (Application Specific Interface)
    Interface subclass: 0x01
    Interface protocol: 0x01

    Endpoint 4
        Direction: IN
        Transfer type: BULK
        Packet size: 64 bytes

    Endpoint 5
        Direction: OUT
        Transfer type: BULK
        Packet size: 64 bytes

Device descriptor
0000  12 01 10 01 00 00 00 08 8a 24 1c 88 00 01 01 02
0010  03 01

Configuration descriptor
0000  09 02 b5 00 05 01 00 a0 19 09 04 00 00 00 01 01
0010  00 00 09 24 01 00 01 26 00 01 01 0c 24 02 04 01
0020  02 00 01 01 00 00 00 08 24 06 05 04 01 03 00 09
0030  24 03 06 01 01 00 05 00 09 04 01 00 00 01 02 00
0040  00 09 04 01 01 01 01 02 00 00 07 24 01 06 01 01
0050  00 0b 24 02 01 01 02 10 01 80 3e 00 09 05 87 0d
0060  20 00 01 00 00 07 25 01 01 00 00 00 09 04 02 00
0070  01 03 01 01 00 09 21 11 01 21 01 22 3b 00 07 05
0080  81 03 08 00 0a 09 04 03 00 01 03 01 02 00 09 21
0090  11 01 21 01 22 8e 00 07 05 82 03 08 00 04 09 04
00a0  04 00 02 fe 01 01 00 07 05 84 02 40 00 00 07 05
00b0  05 02 40 00 00
aosocorro commented 1 year ago

@manuelbl Logs with some scenario where a USB command works and one failure. To generate the failure, I have had to plug the device in few seconds after the laptop is awaken after being idle:

// App is started. USB device is plugged in at this time. Command (buzz) works
2023-09-21 20:55:14.036 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:55:14.065 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:55:14.066 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:55:14.066 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:55:14.084 [main] INFO  o.m.d.c.usb.impl.USBProviderImpl - Found USB paired device. Attaching: RF427C
2023-09-21 20:55:37.857 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote

// Unplug and plug. Command continues working
2023-09-21 20:56:01.067 [DefaultDispatcher-worker-7] INFO  o.m.d.c.usb.impl.USBProviderImpl - Not found USB paired device. Detaching...
2023-09-21 20:56:04.695 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Sleeping for 200ms (after unsuccessfully retrieving DEVPKEY_Device_Children)
2023-09-21 20:56:04.898 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:56:04.899 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:56:04.900 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-21 20:56:04.910 [DefaultDispatcher-worker-22] INFO  o.m.d.c.usb.impl.USBProviderImpl - Found USB paired device. Attaching: RF427C
2023-09-21 20:56:22.911 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote

// Laptop is becoming idle. Last application log happened at 2023-09-21 20:56:51.916
2023-09-21 20:56:40.021 [DefaultDispatcher-worker-17] INFO  o.m.d.c.usb.impl.USBProviderImpl - Not found USB paired device. Detaching...

// Laptop is awaken the following day at 2023-09-22 09:47:30.517. USB device is plugged in some seconds later. Command does not work 
2023-09-22 09:47:35.204 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 09:47:36.104 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 09:47:36.114 [DefaultDispatcher-worker-20] INFO  o.m.d.c.usb.impl.USBProviderImpl - Found USB paired device. Attaching: RF427C
2023-09-22 09:47:56.285 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote
2023-09-22 09:47:56.285 [DefaultDispatcher-worker-6] ERROR o.m.d.c.usb.impl.USBProviderImpl - Unable to execute USB operation 
net.codecrete.usb.USBException: interface number 4 cannot be claimed (non WinUSB device?)
    at net.codecrete.usb.windows.WindowsUSBException.throwException(WindowsUSBException.java:65)
    at net.codecrete.usb.windows.WindowsUSBDevice.claimInterface(WindowsUSBDevice.java:119)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl.executeOperation(USBProviderImpl.kt:124)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl.access$executeOperation(USBProviderImpl.kt:21)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl$buzzRemote$1.invokeSuspend(USBProviderImpl.kt:61)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
2023-09-22 09:48:18.166 [DefaultDispatcher-worker-19] ERROR o.m.d.c.usb.impl.USBProviderImpl - Unable to execute USB operation 
net.codecrete.usb.USBException: interface number 4 cannot be claimed (non WinUSB device?)
    at net.codecrete.usb.windows.WindowsUSBException.throwException(WindowsUSBException.java:65)
    at net.codecrete.usb.windows.WindowsUSBDevice.claimInterface(WindowsUSBDevice.java:119)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl.executeOperation(USBProviderImpl.kt:124)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl.access$executeOperation(USBProviderImpl.kt:21)
    at org.merlyn.desktopapp.coresdk.usb.impl.USBProviderImpl$buzzRemote$1.invokeSuspend(USBProviderImpl.kt:61)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)

// Unplug and plug. Command works again
2023-09-22 09:55:25.840 [DefaultDispatcher-worker-5] INFO  o.m.d.c.usb.impl.USBProviderImpl - Not found USB paired device. Detaching...
2023-09-22 09:55:29.803 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Sleeping for 200ms (after unsuccessfully retrieving DEVPKEY_Device_Children)
2023-09-22 09:55:30.009 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 09:55:30.010 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 09:55:30.011 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 09:55:30.027 [DefaultDispatcher-worker-8] INFO  o.m.d.c.usb.impl.USBProviderImpl - Found USB paired device. Attaching: RF427C
2023-09-22 09:55:37.767 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote
2023-09-22 10:12:50.362 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote

// Unplug and plug. Command continues working
2023-09-22 10:21:41.737 [DefaultDispatcher-worker-12] INFO  o.m.d.c.usb.impl.USBProviderImpl - Not found USB paired device. Detaching...
2023-09-22 10:21:46.368 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Sleeping for 200ms (after unsuccessfully retrieving DEVPKEY_Device_Children)
2023-09-22 10:21:46.572 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 10:21:46.573 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 10:21:46.574 [USB device monitor] DEBUG n.c.u.w.WindowsUSBDeviceRegistry - Child device {0} has no device path
2023-09-22 10:21:46.585 [DefaultDispatcher-worker-3] INFO  o.m.d.c.usb.impl.USBProviderImpl - Found USB paired device. Attaching: RF427C
2023-09-22 10:21:50.202 [JavaFX Application Thread] INFO  BuzzRemote - RCU service invoked to buzz remote

It seems that when claiming interface fails, there is one Child device {0} has no device path trace less than when it works; and the log Sleeping for 200ms (after unsuccessfully retrieving DEVPKEY_Device_Children) is missing when claiming interface fails.

manuelbl commented 1 year ago

@aosocorro Thank you for the additional information. I can reproduce the problem related to disconnecting and connecting the device. And I have a prototypic fix in C++, which I will now apply to Java with some enhancements.

Regarding WCID: I‘m surprised to learn that it only works if the USB version is declared as 2.00 or higher (as you already mentioned). So I wonder: how did you install the WinUSB v10 driver? It didn’t happen automatically when you plugged in the device, did it?

aosocorro commented 1 year ago

@manuelbl Those are great news! Looking forward to testing the new version when ready. Thanks!

About how to install WinUSB v10 driver, it has to be installed using Device Manager tool. The device is handled as “Other device”, and this procedure is followed to let Windows install its “default” WinUSB version (which is v10 in Windows 11 and requires downgrading for my device, as mentioned)

It would be fantastic if JavaDoesUSB could somehow automate this process for this kind of device. But maybe there are not so many devices like this to make the effort worthy (to say nothing about its complexity)…

manuelbl commented 1 year ago

The code now includes a fix for dealing with composite devices on Windows when they are plugged in and Windows discovers the subdevices one by one. You can wait for the official release (probably early next week). Or you can try the snapshot:

cd java-does-usb
mvn install -DskipTests

Then you need to change your project to use version 0.6.1-SNAPSHOT.

Independent of this fix: In order to automatically install the WinUSB driver, the device needs to implement Microsoft OS Compatibility Descriptors 2.0. As far as I can tell, the older 1.0 version (aka WCID) does not work for composite devices (and your device is a composite device). All other options include manual installation steps. The options are:

I have tested the procedure you have linked to. It didn't work. I've debugged it and found that the reason is that SetupDiOpenDevRegKey returns a registry key at CurrentControlSet001while the description refers to CurrentControlSet. So the GUID in DeviceInterfaceGUIDs is not found. This might be a change from earlier Windows version. But the function SetupDiOpenDevRegKey is likely authoritative and returns what the operation system actually uses.

The reason Zadig works is not because the older WinUSB driver is better. It is because the Zadig installation procedure creates the correct registry keys. Zadig would achieve the same with the latest driver. But it can only install the version bundled with itself, and that is version 6.1.

manuelbl commented 1 year ago

Release 0.6.1 with the fixes for this issue has been published

aosocorro commented 1 year ago

Thanks! I will test it and I will close the issue once verified

aosocorro commented 1 year ago

Tested successfully. Closing issue