search

arjenbos / ha-postnl

Custom PostNL Home Assistant integration
Apache License 2.0
31 stars 2 forks source link

Integration stops working #19

Open brhahlen opened 7 months ago

brhahlen commented 7 months ago

After setting up the integration, it will stop working after some time. Error being thrown:

Logger: homeassistant.config_entries
Source: config_entries.py:504
First occurred: 11:20:46 (2 occurrences)
Last logged: 15:40:41

Error setting up entry <id> for postnl
Traceback (most recent call last):
  File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token
    await self.oauth_session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 519, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 94, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 184, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 217, in _token_request
    resp.raise_for_status()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 1060, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://login.postnl.nl/<id>/login/token')

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 504, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry
    await auth.check_and_refresh_token()
  File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token
    raise HomeAssistantError(exception) from exception
homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url=URL('https://login.postnl.nl/<id>/login/token')

Also getting:

Logger: homeassistant.helpers.config_entry_oauth2_flow
Source: helpers/config_entry_oauth2_flow.py:211
First occurred: 11:20:46 (2 occurrences)
Last logged: 15:40:41

Token request for postnl_postnl failed (invalid_grant): refresh_token is invalid
arjenbos commented 7 months ago

Could you please enable debugging for the integration and share the debug log?

brhahlen commented 7 months ago 
2024-04-03 17:09:57.975 DEBUG (MainThread) [custom_components.postnl] Setup Entry PostNL
2024-04-03 17:09:58.463 ERROR (MainThread) [homeassistant.helpers.config_entry_oauth2_flow] Token request for postnl_postnl failed (invalid_grant): refresh_token is invalid
2024-04-03 17:09:58.463 DEBUG (MainThread) [custom_components.postnl] API error: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')
2024-04-03 17:09:58.466 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry deb0a372-6d72-4e09-83fe-997beacbd137 for postnl
Traceback (most recent call last):
  File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token
    await self.oauth_session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 519, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 94, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 184, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 217, in _token_request
    resp.raise_for_status()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 1060, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 504, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry
    await auth.check_and_refresh_token()
  File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token
    raise HomeAssistantError(exception) from exception
homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')

Guess this should be it

brhahlen commented 7 months ago

Enabled debug logging from the UI and reloaded the plugin:


2024-04-04 09:38:04.340 ERROR (MainThread) [homeassistant.helpers.config_entry_oauth2_flow] Token request for postnl_postnl failed (invalid_grant): refresh_token is invalid
2024-04-04 09:38:04.341 DEBUG (MainThread) [custom_components.postnl] API error: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')
2024-04-04 09:38:04.344 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry deb0a372-6d72-4e09-83fe-997beacbd137 for postnl
Traceback (most recent call last):
  File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token
    await self.oauth_session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 523, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 94, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 184, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 217, in _token_request
    resp.raise_for_status()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 1060, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 551, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry
    await auth.check_and_refresh_token()
  File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token
    raise HomeAssistantError(exception) from exception
homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')```
brhahlen commented 7 months ago

Just reauthenticated after installing latest version. Will let you know if the issue occurs again

arjenbos commented 7 months ago

Thanks for sharing the logs. Unfortunately they aren't very helpful. Bad request can mean a lot of things and I want to pin point what the actual problem is. If it happens again, then I will add some extra logging in the integration.

poudenes commented 6 months ago

Since today have same issue

2024-05-02 08:40:43.909 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry PostNL for postnl
Traceback (most recent call last):
  File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token
    await self.oauth_session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 523, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 94, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 184, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 217, in _token_request
    resp.raise_for_status()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 1070, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-SNAP-2f1b2d370d7c/login/token')

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 575, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry
    await auth.check_and_refresh_token()
  File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token
    raise HomeAssistantError(exception) from exception
homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-SNAP-2f1b2d370d7c/login/token')

checked the URL in browser and get a error

{
    "error": "Requested endpoint is forbidden"
}
arjenbos commented 6 months ago

@poudenes fyi: no need to change the URL in your error log. It's hard coded in the code. It's only needed when there is a track and trace or postal code in the get URL.

Could you please reload (and if that doesn't work reinstall) the integration?

brhahlen commented 5 months ago

@arjenbos Just happened to me again, when restarting HomeAssistant:

Logger: homeassistant.config_entries
Source: config_entries.py:584
First occurred: 15:57:01 (2 occurrences)
Last logged: 16:18:53

Error setting up entry deb0a372-6d72-4e09-83fe-997beacbd137 for postnl
Traceback (most recent call last):
  File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token
    await self.oauth_session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 523, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 94, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 184, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 217, in _token_request
    resp.raise_for_status()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 1070, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 584, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry
    await auth.check_and_refresh_token()
  File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token
    raise HomeAssistantError(exception) from exception
homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url=URL('https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token')
arjenbos commented 5 months ago

Alright, hopefully I can debug it when I have time. Looks like a retrieving a new access token breaks for some reason. I assume due to an invalid refresh token.

IIIdefconIII commented 5 months ago

same here, maybe i messed up something myself do

thoompje commented 3 months ago

Same issue here.

IIIdefconIII commented 3 months ago

i have to restart my server to get it running again and kinda randomly disconnect, some times it even doesnt show up anymore, i have the same isseu for several weeks now but i tought the project is not beein maintenced anymore.

@arjenbos any updates? have a good one!

arjenbos commented 3 months ago

This issue is really odd. I never had it and i'm hoping that I will get it. Now, I can't really debug it with the limited amount of information. Of course, I know where in the code this happens, but I don't know why. Why does PostNL return a Bad Request response?

Hopefully I get the same issue as well, so I can start fixing it.

IIIdefconIII commented 3 months ago

Let me know if u need a tester I'm all here

jonisnet commented 2 months ago

Maybe this debug log will help.


2024-08-19 16:35:36.312 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration postnl which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

2024-08-19 16:35:51.357 DEBUG (MainThread) [custom_components.postnl] Setup Entry PostNL

2024-08-19 16:36:01.924 ERROR (MainThread) [homeassistant.helpers.config_entry_oauth2_flow] Token request for postnl_pietje failed (invalid_grant): refresh_token is invalid

2024-08-19 16:36:01.925 DEBUG (MainThread) [custom_components.postnl] API error: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'

2024-08-19 16:36:01.944 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry deb0a372-6d72-4e09-83fe-997beacbd137 for postnl

File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token

aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'

File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry

File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token

homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'

2024-08-19 16:36:59.769 DEBUG (MainThread) [custom_components.postnl] Setup Entry PostNL

2024-08-19 16:36:59.862 ERROR (MainThread) [homeassistant.helpers.config_entry_oauth2_flow] Token request for postnl_pietje failed (invalid_grant): refresh_token is invalid

2024-08-19 16:36:59.863 DEBUG (MainThread) [custom_components.postnl] API error: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'

2024-08-19 16:36:59.865 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry deb0a372-6d72-4e09-83fe-997beacbd137 for postnl

File "/config/custom_components/postnl/__init__.py", line 92, in check_and_refresh_token

aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'

File "/config/custom_components/postnl/__init__.py", line 35, in async_setup_entry

File "/config/custom_components/postnl/__init__.py", line 98, in check_and_refresh_token

homeassistant.exceptions.HomeAssistantError: 400, message='Bad Request', url='https://login.postnl.nl/101112a0-4a0f-4bbb-8176-2f1b2d370d7c/login/token'
IIIdefconIII commented 2 months ago

mm i wonder if some add blocker or my internet seutiy suite i blocking this and will check this tomorrow thanks for ur reply!

arjenbos commented 2 months ago

I finally had the same issue on my dev env. The logs state that the refresh token is invalid/expired. The core of Home Assistant should take care of refreshing the refresh token after every request, but for some reason HA fails in refreshing the refresh token in your installation. In my installation, I never encounter this problem.

oAuth2 clearly states that if the refresh token is invalid, then a new authorization needs to take place. This is what I will change in the code, but it will only request you to re-auth the PostNL integration. Since there is NO valid refresh or access token, we need to re-auth the integration.

I will change the main branch and not release the code yet. Hopefully you can checkout the main branch and see what happens. Also, maybe check if the integration is running twice and it's using the same refresh_token for multiple instances.

If a refresh token expires for any reason, then the only action the application can take is to ask the user to log in again, starting a new OAuth flow from scratch, which will issue a new access token and refresh token to the application. That’s the reason it doesn’t matter whether the application knows the expected lifetime of the refresh token, because regardless of the reason it expires the outcome is always the same.

Source: https://www.oauth.com/oauth2-servers/making-authenticated-requests/refreshing-an-access-token/

Please be aware that if you run your HA multiple times with the same DB (for some reason), then HA uses the refresh token twice, and the refresh token should be revoked.

When the refresh token changes after each use, if the authorization server ever detects a refresh token was used twice, it means it has likely been copied and is being used by an attacker, and the authorization server can revoke all access tokens and refresh tokens associated with it immediately.

Source: https://www.oauth.com/oauth2-servers/making-authenticated-requests/refreshing-an-access-token/

It has nothing to do with an ad blocker or security suite.

IIIdefconIII commented 2 months ago

This sounds perfect the devs are working on it. Thank you many many times