NUT Windows v2.8.0 with LibUSB Eaton device descriptor matching errors

[joachim-heck]

I'm using an EATON UPS in combination with the LibUSB 1.2.6.0 and the newest build of the Windows NUT Server v2.8.0 which is working like charm on my linux machine, but doesn't want to connect on the windows build. The old NUT server version 2.6.5 was working on windows but the returned values where partially incorrect and fewer values where collected and returned. The EATON is connected correctly and detected - also accessible with the eaton tools.

Somehow this is also related to the LibUSB discussion in your mentioned #5 issue.

Console-Output:
.\usbhid-ups.exe -DD -a eaton

Network UPS Tools - Generic HID driver 0.49 (2.8.0-Windows-55-g6538df32e)
USB communication driver (libusb 1.0) 0.43
   0.000000     [D1] debug level is '2'
   0.001217     [D2] Initializing an USB-connected UPS with library libusb-1.0.26 (API: 0x1000109) (NUT subdriver name='USB communication driver (libusb 1.0)' ver='0.43')
   0.008066     [D1] upsdrv_initups (non-SHUT)...
   2.648681     [D2] Checking device 1 of 5 (0B1F/03E9)
   2.650760     [D2] - VendorID: 0b1f
   2.652079     [D2] - ProductID: 03e9
   2.653508     [D2] - Manufacturer: unknown
   2.655120     [D2] - Product: unknown
   2.656570     [D2] - Serial Number: unknown
   2.658212     [D2] - Bus: 001
   2.659397     [D2] - Device: unknown
   2.660813     [D2] - Device release number: 0100
   2.662618     [D2] Trying to match device
   2.665398     [D2] match_function_subdriver (non-SHUT mode): matching a device...
   2.668322     [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID
   2.672318     [D2] Device does not match - skipping
   2.674244     [D2] Checking device 2 of 5 (0B1F/03E8)
   2.676190     [D1] Failed to open device (0B1F/03E8), skipping: Operation not supported or unimplemented on this platform
   2.681766     [D2] Checking device 3 of 5 (0463/FFFF)
   2.760148     [D2] - VendorID: 0463
   2.761392     [D2] - ProductID: ffff
   2.762896     [D2] - Manufacturer: EATON
   2.764443     [D2] - Product: Eaton 9SX
   2.765955     [D2] - Serial Number: GC36L47026
   2.767691     [D2] - Bus: 001
   2.768876     [D2] - Device: unknown
   2.770287     [D2] - Device release number: 0202
   2.773241     [D2] Trying to match device
   2.774883     [D2] match_function_subdriver (non-SHUT mode): matching a device...
   2.777807     [D2] Device matches
   2.779104     [D2] Reading first configuration descriptor
   2.781234     [D2] Claimed interface 0 successfully
   2.783112     [D2] Unable to get HID descriptor (Invalid parameter)
   2.785526     [D1] Eaton device v2.02. Using full report descriptor
   2.788847     [D2] Unable to retrieve any HID descriptor
   2.790950     [D2] Checking device 4 of 5 (8086/A1AF)
   2.792899     [D1] Failed to open device (8086/A1AF), skipping: Operation not supported or unimplemented on this platform
   2.797354     [D2] Checking device 5 of 5 (064F/2AF9)
   2.799764     [D1] Failed to open device (064F/2AF9), skipping: Input/Output Error
   2.802438     [D2] libusb1: No appropriate HID device found
   2.805581     libusb1: Could not open any HID devices: insufficient permissions on everything
   2.808935     No matching HID UPS found

From my point of view this is somehow related to this part in the codebase of libusb1:
https://github.com/networkupstools/nut/blob/035ae79dc28a04c443f110bd7046aab3c504319b/drivers/libusb1.c

• Initially row 449 fails and returns -1
• Then row 507 sets rdlen = rdlen1 which is still -1 at this point
• then row 515 checks whether rdlen is < 0 which to debug output a continue to next device
• which shouldn't happen

Is this behaviour intentended?

[jimklimov]

Well, blindly selecting an invalid value does not seem right. Probably makes sense to make a check similar to line 512 but preferring rdlen1 in this case.

Other than that, keep in mind that the Windows builds revival did not yet deal with installer, and in particular that of some low-level component of libusb driver that may exclusively grab the device. Would love to see that bit solved.

CC @aquette for possibly more insights

[joachim-heck]

Thanks for your feedback and time - I think so aswell.

Its a bit weird that the correct device is identified

   2.648681     [D2] Checking device 1 of 5 (0B1F/03E9)
   2.650760     [D2] - VendorID: 0b1f
   2.652079     [D2] - ProductID: 03e9
   2.653508     [D2] - Manufacturer: unknown
   2.655120     [D2] - Product: unknown
   2.656570     [D2] - Serial Number: unknown
   2.658212     [D2] - Bus: 001
   2.659397     [D2] - Device: unknown
   2.660813     [D2] - Device release number: 0100
   2.662618     [D2] Trying to match device
   2.665398     [D2] match_function_subdriver (non-SHUT mode): matching a device...

Device Vendor and Product ID has been successfully identified.
But then a manual mapping in 507 is proceeded which I don't understand - and finally fails.

   2.668322     [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID
   2.672318     [D2] Device does not match - skipping

I think the follow up errors which are pointing to some permission errors are probably misleading. Maybe this is some other hardware HID device in the system (mouse, keyboard HID) and not related to the UPS.

I'm currently investigating on the low level exclusive usage of the device. We've already tried to uninstall all other UPS related applications on the host system (Eaton Management Tools and drivers, Windows HID UPS driver). We also tried with different versions of the libusb - as a next step, I will try to compile as 32Bit and check whether this brings any change.

[jimklimov]

And just wanted to stress: the culprit may be an incomplete installation into the OS (some Windows driver and reboot?) of whatever libusb needs to get those HID report descriptors from that device and pass to a NUT driver program. It is likely not a fault of the NUT driver (might still be), but of that libusb installation puzzle part that is not solved/modernized yet.

[joachim-heck]

Ok, I keep on digging. We have already tested this on a second host - but unfortunately with the same result.
Maybe we need to use a specific LibUSB version?

For reference: #1646 is pointing at the same spot.

[jimklimov]

Unfortunately I can't say more at the moment - did not test with a Windows machine where I could arbitrarily change the low-level drivers etc. At some point I wanted to try with a snapshotable Windows VM with USB pass-through (hoping the host OS would truly and exclusively dedicate the USB HID device to the guest) in order to try different approaches, but did not have time to pursue that.

From what I gathered so far, back when NUT for Windows was made (with 2.6.5 and earlier baselines), libusb-win32 project was used (and alive), and included a libusbK.sys (IIRC) for the "Windows kernel" side driver. Currently that project seems nearly defunct, but libusb website claims that libusb-1.0 natively supports Windows (so there is no need to fork it for the platform) and documents several approaches to installation. But I did not take the further steps...

• https://github.com/libusb/libusb/wiki/Windows

Maybe we just need to set (and test) the option for "backend" (there are several, maybe chosen at runtime... defaulted, guessed, specified via NUT config files?) in case (ifdef) of Windows and libusb-1.0 builds, like this example from their wiki:

libusb_context * ctx = NULL;
libusb_init(&ctx);
libusb_set_option(ctx, LIBUSB_OPTION_USE_USBDK);

[joachim-heck]

Thanks for your great support - fortunately I think we found the issue.

Sometimes you should just follow the instructions exactely, and step by step: https://github.com/libusb/libusb/wiki/Windows#how-to-use-libusb-on-windows
I've used the zadig (http://zadig.akeo.ie) USB-driver installation tool to double check the installed driver for the USB device. It seems like, whatever you do, windows 10 is for some reasing trying to reinstall its USB HID Battery default driver or libusb0 in the background. Sometimes windows does this instantely, sometime after the first reboot, sometimes after the second reboot.
Both drivers will show the faulty behaviour where the initialization fails.

By manually deinstalling the Windows HID USB Battery driver and LibUSB, and installing the WinUSB driver via the ZADIG tool, I was finally able to get the NUT Server running for a moment.
Until Windows 10 again replaced the WinUSB with the libusb0 or Windows HID Battery after the next reboot. This behaviour is also described here: https://github.com/pbatard/libwdi/wiki/Zadig#the-problem

We are currently investigation who to prevent windows to replace WinUSB with other drivers.
I will come back with a detailed description and workaround, when we figured out a solution.

[jimklimov]

Sounds great, thanks!

[joachim-heck]

Ok, so finally we have everything up and running. A key tool to get a clean overview over the currently installed and used drivers was: Driver Store Explorer (https://github.com/lostindark/DriverStoreExplorer)

With this tool, we could see that several drivers were still present on our test system. We first removed all Eaton tools, then all LibUSB drivers via the Windows 10 Programs and Apps. Then we manually removed, and forcibly removed all other versions of lisbusb, lisbusk, libwdi, eaton, etn_libusb,... in the Driver Store Explorer.

After system reboot windows was by default using the HidUSB (v10) which we could see via the Zadig tool.

We selected the Eaton 9SX from the dropdown and replaced the HidUSB with the WinUSB (v6.1) and rebooted the system.

From now on, windows didn't change the drivers automatically - maybe this strange previous behaviour was related to the presence of the other driver instances.

But somehow, the NUT Server still didn't come up - meanwhile the .\usbhid-ups.exe -DD -a eaton test-tool worked like a charm.

The solution to this was found in the windows eventlog:

Via the eventlog we where able to detect, that the NUT Server is trying to start the upsdrvctl.exe from the wrong directory /bin instead of /sbin – so I copied the upsdrvctl.exe to the bin folder aswell. <= This could somehow relate to our Windows Version build process (as stated here: #1687). We didn't build the installer and setup files, but reused to old installer to setup the service - and manually replaced the files from the installed directory with our build output. Maybe this copy process is handled in the installer.

Additionally we needed to configure the NUT windows service startup behaviour to "Autostart (delayed)" because of our Network interface was coming up too late.

After this, and a final reboot it now seems to run perfectly:

Thanks and regards!

[jimklimov]

Sounds great and encouraging, thanks!

Now, if only someone were to automate these bits of logic and knowledge with the WiX installer and tools from mingw, to produce MSI snapshots right from CI...