Velux component in Home Assistant does not set-up due to timeout.

[madzrobz]

Since I have upgraded to Home Assistant release 116 (I have skipped 115) my Velux component will simply not set-up. To me it seems like the SSL timeout was reduced from 30s to 5s and during HA start this interval is too short.

2020-10-08 23:09:21 INFO (MainThread) [homeassistant.setup] Setting up velux
2020-10-08 23:09:21 WARNING (MainThread) [pyvlx] Connecting to KLF 200.
2020-10-08 23:09:31 ERROR (MainThread) [homeassistant.setup] Error during setup of component velux
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/setup.py", line 213, in _async_setup_component
    result = await task
  File "/usr/src/homeassistant/homeassistant/components/velux/__init__.py", line 31, in async_setup
    await hass.data[DATA_VELUX].async_start()
  File "/usr/src/homeassistant/homeassistant/components/velux/__init__.py", line 69, in async_start
    await self.pyvlx.load_scenes()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/pyvlx.py", line 96, in load_scenes
    await self.scenes.load()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/scenes.py", line 51, in load
    await get_scene_list.do_api_call()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/api_event.py", line 21, in do_api_call
    await self.send_frame()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/api_event.py", line 33, in send_frame
    await self.pyvlx.send_frame(self.request_frame())
  File "/usr/local/lib/python3.8/site-packages/pyvlx/pyvlx.py", line 82, in send_frame
    await self.connect()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/pyvlx.py", line 46, in connect
    await self.connection.connect()
  File "/usr/local/lib/python3.8/site-packages/pyvlx/connection.py", line 86, in connect
    self.transport, _ = await self.loop.create_connection(
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1050, in create_connection
    transport, protocol = await self._create_connection_transport(
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1080, in _create_connection_transport
    await waiter
ConnectionAbortedError: SSL handshake is taking longer than 5 seconds: aborting the connection

Less than a minute later, the KLF200 connection is established again - this time succesfully. Subsequently KLF200 sends updates to HA which also are properly logged --> the connection is alive. However as the set-up of the component failed, the devices are invisible to HA and can't be controlled.

2020-10-08 23:10:21 WARNING (MainThread) [pyvlx] Connecting to KLF 200.
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] SEND: <FramePasswordEnterRequest password=ve****/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] REC: <FramePasswordEnterConfirmation status='PasswordEnterConfirmationStatus.SUCCESSFUL'/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] SEND: <FrameGetVersionRequest/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] REC: <FrameGetVersionConfirmation software_version="0.2.0.0.71.0" harware_version="5" product="KLF 200"/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] SEND: <FrameGetProtocolVersionRequest/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] REC: <FrameGetProtocolVersionConfirmation version="3.14"/>
2020-10-08 23:10:26 WARNING (MainThread) [pyvlx] Connected to: KLF 200: Software version: 0.2.0.0.71.0, hardware version: 5, protocol version: 3.14
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] SEND: <FrameSetUTCRequest time="2020-10-08 23:10:26"/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] REC: <FrameSetUTCConfirmation/>
2020-10-08 23:10:26 DEBUG (MainThread) [pyvlx] SEND: <FrameHouseStatusMonitorEnableRequest/>
2020-10-08 23:10:29 DEBUG (MainThread) [pyvlx] REC: <FrameHouseStatusMonitorEnableConfirmation/>
2020-10-08 23:10:29 DEBUG (MainThread) [pyvlx] SEND: <FrameGetStateRequest/>
2020-10-08 23:10:29 DEBUG (MainThread) [pyvlx] REC: <FrameGetStateConfirmation gateway_state="GatewayState.GATEWAY_MODE_WITH_ACTUATORS" gateway_sub_state="GatewaySubState.IDLE"/>
2020-10-08 23:11:29 DEBUG (MainThread) [pyvlx] SEND: <FrameGetStateRequest/>
2020-10-08 23:11:29 DEBUG (MainThread) [pyvlx] REC: <FrameGetStateConfirmation gateway_state="GatewayState.GATEWAY_MODE_WITH_ACTUATORS" gateway_sub_state="GatewaySubState.IDLE"/>
...

[Julius2342]

Hi @madzrobz !

yes, the problem is, that the lib cant connect to HASS at all - bc the KLF refuses to accept connections. This problem would persist independently of the set timeout.

The devices are only initialized on startup - i have no idea if it is possible to add devices asynchronously. May I ask you to connect to the HASS team and ask how we should change the integration.

Best

Julius

[madzrobz]

Hi @Julius2342 ,

thank you for the quick reply.

As you can see in the log, less than one minute later, the connection gets established - so the KLF itself (which I reboot before each restart of HA) accepts the connection. Thus I somehow don’t understand your reply - but this can easily be due to my lack of knowledge- sorry for that.

Best
Robert

[Julius2342]

the problem is, we should not wait till the KLF has self-repaired. (bc it is not predictable how long this will take).

(we could try to set the timeout to less then a second and immediately retry? But im not sure if this is an elegant approach.

[madzrobz]

Hi @Julius2342,

I checked the content of the file /usr/local/lib/python3.8/site-packages/pyvlx/connection.py on my Home Assistant machine and found the following code:

    async def connect(self):
        """Connect to gateway via SSL."""
        tcp_client = TCPTransport(self.frame_received_cb, self.connection_closed_cb)
        self.transport, _ = await self.loop.create_connection(
            lambda: tcp_client,
            host=self.config.host,
            port=self.config.port,
            ssl=self.create_ssl_context(),
            ssl_handshake_timeout=5,
        )

Strangely, connection.py in your Git repository and part of the 0.2.17 release code looks as follows:

    async def connect(self):
        """Connect to gateway via SSL."""
        tcp_client = TCPTransport(self.frame_received_cb, self.connection_closed_cb)
        self.transport, _ = await self.loop.create_connection(
            lambda: tcp_client,
            host=self.config.host,
            port=self.config.port,
            ssl=self.create_ssl_context(),
        )

I don't understand, how the parameter ssl_handshake_timeout=5 came into my local file. I have changed the value of the timeout to 60 which has solved the problem for me.

the problem is, we should not wait till the KLF has self-repaired. (bc it is not predictable how long this will take).
(we could try to set the timeout to less then a second and immediately retry? But im not sure if this is an elegant approach.

I would prefer to wait as long as it takes during startup for the component to be set-up properly as I only restart the server during version updates - especially with the latest features which allow almost everything to be reloaded without a restart. Maybe the ssl_handshake_timeout and a repeat_counter during start-up could be exposed as parameters so everybody can configure the start-up behavior as preferred.

Best
Robert

[sbyx]

@madzrobz seems there was an issue in the pip release of 0.2.17 since I was seeing the same thing. Julius released 0.2.18 and I just got the bump in Home Assistant approved: home-assistant/core#42895 so hope we have this out of the way.