search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
74.11k stars 31.11k forks source link

lutron failing shortly after a restart #124953

Open mralanlee opened 3 months ago

mralanlee commented 3 months ago

The problem

Noticed that some triggers to execute a turn on/off for my Lutron Caseta switches suddenly stopped working. Upon a restart of home assistant OS, it will start working again. But also immediately, they will fail. 

Logger: pylutron_caseta.smartbridge
Source: runner.py:190
First occurred: 4:34:06 PM (12 occurrences)
Last logged: 4:42:42 PM

ping was not answered. closing connection.
Reconnecting after error: SSL shutdown timed out
Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/commands.py:241
integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 4:33:41 PM (12 occurrences)
Last logged: 4:37:40 PM

[140494361636304] Unexpected exception
[140494646143456] Unexpected exception
[140494355541744] Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 286, in _request
    response = await self._leap.request(
               ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/leap.py", line 75, in request
    return await future
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 241, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2763, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2806, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 999, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1071, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 626, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/lutron_caseta/light.py", line 174, in async_turn_on
    await self._async_set_brightness(brightness, color, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/lutron_caseta/light.py", line 134, in _async_set_brightness
    await self._smartbridge.set_value(
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 466, in set_value
    await self._request(
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 285, in _request
    async with asyncio_timeout(REQUEST_TIMEOUT):
  File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
Logger: asyncio
Source: components/lutron_caseta/light.py:134
First occurred: 4:37:35 PM (3 occurrences)
Last logged: 4:37:35 PM

SSL connection is closed

What version of Home Assistant Core has the issue?

2024.8.3

What was the last working version of Home Assistant Core?

2024.8.2

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Lutron Caseta

Link to integration documentation on our website

No response

Diagnostics information

config_entry-lutron_caseta-4fb6da5993fc14546fadbf8f6e7f52ae.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 3 months ago

Hey there @swails, @bdraco, @danaues, @eclair4151, mind taking a look at this issue as it has been labeled with an integration (lutron_caseta) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `lutron_caseta` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign lutron_caseta` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

lutron_caseta documentation lutron_caseta source (message by IssueLinks)

mralanlee commented 2 months ago

Additional logs... It seems like the request sometimes fails.

2024-09-17 16:35:12.724 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140193699511840] Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 286, in _request
    response = await self._leap.request(
               ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/leap.py", line 75, in request
    return await future
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2761, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 637, in async_handle_light_off_service
    await light.async_turn_off(**filter_turn_off_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/lutron_caseta/light.py", line 178, in async_turn_off
    await self._async_set_brightness(0, None, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/lutron_caseta/light.py", line 134, in _async_set_brightness
    await self._smartbridge.set_value(
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 466, in set_value
    await self._request(
  File "/usr/local/lib/python3.12/site-packages/pylutron_caseta/smartbridge.py", line 285, in _request
    async with asyncio_timeout(REQUEST_TIMEOUT):
  File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
mralanlee commented 2 months ago

It looks like the hub becomes unavailable. Some additional debug logging after the failure occurs:

2024-09-17 17:19:36.602 WARNING (MainThread) [pylutron_caseta.smartbridge] Reconnecting after error: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2685)
2024-09-17 17:19:38.604 DEBUG (MainThread) [pylutron_caseta.smartbridge] Connecting to Smart Bridge via SSL
2024-09-17 17:19:38.832 DEBUG (MainThread) [pylutron_caseta.smartbridge] Successfully connected to Smart Bridge.
2024-09-17 17:19:38.832 DEBUG (MainThread) [pylutron_caseta.smartbridge] Loading areas from the Smart Bridge
2024-09-17 17:19:38.832 DEBUG (MainThread) [pylutron_caseta.leap] sending b'{"CommuniqueType": "ReadRequest", "Header": {"ClientTag": "3b7204e7-4c3a-48f7-97df-640cf6474e4a", "Url": "/area"}}'
2024-09-17 17:19:38.837 DEBUG (MainThread) [pylutron_caseta.leap] Received message with no tag: {'CommuniqueType': 'SubscribeResponse', 'Header': {'StatusCode': '204 NoContent', 'Url': '/device/status/deviceheard'}}
2024-09-17 17:19:38.849 DEBUG (MainThread) [pylutron_caseta.leap] Received message with no tag: {'CommuniqueType': 'SubscribeResponse', 'Header': {'StatusCode': '204 NoContent', 'Url': '/zone/status/deprecated/level'}}
2024-09-17 17:19:38.862 DEBUG (MainThread) [pylutron_caseta.leap] received: {'CommuniqueType': 'ReadResponse', 'Header': {'MessageBodyType': 'MultipleAreaDefinition', 'StatusCode': '200 OK', 'Url': '/area'}, 'Body': {'Areas': [{'href': '/area/1', 'Name': 'root', 'LoadShedding': {'href': '/area/1/loadshedding'}, 'IsLeaf': False}, {'href': '/area/2', 'Name': 'Garage Entry', 'Parent': {'href': '/area/1'}, 'Category': {'Type': 'GarageEntry'}, 'AssociatedDevices': [{'href': '/device/2'}], 'AssociatedOccupancyGroups': [{'href': '/occupancygroup/1'}], 'LoadShedding': {'href': '/area/2/loadshedding'}, 'OccupancySettings': {'href': '/area/2/occupancysettings'}, 'OccupancySensorSettings': {'href': '/area/2/occupancysensorsettings'}, 'DaylightingGainSettings': {'href': '/area/2/daylightinggainsettings'}, 'IsLeaf': True}, {'href': '/area/3', 'Name': 'Living Room', 'Parent': {'href': '/area/1'}, 'Category': {'Type': 'LivingRoom'}, 'AssociatedDevices': [{'href': '/device/3'}], 'AssociatedOccupancyGroups': [{'href': '/occupancygroup/2'}], 'LoadShedding': {'href': '/area/3/loadshedding'}, 'OccupancySettings': {'href': '/area/3/occupancysettings'}, 'OccupancySensorSettings': {'href': '/area/3/occupancysensorsettings'}, 'DaylightingGainSettings': {'href': '/area/3/daylightinggainsettings'}, 'IsLeaf': True}]}}
2024-09-17 17:19:38.863 DEBUG (MainThread) [pylutron_caseta.leap] sending b'{"CommuniqueType": "ReadRequest", "Header": {"ClientTag": "208d1cc6-5ad2-4933-b031-6c83e93749f3", "Url": "/project"}}'
2024-09-17 17:19:38.870 DEBUG (MainThread) [pylutron_caseta.leap] received: {'CommuniqueType': 'ReadResponse', 'Header': {'MessageBodyType': 'OneProjectDefinition', 'StatusCode': '200 OK', 'Url': '/project'}, 'Body': {'Project': {'href': '/project', 'Name': 'Smart Bridge Project', 'ProductType': 'Lutron Smart Bridge Project', 'MasterDeviceList': {'Devices': [{'href': '/device/1'}]}, 'GUID': '04D0C3AFE00414FFB6CF2FDBA1523CBB34B29C44', 'TimeclockEventRules': {'href': '/project/timeclockeventrules'}, 'DeviceRules': {'href': '/project/devicerule/1'}}}}
2024-09-17 17:19:38.870 DEBUG (MainThread) [pylutron_caseta.smartbridge] Caseta bridge detected
2024-09-17 17:19:38.870 DEBUG (MainThread) [pylutron_caseta.smartbridge] Loading devices
2024-09-17 17:19:38.871 DEBUG (MainThread) [pylutron_caseta.leap] sending b'{"CommuniqueType": "ReadRequest", "Header": {"ClientTag": "96b9af3d-d702-4a09-8b01-3d8fe9d405bc", "Url": "/device"}}'