Issue with HomeAssistant 2023.8 and 2023.8.1

[fabir-git]

Hello, I get the following issues, when an automation or script with multiple shutters is running. There is no problem if I execute the service calls manually.

Perhaps this is a similar issue (exept for ZWAVE devices): https://github.com/home-assistant/core/issues/97854 HA seems to have a problem with the device response time there. Perhaps this is similar?

File "/usr/src/homeassistant/homeassistant/helpers/[script.py](http://script.py/)", line [468](tel:468), in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/[script.py](http://script.py/)", line [703](tel:703), in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/[script.py](http://script.py/)", line [665](tel:665), in _async_run_long_action return long_task.result() ^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/[core.py](http://core.py/)", line [1974](tel:1974), in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/[core.py](http://core.py/)", line [2011](tel:2011), in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/[entity_component.py](http://entity_component.py/)", line [235](tel:235), in handle_service return await service.entity_service_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/[service.py](http://service.py/)", line [870](tel:870), in entity_service_call response_data = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/[service.py](http://service.py/)", line [942](tel:942), in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/velux/[cover.py](http://cover.py/)", line [191](tel:191), in async_set_cover_position await self.node.set_position(position=position, wait_for_completion=False) File "/usr/local/lib/python[3.11](tel:311)/site-packages/pyvlx/[opening_device.py](http://opening_device.py/)", line [70](tel:70), in set_position raise PyVLXException("Unable to send command") pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />

[DarkWarden85]

Hi, I noticed the same issue in my installation. It seems to happen when multiple Velux covers are called at the same time. I'm also on Home Assistant 2023.8.1

[fabir-git]

I also fixed the problem temporarily. When I call the shutters one by one the script works. If I do it in parallel the error occurs.

[dumpfheimer]

Do you have any other errors concerning pyvlx/velux in your logs?

[crivchri]

Hi, I have also the exact same issue since the update to the current version 2023.8.2.

[fabir-git]

Do you have any other errors concerning pyvlx/velux in your logs?

No, there is no other error showing up.

Here is the whole error message (I edited some parts out):

`Dieser Fehler wurde von einer benutzerdefinierten Integration verursacht

Logger: homeassistant.core Source: custom_components/velux/cover.py:181 Integration: Velux First occurred: 15. August 2023 um 15:54:15 (4 occurrences) Last logged: 15. August 2023 um 15:54:16

Error executing service: <ServiceCall cover.open_cover (c:random string was edited for the posting): entity_id=['entity_id was edited for the posting']> Error executing service: <ServiceCall cover.open_cover (c:random string was edited for the posting): entity_id=['entity_id was edited for the posting']> Error executing service: <ServiceCall cover.open_cover (c:random string was edited for the posting): entity_id=['entity_id was edited for the posting']> Error executing service: <ServiceCall cover.open_cover (c:random string was edited for the posting): entity_id=['entity_id was edited for the posting']> Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/core.py", line 1990, in _run_service_call_catch_exceptions await coro_or_task File "/usr/src/homeassistant/homeassistant/core.py", line 2011, in _execute_service return await target(service_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service return await service.entity_service_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call response_data = await _handle_entity_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/velux/cover.py", line 181, in async_open_cover await self.node.open(wait_for_completion=False) File "/usr/local/lib/python3.11/site-packages/pyvlx/opening_device.py", line 82, in open await self.set_position( File "/usr/local/lib/python3.11/site-packages/pyvlx/opening_device.py", line 70, in set_position raise PyVLXException("Unable to send command") pyvlx.exception.PyVLXException: `

[pawlizio]

seems to be similar to issue #28 , please also activate the debugging of pyvlx and velux custom component and share the logs.

[pawlizio]

Please can you update to latest custom component version and restart HA. Hope this is fixed now.

[fabir-git]

Please can you update to latest custom component version and restart HA. Hope this is fixed now.

Thank you very much for your work.The fix works for me

[fabir-git]

Issue is fixed with version 2.9.3

[crivchri]

Hi,

I still have similar issues with Home Assistant 2023.8.4 (Core), updated to the latest versions from the UI, when opening several covers at the same time. However I do not know how to check which version of Velux component I have.

Also reported in: https://github.com/pawlizio/my_velux/issues/28#issuecomment-1697833372

I get following error several times:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/velux/cover.py:106 
Integration: Home Assistant WebSocket API (documentation, issues) 
First occurred: 18:50:51 (6 occurrences) 
Last logged: 18:51:41

[139751897971008] <PyVLXException description="Unable to send command" />
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 226, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1974, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2011, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/scene/__init__.py", line 114, in _async_activate
    await self.async_activate(**kwargs)
  File "/usr/src/homeassistant/homeassistant/components/homeassistant/scene.py", line 334, in async_activate
    await async_reproduce_state(
  File "/usr/src/homeassistant/homeassistant/helpers/state.py", line 67, in async_reproduce_state
    await asyncio.gather(
  File "/usr/src/homeassistant/homeassistant/helpers/state.py", line 61, in worker
    await platform.async_reproduce_states(
  File "/usr/src/homeassistant/homeassistant/components/cover/reproduce_state.py", line 125, in async_reproduce_states
    await asyncio.gather(
  File "/usr/src/homeassistant/homeassistant/components/cover/reproduce_state.py", line 86, in _async_reproduce_state
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1974, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2011, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/velux/cover.py", line 106, in async_set_cover_position
    await self.node.set_position(
  File "/usr/local/lib/python3.11/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" />

Thank you in advance for your help and kind regards.

[DarkWarden85]

Hi, I also still have the same issue.

[pawlizio]

Can someone post a full log for pyvlx and velux custom component, not just the error.

[crivchri]

Can someone post a full log for pyvlx and velux custom component, not just the error.

Hi @pawlizio,

Enclosed the full log for pyvlx and velux custom component. home-assistant.log

Thank you in advance and kind regards.

[pawlizio]

In which use case does this error appear? Can you share the automation / script which you're using. So far it is not clear from the log what is going on.

[crivchri]

In which use case does this error appear? Can you share the automation / script which you're using. So far it is not clear from the log what is going on.

Hi,

I have following scene, called from an automation:

- id: '###########'
  name: Fenêtres Velux 50%
  entities:
    cover.fenetrebalneobas:
      current_position: 50
      device_class: window
      friendly_name: FenetreBalneoBas
      supported_features: 15
      state: open
    cover.fenetrebalneohaut:
      current_position: 100
      device_class: window
      friendly_name: FenetreBalneoHaut
      supported_features: 15
      state: open
    cover.fenetrebalneomilieu:
      current_position: 50
      device_class: window
      friendly_name: FenetreBalneoMilieu
      supported_features: 15
      state: open
    cover.fenetrebureaubas:
      current_position: 50
      device_class: window
      friendly_name: FenetreBureauBas
      supported_features: 15
      state: open
    cover.fenetrebureauhaut:
      current_position: 100
      device_class: window
      friendly_name: FenetreBureauHaut
      supported_features: 15
      state: open
    cover.fenetretv:
      current_position: 50
      device_class: window
      friendly_name: FenetreTV
      supported_features: 15
      state: open
  metadata:
    cover.fenetrebalneobas:
      entity_only: true
    cover.fenetrebalneohaut:
      entity_only: true
    cover.fenetrebalneomilieu:
      entity_only: true
    cover.fenetrebureaubas:
      entity_only: true
    cover.fenetrebureauhaut:
      entity_only: true
    cover.fenetretv:
      entity_only: true

Thank you in advance.

[pawlizio]

Actually I never used scenes with my covers, but has this ever worked? I don't know how HA is submitting commands for scenes to their components.

[pawlizio]

Have you ever modified the scene in your yaml files? If I save the scene via UI, I can call it, but after modification in yaml I have similar problems.

[pawlizio]

Can you create a second scene and test if those is working. Actually I observed similiar problems, but it is difficult to reproduce. With a new scene it is running now.

[fabir-git]

Sadly I have to admit that the problem is back for me. I had set my script to run in "queued" mode (so the shutters were called individually). When I switch the script back to "parallel" the error is back. Do you need special information from me in order to pinpoint the issue?

[dumpfheimer]

@crivchri

are you sure you are using the latest code?

In your log in the stack trace it says pyvlx/opening_device.py line 49 should be throwing an exception, which is a comment in the master branch: https://github.com/pawlizio/pyvlx/blob/2849d3361dfd435ed3ba91cb666bd36d236c470e/pyvlx/opening_device.py#L49C1-L50C1

[dumpfheimer]

Looks to me like your pyvlx version is quite old, this looks like the latest possible code you are running: https://github.com/pawlizio/pyvlx/blob/68571c13ed87010a3c43a0b14a0fa21b591ea52b/pyvlx/opening_device.py

[crivchri]

@crivchri

are you sure you are using the latest code?

In your log in the stack trace it says pyvlx/opening_device.py line 49 should be throwing an exception, which is a comment in the master branch:

https://github.com/pawlizio/pyvlx/blob/2849d3361dfd435ed3ba91cb666bd36d236c470e/pyvlx/opening_device.py#L49C1-L50C1

Hi @dumpfheimer,

Since I am using Home Assistant, the my_velux/pyvlx code is integrated. I am running the latest version of Home Assistant 2023.9.1, but I not know which version of my_velux or of pyvlx in integrated.

Any hint on how to check which version of my_velux or of pyvlx I have in HA?

[crivchri]

Can you create a second scene and test if those is working. Actually I observed similiar problems, but it is difficult to reproduce. With a new scene it is running now.

Hi @pawlizio,

I have abandoned using scenes, as it seems to be buggy, using scripts or automations, even with parallel calls, is working fine.

I do not know what is different with scenes...

[dumpfheimer]

I took another look at the logs.

Actually it seems like pyvlx is doing everything sensibly.

Multiple requests are seemingly correctly sent to the gateway ( I will omit all but session 29 and 31):

2023-09-01 08:07:39.579 DEBUG (MainThread) [pyvlx] SEND: <FrameCommandSendRequest node_ids="[6]" parameter="100 %" functional_parameter="fp1: 0 %, fp2: 0 %, fp3: 0 %, fp4: 0 %, fp5: 0 %, fp6: 0 %, fp7: 0 %, fp8: 0 %, fp9: 0 %, fp10: 0 %, fp11: 0 %, fp12: 0 %, fp13: 0 %, fp14: 0 %, fp15: 0 %, fp16: 0 %, " session_id="29" originator="Originator.USER"/>
2023-09-01 08:07:39.583 DEBUG (MainThread) [pyvlx] SEND: <FrameCommandSendRequest node_ids="[7]" parameter="100 %" functional_parameter="fp1: 0 %, fp2: 0 %, fp3: 0 %, fp4: 0 %, fp5: 0 %, fp6: 0 %, fp7: 0 %, fp8: 0 %, fp9: 0 %, fp10: 0 %, fp11: 0 %, fp12: 0 %, fp13: 0 %, fp14: 0 %, fp15: 0 %, fp16: 0 %, " session_id="31" originator="Originator.USER"/>

And the gateway then sends an "accept" for request 29 and 30, but not the other requests:

2023-09-01 08:07:39.628 DEBUG (MainThread) [pyvlx] REC: <FrameCommandSendConfirmation session_id="29" status="CommandSendConfirmationStatus.ACCEPTED"/>

Which then results in a timeout 30 seconds later.

I would exepect the gateway to either accept or reject the request. Doing nothing seems... sub-optimal. The question is if pyvlx should try to work around this issue (or if this is actually a documented limitation of the gateway; eg only one or two concurrent session at the same time; possibly a memory constraint on the gateway). Will try to look into that.

[roschnei]

Hi,

I switched from the home assistant integration to this custom integration, in the hopes that the problem would be solved here. But I am getting the same error as fabir-git. I have scenes with 4 Velux covers and windows, in fully open or fully closed state. When I run the scene (even outside of an automation) for instance to open the 4 covers, only 3 of them open at the same time, and the fourth stays closed, with the message above. The only difference with the HomeAssistant integration is that there 2 covers remain closed whereas here only 1 remains closed. The scenes used to work like a charm until a recent Home Assistant upgrade, which must have changed something to do with sending parallel commands to several entities. Please let me know if I can provide anything to help identify the problem.

[roschnei]

Update: I just reverted back to HomeAssistant 2023.7.3 and my scenes work again like before.

[rjlee]

Similar issues to @roschnei. Worked fine on 2023.7 with the HA velux integration, experienced issues with 2023.8+, so migrated to this and still seeing the same issues. I call my covers from a script:

script:
  main_bedroom_blind_open:
    alias: Main bedroom Blinds Open
    mode: single
    icon: mdi:window-shutter
    sequence:
      - service: cover.open_cover
        target:
          entity_id:
            - cover.main_bedroom_1
      - delay: 2
      - service: cover.open_cover
        target:
          entity_id:
            - cover.main_bedroom_2

I also experience intermittent failures from a script that controls one cover:

script:
  bedroom1_blind_open:
    alias: Bedroom 1 Blinds Open
    mode: single
    icon: mdi:window-shutter
    sequence:
      - service: cover.open_cover
        target:
          entity_id: cover.bedroom_1

Sample error from logs:

Main bedroom Blinds Close: Error executing script. Unexpected error for call_service at pos 1: <PyVLXException description="Unable to send command" />
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 704, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 1969, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2006, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/config/custom_components/velux/cover.py", line 226, in async_close_cover
    await self.node.close(**close_args)
  File "/usr/local/lib/python3.11/site-packages/pyvlx/opening_device.py", line 104, in close
    await self.set_position(
  File "/usr/local/lib/python3.11/site-packages/pyvlx/opening_device.py", line 77, in set_position
    raise PyVLXException("Unable to send command")
pyvlx.exception.PyVLXException: <PyVLXException description="Unable to send command" />

Currently on:

Home Assistant 2023.9.2
Supervisor 2023.09.2
Operating System 10.5
Frontend 20230911.0 - latest

My Velux: 2.9.3

[rjlee]

Related issue on the HA velux integration: https://github.com/home-assistant/core/issues/98168#issuecomment-1722253939

[rjlee]

For those who are waiting for a fix on this, I've updated my scripts to randomize the exact timing when the commands execute (between 0-30 seconds) and everything has worked fine this evening for my automations:

script:
  bedroom2_blind_open:
    alias: Bedroom 2 Blinds Open
    mode: single
    icon: mdi:window-shutter
    sequence:
      - delay: 
          seconds: '{{ range(0, 31) | random }}'
      - service: cover.open_cover
        target:
          entity_id: cover.bedroom_2

[rjlee]

I've been testing a mitigation for this, which I've made a pull request for: https://github.com/pawlizio/my_velux/pull/34

It introduces the backoff package which is an asyncio compatible backoff request library, which basically allows failed requests to the gateway to be retried. It seems to have addressed the issues in my HA install. It's only implemented for covers as I only have those, but would be simple to extend to other entity types.

[pawlizio]

I've fixed this issue on pyvlx side, at least at my setup it is now working. I was able to reproduce the issue and basically can confirm what @dumpfheimer wrote above. In scenes HA sends very fast commands to each device, however the KLF200 just recognize the first 2 commands and the other commands goes lost. So KLF200 changed only two covers when a scene is activated. For the other pyvlx just recognized that the KLF200 did not respond on the request and fired an exeption. @rjlee, I saw your pull request, but I found a way to manage this in another way then waiting for timeouts retries.

I added a Semaphore for all commands, so that pyvlx does not send more than 2 requests in parallel, after the first one was acknowledged by KLF200, the next command is send and so on. At least I tested this at it was working.

To have this fix applied it is only necessary to reboot HA. After reboot pyvlx should load in version 0.1.69 or higher, which contains the updates. When debugging is on for pyvlx this can be check during log entry at startup.

PYVLXLOG.debug("Loading https://github.com/pawlizio/pyvlx.git@handle_timeout 0.1.69")

A short feedback if it's working is much appreciated.

[rjlee]

I've just set my_velux back to default and rebooted HAOS and it's not put that logline out.

I've got logging enabled:

logger:
#  default: warning
  default: info
  logs:
    custom_components.overkiz: debug
    pyvlx: debug
    custom_components.velux: debug

Maybe someone else can test to see if it pulls through though.

[pawlizio]

What are your first pyvlx debug messages after startup of HA? It's enough to restart HA, not necessary to reboot the Host.

[pawlizio]

Nevertheless, did you try to change something using scenes and have you still any issues?

[rjlee]

It typically only happens with my automations (morning and evening), so I'll see how it performs over the next couple of days.

[pawlizio]

OK, but you can trigger your automations at any time... Actually as wrote above, I was able to reproduce the "Unable to send command" exception. It was simply necessary to have more than 2 devices in a scene and ensure that all devices are not in the targen position, when triggering the scene. This caused always the "Unable to send command" exception.

[rjlee]

I've tried triggering it manually with limited success before TBH, it's generally reliably triggered when all my covers (x5) are triggered by sunset/sunrise automations across the various rooms in the house.

[fabir-git]

I've fixed this issue on pyvlx side, at least at my setup it is now working. I was able to reproduce the issue and basically can confirm what @dumpfheimer wrote above. In scenes HA sends very fast commands to each device, however the KLF200 just recognize the first 2 commands and the other commands goes lost. So KLF200 changed only two covers when a scene is activated. For the other pyvlx just recognized that the KLF200 did not respond on the request and fired an exeption. @rjlee, I saw your pull request, but I found a way to manage this in another way then waiting for timeouts retries.

I added a Semaphore for all commands, so that pyvlx does not send more than 2 requests in parallel, after the first one was acknowledged by KLF200, the next command is send and so on. At least I tested this at it was working.

To have this fix applied it is only necessary to reboot HA. After reboot pyvlx should load in version 0.1.69 or higher, which contains the updates. When debugging is on for pyvlx this can be check during log entry at startup.

PYVLXLOG.debug("Loading https://github.com/pawlizio/pyvlx.git@handle_timeout 0.1.69")

A short feedback if it's working is much appreciated.

Works for me, tested it over two days. I also had the line in my logs (with version 0.1.70).

Thanks very much for your help.

I'll close the issue if the others report the same.

[rjlee]

Seems to be working for me, I had an issue with my Velux gateway not responding which I think was separate to this, but certainly this evening everything seems to have worked correctly. No logline for me, which is odd but nonetheless things seemed to work fine this evening.

[spitfire]

Also had this problem, but not after I switched to @pawlizio's integration/library. @fabir-git why did you close it if it's still a problem in the integration included with core? Since I can see its maintainer has not been active in his project nor here, it feels like @pawlizio's integration (which has more features, configuration via UI and is more reliable) should replace it in core.