[BUG] Unable to use light on Windows

[Ferkeltod]

Software Versions:

• Operating System: Windows 11 (x64)
• Python version: 3.10.1
• BusyLight version: busylight-for-humans 0.13.2

General Type of Problem

• [X] Command-line

Describe the Problem USB-connected Embrava BLYNC USB 30s. Command line parameters "list" and "supported" never return. Debug output shows endless loop of iterating over same device. Any control command hangs as well, does not control the light and never returns. Same behavior running with and w/o admin-privileges. Having installed Embrava Software does not change behavior.

Expected Behavior Listing compatible resp. supported device, in my case Embrava BLYNC USB 30s

Error Output see attached debug log busylight_list_debug.txt

[JnyJny]

This is a duplicate of issue #56 unfortunately. I wrote BusyLight with the assumption that files are generally opened with exclusive access (meaning the file gets opened once and successive opens fail until the file is closed). The entire light discovery strategy hinges on this behavior, which Windows does not honor. This will remain broken until I have time to fix it or someone kindly contributes a fix.

[Ferkeltod]

My bad - I did not read #56 as the title did not hint at the same issue. I will play a bit around if I can get it to work using Python in WSL2 (Debian 11) on the same machine - maybe it does something differently when inside the de-facto WSL VM.

[JnyJny]

Knowing more people are interested in using it on Windows helps motivate me to fix it, thanks for the bug report. I'm curious if WSL has the same problem (I suspect it does not).

[Ferkeltod]

Indeed - it works! Followed instructions from https://devblogs.microsoft.com/commandline/connecting-usb-devices-to-wsl/ , installed usbipd-win from https://github.com/dorssel/usbipd-win/ (also available via Windows packet manager), attached the USB device to the WSL-VM:

>usbipd wsl list
BUSID  DEVICE                                                        STATE
1-7    USB Input Device                                              Attached - Debian

dmesg shows it nicely:

[ 1220.379646] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
[ 1220.379649] vhci_hcd vhci_hcd.0: devid(65543) speed(1) speed_str(low-speed)
[ 1220.379674] vhci_hcd vhci_hcd.0: Device attached
[ 1220.722102] usb 1-1: new low-speed USB device number 2 using vhci_hcd
[ 1220.882125] usb 1-1: SetAddress Request (2) to port 0
[ 1220.935247] usb 1-1: New USB device found, idVendor=0e53, idProduct=2517, bcdDevice= 1.00
[ 1220.935248] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1220.935249] usb 1-1: Product: Blynclight

root@sugarcube:~# busylight list
ID: Device Name
 0: Blynclight

and does exactly what it was intended to do - controls the light nicely. Need to create an udev-rule to sort out the device permissions to work non-root, but that's no real issue anymore.

However, found an 2 errors in debug output when calling busylight list in attachment: blynclight_2nd_hid_open_error.txt That's probably due to the way you do the device locking. First exclusive lock seems successful, second one failed.

I believe USB devices are kind of pass-thru to the (under-the-hood) Hyper-V based VM, but directly on (raw) device level. Your code - resp. Python - seems to work on one abstraction layer higher, "device control level". That name might be completely wrong, but I hope you get what I'm trying to convey.

[JnyJny]

Thank you for the report that it works on Windows from within WSL. The "errors" in the debug output are expected, as you surmised.

[JnyJny]

Windows tests as of version 0.22.2 are passing, indicating that the change in software architecture might have benefited Windows users. Any reports good or bad for this latest version on Windows?

[remss]

On Windows with busylight v0.26.0 the devices are correctly detected but nothing happens when I try to set a color, the device light is still off.

> busylight list
  0 Blinkstick Square
  1 Blinkstick Square
  2 Flag

> busylight.exe --all -D on green
2023-02-28 17:30:37.299 | INFO     | busylight.__main__:precommand_callback:132 - version 0.26.0
2023-02-28 17:30:37.301 | INFO     | busylight.__main__:precommand_callback:133 - timeout=None
2023-02-28 17:30:37.302 | INFO     | busylight.__main__:precommand_callback:134 -     dim=1.0
2023-02-28 17:30:37.303 | INFO     | busylight.__main__:precommand_callback:135 -  lights=[]
2023-02-28 17:30:37.303 | INFO     | busylight.__main__:precommand_callback:136 -     cmd='on'
2023-02-28 17:30:37.304 | INFO     | busylight.__main__:turn_lights_on:149 - activating lights
2023-02-28 17:30:37.600 | INFO     | busylight.lights.hidlight:available_lights:50 - BlinkStick found 2
2023-02-28 17:30:37.615 | INFO     | busylight.lights.hidlight:acquire:106 - Blinkstick Square open_path(b'\\\\?\\HID#VID_20A0&PID_41E5#7&2d5112df&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}') succeeded
2023-02-28 17:30:37.630 | INFO     | busylight.lights.hidlight:acquire:106 - Blinkstick Square open_path(b'\\\\?\\HID#VID_20A0&PID_41E5#9&790a9a1&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}') succeeded
2023-02-28 17:30:37.632 | INFO     | busylight.lights.light:all_lights:160 - BlinkStick found 2 lights.
2023-02-28 17:30:37.736 | INFO     | busylight.lights.hidlight:available_lights:50 - Blynclight found 0
2023-02-28 17:30:37.737 | INFO     | busylight.lights.light:all_lights:160 - Blynclight found 0 lights.
2023-02-28 17:30:37.841 | INFO     | busylight.lights.hidlight:available_lights:50 - Blynclight_Mini found 0
2023-02-28 17:30:37.842 | INFO     | busylight.lights.light:all_lights:160 - Blynclight_Mini found 0 lights.
2023-02-28 17:30:37.945 | INFO     | busylight.lights.hidlight:available_lights:50 - Blynclight_Plus found 0
2023-02-28 17:30:37.947 | INFO     | busylight.lights.light:all_lights:160 - Blynclight_Plus found 0 lights.
2023-02-28 17:30:38.052 | INFO     | busylight.lights.hidlight:available_lights:50 - Status_Indicator found 0
2023-02-28 17:30:38.053 | INFO     | busylight.lights.light:all_lights:160 - Status_Indicator found 0 lights.
2023-02-28 17:30:38.159 | INFO     | busylight.lights.hidlight:available_lights:50 - Busylight_Alpha found 0
2023-02-28 17:30:38.160 | INFO     | busylight.lights.light:all_lights:160 - Busylight_Alpha found 0 lights.
2023-02-28 17:30:38.266 | INFO     | busylight.lights.hidlight:available_lights:50 - Busylight_Omega found 0
2023-02-28 17:30:38.267 | INFO     | busylight.lights.light:all_lights:160 - Busylight_Omega found 0 lights.
2023-02-28 17:30:38.370 | INFO     | busylight.lights.hidlight:available_lights:50 - Flag found 1
2023-02-28 17:30:38.376 | INFO     | busylight.lights.hidlight:acquire:106 - Flag open_path(b'\\\\?\\HID#VID_04D8&PID_F372#9&987b382&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}') succeeded
2023-02-28 17:30:38.377 | INFO     | busylight.lights.light:all_lights:160 - Flag found 1 lights.
2023-02-28 17:30:38.483 | INFO     | busylight.lights.hidlight:available_lights:50 - Bluetooth found 0
2023-02-28 17:30:38.484 | INFO     | busylight.lights.light:all_lights:160 - Bluetooth found 0 lights.
2023-02-28 17:30:38.590 | INFO     | busylight.lights.hidlight:available_lights:50 - Mute found 0
2023-02-28 17:30:38.591 | INFO     | busylight.lights.light:all_lights:160 - Mute found 0 lights.
2023-02-28 17:30:38.695 | INFO     | busylight.lights.hidlight:available_lights:50 - Orb found 0
2023-02-28 17:30:38.801 | INFO     | busylight.lights.hidlight:available_lights:50 - MuteMe found 0
2023-02-28 17:30:38.802 | INFO     | busylight.lights.light:all_lights:160 - MuteMe found 0 lights.
2023-02-28 17:30:38.905 | INFO     | busylight.lights.hidlight:available_lights:50 - MuteMe_Mini found 0
2023-02-28 17:30:38.906 | INFO     | busylight.lights.light:all_lights:160 - MuteMe_Mini found 0 lights.
2023-02-28 17:30:39.009 | INFO     | busylight.lights.hidlight:available_lights:50 - Blink1 found 0
2023-02-28 17:30:39.010 | INFO     | busylight.lights.light:all_lights:160 - Blink1 found 0 lights.
2023-02-28 17:30:39.014 | INFO     | busylight.lights.seriallight:available_lights:83 - Fit_StatUSB found 0
2023-02-28 17:30:39.015 | INFO     | busylight.lights.light:all_lights:160 - Fit_StatUSB found 0 lights.
2023-02-28 17:30:39.019 | INFO     | busylight.lights.seriallight:available_lights:83 - MuteSync found 0
2023-02-28 17:30:39.020 | INFO     | busylight.lights.light:all_lights:160 - MuteSync found 0 lights.
2023-02-28 17:30:39.021 | INFO     | busylight.lights.light:all_lights:153 - Light found 3 lights total.
2023-02-28 17:30:39.023 | INFO     | busylight.lights.light:exclusive_access:529 - Entering exclusive access for Blinkstick Square      
2023-02-28 17:30:39.024 | INFO     | busylight.lights.light:update:557 - data:26 = b'\x06\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00' wrote -1
2023-02-28 17:30:39.025 | INFO     | busylight.lights.light:exclusive_access:543 - Exiting exclusive access for Blinkstick Square       
2023-02-28 17:30:39.026 | INFO     | busylight.lights.light:exclusive_access:529 - Entering exclusive access for Blinkstick Square      
2023-02-28 17:30:39.027 | INFO     | busylight.lights.light:update:557 - data:26 = b'\x06\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00' wrote -1
2023-02-28 17:30:39.028 | INFO     | busylight.lights.light:exclusive_access:543 - Exiting exclusive access for Blinkstick Square       
2023-02-28 17:30:39.028 | INFO     | busylight.lights.light:exclusive_access:529 - Entering exclusive access for Flag
2023-02-28 17:30:39.030 | INFO     | busylight.lights.light:update:557 - data:7 = b'\x01\xff\x00\x80\x00\x00\x00' wrote 9
2023-02-28 17:30:39.031 | INFO     | busylight.lights.light:exclusive_access:543 - Exiting exclusive access for Flag

Note I tried on MacOSX and I works fine.

[JnyJny]

2023-02-28 17:30:39.024 | INFO     | busylight.lights.light:update:557 - data:26 = b'\x06\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00' wrote -1
2023-02-28 17:30:39.027 | INFO     | busylight.lights.light:update:557 - data:26 = b'\x06\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00\x80\x00\x00' wrote -1
2023-02-28 17:30:39.030 | INFO     | busylight.lights.light:update:557 - data:7 = b'\x01\xff\x00\x80\x00\x00\x00' wrote 9

This is the interesting part of the debug output, both writes to the Blinkstick Square devices failed "wrote -1" and the flag write succeed with a 9 but the command word is seven bytes (I think there is a 0x0000 prepended which would bring it up to nine bytes, I have to go back and look at the code).

@remss if you have some time and are willing, could you try running this fragment in a repl?

from busylight.lights import Flag
l = Flag.first_light(exclusive=False)
l.on((0,255,0))

[remss]

Here the result, and the light of the Luxafor device is still off

Python 3.11.0 (main, Oct 24 2022, 18:26:48) [MSC v.1933 64 bit (AMD64)] on win32
Type "help", "copyright", "credits" or "license" for more information.
>>> import busylight                      
>>> from busylight.lights import Flag     
>>> l = Flag.first_light(exclusive=False)
>>> busylight.logger.enable("busylight")  
>>> l.on((0,255,0))
2023-03-01 16:06:21.881 | INFO     | busylight.lights.light:exclusive_access:529 - Entering exclusive access for Flag
2023-03-01 16:06:21.882 | INFO     | busylight.lights.light:exclusive_access:532 - Acquiring device for Flag
2023-03-01 16:06:21.953 | INFO     | busylight.lights.hidlight:acquire:106 - Flag open_path(b'\\\\?\\HID#VID_04D8&PID_F372#9&987b382&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}') succeeded
2023-03-01 16:06:21.954 | INFO     | busylight.lights.light:exclusive_access:534 - Acquired for Flag
2023-03-01 16:06:21.955 | INFO     | busylight.lights.light:update:557 - data:7 = b'\x01\xff\x00\xff\x00\x00\x00' wrote 9
2023-03-01 16:06:21.956 | INFO     | busylight.lights.light:exclusive_access:539 - Releasing device for Flag
2023-03-01 16:06:21.957 | INFO     | busylight.lights.hidlight:release:114 - Flag close succeeded
2023-03-01 16:06:21.958 | INFO     | busylight.lights.light:exclusive_access:541 - Released for Flag
2023-03-01 16:06:21.959 | INFO     | busylight.lights.light:exclusive_access:543 - Exiting exclusive access for Flag

[JnyJny]

Well, darn. Until I have a windows machine to debug on (or someone submits a patch) this is going to stay broken for now.

We could try to verify that hidapi works by doing something like:

import hid
device = hid.device()
device.open(0x04d8, 0xf372)
device.write([ 0x1, 0xff, 0, 0xff, 0, 0, 0]). # cmd, leds, red, green, blue, fade, repeat
# flag should be on with a green color

[remss]

The hidapi is working well, the light comes green (I had to change a little the data to send, an initial 0 was missing)

>>> import hid
>>> device = hid.device()
>>> device.open(0x04d8, 0xf372)
>>> device.get_manufacturer_string()
'Microchip Technology Inc.'
>>> device.get_product_string()     
'LUXAFOR FLAG'
>>> device.write([ 0, 0x1, 0xff, 0, 0xff, 0, 0, 0])
9

My 2 cents about Windows machine,: you might use VirtualBox and prebuilt images from https://developer.microsoft.com/en-us/windows/downloads/virtual-machines/

[JnyJny]

That is odd. AFAIK the first byte in the Luxafor instruction buffer of eight bytes is a command whose valid values are 1, 2, 3, 4, and 6. Also there are only eight items in the list you passed to device.write and it returned 9 (number of bytes written). I am starting to suspect a bug of some sort in the Windows version of hidapi (smells like an off-by-one error).

[JnyJny]

I'll have a windows machine to test on in the near future, I guess stay tuned. >>shudder<<

[magic-muschrum]

Hi, was not sure if it was best to add to this on #56 or here but I would like to say that the problem is also happening with Win 10 under python 3.7. and 3.11. Flag is listed and log looks like this:

busylight.lights.hidlight:available_lights:50 - Flag found 1                      
2023-05-03 23:43:50.765 | INFO     | busylight.lights.hidlight:acquire:106 - Flag open_path(b'\\\\\\HID#VID_04D8&PID_F372#a&172874d6&0&0000#{4d1e55b2-f16f-11cf-88cb-001111000030}') succeeded 
2023-05-03 23:43:50.765 | INFO     | busylight.lights.light:all_lights:160 - Flag found 1 lights.
(...)
busylight.lights.light:all_lights:153 - Light found 1 lights total.
2023-05-03 23:43:51.698 | INFO     | busylight.lights.light:exclusive_access:529 - Entering exclusive access for Flag
2023-05-03 23:43:51.706 | INFO     | busylight.lights.light:update:557 - data:7 = b'\x01\xff\x00\x80\x00\x00\x00' wrote 9
2023-05-03 23:43:51.706 | INFO     | busylight.lights.light:exclusive_access:543 - Exiting exclusive access for Flag

Hope that helps. If there is anyway I can support, please let me know. Thank you for looking into it.

[Gunni]

Hey this is still broken, I have Kuando Busylight Alpha and while the program seems to pretend to be doing something, nothing happens on the light itself.

[JnyJny]

Hi @Gunni, no new progress has been made on getting Busylight working in the Windows environment. My plans for a Windows development machine have not yet come to fruition.