search

JnyJny / busylight

Control USB connected presence lights from multiple vendors via the command-line or web API.
Apache License 2.0
220 stars 25 forks source link

[BUG] Busylight UC Omega not detected #113

Closed dfangl closed 2 years ago

dfangl commented 2 years ago

Software Versions:

General Type of Problem

Describe the Problem Busylight Omega is not detected. It seems a new revision is out, with the product ID 0x3BCF. Currently, only 0x3BCD is defined. Also, busylight throws an error for a failing assertion on exit.

Expected Behavior Correct detection of omega light and no assertion error on exit.

Error Output Error missing Product ID:

$ busylight -D on red
2022-02-21 19:24:06.382 | INFO     | busylight.manager:update:172 - Manager has 0 lights
2022-02-21 19:24:06.382 | DEBUG    | busylight.lights.usblight:all_lights:177 - USBLight querying subclass lights...
2022-02-21 19:24:06.382 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: BlinkStick
2022-02-21 19:24:06.382 | DEBUG    | busylight.lights.usblight:first_light:118 - BlinkStick looking for first unclaimed light...
2022-02-21 19:24:06.384 | DEBUG    | busylight.lights.usblight:first_light:137 - BlinkStick found no unclaimed lights.
2022-02-21 19:24:06.384 | DEBUG    | busylight.lights.usblight:all_lights:174 - BlinkStick found 0 lights
2022-02-21 19:24:06.384 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Blynclight
2022-02-21 19:24:06.384 | DEBUG    | busylight.lights.usblight:first_light:118 - Blynclight looking for first unclaimed light...
2022-02-21 19:24:06.384 | DEBUG    | busylight.lights.usblight:first_light:137 - Blynclight found no unclaimed lights.
2022-02-21 19:24:06.385 | DEBUG    | busylight.lights.usblight:all_lights:174 - Blynclight found 0 lights
2022-02-21 19:24:06.385 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Busylight
2022-02-21 19:24:06.385 | DEBUG    | busylight.lights.usblight:first_light:118 - Busylight looking for first unclaimed light...
2022-02-21 19:24:06.387 | DEBUG    | busylight.lights.usblight:first_light:121 - Busylight entry found for vendor_id 27bb
2022-02-21 19:24:06.387 | DEBUG    | busylight.lights.usblight:first_light:125 - entry: {'path': b'1-1:1.0', 'vendor_id': 10171, 'product_id': 15311, 'serial_number': '922092FF001024FF13FFFFFF8102FFFF9102FFFF', 'release_number': 256, 'manufacturer_string': 'PLENOM A/S', 'product_string': 'BUSYLIGHT OMEGA', 'usage_page': 0, 'usage': 0, 'interface_number': 0}
2022-02-21 19:24:06.387 | ERROR    | busylight.lights.usblight:first_light:132 - Busylight Requested device product_id not supported: product_id=0x3bcf for vendor_id 27bb
2022-02-21 19:24:06.387 | ERROR    | busylight.lights.usblight:identifier:384 - unsupported format string passed to NoneType.__format__
Traceback (most recent call last):

  File "/home/daniel/projects/busylight/.venv/bin/busylight", line 8, in <module>
    sys.exit(cli())
    │   │    └ <typer.main.Typer object at 0x7f6065886df0>
    │   └ <built-in function exit>
    └ <module 'sys' (built-in)>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/typer/main.py", line 214, in __call__
    return get_command(self)(*args, **kwargs)
           │           │      │       └ {}
           │           │      └ ()
           │           └ <typer.main.Typer object at 0x7f6065886df0>
           └ <function get_command at 0x7f6064d2c700>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
           │    │     │       └ {}
           │    │     └ ()
           │    └ <function BaseCommand.main at 0x7f6064d54280>
           └ <TyperGroup main-callback>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
         │    │      └ <click.core.Context object at 0x7f6064c7d3a0>
         │    └ <function MultiCommand.invoke at 0x7f6064d56310>
         └ <TyperGroup main-callback>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
           │               │       │       │      └ <click.core.Context object at 0x7f60649dc4f0>
           │               │       │       └ <function Command.invoke at 0x7f6064d54d30>
           │               │       └ <TyperCommand on>
           │               └ <click.core.Context object at 0x7f60649dc4f0>
           └ <function MultiCommand.invoke.<locals>._process_result at 0x7f60649d7670>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           │   │      │    │           │   └ {'color': 'red'}
           │   │      │    │           └ <click.core.Context object at 0x7f60649dc4f0>
           │   │      │    └ <function on_subcommand at 0x7f60649d71f0>
           │   │      └ <TyperCommand on>
           │   └ <function Context.invoke at 0x7f6064daaaf0>
           └ <click.core.Context object at 0x7f60649dc4f0>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
                       │       └ {'color': 'red'}
                       └ ()
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/typer/main.py", line 500, in wrapper
    return callback(**use_params)  # type: ignore
           │          └ {'ctx': <click.core.Context object at 0x7f60649dc4f0>, 'color': 'red'}
           └ <function on_subcommand at 0x7f60649c1e50>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/__main__.py", line 126, in on_subcommand
    manager = LightManager()
              └ <class 'busylight.manager.LightManager'>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/manager.py", line 86, in __init__
    self.update()
    │    └ <function LightManager.update at 0x7f60649c1820>
    └ LightManager()
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/manager.py", line 173, in update
    self.lights.extend(USBLight.all_lights())
    │    │             │        └ <classmethod object at 0x7f6064d46070>
    │    │             └ <class 'busylight.lights.usblight.USBLight'>
    │    └ <property object at 0x7f6064c79360>
    └ LightManager()
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/usblight.py", line 179, in all_lights
    lights.extend(supported_light.all_lights())
    │      │      │               └ <classmethod object at 0x7f6064d46070>
    │      │      └ <class 'busylight.lights.kuando.busylight.Busylight'>
    │      └ <method 'extend' of 'list' objects>
    └ []
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/usblight.py", line 170, in all_lights
    lights.append(cls.first_light())
    │      │      │   └ <classmethod object at 0x7f6064d3cfd0>
    │      │      └ <class 'busylight.lights.kuando.busylight.Busylight'>
    │      └ <method 'append' of 'list' objects>
    └ []
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/usblight.py", line 135, in first_light
    pass
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/usblight.py", line 250, in __del__
    self.release()
    │    └ <function Busylight.release at 0x7f6064c47160>
    └ <unprintable Busylight object>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/kuando/busylight.py", line 145, in release
    self.keepalive_thread.cancel()
    │    └ <property object at 0x7f6064c41180>
    └ <unprintable Busylight object>
  File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/kuando/busylight.py", line 126, in keepalive_thread
    self.keepalive(), f"keepalive-{self.identifier}"
    │    └ <function Busylight.keepalive at 0x7f6064cbaee0>
    └ <unprintable Busylight object>
> File "/home/daniel/projects/busylight/.venv/lib/python3.8/site-packages/busylight/lights/usblight.py", line 382, in identifier
    return f"0x{self.vendor_id:04x}:0x{self.product_id:04x}"

TypeError: unsupported format string passed to NoneType.__format__
2022-02-21 19:24:06.393 | DEBUG    | busylight.lights.usblight:stop_animation:541 - 'Busylight' object has no attribute '_animation_thread'
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:137 - Busylight found no unclaimed lights.
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:174 - Busylight found 0 lights
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Flag
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:118 - Flag looking for first unclaimed light...
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:137 - Flag found no unclaimed lights.
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:174 - Flag found 0 lights
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Status_Indicator
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:118 - Status_Indicator looking for first unclaimed light...
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:137 - Status_Indicator found no unclaimed lights.
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:174 - Status_Indicator found 0 lights
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Blink1
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:118 - Blink1 looking for first unclaimed light...
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:first_light:137 - Blink1 found no unclaimed lights.
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:174 - Blink1 found 0 lights
2022-02-21 19:24:06.394 | DEBUG    | busylight.lights.usblight:all_lights:180 - USBLight found 0 in total.
2022-02-21 19:24:06.394 | INFO     | busylight.manager:update:175 - After all_lights, Manager has 0 lights
2022-02-21 19:24:06.395 | INFO     | busylight.manager:update:182 - Manager has 0 lights after update
Light '0' not in the range of 0..-1

Error assertion (after adding product ID):

$ busylight -D on red
2022-02-21 19:25:07.897 | INFO     | busylight.manager:update:172 - Manager has 0 lights
2022-02-21 19:25:07.897 | DEBUG    | busylight.lights.usblight:all_lights:177 - USBLight querying subclass lights...
2022-02-21 19:25:07.897 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: BlinkStick
2022-02-21 19:25:07.897 | DEBUG    | busylight.lights.usblight:first_light:118 - BlinkStick looking for first unclaimed light...
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:first_light:137 - BlinkStick found no unclaimed lights.
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:all_lights:174 - BlinkStick found 0 lights
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Blynclight
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:first_light:118 - Blynclight looking for first unclaimed light...
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:first_light:137 - Blynclight found no unclaimed lights.
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:all_lights:174 - Blynclight found 0 lights
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Busylight
2022-02-21 19:25:07.899 | DEBUG    | busylight.lights.usblight:first_light:118 - Busylight looking for first unclaimed light...
2022-02-21 19:25:07.901 | DEBUG    | busylight.lights.usblight:first_light:121 - Busylight entry found for vendor_id 27bb
2022-02-21 19:25:07.901 | DEBUG    | busylight.lights.usblight:first_light:125 - entry: {'path': b'1-1:1.0', 'vendor_id': 10171, 'product_id': 15311, 'serial_number': '922092FF001024FF13FFFFFF8102FFFF9102FFFF', 'release_number': 256, 'manufacturer_string': 'PLENOM A/S', 'product_string': 'BUSYLIGHT OMEGA', 'usage_page': 0, 'usage': 0, 'interface_number': 0}
2022-02-21 19:25:07.901 | DEBUG    | busylight.lights.usblight:__init__:243 - Busylight init 27bb 3bcf b'1-1:1.0' False
2022-02-21 19:25:07.901 | DEBUG    | busylight.lights.usblight:acquire:473 - Busylight.acquire(reset=False)
2022-02-21 19:25:07.901 | DEBUG    | busylight.lights.usblight:acquire:475 - lock acquired
2022-02-21 19:25:07.902 | SUCCESS  | busylight.lights.usblight:acquire:491 - Busylight hid.open_path('1-1:1.0') was a success None
2022-02-21 19:25:07.902 | DEBUG    | busylight.lights.thread:run:73 -  <CancellableThread(keepalive-0x27bb:0x3bcf, started daemon 139864402024000)> running target <generator object Busylight.keepalive at 0x7f34baeb36d0>
2022-02-21 19:25:07.902 | INFO     | busylight.lights.kuando.busylight:keepalive:98 - keepalive generator 8f00000000000000, 15 s 0.100
2022-02-21 19:25:07.904 | DEBUG    | busylight.lights.usblight:all_lights:171 - Busylight added a light Kuando Busylight Omega: 0x27bb:0x3bcf
2022-02-21 19:25:07.904 | DEBUG    | busylight.lights.usblight:first_light:118 - Busylight looking for first unclaimed light...
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:first_light:121 - Busylight entry found for vendor_id 27bb
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:first_light:125 - entry: {'path': b'1-1:1.0', 'vendor_id': 10171, 'product_id': 15311, 'serial_number': '922092FF001024FF13FFFFFF8102FFFF9102FFFF', 'release_number': 256, 'manufacturer_string': 'PLENOM A/S', 'product_string': 'BUSYLIGHT OMEGA', 'usage_page': 0, 'usage': 0, 'interface_number': 0}
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:__init__:243 - Busylight init 27bb 3bcf b'1-1:1.0' False
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:acquire:473 - Busylight.acquire(reset=False)
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:acquire:475 - lock acquired
2022-02-21 19:25:07.907 | ERROR    | busylight.lights.usblight:acquire:479 - hid_open open failed for open_path('1-1:1.0')
2022-02-21 19:25:07.907 | ERROR    | busylight.lights.usblight:first_light:132 - Busylight Device open failed, already open for vendor_id 27bb
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:stop_animation:541 - 'Busylight' object has no attribute '_animation_thread'
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:first_light:137 - Busylight found no unclaimed lights.
2022-02-21 19:25:07.907 | DEBUG    | busylight.lights.usblight:all_lights:174 - Busylight found 1 lights
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Flag
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:118 - Flag looking for first unclaimed light...
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:137 - Flag found no unclaimed lights.
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:174 - Flag found 0 lights
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Status_Indicator
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:118 - Status_Indicator looking for first unclaimed light...
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:137 - Status_Indicator found no unclaimed lights.
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:174 - Status_Indicator found 0 lights
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:167 - Searching for lights belonging to: Blink1
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:118 - Blink1 looking for first unclaimed light...
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:first_light:137 - Blink1 found no unclaimed lights.
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:174 - Blink1 found 0 lights
2022-02-21 19:25:07.908 | DEBUG    | busylight.lights.usblight:all_lights:180 - USBLight found 1 in total.
2022-02-21 19:25:07.908 | INFO     | busylight.manager:update:175 - After all_lights, Manager has 1 lights
2022-02-21 19:25:07.908 | INFO     | busylight.manager:update:182 - Manager has 1 lights after update
2022-02-21 19:25:07.909 | DEBUG    | busylight.lights.usblight:stop_animation:541 - 'Busylight' object has no attribute '_animation_thread'
2022-02-21 19:25:07.909 | DEBUG    | busylight.lights.usblight:update:554 - Busylight update for b'\x10\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xff\xff\xff\x03\r'
2022-02-21 19:25:07.909 | DEBUG    | busylight.lights.usblight:stop_animation:541 - 'Busylight' object has no attribute '_animation_thread'
2022-02-21 19:25:07.909 | DEBUG    | busylight.lights.usblight:update:554 - Busylight update for b'\x10\x00d\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xff\xff\xff\x03q'
^C2022-02-21 19:25:10.286 | DEBUG    | busylight.lights.usblight:stop_animation:541 - 'Busylight' object has no attribute '_animation_thread'
2022-02-21 19:25:10.287 | DEBUG    | busylight.lights.usblight:update:554 - Busylight update for b'\x10\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xff\xff\xff\x03\r'
python: io.c:2115: handle_events: Assertion `ctx->pollfds_cnt >= internal_nfds' failed.
[1]    215416 IOT instruction (core dumped)  busylight -D on red

Additional Infos

I will file a quick PR for the missing ID myself, not sure what goes on with the wrong assertion though, and cannot test with other devices if this is something new with the new Product ID. Is this error currently expected?

JnyJny commented 2 years ago

Hi and thanks for the bug report and the pull request with the new product_id value!

The other thing you noticed is the result of my decision to use threads to update the Busylight family of devices in the background. Unfortunately, HIDAPI doesn't support accessing HID devices from multiple threads and has recently started crashing under MacOS in the tests (and presumably Linux too, I haven't looked to closely at the results of the automated testing).

I'm in the process of re-writing with an eye towards using asyncio to keep everything in a single thread while taking advantage of an asyncio event loop to deliver keep-alive messages to Busylights. Easily my least favorite light since it needs so much hand-holding.

No ETA for the re-write as I've just begun this weekend, however it's giving me the opportunity to clean up a bunch of kludges.

dfangl commented 2 years ago

Thanks for the quick response! If you need any help, or help testing, I would be happy to lend a hand!