SAIC-iSmart-API / saic-python-mqtt-gateway

A service that queries the data from an MG iSMART account and publishes the data over MQTT and to other sources
MIT License
71 stars 21 forks source link

WIP: New SAIC API #131

Closed nanomad closed 8 months ago

nanomad commented 9 months ago

This migrates the current python gateway to the new SAIC API.

nanomad commented 9 months ago

Blocked by https://github.com/SAIC-iSmart-API/saic-python-client-ng/issues/1

an0Nym0us63 commented 8 months ago

Hello as issues are not available on @nanomad repo

I will use this PR to transmit a "bug"

If a phone logs in ismart app, the gateway in this new version sees the token expiry and says it will wait (normally 15 minutes) but despite the message it keeps trying to get new messages each minutes without relogin in and throws error

2024-01-24 12:25:51,024 [WARNING ] Waiting since we got logged out: 401: {"code":401,"message":"Token expired"} - saic_ismart_client_ng.api.base 2024-01-24 12:26:39,061 [ INFO ] Running job "Check for new messages (trigger: interval[0:01:00], next run at: 2024-01-24 12:27:39 CET)" (scheduled at 2024-01-24 12:26:39.047121+01:00) - apscheduler.executors.default 2024-01-24 12:26:39,062 [ ERROR ] MessageHandler poll loop failed - __main__ Traceback (most recent call last): File "/usr/src/app/./mqtt_gateway.py", line 447, in __polling unread_count = await self.saicapi.get_unread_messages_count() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/message/__init__.py", line 59, in get_unread_messages_count return await self.execute_api_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 89, in execute_api_call response = await self.api_client.client.send(req) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1646, in send response = await self._send_handling_auth( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1674, in _send_handling_auth response = await self._send_handling_redirects( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1709, in _send_handling_redirects await hook(request) File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/net/client/api.py", line 47, in __encrypt_request raise SaicApiException("Client not authenticated, please call login first") saic_ismart_client_ng.exceptions.SaicApiException: Client not authenticated, please call login first 2024-01-24 12:26:39,066 [ INFO ] Job "Check for new messages (trigger: interval[0:01:00], next run at: 2024-01-24 12:27:39 CET)" executed successfully - apscheduler.executors.default

nanomad commented 8 months ago

Hello as issues are not available on @nanomad repo

I will use this PR to transmit a "bug"

If a phone logs in ismart app, the gateway in this new version sees the token expiry and says it will wait (normally 15 minutes) but despite the message it keeps trying to get new messages each minutes without relogin in and throws error

The exception stacktrace can be ignored, the current implementation works like this:

an0Nym0us63 commented 8 months ago

Hello as issues are not available on @nanomad repo I will use this PR to transmit a "bug" If a phone logs in ismart app, the gateway in this new version sees the token expiry and says it will wait (normally 15 minutes) but despite the message it keeps trying to get new messages each minutes without relogin in and throws error

The exception stacktrace can be ignored, the current implementation works like this:

  • The first API call that detects a 401 "waits" for the wait time, then logs back in, then throws the exception forward (since it doesn't make sense to retry an old command after 15 minutes)
  • The "message poller" is configured with max 1 pending check, so all the other checks are ignored (you can see that in the apscheduler logs)
  • If a command is requested during the "wait" period, the commands fails since the user token is not set (it will be set after the login)

Thats what i understood but looking AT my logs it happened more than 10 Times in a row (one minute each)

I was thinking that After the first one (which IS already scheduled, im ok with that) it wont try gain until the wait Time.

You Can see at the end of my log that it rescheduled it one minute After.

But i think After re Reading your answer that this IS normal and the message poller will check each minutes failing until the waiter will relogin.

an0Nym0us63 commented 8 months ago

@nanomad

I also often get `2024-01-25 13:41:05,346 [ ERROR ] MessageHandler poll loop failed - main Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 130, in deserialize json_data = response.json() ^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_models.py", line 762, in json return jsonlib.loads(self.content, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/json/init.py", line 346, in loads return _default_decoder.decode(s) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/json/decoder.py", line 337, in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/json/decoder.py", line 355, in raw_decode raise JSONDecodeError("Expecting value", s, err.value) from None json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/app/./mqtt_gateway.py", line 447, in __polling unread_count = await self.saicapi.get_unread_messages_count() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/message/init.py", line 59, in get_unread_messages_count return await self.execute_api_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 90, in execute_api_call return await self.deserialize(req, response, out_type) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 179, in deserialize raise SaicApiException(f"Failed to deserialize response: {e}. Original json was {response.text}") from e saic_ismart_client_ng.exceptions.SaicApiException: Failed to deserialize response: Expecting value: line 1 column 1 (char 0). Original json was

504 Gateway Time-out

504 Gateway Time-out

`

I never had this message before.

And when this happens even a force refresh doesnt work.

It looks like a server issue but i dont have this with the oldest gateway

an0Nym0us63 commented 8 months ago

also got this one

Traceback (most recent call last): File "/usr/src/app/./mqtt_gateway.py", line 91, in handle_vehicle vehicle_status = await self.update_vehicle_status() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/app/./mqtt_gateway.py", line 121, 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 13, 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 120, 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.py", line 88, in async_wrapped return await fn(*args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/tenacity/_asyncio.py", line 47, in __call__ do = self.iter(retry_state=retry_state) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/tenacity/__init__.py", line 314, in iter return fut.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.py", line 50, in __call__ result = await fn(*args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/api/base.py", line 111, 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 89, in execute_api_call response = await self.api_client.client.send(req) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1646, in send response = await self._send_handling_auth( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1674, in _send_handling_auth response = await self._send_handling_redirects( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1732, in _send_handling_redirects raise exc File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1714, in _send_handling_redirects await hook(response) File "/usr/local/lib/python3.12/site-packages/saic_ismart_client_ng/net/security.py", line 57, in decrypt_response original_response_key = app_send_date + "1" + original_content_type

task: <Task pending name='Task-1' coro=<Client._resend_qos_messages() running at /usr/local/lib/python3.12/site-packages/gmqtt/client.py:176>> - asyncio sys:1: RuntimeWarning: coroutine 'Client._resend_qos_messages' was never awaited

nanomad commented 8 months ago

@sarakha63 504: is due to a container crashing on SAIC end that handles the translation between the old and new API. It has been crashing randomly for at least a day. The second crash has the same underlying issue. I've updated the api code to handle it a bit more gracefully. I also see a coroutine that wasn't awaited in the MQTT library code, so I'll analyze that as well

an0Nym0us63 commented 8 months ago

@sarakha63 504: is due to a container crashing on SAIC end that handles the translation between the old and new API. It has been crashing randomly for at least a day. The second crash has the same underlying issue. I've updated the api code to handle it a bit more gracefully. I also see a coroutine that wasn't awaited in the MQTT library code, so I'll analyze that as well

Great thanks for your feedback.

I'll keep testing and report what i notice ;)