search

Dielee / volvo2mqtt

Home Assistant addon for connecting AAOS Volvos
MIT License
143 stars 30 forks source link

Force Update Data leads to "not available" #209

Closed HWiese1980 closed 2 months ago

HWiese1980 commented 3 months ago

Describe the bug Pushing the "Force Update Data" button leads to all sensors going into "not available" state after a couple seconds. It seems like the addon crashes or freezes.

Frequent automatic update works.

To Reproduce:
Steps to reproduce the behavior:

  1. push Force Update Data button
  2. wait a couple seconds
  3. see sensors go down
  4. restart of the addon required

Expected behavior:
Forcing an update should not lead to "not available"

Version info:
volvo2mqtt: 1.9.3 Home Assistant: 2024.7.1 Mosquitto Addon: 6.4.1

Logs:
There is nothing in the logs that might indicate why the addon stops working. It just does. No errors, no anomalies, everything looks like it's working. I also refrain from posting debug logs because they may contain personal information and details about my car that I do not want to share publicly. If you really need the logs despite them not showing anything of value, I have to clean them from personal data first. Please say so if you need me to do that.

Dielee commented 3 months ago

If the addon crashes, there have to be logs. Please log at the supervisor logs.

HWiese1980 commented 3 months ago

It does not crash, like, exiting. It just stops working, more like freezing.

ahammas commented 3 months ago

I've recently also had the sensors become unavailable. Seemed very random until I read this report. I tried pressing the Refresh-button and after a while they became unavailable. This is what my log says:

Jul 08 06:57:12 volvo2mqtt [106] - INFO: Sending mqtt update... Jul 08 06:57:13 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds. Exception in thread Thread-1 (_thread_main): Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 466, in _make_request self._validate_conn(conn) File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 1095, in _validate_conn conn.connect() File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 652, in connect sock_and_verified = _ssl_wrap_socket_and_match_hostname( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 805, in _ssl_wrap_socket_and_match_hostname ssl_sock = ssl_wrapsocket( ^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/ssl.py", line 465, in ssl_wrap_socket ssl_sock = _ssl_wrap_socket_impl(sock, context, tls_in_tls, serverhostname) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/ssl.py", line 509, in _ssl_wrap_socket_impl return ssl_context.wrap_socket(sock, server_hostname=server_hostname) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 455, in wrap_socket return self.sslsocket_class._create( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 1042, in _create self.do_handshake() File "/usr/lib/python3.12/ssl.py", line 1320, in do_handshake self._sslobj.do_handshake() ssl.SSLCertVerificationError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed: certificate has expired (_ssl.c:1000)

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen response = self._make_request( ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 490, in _make_request raise new_e urllib3.exceptions.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed: certificate has expired (_ssl.c:1000)

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

Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send resp = conn.urlopen( ^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen retries = retries.increment( ^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 519, in increment raise MaxRetryError(_pool, url, reason) from reason # type: ignore[arg-type] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='oip-dev-bff.euwest1.production.volvo.care', port=443): Max retries exceeded with url: /api/v1/backend-status (Caused by SSLError(SSLCertVerificationError(1, '[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed: certificate has expired (_ssl.c:1000)')))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner self.run() File "/usr/lib/python3.12/threading.py", line 1010, in run self._target(*self._args, self._kwargs) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3591, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1756, in loop_forever rc = self._loop(timeout) ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1164, in _loop rc = self.loop_read() ^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1556, in loop_read rc = self._packet_read() ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 2439, in _packet_read rc = self._packet_handle() ^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle return self._handle_publish() ^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish self._handle_on_message(message) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message on_message(self, self._userdata, message) File "/volvoAAOS2mqtt/mqtt.py", line 160, in on_message update_car_data(True) File "/volvoAAOS2mqtt/mqtt.py", line 305, in update_car_data state = volvo.get_backend_status() ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status response = session.get(API_BACKEND_STATUS, timeout=15) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get return self.request("GET", url, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request resp = self.send(prep, send_kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send r = adapter.send(request, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 698, in send raise SSLError(e, request=request) requests.exceptions.SSLError: HTTPSConnectionPool(host='oip-dev-bff.euwest1.production.volvo.care', port=443): Max retries exceeded with url: /api/v1/backend-status (Caused by SSLError(SSLCertVerificationError(1, '[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed: certificate has expired (_ssl.c:1000)')))

ahammas commented 3 months ago

As @HWiese1980 says it doesn't seem to crash. I have watchdog enabled so it should restart itself if it did. After a manually restarting it works as it should again.

I recently changed my remote connection to use nginx and after this it first appeared so my first thought was that this has something to do with it as the log says something about SSL not being authorized. But in the same time frame I've also updated to 2024.7.0 so it was har to know which was the most likely candidate to direct the blame at.

Good to know that it could be caused by the refresh button. I will stop using it and see if the unavailability stops as well.

HWiese1980 commented 3 months ago

Thanks for the confirmation, @ahammas. Weird though. Why do I not see that in my logs? I have no error whatsoever in my logs.

ahammas commented 3 months ago

@HWiese1980 No problem! It's in my interest too :) Do you also remote connect through nginx?

When I look through the logs there seem to be something going on with port 443, which is the same port that I've opened up for nginx remote connection. I understand 443 is a general ssl port so I guess it could be unrelated to my change in remote connection but as the saying goes "hate the coincidence".

HWiese1980 commented 3 months ago

Outgoing connections from Home Assistant in my setup are direct connections, no proxy in between. For incoming connections like accessing the frontend, I'm using a Traefik reverse proxy.

Regarding 443, that's certainly also the port that the Volvo API is listening on. Since the addon uses an outgoing request to query the API the local port should be randomly chosen from available ports and as such irrelevant.

Dielee commented 3 months ago

Please try v1.9.4 if its ready

elGamo commented 3 months ago

Please try v1.9.4 if its ready

How do I update to 1.9.4 from 1.9.3? I have auto update addon set to on and I have restarted HA, but still 1.9.3.

HWiese1980 commented 3 months ago

Please try v1.9.4 if its ready

How do I update to 1.9.4 from 1.9.3? I have auto update addon set to on and I have restarted HA, but still 1.9.3.

I think that's what Linus meant by "if its ready", aka "when it's done". ;-)

elGamo commented 3 months ago

Please try v1.9.4 if its ready

How do I update to 1.9.4 from 1.9.3? I have auto update addon set to on and I have restarted HA, but still 1.9.3.

I think that's what Linus meant by "if its ready", aka "when it's done". ;-)

Ahh, I read it as "it is ready" :) I'll wait then.

Dielee commented 3 months ago

Build is done, feel free to test

HWiese1980 commented 3 months ago

As soon as it's available in the Home Assistant Addon Update overview, I'll be happy to do so, thanks.

HWiese1980 commented 3 months ago

Alright, update is available. I'll go check it out

HWiese1980 commented 3 months ago

Yepp, problem seems to be fixed for me. Thanks a million! Keep rocking, @Dielee! @elGamo, @ahammas, could you confirm please?

elGamo commented 3 months ago

SSL error went away in 1.9.4 so I got in the info again, but have some errors in log after I do a force update of the api info. Perhaps they just block it on their side so maybe nothing to worry about?

Jul 08 14:10:44 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.
Jul 08 14:15:44 volvo2mqtt [106] - INFO: Sending mqtt update...
Jul 08 14:15:45 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.
Exception in thread Thread-1 (_thread_main):
Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 536, in _make_request
    response = conn.getresponse()
               ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 464, in getresponse
    httplib_response = super().getresponse()
                       ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 1428, in getresponse
    response.begin()
  File "/usr/lib/python3.12/http/client.py", line 331, in begin
    version, status, reason = self._read_status()
                              ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 292, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/socket.py", line 707, in readinto
    return self._sock.recv_into(b)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1252, in recv_into
    return self.read(nbytes, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1104, in read
    return self._sslobj.read(len, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TimeoutError: The read operation timed out

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

Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 474, in increment
    raise reraise(type(error), error, _stacktrace)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/util.py", line 39, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen
    response = self._make_request(
               ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 538, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 369, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3591, in _thread_main
    self.loop_forever(retry_first_connection=True)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
         ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
         ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle
    return self._handle_publish()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish
    self._handle_on_message(message)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message
    on_message(self, self._userdata, message)
  File "/volvoAAOS2mqtt/mqtt.py", line 160, in on_message
    update_car_data(True)
  File "/volvoAAOS2mqtt/mqtt.py", line 305, in update_car_data
    state = volvo.get_backend_status()
            ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status
    response = session.get(API_BACKEND_STATUS, timeout=15)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get
    return self.request("GET", url, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 713, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)
ahammas commented 2 months ago

Yepp, problem seems to be fixed for me. Thanks a million! Keep rocking, @Dielee! @elGamo, @ahammas, could you confirm please?

It's fixed as far as I can see. The sensors stay after Refresh is requested. Can't see any errors in the log.

Solid work as always @Dielee!

Dielee commented 2 months ago

SSL error went away in 1.9.4 so I got in the info again, but have some errors in log after I do a force update of the api info. Perhaps they just block it on their side so maybe nothing to worry about?

Jul 08 14:10:44 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.
Jul 08 14:15:44 volvo2mqtt [106] - INFO: Sending mqtt update...
Jul 08 14:15:45 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.
Exception in thread Thread-1 (_thread_main):
Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 536, in _make_request
    response = conn.getresponse()
               ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 464, in getresponse
    httplib_response = super().getresponse()
                       ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 1428, in getresponse
    response.begin()
  File "/usr/lib/python3.12/http/client.py", line 331, in begin
    version, status, reason = self._read_status()
                              ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 292, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/socket.py", line 707, in readinto
    return self._sock.recv_into(b)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1252, in recv_into
    return self.read(nbytes, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1104, in read
    return self._sslobj.read(len, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TimeoutError: The read operation timed out

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

Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 474, in increment
    raise reraise(type(error), error, _stacktrace)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/util.py", line 39, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen
    response = self._make_request(
               ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 538, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 369, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3591, in _thread_main
    self.loop_forever(retry_first_connection=True)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
         ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
         ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle
    return self._handle_publish()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish
    self._handle_on_message(message)
  File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message
    on_message(self, self._userdata, message)
  File "/volvoAAOS2mqtt/mqtt.py", line 160, in on_message
    update_car_data(True)
  File "/volvoAAOS2mqtt/mqtt.py", line 305, in update_car_data
    state = volvo.get_backend_status()
            ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status
    response = session.get(API_BACKEND_STATUS, timeout=15)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get
    return self.request("GET", url, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 713, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

This is just a timeout, nothing to worry about...

ahammas commented 2 months ago

I get the same now and the sensor becomes unavailable.

Well, it's just to change usage pattern and stop the force update I guess.

My log below:

response = conn.getresponse()
           ^^^^^^^^^^^^^^^^^^

File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 464, in getresponse httplib_response = super().getresponse() ^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/http/client.py", line 1428, in getresponse response.begin() File "/usr/lib/python3.12/http/client.py", line 331, in begin version, status, reason = self._read_status() ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/http/client.py", line 292, in _read_status line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1") ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/socket.py", line 707, in readinto return self._sock.recv_into(b) ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 1252, in recv_into return self.read(nbytes, buffer) ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 1104, in read return self._sslobj.read(len, buffer) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ TimeoutError: The read operation timed out

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

Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send resp = conn.urlopen( ^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen retries = retries.increment( ^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 474, in increment raise reraise(type(error), error, _stacktrace) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/util.py", line 39, in reraise raise value File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen response = self._make_request( ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 538, in _make_request self._raise_timeout(err=e, url=url, timeout_value=read_timeout) File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 369, in _raise_timeout raise ReadTimeoutError( urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner self.run() File "/usr/lib/python3.12/threading.py", line 1010, in run self._target(*self._args, self._kwargs) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3591, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1756, in loop_forever rc = self._loop(timeout) ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1164, in _loop rc = self.loop_read() ^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1556, in loop_read rc = self._packet_read() ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 2439, in _packet_read rc = self._packet_handle() ^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle return self._handle_publish() ^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish self._handle_on_message(message) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message on_message(self, self._userdata, message) File "/volvoAAOS2mqtt/mqtt.py", line 160, in on_message update_car_data(True) File "/volvoAAOS2mqtt/mqtt.py", line 305, in update_car_data state = volvo.get_backend_status() ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status response = session.get(API_BACKEND_STATUS, timeout=15) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get return self.request("GET", url, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request resp = self.send(prep, send_kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send r = adapter.send(request, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 713, in send raise ReadTimeout(e, request=request) requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15) Jul 08 17:33:04 volvo2mqtt [106] - INFO: Sending mqtt update... Jul 08 17:33:08 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds. Jul 08 17:38:08 volvo2mqtt [106] - INFO: Sending mqtt update... Jul 08 17:38:12 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds. Jul 08 17:43:12 volvo2mqtt [106] - INFO: Sending mqtt update... Jul 08 17:43:15 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.

ahammas commented 2 months ago

The delay also seem to be affecting their own app. My V90 is indicated as being in use while it's in reality is parked and locked.

elGamo commented 2 months ago

Yeah, force update brakes it and I have to restart the addon to make it work again. No big deal since I usually not force it manually but I do it in an automation and that I have to change.

HWiese1980 commented 2 months ago

Is it still an issue for you guys, even in 1.9.4?

elGamo commented 2 months ago

Yes, I did test it right now and after a Force all data got "Unavailable" but when I did the same earlier today it worked, so no idea if it is something on their side. Here are logs after it failed now, and even though the last two lines looks like it is working it is not, it needs a restart of the addon to come alive again:

`Jul 09 12:18:58 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds. Exception in thread Thread-1 (_thread_main): Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 536, in _make_request response = conn.getresponse() ^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 464, in getresponse httplib_response = super().getresponse() ^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/http/client.py", line 1428, in getresponse response.begin() File "/usr/lib/python3.12/http/client.py", line 331, in begin version, status, reason = self._read_status() ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/http/client.py", line 292, in _read_status line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1") ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/socket.py", line 707, in readinto return self._sock.recv_into(b) ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 1252, in recv_into return self.read(nbytes, buffer) ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/ssl.py", line 1104, in read return self._sslobj.read(len, buffer) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ TimeoutError: The read operation timed out

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

Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send resp = conn.urlopen( ^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen retries = retries.increment( ^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 474, in increment raise reraise(type(error), error, _stacktrace) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/util/util.py", line 39, in reraise raise value File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen response = self._make_request( ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 538, in _make_request self._raise_timeout(err=e, url=url, timeout_value=read_timeout) File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 369, in _raise_timeout raise ReadTimeoutError( urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner self.run() File "/usr/lib/python3.12/threading.py", line 1010, in run self._target(*self._args, self._kwargs) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3591, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1756, in loop_forever rc = self._loop(timeout) ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1164, in _loop rc = self.loop_read() ^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 1556, in loop_read rc = self._packet_read() ^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 2439, in _packet_read rc = self._packet_handle() ^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle return self._handle_publish() ^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish self._handle_on_message(message) File "/usr/lib/python3.12/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message on_message(self, self._userdata, message) File "/volvoAAOS2mqtt/mqtt.py", line 160, in on_message update_car_data(True) File "/volvoAAOS2mqtt/mqtt.py", line 305, in update_car_data state = volvo.get_backend_status() ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status response = session.get(API_BACKEND_STATUS, timeout=15) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get return self.request("GET", url, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request resp = self.send(prep, send_kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send r = adapter.send(request, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 713, in send raise ReadTimeout(e, request=request) requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15) Jul 09 12:23:58 volvo2mqtt [106] - INFO: Sending mqtt update... Jul 09 12:23:59 volvo2mqtt [106] - INFO: Mqtt update done. Next run in 300 seconds.`

Crouze commented 2 months ago

Is it still an issue for you guys, even in 1.9.4?

For me, the issue started with 1.9.4. Same behavior as described above: a force update breaks all sensors until I restart the addon . It started doing so after the upgrade from 1.9.3 yesterday.

It's not breaking the usage of the addon, just an annoyance, but should not happen nevertheless and in my humble opinion the issue was closed prematurely.

ahammas commented 2 months ago

Yes, it still happens. I've resorted to not use the force update and wait until next update. A bit annoying but the only reason for me to force update is to check when the car is done charging after I've changed the current setting on my charger.

As I understood @Dielee it seem to be something on the Volvo side so it's out of 3rd party dev hands.

I also noticed that there was some lag in the Volvo app so maybe there's something central that is not working as it should and is pending vacation period to end before it's properly fixed :)

Dielee commented 2 months ago

@ahammas how often do you use the force update button ? And are you able to load the following URL in your browser: https://public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz/api/v1/backend-status

If not, where are you from ?

HWiese1980 commented 2 months ago

@Dielee Unfortunately, I have to tell you, the behavior seems to be back... Not as frequent and reliable as before but the addon still freezes under certain circumstances. And there is still no indication of a problem in the logs.

HWiese1980 commented 2 months ago

@Dielee Oh, and regarding your last question about how often that functionality is used, I thought I already had replied to it, must have forgotton to hit send...

I use the triggered update quite often, depending on the situation and under certain circumstances even based on an automation that triggers the update every 30 seconds for short periods during the day.

Dielee commented 2 months ago

Yeah, the frequent use of force update will use a lot more API calls than the regular update.. so maybe Volvo is blocking the backen API url if the call happens too often. I will check this later or tomorrow.

HWiese1980 commented 2 months ago

I'll have to verify that the freezes that I'm currently experiencing correlate with the high frequency requests. My gut feelings say no...

Dielee commented 2 months ago

It has to be... The timeout in the logs are comming from the backen API endpoint.

HWiese1980 commented 2 months ago

Weirdly enough I do not have any timeouts or exceptions in the logs even though debug log level is active.

Dielee commented 2 months ago

So if there are no errors, what's your problem ?

HWiese1980 commented 2 months ago

My problem is that the addon sometimes simply goes into "not available", does not publish updates anymore and needs a forced restart to get working again. It seems like it just freezes at some point, maybe waiting for some response that never comes and never times out.

All of this without any errors in the logs.

Dielee commented 2 months ago

If the entities are going to "not available" the addon restarts because of an error. Please check the supervisor logs if this happens.

ahammas commented 2 months ago

@ahammas how often do you use the force update button ?

And are you able to load the following URL in your browser: https://public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz/api/v1/backend-status

If not, where are you from ?

@Dielee It varies quite a bit depending on the day. The most normal use case is when I'm trying to adjust the chargers allowed current while at the same time trying to match the midday spot price dip. My estimation is that it might be 5-10 updates over a 2-3h period. So it's not a huge amount.

Dielee commented 2 months ago

And what happens if it doesn't work?

HWiese1980 commented 2 months ago

If the entities are going to "not available" the addon restarts because of an error. Please check the supervisor logs if this happens.

I have created an automation now that does this. When the entities go to "not available" for 30 seconds, the addon is automatically restarted. It helps but I guess it's - as we Germans like to say - "nicht im Sinne des Erfinders".

HWiese1980 commented 2 months ago

Oh, just to mention it, supervisor logs are a problem on my HA host at the moment because for some reason the systemd journal gateway doesn't work. The available fixes didn't help. I'm thinking of migrating the HA setup to a different machine. But that's a different story. I can only tail the volvo2mqtt logs themselves by using the Terminal addon and doing an actual "tail -f" on the log file.

Dielee commented 2 months ago

So maybe the addon crashes, the logs will be inside the supervisor.. please try to provide these

HWiese1980 commented 2 months ago

Yeah, I will, as soon as I've fixed that verflixte journal gateway problem...

HWiese1980 commented 2 months ago

Okay, I've now fixed the logging problem by migrating Home Assistant from a supervised installation to a Home Assistant OS installation. Logs work again. I'll keep an eye open for weird behavior from the addon.

Just to keep you updated.

d1nd141 commented 2 months ago

Had the same issue (cert expired etc) Updated to latest docker image, got an sms from volvo with my new token (6 digits), published to volvoAAOS2mqtt/otp_code end everything up again. Thanks!!

HWiese1980 commented 2 months ago 
Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 536, in _make_request
    response = conn.getresponse()
               ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connection.py", line 464, in getresponse
    httplib_response = super().getresponse()
                       ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 1428, in getresponse
    response.begin()
  File "/usr/lib/python3.12/http/client.py", line 331, in begin
    version, status, reason = self._read_status()
                              ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/http/client.py", line 292, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/socket.py", line 707, in readinto
    return self._sock.recv_into(b)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1252, in recv_into
    return self.read(nbytes, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/ssl.py", line 1104, in read
    return self._sslobj.read(len, buffer)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TimeoutError: The read operation timed out

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

Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 667, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 843, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/retry.py", line 474, in increment
    raise reraise(type(error), error, _stacktrace)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/util/util.py", line 39, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 789, in urlopen
    response = self._make_request(
               ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 538, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/lib/python3.12/site-packages/urllib3/connectionpool.py", line 369, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/volvoAAOS2mqtt/volvo.py", line 428, in backend_status_loop
    get_backend_status()
  File "/volvoAAOS2mqtt/volvo.py", line 435, in get_backend_status
    response = session.get(API_BACKEND_STATUS, timeout=15)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 602, in get
    return self.request("GET", url, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/requests/adapters.py", line 713, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='public-developer-portal-bff.weu-prod.ecpaz.volvocars.biz', port=443): Read timed out. (read timeout=15)

I'm seeing the timeout as well. However, it seems like it is not related to the freeze. The addon just kept working afterwards.

HWiese1980 commented 2 months ago

I got the timeout right now and the addon went into the infamous freeze. Seems to be somewhat related and not fixed, unfortunately. I would recommend reopening this issue. (@Dielee)

Dielee commented 2 months ago

Please provide logs

HWiese1980 commented 2 months ago

Logs with the error are truncated in the UI and the error that lead to the freeze is not visible anymore. Even if I run `ha addons log \<volvo2mqtt slug> there's only so much to see, equally truncated.

The addon logs on the harddisk (addons/volvo2mqtt/logs/...) do not contain any error message for some reason. I do not see why this is the case. Where are the full logs of the addon?