HA sensors going often to unavailable state

[elmr91]

I noticed I got several error messages when the vehicule is active/driving:

Note : Polling was initially every 60s, I decreased it to 30s for testing (not better).

2025-04-14 19:01:54,012 [ ERROR  ] handle_vehicle loop failed during SAIC API call - handlers.vehicle
Traceback (most recent call last):
  File "/usr/src/app/handlers/vehicle.py", line 97, in handle_vehicle
    await self.__polling()
  File "/usr/src/app/handlers/vehicle.py", line 124, in __polling
    vehicle_status = await self.update_vehicle_status()
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/handlers/vehicle.py", line 181, in update_vehicle_status
    vehicle_status_response = await self.saic_api.get_vehicle_status(self.vin_info.vin)
                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/vehicle/__init__.py", line 15, in get_vehicle_status
    return await self.execute_api_call_with_event_id(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 139, in execute_api_call_with_event_id
    return await execute_api_call_with_event_id_inner(event_id='0')
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 189, in async_wrapped
    return await copy(fn, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 111, in __call__
    do = await self.iter(retry_state=retry_state)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 153, in iter
    result = await action(retry_state)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/_utils.py", line 99, in inner
    return call(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/__init__.py", line 418, in exc_check
    raise retry_exc.reraise()
          ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tenacity/__init__.py", line 185, in reraise
    raise self.last_attempt.result()
          ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 449, in result
    return self.__get_result()
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 401, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 114, in __call__
    result = await fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 130, in execute_api_call_with_event_id_inner
    return await self.__execute_api_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 107, in __execute_api_call
    return await self.__deserialize(req, response, out_type, allow_null_body)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 200, in __deserialize
    raise se
  File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 167, in __deserialize
    raise SaicApiRetryException(error_message, event_id=event_id, return_code=return_code)
saic_ismart_client_ng.exceptions.SaicApiRetryException: return code: 4, message: The remote control instruction failed, please try again later., event_id: 1548216868
2025-04-14 19:02:22,507 [  INFO  ] Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-04-14 19:02:52 CEST)" (scheduled at 2025-04-14 19:02:22.505006+02:00) - apscheduler.executors.default
2025-04-14 19:02:22,702 [  INFO  ] Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-04-14 19:02:52 CEST)" executed successfully - apscheduler.executors.default
2025-04-14 19:02:52,506 [  INFO  ] Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-04-14 19:03:22 CEST)" (scheduled at 2025-04-14 19:02:52.505006+02:00) - apscheduler.executors.default
2025-04-14 19:02:52,660 [  INFO  ] Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-04-14 19:03:22 CEST)" executed successfully - apscheduler.executors.default`

Next loop (or the one after) is generally OK.

When this error occurs, it seems the HA position sensor is switched temporarily to "unavailable"
This causes problems with scenario based on movement calculations.
Would it be possible to be tolerant to intermittent failures (for few consecutive polling errors) ?

[elmr91]

I checked again today.
MG position sensor is switching to unavailable every times SAIC server is sending a "try again later" message:

saic_ismart_client_ng.exceptions.SaicApiRetryException: return code: 4, message: The remote control instruction failed, please try again later., event_id: 1548216868

It corresponds to "try again later" from SAIC server:

bf995ce7_saic_python_mqtt_gateway_2025-04-15T11-14-13.857Z.log

[nanomad]

@elmr91 this is done not at the first "try again" but after 30s since the request has been sent to the car.

This is to mimick the app behaviour.

You could contribute a PR to increase that timeout, but I'd still default to 30s

See:

saic_ismart_client_ng.api.base.saic_api_retry_policy

[Muncee]

I'm getting this issue too, my MGEV4 is essentially unavailable most of the time at the moment.

[jkrenzer]

The same with our MG ZS EV. It apparently just started somewhere in the last weeks for our vehicle. I am not sure if it was a change in the API policies or if I did just update late to the newest version of the gateway.

[elmr91]

Things are getting worse these days:
6 times unavailable in the last 5 hours :

2025-06-18 12:18:48,788 [INFO]: Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:19:18 CEST)" (scheduled at 2025-06-18 12:18:48.786558+02:00) - apscheduler.executors.default
2025-06-18 12:18:48,993 [INFO]: 2 messages received - handlers.message
2025-06-18 12:18:48,994 [INFO]: Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:19:18 CEST)" executed successfully - apscheduler.executors.default
2025-06-18 12:19:16,432 [ERROR]: handle_vehicle loop failed during SAIC API call - handlers.vehicle
Traceback (most recent call last):
  File "/usr/src/app/handlers/vehicle.py", line 118, in handle_vehicle
    await self.__polling()
  File "/usr/src/app/handlers/vehicle.py", line 151, in __polling
    ) = await self.update_vehicle_status()
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/handlers/vehicle.py", line 242, in update_vehicle_status
    vehicle_status_response = await self.saic_api.get_vehicle_status(
                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/vehicle/__init__.py", line 45, in get_vehicle_status
    return await self.execute_api_call_with_event_id(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 221, in execute_api_call_with_event_id
    result = await self.__execute_api_call_with_event_id(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 284, in __execute_api_call_with_event_id
    return await execute_api_call_with_event_id_inner(event_id="0")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 189, in async_wrapped
    return await copy(fn, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 111, in __call__
    do = await self.iter(retry_state=retry_state)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 153, in iter
    result = await action(retry_state)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/_utils.py", line 99, in inner
    return call(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/__init__.py", line 420, in exc_check
    raise retry_exc.reraise()
          ^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/__init__.py", line 187, in reraise
    raise self.last_attempt.result()
          ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 449, in result
    return self.__get_result()
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 401, in __get_result
    raise self._exception
  File "/usr/src/app/.venv/lib/python3.12/site-packages/tenacity/asyncio/__init__.py", line 114, in __call__
    result = await fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 275, in execute_api_call_with_event_id_inner
    return await self.__execute_api_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 205, in __execute_api_call
    raise e
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 203, in __execute_api_call
    return await self.__deserialize(req, response, out_type, allow_null_body)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 356, in __deserialize
    raise se
  File "/usr/src/app/.venv/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 319, in __deserialize
    raise SaicApiRetryException(
saic_ismart_client_ng.exceptions.SaicApiRetryException: return code: 4, message: The remote control instruction failed, please try again later., event_id: 449428248
2025-06-18 12:19:16,438 [INFO]: Sending HA discovery messages for LSJWH4095PN049490 (Force: False) - handlers.vehicle
2025-06-18 12:19:18,788 [INFO]: Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:19:48 CEST)" (scheduled at 2025-06-18 12:19:18.786558+02:00) - apscheduler.executors.default
2025-06-18 12:19:18,996 [INFO]: 2 messages received - handlers.message
2025-06-18 12:19:18,996 [INFO]: Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:19:48 CEST)" executed successfully - apscheduler.executors.default
2025-06-18 12:19:46,492 [INFO]: Updating vehicle status - handlers.vehicle
2025-06-18 12:19:48,790 [INFO]: Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:20:18 CEST)" (scheduled at 2025-06-18 12:19:48.786558+02:00) - apscheduler.executors.default
2025-06-18 12:19:48,970 [INFO]: 2 messages received - handlers.message
2025-06-18 12:19:48,971 [INFO]: Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:20:18 CEST)" executed successfully - apscheduler.executors.default
2025-06-18 12:19:56,212 [INFO]: Updating charging status - handlers.vehicle
2025-06-18 12:19:59,499 [INFO]: Updating scheduled battery heating status - handlers.vehicle
2025-06-18 12:19:59,542 [INFO]: Refreshing vehicle status succeeded... - handlers.vehicle
2025-06-18 12:19:59,543 [INFO]: ABRP not refreshed, reason ABRP request skipped because of missing configuration - handlers.vehicle
2025-06-18 12:19:59,544 [INFO]: Sending HA discovery messages for LSJWH4095PN049490 (Force: False) - handlers.vehicle
2025-06-18 12:20:18,788 [INFO]: Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:20:48 CEST)" (scheduled at 2025-06-18 12:20:18.786558+02:00) - apscheduler.executors.default
2025-06-18 12:20:19,039 [INFO]: 2 messages received - handlers.message
2025-06-18 12:20:19,040 [INFO]: Job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:20:48 CEST)" executed successfully - apscheduler.executors.default
2025-06-18 12:20:48,788 [INFO]: Running job "Check for new messages (trigger: interval[0:00:30], next run at: 2025-06-18 12:21:18 CEST)" (scheduled at 2025-06-18 12:20:48.786558+02:00) - apscheduler.executors.default
2025-06-18 12:20:49,074 [INFO]: 2 messages received - handlers.message

I don't understand the retry procedure (I should have a look to the code):
Polling in done every 30s (in my case)
polling is done at 12:18:48 / next polling should be performed at 12:19:18 (30s later)
Exception rose at 12:19:16 (before next polling)
Trace shows that we are already in retry procedure (exceptions.SaicApiRetryException) after some previous failure (not displayed)
What should be the delay between retries and number of retries ?

In this case, time between working/exception was 28s : it means we cannot cope with server unavailability longer than few seconds ?

[Muncee]

if its any consolation its got worse for me too, i've got an automation that forces refresh when unavailable but isn't working reliably, it does seem to be worse if im plugged in.

[jkrenzer]

if its any consolation its got worse for me too, i've got an automation that forces refresh when unavailable but isn't working reliably, it does seem to be worse if im plugged in.

I tried the same automation setup to no avail. The frequent unavailability makes the setup near to unusable at times. Before it ran quite reliably for a long time, so I am too uncertain if this might have been some change in API policy on the SAIC side or some regression in an update.

[elmr91]

Hi @nanomad, I had a look to the code:

In __execute_api_call (base.py #202)
we send are calling the API -> self.__api_client.send(req)
and receiving/analyzing the response -> self.__deserialize(req, response, out_type, allow_null_body)

in __deserialize (base.py #286)
when receiving a return_code = 4 (The remote control instruction failed, please try again later), we are raising SaicApiRetryException

But this exception does not seems to trigger any retry mechanism.

Raising this exception immediately cause the HA device to go to unavailable state (at the exact same second) :

2025-07-03 13:37:53,849 [ERROR]: handle_vehicle loop failed during SAIC API call - handlers.vehicle
Traceback (most recent call last):

bf995ce7_saic_python_mqtt_gateway_2025-07-03T15-50-31.929Z.log

[nanomad]

Uhm that's weird, there's a SaicApiRetryPolicy that should handle exactly that scenario.

Let me write a test case and check

[elmr91]

I noticed this that should handle this case:
@tenacity.retry(
stop=tenacity.stop_after_delay(30),
wait=delay or tenacity.wait_fixed(self.__configuration.sms_delivery_delay),
retry=SaicApiRetryPolicy(),
after=saic_api_after_retry,
reraise=True,
)

But I don't know exactly on which criteria it should be triggered (timeout, no answer, exception ?)

Anyway, thanks for having a look on it.