Using parameter "all" for service "ask_for_update" gives error in v0.5.4
Closed this issue · 6 comments
Running v0.5.4 using
service: duofern.ask_for_update
data:
all: true
gives this in the UI: Error calling service duofern.ask_for_update. Unknown error
and this in the HA log:
2023-04-02 18:38:51.208 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: local variable 'sets' referenced before assignment
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in _async_step
await getattr(self, handler)()
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 684, in _async_call_service_step
await service_task
File "/usr/src/homeassistant/homeassistant/core.py", line 1745, in async_call
task.result()
File "/usr/src/homeassistant/homeassistant/core.py", line 1788, in _execute_service
await self._hass.async_add_executor_job(
File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
result = self.fn(*self.args, **self.kwargs)
File "/config/custom_components/duofern/__init__.py", line 152, in ask_for_update
getDuofernStick(hass).command(device_id, 'getStatus')
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern_stick.py", line 576, in command
self.duofern_parser.set(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern.py", line 770, in set
logger.debug(sets.keys()) # join(" ", sort keys sets)
UnboundLocalError: local variable 'sets' referenced before assignment
2023-04-02 18:38:51.215 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547173666864] Error handling message: Unknown error (unknown_error) from xxx.xxx.xxx.xxx (Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/111.0)
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
await func(hass, connection, msg)
File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 646, in handle_execute_script
await script_obj.async_run(msg.get("variables"), context=context)
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1524, in async_run
await asyncio.shield(run.async_run())
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 409, in async_run
await self._async_step(log_exceptions=False)
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 453, in _async_step
self._handle_exception(
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _handle_exception
raise exception
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in _async_step
await getattr(self, handler)()
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 684, in _async_call_service_step
await service_task
File "/usr/src/homeassistant/homeassistant/core.py", line 1745, in async_call
task.result()
File "/usr/src/homeassistant/homeassistant/core.py", line 1788, in _execute_service
await self._hass.async_add_executor_job(
File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
result = self.fn(*self.args, **self.kwargs)
File "/config/custom_components/duofern/__init__.py", line 152, in ask_for_update
getDuofernStick(hass).command(device_id, 'getStatus')
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern_stick.py", line 576, in command
self.duofern_parser.set(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern.py", line 770, in set
logger.debug(sets.keys()) # join(" ", sort keys sets)
UnboundLocalError: local variable 'sets' referenced before assignment
Interesting part:
File "/config/custom_components/duofern/__init__.py", line 152, in ask_for_update
getDuofernStick(hass).command(device_id, 'getStatus')
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern_stick.py", line 576, in command
self.duofern_parser.set(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern.py", line 770, in set
logger.debug(sets.keys()) # join(" ", sort keys sets)
UnboundLocalError: local variable 'sets' referenced before assignment
Additional notes after a bit more of blackbox testing (to find a work around for updating all devices):
❓ Gives no error but likely does nothing (?):
service: duofern.ask_for_update
data: {}
❌ Gives an error (wrong syntax)
service: duofern.ask_for_update
data:
device_id: all
❓ Gives no error and makes use of HA magic "all", but likely does nothing (according to debug logs which contain nothing):
service: duofern.ask_for_update
data:
device_id:
- all
❓ Gives no error and uses a group of devices (cover group), but likely does nothing (according to debug logs which contain nothing):
service: duofern.ask_for_update
data:
device_id:
- cover.all_covers
Before I update my automations.yaml and scripts.yaml the 7th time during the last weeks I want to be sure to have a working service (syntax) 😃
Update: even using the service correctly by specifying only a single entity for the device_id (without all), having debugging enabled I see absolutely nothing in the logs.
service: duofern.ask_for_update
data:
device_id:
- cover.cover_a
Therefore I have no idea if/technical proof that the service is working at all, even if the GUI does not indicate an error.
Regarding the original error
File "/usr/local/lib/python3.10/site-packages/pyduofern/duofern.py", line 770, in set
logger.debug(sets.keys()) # join(" ", sort keys sets)
UnboundLocalError: local variable 'sets' referenced before assignment
You mentioned that you had bogous devices (ones that you didn't pair yourself) detected by duofern - I believe having a potentially non-existing device type triggered this. Sets were always set for "existing" duofern device types - therefore this didn't show up before. but the bogous devices seem to not match that description. I fixed duofern to not raise that error any more (will be in 0.5.5). you will likely be able to trigger this by running the update exclusively by updating one of the "bogous" devices.
Regarding "how to use all"
Your initial attempt is fine.
service: duofern.ask_for_update
data:
all: true
Is the yaml the UI also produces when checking the box and it works on my side. The error it triggered on your side because of the ghost devices should be fixed with 0.5.5. (can't test for lack of ghost devices).
Regarding the logging:
Already in 0.5.4 there should always be info level logs when running the ask_for_update. They look like this:
2023-04-02 21:19:27.503 INFO (SyncWorker_7) [custom_components.duofern] asking ffffff for update
If they are not there (but other info level logging is), the command didn't go out. This may have been caused by the duofern thread crashing due to the issue you describe above.
Nevertheless I added a bunch more verbosity to the update function - it might help in case we get another issue with bogous devices. It now also warns when it does not find a single device to apply the command to, to make this case more obvious.
edit: noticed that my mental counter was off by one minor minor version so I had to increment version numbers mentioned...
Interesting. I used the service pointing at only one specific device_id with debug logging enabled and there is - no - log entry.
Will update to 0.5.5.
edit: noticed that my mental counter was off by one minor minor version so I had to increment version numbers mentioned...
Edit: HACS now only showed ..., ..., (other old ones), 0.5.3 and 0.5.5 (no 0.5.4 anymore). I had to "reinstall" the 0.5.5 for an instant update/reinstall and hope this gives an update. No idea what the normal behaviour of HACS is in this case. (newer version number triggers an update?)
Now with 0.5.5 I get this:
When running
1. As intended
service: duofern.ask_for_update
data:
all: true
--> Absolutely NOTHING in debug log.
2. As not intended
service: duofern.ask_for_update
data: {}
--> gives 2023-04-02 23:58:02.891 WARNING (SyncWorker_0) [custom_components.duofern] Found no valid device ids???
❓
Do you have info level logging enabled? As I said the verbose logging is only "Info" level. There should be no codepath left entirely without logging in the ask_for_update function. It's really verbose now. But if everything goes well it only logs on the "INFO" level. It's homeassistant policy that you shouldn't log warnings unless something negative or unexpected happened that the user needs to be informed about.
For instance when doing ask_for_update with all:true this is what I get for logging:
If you only ever see "WARNING" from duofern and never "INFO", you need to enable info logging for duofern. but be warned, it's verbose.
For me that means I have the following in configuration.yaml (you can likely also put info instead of debug, but it makes little difference, because I rarely/never use the debug level).
logger:
default: warning
logs:
custom_components.duofern: debug
Regarding why "updatecallback for xyz" is called so often: that is entirely dependent on what the shutters send and I have no influence over it. it's basically "we received a message and notify homeassistant about it". **edit:**The shutters send several messages with one transmission. e.g. "I'm open 50%", "my state is OK", "my version is X". The log message is printed for each of these bits of information.
Also updating state does not imply that rf messages were received. I'ts just "homeassistant asked me about the state and I returned it from memory.
My fault. I used the "enable debug logging" from the GUI:
...which created no logs for duofern at all.
But using
service: logger.set_level
data:
custom_components.duofern: debug
and firing
service: duofern.ask_for_update
data:
all: true
afterwards gave the expected log output. (I used the same service to set it back to "warning" for duofern) Unfortunately it reminded me of my plenty ghost devices, I think I need a separate issue for them :-(
So I can confirm the new "all" syntax is working. I also did not see this issue anymore since on 0.5.5. So I closed this one.