skodaconnect / homeassistant-skodaconnect

Skoda Connect - A home assistant plugin to add integration with your car
Apache License 2.0
233 stars 27 forks source link

KeyError in _async_setup_platform / async_setup_entry -> all values "unavailable" in HA dashboard #284

Closed nation-wide closed 6 months ago

nation-wide commented 6 months ago

Describe the bug All values report as "unavailable" in HA dashboard.

It seems that values are fetched correctly from VW API but some key error appears later.

**Is this working in MySkoda app?*** Yes

Latest working release No version changes to skodaconnect recently.

Debug logs

2024-05-08 09:00:06.582 DEBUG (MainThread) [custom_components.skodaconnect] Updating data from Skoda Connect 2024-05-08 09:00:06.582 DEBUG (MainThread) [skodaconnect.vehicle] Starting discovery for vehicle REDACTED 2024-05-08 09:00:06.582 DEBUG (MainThread) [skodaconnect.connection] No valid access token for "vwg" 2024-05-08 09:00:06.582 DEBUG (MainThread) [skodaconnect.connection] Refreshing tokens for client "vwg" 2024-05-08 09:00:06.791 DEBUG (MainThread) [skodaconnect.connection] Refresh tokens succeeded, revoking old refresh tokens 2024-05-08 09:00:06.848 DEBUG (MainThread) [skodaconnect.connection] Revocation of token for client "vwg" successful 2024-05-08 09:00:06.848 DEBUG (MainThread) [skodaconnect.connection] Tokens refreshed successfully for client "vwg" 2024-05-08 09:00:07.166 DEBUG (MainThread) [skodaconnect.connection] Request for "https://mal-1a.prd.ece.vwg-connect.com/api/cs/vds/v1/vehicles/*REDACTED*/homeRegion" returned with status code [200] 2024-05-08 09:00:07.166 DEBUG (MainThread) [skodaconnect.vehicle] Get homeregion for VIN REDACTED 2024-05-08 09:00:07.166 DEBUG (MainThread) [skodaconnect.connection] Attempting extraction of jwt subject from identity token. 2024-05-08 09:00:07.312 DEBUG (MainThread) [skodaconnect.connection] Request for "https://customer-profile.vwgroup.io/v2/customers/*REDACTED*/realCarData" returned with status code [200] 2024-05-08 09:00:07.312 DEBUG (MainThread) [skodaconnect.vehicle] Attempting discovery of supported API endpoints for vehicle. 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.connection] Request for "https://mal-3a.prd.eu.dp.vwg-connect.com/api/rolesrights/operationlist/v3/vehicles/*REDACTED" returned with status code [200] 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: rlu_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: trip_statistic_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: statusreport_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: rclima_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: timerprogramming_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: rbatterycharge_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: rhonk_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:07.890 DEBUG (MainThread) [skodaconnect.vehicle] Discovered active supported service: carfinder_v1, licensed until 2024-08-11 12:55:00 2024-05-08 09:00:08.318 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/cf/v1/skoda/CZ/vehicles/REDACTED/position" returned with status code [200] 2024-05-08 09:00:08.319 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/tripstatistics/v1/skoda/CZ/vehicles/REDACTED/tripdata/shortTerm?newest" returned with status co de [200] 2024-05-08 09:00:08.322 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/departuretimer/v1/skoda/CZ/vehicles/REDACTED/timer" returned with status code [200] 2024-05-08 09:00:08.338 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/batterycharge/v1/skoda/CZ/vehicles/REDACTED/charger" returned with status code [200] 2024-05-08 09:00:08.388 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/vsr/v1/skoda/CZ/vehicles/REDACTED/status" returned with status code [200] 2024-05-08 09:00:08.397 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/climatisation/v1/skoda/CZ/vehicles/REDACTED/climater" returned with status code [200] 2024-05-08 09:00:08.579 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/tripstatistics/v1/skoda/CZ/vehicles/REDACTED/tripdata/longTerm?newest" returned with status cod e [200] 2024-05-08 09:00:08.711 DEBUG (MainThread) [skodaconnect.connection] Request for "https://fal-3a.prd.eu.dp.vwg-connect.com/fs-car/bs/tripstatistics/v1/skoda/CZ/vehicles/REDACTED*/tripdata/cyclic?newest" returned with status code [200] 2024-05-08 09:00:08.712 DEBUG (MainThread) [custom_components.skodaconnect] Finished fetching skodaconnect data in 2.130 seconds (success: True) 2024-05-08 09:00:08.712 INFO (MainThread) [homeassistant.components.sensor] Setting up skodaconnect.sensor 2024-05-08 09:00:08.712 ERROR (MainThread) [homeassistant.components.sensor] Error while setting up skodaconnect platform for sensor Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform await asyncio.shield(awaitable) File "/config/custom_components/skodaconnect/sensor.py", line 22, in async_setup_entry data = hass.data[DOMAIN][entry.entry_id][DATA]


KeyError: '37ad9c5f6a08a212a610e8713e383f05'
2024-05-08 09:00:08.713 INFO (MainThread) [homeassistant.components.device_tracker] Setting up skodaconnect.device_tracker
2024-05-08 09:00:08.713 ERROR (MainThread) [homeassistant.components.device_tracker] Error while setting up skodaconnect platform for device_tracker
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/skodaconnect/device_tracker.py", line 18, in async_setup_entry
    data = hass.data[DOMAIN][entry.entry_id][DATA]
           ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '37ad9c5f6a08a212a610e8713e383f05'
2024-05-08 09:00:08.713 INFO (MainThread) [homeassistant.components.switch] Setting up skodaconnect.switch
2024-05-08 09:00:08.713 ERROR (MainThread) [homeassistant.components.switch] Error while setting up skodaconnect platform for switch
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/skodaconnect/switch.py", line 25, in async_setup_entry
    data = hass.data[DOMAIN][entry.entry_id][DATA]
           ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '37ad9c5f6a08a212a610e8713e383f05'
2024-05-08 09:00:08.713 INFO (MainThread) [homeassistant.components.lock] Setting up skodaconnect.lock
2024-05-08 09:00:08.714 ERROR (MainThread) [homeassistant.components.lock] Error while setting up skodaconnect platform for lock
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/skodaconnect/lock.py", line 23, in async_setup_entry
    data = hass.data[DOMAIN][entry.entry_id][DATA]
           ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '37ad9c5f6a08a212a610e8713e383f05'
2024-05-08 09:00:08.714 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up skodaconnect.binary_sensor
2024-05-08 09:00:08.714 ERROR (MainThread) [homeassistant.components.binary_sensor] Error while setting up skodaconnect platform for binary_sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/skodaconnect/binary_sensor.py", line 22, in async_setup_entry
    data = hass.data[DOMAIN][entry.entry_id][DATA]
           ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^
KeyError: '37ad9c5f6a08a212a610e8713e383f05'

**Installation:**
 - Home Assistant variant: v2024.5.2, Docker

**Additional context**
Not sure exactly when this first appeared but it has been in this state for few days. It could be related to recent update to HA 2024.5.2 but I am not 100% sure.
dvx76 commented 6 months ago

If you have 2 cars configured then this is resolved by https://github.com/skodaconnect/homeassistant-skodaconnect/pull/282 (and indeed introduced by one of the more recent HA updates)

nation-wide commented 6 months ago

If you have 2 cars configured then this is resolved by #282 (and indeed introduced by one of the more recent HA updates)

I only have 1 car configured.

dvx76 commented 6 months ago

Then you may want to try and remove the integration/device in HA and add it again. #206 had something similar. The source of the KeyError and where it's being looked up is explained in this comment in that issue.

nation-wide commented 6 months ago

I re-added the integration but same errors remain. Only difference seem to be the changed key. I checked that new key can be found in the core.config_entries but not in core.entity_registry.

Start of entry in core.config_entries

  {
    "entry_id": "45fa07167ec1b0db1f45bb81dd27a2ce",
    "version": 3,
    "minor_version": 1,
    "domain": "skodaconnect",
mvzut commented 6 months ago

I had the same, and it was solved by removing the plugin and installing it again. I did have to completely restart HA before the devices were re-added, strangely enough.

nation-wide commented 6 months ago

I had the same, and it was solved by removing the plugin and installing it again. I did have to completely restart HA before the devices were re-added, strangely enough.

Yep, got it working with same steps. Thanks!

zandzpider commented 6 months ago

This error also happens when you try to disable polling on the entity. Restart HA (all works fine) Disable polling -> results in error above

dvx76 commented 6 months ago

Closing as the original issue reported by @nation-wide is resolved.

@zandzpider , I can't seem to reproduce this issue by disabling polling. If you're still seeing issues please create a new issue and include debug logs from before you disable polling (and everything works) until the moment you get an error. Thanks.

nation-wide commented 6 months ago

I would like to add further information that the KeyError seem to appear if you modify the polling interval in the integration settings. I suspect this has been the original source for my error, alongside with the new HA version, because I have cron jobs to change interval for nights etc. in order to avoid VW API rate limit issues and thus did not immediately understand why the HA dashboard went broken.

I can also confirm that if you restart HA after polling interval change it fixes the dashboard, but I think it should not require that. Or at least it should notify the user if a restart is needed.

dvx76 commented 6 months ago

@nation-wide thanks. See https://github.com/skodaconnect/homeassistant-skodaconnect/issues/285#issuecomment-2115877787 . Should be fixed in new release 1.2.11