Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Automations for setting the position of covers with Velux no longer work #72971

Closed
pyrrolizin opened this issue Jun 3, 2022 · 27 comments · Fixed by #72974
Closed

Automations for setting the position of covers with Velux no longer work #72971

pyrrolizin opened this issue Jun 3, 2022 · 27 comments · Fixed by #72974

Comments

@pyrrolizin
Copy link

pyrrolizin commented Jun 3, 2022

The problem

After updating to 2022.6.0 or 2022.6.1, I can still use the Velux integration to retrieve or set the position of individual cover entries. Unfortunately, my automations (scheduled or manually started) no longer work.

What version of Home Assistant Core has the issue?

2022.6.1

What was the last working version of Home Assistant Core?

2022.5.5

What type of installation are you running?

Home Assistant OS

Integration causing the issue

velux

Link to integration documentation on our website

https://www.home-assistant.io/integrations/velux/

Diagnostics information

No response

Example YAML snippet

velux:
  host: !secret velux_ip
  password: !secret velux_password

logger:
  default: warn
  logs:
    homeassistant.components.velux: debug
    pyvlx: debug

Anything in the logs that might be useful for us?

2022-06-03 10:59:05 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall cover.open_cover (c:01G4MCJEGY59MDP1YBDTT08E6B): entity_id=['cover.office', 'cover.kitchen', 'cover.floor', 'cover.floor_door', 'cover.living_left', 'cover.living_second', 'cover.living_door']>
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/core.py", line 1722, in catch_exceptions
await coro_or_task
File "/usr/src/homeassistant/homeassistant/core.py", line 1741, in _execute_service
await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
await service.entity_service_call(
File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 680, in entity_service_call
future.result() # pop exception if have
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 964, in async_request_call
await coro
File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 717, in _handle_entity_call
await result
File "/usr/src/homeassistant/homeassistant/components/velux/cover.py", line 96, in async_open_cover
await self.node.open(wait_for_completion=False)
File "/usr/local/lib/python3.9/site-packages/pyvlx/opening_device.py", line 58, in open
await self.set_position(
File "/usr/local/lib/python3.9/site-packages/pyvlx/opening_device.py", line 47, in set_position
raise PyVLXException("Unable to send command")
pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />
2022-06-03 10:59:27 DEBUG (MainThread) [pyvlx] REC: <FrameNodeStatePositionChangedNotification node_id="6" state="5" current_position="0x0000" target="0x0000" current_position_fp1="0xF7FF" current_position_fp2="0xF7FF" current_position_fp3="0xF7FF" current_position_fp4="0xF7FF" remaining_time="0" time="2079-03-11 10:16:48"/>
2022-06-03 10:59:27 DEBUG (MainThread) [pyvlx] NodeUpdater process frame: <FrameNodeStatePositionChangedNotification node_id="6" state="5" current_position="0x0000" target="0x0000" current_position_fp1="0xF7FF" current_position_fp2="0xF7FF" current_position_fp3="0xF7FF" current_position_fp4="0xF7FF" remaining_time="0" time="2079-03-11 10:16:48"/>
2022-06-03 10:59:41 DEBUG (MainThread) [pyvlx] SEND: <FrameGetStateRequest/>
2022-06-03 10:59:41 DEBUG (MainThread) [pyvlx] REC: <FrameGetStateConfirmation gateway_state="GatewayState.GATEWAY_MODE_WITH_ACTUATORS" gateway_sub_state="GatewaySubState.IDLE"/>

Additional information

Due to the changelogs pyvlx got bumped to 0.2.20 in dev #72678
( Changelog for pyvlx 0.2.20: https://github.com/Julius2342/pyvlx/releases/tag/0.2.20 )

The same error occurs with the service cover.set_cover_position

Home Assistant and KLF200 were restarted a few times for troubleshooting purposes

@probot-home-assistant
Copy link

velux documentation
velux source
(message by IssueLinks)

@probot-home-assistant
Copy link

Hey there @Julius2342, mind taking a look at this issue as it has been labeled with an integration (velux) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)

@marcelveldt
Copy link
Member

marcelveldt commented Jun 3, 2022

I can confirm the same issue.

Most likely the fact that the service calls are parallel instead of serial is causing the velux box to be overloaded with requests. I'm not familiar with the Velux code but I'll see if I can find a quick fix.

@pyrrolizin
Copy link
Author

Thank you for your fast response.

Was there a change from serial to parallel for this? Or something else leading to this overload? Because before it worked for over 1 year without an error.

And if the workaround works, could you change the asyncio.sleep() from 2 seconds to something shorter (e.g. 0.5 seconds)? :)

@marcelveldt
Copy link
Member

0.5 seconds is not enough I think. I just tested this with a bunch of covers (kind of stress testing) and with 0.5secs it was still hit and miss, hence the 2 seconds. Maybe 1 second is enough.

A lot of changes happened lately in relation to speedups and with the new additions to let your whole automation/script run in parallel I think this slipped in as a side effect. Actually a good thing because we want as many to happen in parallel as possible

@pyrrolizin
Copy link
Author

I placed your patched version from your branch in custom_components/velux/ and unfortunately the error still occurs:

Logger: homeassistant.core
Source: custom_components/velux/cover.py:98 
Integration: Velux 
First occurred: 14:57:32 (1 occurrences) 
Last logged: 14:57:32

Error executing service: <ServiceCall cover.open_cover (c:01G4MT72FT1W4WAW4NEQA4SP1B): entity_id=['cover.office', 'cover.kitchen', 'cover.floor', 'cover.floor_door', 'cover.living_left', 'cover.living_second', 'cover.living_door']>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1722, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1741, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 680, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 964, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 717, in _handle_entity_call
    await result
  File "/config/custom_components/velux/cover.py", line 98, in async_open_cover
    await self.node.open(wait_for_completion=False)
  File "/usr/local/lib/python3.9/site-packages/pyvlx/opening_device.py", line 60, in open
    await self.set_position(
  File "/usr/local/lib/python3.9/site-packages/pyvlx/opening_device.py", line 49, in set_position
    raise PyVLXException("Unable to send command")
pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />

The throttle works:
my custom patch:

    @asynccontextmanager
    async def throttle(self):
        """Throttle commands to the underlying device."""
        async with self.lock:
            yield None
            _LOGGER.exception("throttle")
            await asyncio.sleep(2)

Log-File:

2022-06-03 15:04:50 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:50 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:52 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:53 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:54 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:54 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:04:56 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:05:12 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:05:13 ERROR (MainThread) [custom_components.velux] throttle
NoneType: None
2022-06-03 15:06:12 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall cover.open_cover ... (truncated)

@pyrrolizin
Copy link
Author

sorry... wrong button

@pyrrolizin pyrrolizin reopened this Jun 3, 2022
@marcelveldt
Copy link
Member

OK, in my case it fixed all issues instantly but maybe I had a slightly different issue where only half of the screens/covers reacted on commands.

Did you try to power cycle your velux box first ? Maybe it is already stuck.
I have an automation that power cycles the box (over POE) at HA restart.

@pyrrolizin
Copy link
Author

If I press each "open" button of all 7 covers very fast (in less than 2 seconds), all covers open without any problems.

@marcelveldt
Copy link
Member

And is that "Unable to send command" error there each time you do execute your automation ?
Did you try to execute blocks of your automation in the develop console ?

@pyrrolizin
Copy link
Author

pyrrolizin commented Jun 3, 2022

Yes, I have done a couple of power cycles today (Home Assistant and KLF 200).

In the development console (kindly find below) the same exception occurs

service: cover.open_cover
data: {}
target:
  entity_id:
    - cover.office
    - cover.kitchen
    - cover.floor
    ...

I am using a script (not an automation) triggered by a button (or the schedule card). And yes, the exception keeps occurring all the time. (Sometimes the first two covers move).

-edit-
no, only the second (and the third) cover opens

@marcelveldt
Copy link
Member

Thanks, that looks familiar to my situation. It fails when executing the "open_cover" call or "close_cover" service call when using multiple entities in the target. One by one it works fine.

Does that error you pasted above still rise when you execute my modified code ?
I'm not familiar enough with the PyVLX library to further be of any assistance. The fix I PR'ed works great in my case but if it does not in your situation there is more going on I'm afraid.

@pyrrolizin
Copy link
Author

Yes, this code leads to the same error even with your change. (only 14 seconds later :) )
Are you using a Raspberry pi 3 b+ or a slower device? I use a Raspberry 4 (8GB)

@marcelveldt
Copy link
Member

Just looked in my log and see the error popping up again...
Maybe try to set the previous version of the lib (.19) in the manifest.json ? Looking at the integration code itself the only related change is the bump of the library to version .20, otherwise only HA core changes that may be related.

I'm wondering if there are any other integrations with this same issue...

@pyrrolizin
Copy link
Author

manifest:
"requirements": ["pyvlx==0.2.19"],
still the same issue.

@WhistleMaster
Copy link

Does not really help but I can confirm the same issue. I had to revert back to HA 2022.5.5. I

have groups of entities for my covers, and I get the same error when trying to close / open / set position those groups covers:

pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />

@Didel
Copy link

Didel commented Jun 3, 2022

I’m the author of #72678 , not sure if I can be of any help here. Note that the change does indeed only bump the underlying version of
PyVLX to a higher version, no other changes are included. Also note that the PR has been merged into develop, but it is not (yet) included in the 2022.6.X release (and maybe never will, it might be part of 2022.7, or even later). If you want to locally test the changes, either use the dev branch of home assistants, or copy the Velux folder from the dev branch into custom_components, add a version number key with a value to the manifest file as described in the documentation and restart HA.

So, to recap, the problem you’re facing is that it fails when running automations or having a group of covers that you try to control at once? I individually control mine them using a dedicated button for each, but haven’t had problems so far. Perhaps I can try to group them and see if that results in the same error?

@marcelveldt
Copy link
Member

Correct, individual control works fine but things do sideways when you try to control multiple in one service call.
E.g. an automation with the target set to multiple entity_id's.

This used to work fine for months/years

@Didel
Copy link

Didel commented Jun 5, 2022

I did some initial testing yesterday (on HA 2022.6.1 and PyVLX 0.2.20) and was not able to reproduce the problem. I did not use an automation, but called the cover.open / close / set_position services both with multiple cover entities supplied and a single cover group entity (containing 2 covers), all worked as expected for all covers.

How is the above different from when you are experiencing problems?

@WhistleMaster
Copy link

Thanks for looking at the issue.

What I can tell is that I have groups between 4 and 15 covers, and I get the error when calling cover.open / close / set_position services. What is strange is that when callings those services, only 1 or 2 covers are responding and then I get the error in the log:

pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />

@Didel
Copy link

Didel commented Jun 5, 2022

@WhistleMaster I only have 3 covers in total, so if the problem is only occurring when controlling 4 or more covers, I’m afraid that I can’t be of much help in reproducing the issue 🙁

@WhistleMaster
Copy link

@Didel Sure, no problem ! Maybe we could provide some logs that could help ?

@drbiosignals
Copy link

drbiosignals commented Jun 5, 2022

I would like to thank you all for your efforts. I can also confirm and reproduce the problem with 4 covers. Using a script or automation and grouping the covers results in a partial respnse: only the first two covers respond. This issue is also new after upgrading to 2022.6

@Didel
Copy link

Didel commented Jun 5, 2022

@Didel Sure, no problem ! Maybe we could provide some logs that could help ?

If you add logging as in the original description (in configuration.yaml :

logger:
  default: warn
  logs:
    homeassistant.components.velux: debug
    pyvlx: debug

) , do you get the same or other errors?

@Bram1nat0r
Copy link

Bram1nat0r commented Jun 5, 2022

I have a group of 4 cover entities that I could open/close/set position in one service call. Now at most 2 out of 4 entities respond.

service: cover.set_cover_position
data:
  position: 50
target:
  entity_id:
    - cover.slaapkamer_rolluik_links
    - cover.slaapkamer_rolluik_rechts
    - cover.studeerkamer_rolluik
    - cover.washok_rolluik

I have included DEBUG output as requested in the previous post.

https://pastebin.com/8B0uWKDi

@marcelveldt
Copy link
Member

velux.zip

I've adjusted the PR to a global lock. Works for me but maybe someone wants to test this too.
Attached the changed files as zip, you can place the velux folder in custom_components

@pyrrolizin
Copy link
Author

pyrrolizin commented Jun 5, 2022

@marcelveldt Wow! Good work!

PR works. I can confirm with 7 covers: all opened without any issue. Thank you :)

@github-actions github-actions bot locked and limited conversation to collaborators Jul 6, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants