robinostlund/homeassistant-volkswagencarnet

[BUG] KeyError: 'value'

StefanoGiu opened this issue · 16 comments

Before you post a new issue - you must first check the following (and check the boxes with an "X" below)

  • 1.) Can you login using the smartphone app Volkswagen/Volkswagen Connect and interact with your car?
  • 2.) Please make sure that you can login into https://vwid.vwgroup.io/ and make sure that any "Terms and Conditions" are all checked
  • 3.) I do not have MFA enabled.

Environment

  • Volkswagencarnet release with the issue: 4.6.0
  • Last working homeassistant-volkswagencarnet release (if known):
  • Home Assistant Core release with the issue: 2024.4.0
  • Operating environment (Home Assistant OS/Supervised/Container/Core/venv): Core
  • Car model and year: Golf 1,4 StyleP 110 TSID6F (2022)
  • Country where the car was bought: Italy
  • Valid VW Connect subscription: Y
  • Have you verified that the We Connect service works via VW´s portal?: Y

Describe the bug

Found this error in the log 5/6 times per hour, constantly. The integration seems to work

Steps to Reproduce

Let the integration run for a while

Expected behavior

No error in the log, or proper try/except handling.

Screenshots

Traceback/Error logs


2024-04-10 22:14:07.702 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "ZZZ\Python312\Lib\site-packages\homeassistant\helpers\update_coordinator.py", line 258, in _handle_refresh_interval
    await self._async_refresh(log_failures=True, scheduled=True)
  File "ZZZ\Python312\Lib\site-packages\homeassistant\helpers\update_coordinator.py", line 414, in _async_refresh
    self.async_update_listeners()
  File "ZZZ\Python312\Lib\site-packages\homeassistant\helpers\update_coordinator.py", line 168, in async_update_listeners
    update_callback()
  File "XXX\.homeassistant\custom_components\volkswagencarnet\__init__.py", line 288, in async_write_ha_state
    backend_refresh_time = self.instrument.last_refresh
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_dashboard.py", line 110, in last_refresh
    if hasattr(self.vehicle, self.attr + "_last_updated"):
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_vehicle.py", line 1789, in window_heater_last_updated
    return self.window_heater_front_last_updated
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_vehicle.py", line 1752, in window_heater_front_last_updated
    return find_path(self.attrs, f"{Services.CLIMATISATION}.windowHeatingStatus.value.carCapturedTimestamp")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_utilities.py", line 72, in find_path
    return find_path(src[path[0]], path[1:])
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_utilities.py", line 72, in find_path
    return find_path(src[path[0]], path[1:])
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "XXX\.homeassistant\deps\Python312\site-packages\volkswagencarnet\vw_utilities.py", line 72, in find_path
    return find_path(src[path[0]], path[1:])
                     ~~~^^^^^^^^^
KeyError: 'value'


Debug information - all JSON responses from logfile

Additional context

Note

Issues lacking sufficient details or context may be subject to closure without prior notice. Detailed bug reports are essential for effective issue resolution. Thank you for your cooperation.

Hi @StefanoGiu,

Please enable the debug logging and share the logs.
The explanation on how to do it is present here: https://github.com/robinostlund/homeassistant-volkswagencarnet/wiki/Enabling-Debug-Logging-in-Home-Assistant

Done and restarted HA... shall I wait for the error to come up again? Which lines do you need?

I need a response from the selectivestatus.
It should look something like this:
DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/Wredfacted5/selectivestatus?jobs=access,batteryChargingCare,batterySupport,charging,climatisation,climatisationTimers,departureProfiles,departureTimers,fuelStatus,measurements,vehicleLights,vehicleHealthInspection,userCapabilities" returned with status code [207], headers: .....

I need a full response with headers: and response:.

I have those lines after:
2024-04-11 12:27:33.445 DEBUG (MainThread) [volkswagencarnet.vw_connection] Did not receive return data for requested service batteryChargingCare. (This is expected for several service/car combinations)
2024-04-11 12:27:33.445 DEBUG (MainThread) [volkswagencarnet.vw_connection] Did not receive return data for requested service batterySupport. (This is expected for several service/car combinations)
2024-04-11 12:27:33.445 DEBUG (MainThread) [volkswagencarnet.vw_connection] Did not receive return data for requested service climatisationTimers. (This is expected for several service/car combinations)
2024-04-11 12:27:33.445 DEBUG (MainThread) [volkswagencarnet.vw_connection] Did not receive return data for requested service departureProfiles. (This is expected for several service/car combinations)
2024-04-11 12:27:33.445 DEBUG (MainThread) [volkswagencarnet.vw_connection] Getting API status updates
2024-04-11 12:27:33.445 DEBUG (MainThread) [custom_components.volkswagencarnet] Updating data from volkswagen WeConnect

There is no header or response

image

Make sure you have this flag turned on.

after enabling you have to restart

2024-04-11 12:46:02.845 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/XXXX/selectivestatus?jobs=access,batteryChargingCare,batterySupport,charging,climatisation,climatisationTimers,departureProfiles,departureTimers,fuelStatus,measurements,vehicleLights,vehicleHealthInspection,userCapabilities" returned with status code [207], headers: <CIMultiDictProxy('Date': 'Thu, 11 Apr 2024 10:46:03 GMT', 'Content-Type': 'application/json; charset=UTF-8', 'Content-Length': '1570', 'Connection': 'keep-alive', 'Bff-Trace-Id': 'XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXX', 'Content-Encoding': 'gzip', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'access': {'accessStatus': {'value': {'overallStatus': 'unsafe', 'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 39, tzinfo=datetime.timezone.utc), 'doors': [{'name': 'bonnet', 'status': ['closed']}, {'name': 'frontLeft', 'status': ['unlocked', 'closed']}, {'name': 'frontRight', 'status': ['unlocked', 'closed']}, {'name': 'rearLeft', 'status': ['unlocked', 'closed']}, {'name': 'rearRight', 'status': ['unlocked', 'closed']}, {'name': 'trunk', 'status': ['unlocked', 'closed']}], 'windows': [{'name': 'frontLeft', 'status': ['closed']}, {'name': 'frontRight', 'status': ['closed']}, {'name': 'rearLeft', 'status': ['closed']}, {'name': 'rearRight', 'status': ['closed']}, {'name': 'roofCover', 'status': ['unsupported']}, {'name': 'sunRoof', 'status': ['unsupported']}], 'doorLockStatus': 'unlocked'}}}, 'userCapabilities': {'capabilitiesStatus': {'value': [{'id': 'access', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'automation', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'charging', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'climatisation', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'cubicNetwork', 'userDisablingAllowed': False}, {'id': 'cubicNetworkConsumption', 'userDisablingAllowed': False}, {'id': 'dealerAppointment', 'status': [1003, 1004], 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': True}, {'id': 'departureTimers', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'emergencyCalling', 'expirationDate': datetime.datetime(2032, 5, 6, 7, 48, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'fuelStatus', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'honkAndFlash', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'measurements', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'oilLevelStatus', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'parkingPosition', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'personalizationOnline', 'userDisablingAllowed': False}, {'id': 'roadsideAssistant', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'state', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'transactionHistoryHonkFlash', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'transactionHistoryLockUnlock', 'expirationDate': datetime.datetime(2025, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'tripStatistics', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleHealth', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleHealthInspection', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleHealthWakeUp', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleHealthWarnings', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleLights', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleWakeUp', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}, {'id': 'vehicleWakeUpTrigger', 'expirationDate': datetime.datetime(2052, 5, 20, 10, 33, tzinfo=datetime.timezone.utc), 'userDisablingAllowed': False}]}}, 'charging': {'batteryStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'currentSOC_pct': 70, 'cruisingRangeElectric_km': 35}}, 'chargingStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'remainingChargingTimeToComplete_min': 85, 'chargingState': 'charging', 'chargeMode': 'manual', 'chargeType': ''}}, 'chargingSettings': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 9, tzinfo=datetime.timezone.utc), 'maxChargeCurrentAC': 'maximum'}}, 'plugStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'plugConnectionState': 'connected', 'plugLockState': 'locked', 'externalPower': 'ready', 'ledColor': 'none'}}, 'chargeMode': {'error': {'message': 'Bad Gateway', 'errorTimeStamp': datetime.datetime(2024, 4, 11, 10, 45, 59, tzinfo=datetime.timezone.utc), 'info': 'Upstream service responded with an unexpected status. If the problem persists, please contact our support.', 'code': 4111, 'group': 2, 'retry': True}}}, 'climatisation': {'climatisationSettings': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 7, 21, 50, 19, tzinfo=datetime.timezone.utc), 'targetTemperature_C': 15.5, 'targetTemperature_F': 59, 'climatisationWithoutExternalPower': True}}, 'climatisationStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 2, tzinfo=datetime.timezone.utc), 'climatisationState': 'off'}}, 'windowHeatingStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 2, tzinfo=datetime.timezone.utc), 'windowHeatingStatus': [{'windowLocation': 'front', 'windowHeatingState': 'off'}, {'windowLocation': 'rear', 'windowHeatingState': 'off'}]}}}, 'departureTimers': {'departureTimersStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2023, 2, 1, 1, 27, 46, tzinfo=datetime.timezone.utc), 'heaterSource': 'electric', 'minSOC_pct': 40, 'timers': [{'id': 1, 'enabled': False, 'charging': True, 'climatisation': False, 'preferredChargingTimes': [{'id': 1, 'enabled': True, 'startTimeLocal': '11:00', 'endTimeLocal': '16:00'}], 'singleTimer': {'departureDateTimeLocal': '2022-08-17T11:00:00', 'targetDateTimeLocal': '2022-08-17T11:00:00'}}, {'id': 2, 'enabled': False, 'charging': True, 'climatisation': False, 'preferredChargingTimes': [{'id': 1, 'enabled': True, 'startTimeLocal': '00:00', 'endTimeLocal': '00:00'}], 'recurringTimer': {'departureTimeLocal': '12:00', 'targetTimeLocal': '12:00', 'repetitionDays': ['monday', 'tuesday', 'wednesday', 'thursday', 'friday', 'saturday', 'sunday'], 'recurringOn': {'mondays': True, 'tuesdays': True, 'wednesdays': True, 'thursdays': True, 'fridays': True, 'saturdays': True, 'sundays': True}}}, {'id': 3, 'enabled': False, 'charging': True, 'climatisation': False, 'preferredChargingTimes': [{'id': 1, 'enabled': True, 'startTimeLocal': '00:00', 'endTimeLocal': '00:00'}], 'recurringTimer': {'departureTimeLocal': '12:00', 'targetTimeLocal': '12:00', 'repetitionDays': ['monday', 'tuesday', 'wednesday', 'thursday', 'friday', 'saturday', 'sunday'], 'recurringOn': {'mondays': True, 'tuesdays': True, 'wednesdays': True, 'thursdays': True, 'fridays': True, 'saturdays': True, 'sundays': True}}}]}}}, 'fuelStatus': {'rangeStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'carType': 'hybrid', 'primaryEngine': {'type': 'gasoline', 'currentSOC_pct': 88, 'remainingRange_km': 580, 'currentFuelLevel_pct': 88}, 'secondaryEngine': {'type': 'electric', 'currentSOC_pct': 70, 'remainingRange_km': 35}, 'totalRange_km': 615}}}, 'measurements': {'rangeStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'electricRange': 35, 'gasolineRange': 580, 'totalRange_km': 615}}, 'odometerStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 39, tzinfo=datetime.timezone.utc), 'odometer': 31286}}, 'fuelLevelStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 10, 44, 10, tzinfo=datetime.timezone.utc), 'currentFuelLevel_pct': 88, 'currentSOC_pct': 70, 'primaryEngineType': 'gasoline', 'secondaryEngineType': 'electric', 'carType': 'hybrid'}}}, 'vehicleLights': {'lightsStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 39, tzinfo=datetime.timezone.utc), 'lights': [{'name': 'right', 'status': 'off'}, {'name': 'left', 'status': 'off'}]}}}, 'vehicleHealthInspection': {'maintenanceStatus': {'value': {'carCapturedTimestamp': datetime.datetime(2024, 4, 11, 9, 19, 39, tzinfo=datetime.timezone.utc), 'inspectionDue_days': 673, 'inspectionDue_km': 28300, 'mileage_km': 31286, 'oilServiceDue_days': 308, 'oilServiceDue_km': 13300}}}}

Now the required data is present:

    "windowHeatingStatus": {
      "value": {
        "carCapturedTimestamp": "datetime.datetime(2024, 4, 11, 9, 19, 2, tzinfo=datetime.timezone.utc)",
        "windowHeatingStatus": [
          { "windowLocation": "front", "windowHeatingState": "off" },
          { "windowLocation": "rear", "windowHeatingState": "off" }
        ]
      }
    }

I guess VW had some glitch on their end, so the carCapturedTimestamp has disappeared.
Now it appears again, and that is the reason why you are not getting an error anymore.

in any case, I will think about adding some protection against such scenarios.

Yes, as I said this is intermittent and happens 3/4 times per hour. Thanks for enforcing the code.

I found also this:
2024-04-11 14:29:51.461 WARNING (MainThread) [volkswagencarnet.vw_connection] Could not fetch vehicle data, error: 'NoneType' object is not iterable

Thanks, have you fixed also this one?

2024-04-11 14:29:51.461 WARNING (MainThread) [volkswagencarnet.vw_connection] Could not fetch vehicle data, error: 'NoneType' object is not iterable

Please try https://github.com/robinostlund/homeassistant-volkswagencarnet/releases/tag/v4.6.1
Now if VW servers remove some key-value pair during the run time, your sensor will change to an unknown state and you will see an error message in the log:
"Dictionary path: <dictionary.path> is no longer present. Dictionary: <full_dictionary>

I don't see it available on Hacs