search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.61k stars 30.77k forks source link

Freebox - Access token query problem (infinite loop or nothing at all) #16934

Closed ghost closed 6 years ago

ghost commented 6 years ago

Home Assistant release (hass --version): 0.78.3

Python release (python3 --version): 3.6

Operating environment: Raspberry PI B (Hassio official release) Raspberry PI 3B+ (Hassio official release) Freebox Revolution r2 3.5.4

Component/platform: Backend device_tracker service + Freebox

Description of problem: The freebox device tracker keeps asking for the token. When accepting it, the service poll successfully. But the next query will result in access token approval notification. If it is not accepted the polling will fail with authentication failed.

Log:

2018-09-28 22:49:22 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed client session
2018-09-28 22:49:22 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed connector
2018-09-28 22:49:22 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
await self.fbx.open(self.host, self.port)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 64, in open
self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 101, in _get_freebox_access
app_token, track_id = await self._get_app_token(base_url, app_desc, timeout)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 170, in _get_app_token
raise AuthorizationError('authentification failed')
aiofreepybox.exceptions.AuthorizationError: authentification failed

One error I don't get anymore

Fri Sep 28 2018 20:21:37 GMT+0200 (heure d’été d’Europe centrale)

Error setting up platform freebox
Traceback (most recent call last):
File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/__init__.py", line 179, in async_setup_platform
    hass, p_config, tracker.async_see, disc_info)
File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 51, in async_setup_scanner
    await scanner.async_start(hass, interval)
File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 96, in async_start
    await self.async_update_info()
File "/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
    await self.fbx.open(self.host, self.port)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 64, in open
    self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 132, in _get_freebox_access
    session_token, session_permissions = await self._get_session_token(base_url, app_token, app_desc['app_id'], timeout)
File "/usr/local/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 222, in _get_session_token
    raise AuthorizationError('get_session_token failed')
aiofreepybox.exceptions.AuthorizationError: get_session_token failed

Expected: Only one query to get the access token.

Bonus: Errors should be handled in order to prevent malfunction and repetitive behavior (newbie of HA, may be irrelevant comment)

Problem-relevant configuration.yaml entries and steps to reproduce: Tried discovery and/or explicit configuration.yaml

device_tracker:
    plateform: freebox
    host: "url"
    port: 4567

All result in the same behavior.

Tried chmod 777 on freebox.confand /config/ over ssh. Still no success

MartinHjelmare commented 6 years ago

Please fill in the issue template completely.

ghost commented 6 years ago

Is it enough ?

Can I add anything more to help ?

ghost commented 6 years ago

After a night sleep, I retried. And it works now. Can't find what was wrong or what changes

SNoof85 commented 6 years ago

I've had the issue also in the beginning i used this. But i've been checking it tonight i can confirm also that issue is gone.

SNoof85 commented 6 years ago

More logging added to aiofreepybox and now i have this when bug is here : 

2018-10-13 14:30:54 INFO (MainThread) [homeassistant.loader] Loaded device_tracker.freebox from homeassistant.components.device_tracker.freebox
2018-10-13 14:30:54 INFO (MainThread) [homeassistant.components.device_tracker] Setting up device_tracker.freebox
2018-10-13 14:30:54 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Discovered Freebox server: x1927a3q.fbxos.fr:443
2018-10-13 14:30:54 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Scanning devices
2018-10-13 14:30:54 INFO (MainThread) [aiofreepybox.aiofreepybox] Read application authorization file
2018-10-13 14:30:54 INFO (MainThread) [aiofreepybox.aiofreepybox] No valid authorization file found
Please confirm the authentification on the freebox
2018-10-13 14:31:11 INFO (MainThread) [aiofreepybox.aiofreepybox] Application authorization granted
2018-10-13 14:31:11 INFO (MainThread) [aiofreepybox.aiofreepybox] Application token file was generated : /home/homeassistant/.homeassistant/freebox.conf
2018-10-13 14:31:12 INFO (MainThread) [aiofreepybox.aiofreepybox] Session opened
2018-10-13 14:31:12 INFO (MainThread) [aiofreepybox.aiofreepybox] Permissions: {'parental': False, 'downloader': True, 'settings': False, 'calls': True, 'explorer': True, 'pvr': True, 'tv': True, 'contacts': True}
2018-10-13 14:31:26 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Scanning devices
2018-10-13 14:31:26 INFO (MainThread) [aiofreepybox.aiofreepybox] Read application authorization file
2018-10-13 14:31:26 INFO (MainThread) [aiofreepybox.aiofreepybox] No valid authorization file found
Please confirm the authentification on the freebox
2018-10-13 14:31:38 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Scanning devices
2018-10-13 14:31:38 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed client session
2018-10-13 14:31:38 INFO (MainThread) [aiofreepybox.aiofreepybox] Read application authorization file
2018-10-13 14:31:38 INFO (MainThread) [aiofreepybox.aiofreepybox] No valid authorization file found
2018-10-13 14:31:40 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
    await self.fbx.open(self.host, self.port)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 65, in open
    self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 124, in _get_freebox_access
    raise AuthorizationError('Authorization timed out')
aiofreepybox.exceptions.AuthorizationError: Authorization timed out
2018-10-13 14:31:40 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed connector
Please confirm the authentification on the freebox
2018-10-13 14:31:50 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Scanning devices
2018-10-13 14:31:50 INFO (MainThread) [aiofreepybox.aiofreepybox] Read application authorization file
2018-10-13 14:31:50 INFO (MainThread) [aiofreepybox.aiofreepybox] No valid authorization file found
Please confirm the authentification on the freebox
2018-10-13 14:31:53 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
    await self.fbx.open(self.host, self.port)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 65, in open
    self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 124, in _get_freebox_access
    raise AuthorizationError('Authorization timed out')
aiofreepybox.exceptions.AuthorizationError: Authorization timed out
2018-10-13 14:32:03 INFO (MainThread) [homeassistant.components.device_tracker.freebox] Scanning devices
2018-10-13 14:32:03 INFO (MainThread) [aiofreepybox.aiofreepybox] Read application authorization file
2018-10-13 14:32:03 INFO (MainThread) [aiofreepybox.aiofreepybox] No valid authorization file found
2018-10-13 14:32:03 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
    await self.fbx.open(self.host, self.port)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 65, in open
    self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 103, in _get_freebox_access
    app_token, track_id = await self._get_app_token(base_url, app_desc, timeout)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 173, in _get_app_token
    .format(json.dumps(resp)))
aiofreepybox.exceptions.AuthorizationError: Authorization failed (APIResponse: {"msg": "Erreur interne", "success": false, "error_code": "internal_error"})
2018-10-13 14:32:06 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/freebox.py", line 106, in async_update_info
    await self.fbx.open(self.host, self.port)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 65, in open
    self._access = await self._get_freebox_access(host, port, self.api_version, self.token_file, self.app_desc, self.timeout)
  File "/srv/homeassistant/lib/python3.6/site-packages/aiofreepybox/aiofreepybox.py", line 124, in _get_freebox_access
    raise AuthorizationError('Authorization timed out')
aiofreepybox.exceptions.AuthorizationError: Authorization timed out

On the 1st auth request i authorized it on the router then we can see the freebox.conf is generated but on the second scan try it's not readen and ask again on the router.

SNoof85 commented 6 years ago

I've been able to reproduce and stop the bug but i don't know how to solve... When the 1st auth token is asked to the router and we confirm the access on the router screen, the freebox.conf file is generated. Then it should be readen by home assistant to use it to connect to the router. But it's not found...(see the logs). If I stop HASS, the start it back, the file is readen and used to connect to the freebox. Why this file is not readable without a reboot ? i don't know, i'm far from HASS code expert. If someone with good knowledge could help out then it would be very nice !

SNoof85 commented 6 years ago

This was due to a dict wich was updated to write the token file. Then the dict was compared to another one to check the token_file integrity. The bug is only present at the first token ask on the freebox. (to avoid it, start HASS, authorize on the router then restart HASS)

It has to be fixed in the aiofreepybox project. I made a PR, then the code owner @stilllman will have to publish a new version on PyPI and then PR here to close this issue. By the way, new methods in aiofreepybox have been implemented to get more functions with freebox in HASS (PR will follow as soon as the new PyPI version will be in HASS)