Evohome fails to initialize - {"error":"invalid_grant"}

[bigbigblue]

Home Assistant release with the issue:

0.97.2

Last working Home Assistant release (if known):

Operating environment (Hass.io/Docker/Windows/etc.): Hassio Supervisor version 181 Component/platform: Evohome Component

Evohome component fails to initialize with following :
Failed to (re)authenticate with the vendor's server. 
Check that your username and password are correct. 
Message is: Unable to obtain an Access Token, hint: {"error":"invalid_grant"}

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

From config.yaml:
evohome: !include evohome.yaml

from evohome.yaml:
  username: !secret evohomeusername
  password: !secret evohomepassword
  scan_interval: 120

Traceback (if applicable):

Additional information:

I know the userid and password are correct as I can logon to the TCC website by copying and pasting the relevant 'secrets' from my secrets.yaml file

Occurs on calling the 'homeassistant.restart' service and also on a reboot of the system.

[zxdavb]

Hi,

I am the CODEOWNER for this integration and should be able to help you. This issue was previously caused by problems with the tokens...

Please add the following to your configuration.yaml:

logger:
## turn off debug messages, generally...
  default: warn

  logs:
    homeassistant.components.evohome: debug
#   homeassistant.components.climate.evohome: debug
#   homeassistant.components.water_heater.evohome: debug
    evohomeclient2: debug

... then restart HA, and provide me with the output of the following:

cat homeassistant.log | grep evohomeclient

[zxdavb]

This was also a known bug with previous versions of the evohomeclient library, so can you confirm you're running 0.3.3 and not 0.3.2:

pip list | grep evohome

[bigbigblue]

the pip command just gives: -bash: pip: command not found I wonder if this is because it is a Hassio installation?

The relevant output from the homeassistant.log is

2019-08-20 18:16:50 DEBUG (SyncWorker_17) [evohomeclient2] Debug mode is not explicitly enabled (but may be enabled elsewhere).
2019-08-20 18:16:50 DEBUG (SyncWorker_17) [evohomeclient2] No/Expired/Invalid access_token, re-authenticating...
2019-08-20 18:16:50 DEBUG (SyncWorker_17) [evohomeclient2] Trying refresh_token...
2019-08-20 18:16:51 ERROR (SyncWorker_17) [homeassistant.components.evohome] Failed to (re)authenticate with the vendor's server. Check that your username and password are correct. Message is: Unable to obtain an Access Token, hint: {"error":"invalid_grant"}
2019-08-20 18:16:51 ERROR (MainThread) [homeassistant.setup] Setup failed for evohome: Integration failed to initialize.

Hope this helps.

[cogneato]

@bigbigblue When running the hassio environment you'd have to run that from within the homeassistant container. I did just now and can confirm 3.3 though I don't use evohome myself.

[bigbigblue]

cognate, Thanks the result is :

bash-5.0# pip list | grep evohomeclient evohomeclient 0.3.3

[zxdavb]

Well your log shows a bug that existed in 0.3.2 & not 0.3.3, so dunno - let me have a think on it....

[zxdavb]

@bigbigblue I would love to have you run a modified version of the evohomeclient. Are you up for that?

You'd have to make changes to .../evohomeclient2/__init__.py, and send me another set of logs.

[bigbigblue]

I am up for that if I can actually change it under HASSIO. I might need some help to make the changes. Cheers

[zxdavb]

I dunno how to do that, sorry, I only ever use a dev environment. How desperate are you to get back up?.

[bigbigblue]

Not hugely desparate as the weather is warm and I don't need to control my heating system as it is mostly off at the moment, BUT I am happy to do whatever will help solve the problem - if I can. In what folder would evohomeclient2 normally be found?

[bigbigblue]

Found it in: /usr/local/lib/python3.7/site-packages/evohomeclient2/ What changes do you want me to make?

[zxdavb]

Woah - that is odd:

_LOGGER.debug("Trying refresh_token...")

exists only in evohomeclient-0.3.2, which has a bug that would cause your problem. In evohomeclient-0.3.3 there is:

_LOGGER.debug("Authenticating with the refresh_token...")

But your log said: Trying refresh_token...

[zxdavb]

So try:

cd /usr/local/
cat lib/python3.6/site-packages/evohomeclient2/__init__.py | grep 'if self.refresh_token' -A 2

[bigbigblue]

The result of that command is:

        if self.refresh_token:
            _LOGGER.debug("Authenticating with the refresh_token...")
            credentials = {'grant_type': "refresh_token",`

[zxdavb]

Yea, sorry - fixed typo, above.

Anyway, your log deffo said: Trying refresh_token..., right?

So can you try:

pip install --upgrade evohomeclient --force

(I dunno how to do this is HASS.IO)

[bigbigblue]

The pip command results in

bash-5.0# pip install --upgrade evohomeclient --force
Collecting evohomeclient
  Downloading https://files.pythonhosted.org/packages/59/f0/f4f5a49cf1370a9af9bf8449ad3b73ea0206e30647cfa9013bb79e6ffc70/evohomeclient-0.3.3-py3-none-any.whl
Collecting requests (from evohomeclient)
  Downloading https://files.pythonhosted.org/packages/51/bd/23c926cd341ea6b7dd0b2a00aba99ae0f828be89d72b2190f27c11d4b7fb/requests-2.22.0-py2.py3-none-any.whl (57kB)
     |████████████████████████████████| 61kB 2.1MB/s
Collecting certifi>=2017.4.17 (from requests->evohomeclient)
  Downloading https://files.pythonhosted.org/packages/69/1b/b853c7a9d4f6a6d00749e94eb6f3a041e342a885b87340b79c1ef73e3a78/certifi-2019.6.16-py2.py3-none-any.whl (157kB)
     |████████████████████████████████| 163kB 4.9MB/s
Collecting idna<2.9,>=2.5 (from requests->evohomeclient)
  Downloading https://files.pythonhosted.org/packages/14/2c/cd551d81dbe15200be1cf41cd03869a46fe7226e7450af7a6545bfc474c9/idna-2.8-py2.py3-none-any.whl (58kB)
     |████████████████████████████████| 61kB 5.8MB/s
Collecting chardet<3.1.0,>=3.0.2 (from requests->evohomeclient)
  Downloading https://files.pythonhosted.org/packages/bc/a9/01ffebfb562e4274b6487b4bb1ddec7ca55ec7510b22e4c51f14098443b8/chardet-3.0.4-py2.py3-none-any.whl (133kB)
     |████████████████████████████████| 143kB 8.8MB/s
Collecting urllib3!=1.25.0,!=1.25.1,<1.26,>=1.21.1 (from requests->evohomeclient)
  Downloading https://files.pythonhosted.org/packages/e6/60/247f23a7121ae632d62811ba7f273d0e58972d75e58a94d329d51550a47d/urllib3-1.25.3-py2.py3-none-any.whl (150kB)
     |████████████████████████████████| 153kB 9.2MB/s
ERROR: wirelesstagpy 0.4.0 has requirement colorlog==3.0.1, but you'll have colorlog 4.0.2 which is incompatible.
ERROR: upsmychoice 1.0.6 has requirement beautifulsoup4==4.5.1, but you'll have beautifulsoup4 4.7.1 which is incompatible.
ERROR: upsmychoice 1.0.6 has requirement python-dateutil==2.6.0, but you'll have python-dateutil 2.8.0 which is incompatible.
ERROR: upsmychoice 1.0.6 has requirement requests==2.12.4, but you'll have requests 2.22.0 which is incompatible.
ERROR: toonapilib 3.2.4 has requirement cachetools~=3.1.1, but you'll have cachetools 2.0.1 which is incompatible.
ERROR: toonapilib 3.2.4 has requirement requests~=2.21.0, but you'll have requests 2.22.0 which is incompatible.
ERROR: skybellpy 0.4.0 has requirement colorlog==3.0.1, but you'll have colorlog 4.0.2 which is incompatible.
ERROR: roku 3.1 has requirement requests<2.11,>=2.10, but you'll have requests 2.22.0 which is incompatible.
ERROR: pyrebase4 4.3.0 has requirement oauth2client==4.1.2, but you'll have oauth2client 4.0.0 which is incompatible.
ERROR: pyicloud 0.9.1 has requirement click<7.0,>=6.0, but you'll have click 7.0 which is incompatible.
ERROR: pyicloud 0.9.1 has requirement keyring<9.0,>=8.0, but you'll have keyring 17.1.1 which is incompatible.
ERROR: pyicloud 0.9.1 has requirement keyrings.alt<2.0,>=1.0, but you'll have keyrings-alt 3.1.1 which is incompatible.
ERROR: openwrt-luci-rpc 1.1.0 has requirement requests==2.21.0, but you'll have requests 2.22.0 which is incompatible.
ERROR: myusps 1.3.2 has requirement beautifulsoup4==4.6.0, but you'll have beautifulsoup4 4.7.1 which is incompatible.
ERROR: myusps 1.3.2 has requirement python-dateutil==2.6.0, but you'll have python-dateutil 2.8.0 which is incompatible.
ERROR: myusps 1.3.2 has requirement requests==2.12.4, but you'll have requests 2.22.0 which is incompatible.
ERROR: myusps 1.3.2 has requirement requests-cache==0.4.13, but you'll have requests-cache 0.5.0 which is incompatible.
ERROR: motorparts 1.1.0 has requirement beautifulsoup4==4.5.1, but you'll have beautifulsoup4 4.7.1 which is incompatible.
ERROR: locationsharinglib 4.0.2 has requirement requests~=2.21.0, but you'll have requests 2.22.0 which is incompatible.
ERROR: ibm-watson 3.0.3 has requirement websocket-client==0.48.0, but you'll have websocket-client 0.54.0 which is incompatible.
ERROR: http3 0.6.7 has requirement h2==3.*, but you'll have h2 2.6.2 which is incompatible.
ERROR: hipnotify 1.0.8 has requirement requests==2.9.1, but you'll have requests 2.22.0 which is incompatible.
ERROR: fedexdeliverymanager 1.0.6 has requirement beautifulsoup4==4.5.1, but you'll have beautifulsoup4 4.7.1 which is incompatible.
ERROR: fedexdeliverymanager 1.0.6 has requirement python-dateutil==2.6.0, but you'll have python-dateutil 2.8.0 which is incompatible.
ERROR: eebrightbox 0.0.4 has requirement certifi==2018.11.29, but you'll have certifi 2019.6.16 which is incompatible.
ERROR: eebrightbox 0.0.4 has requirement requests==2.21.0, but you'll have requests 2.22.0 which is incompatible.
ERROR: eebrightbox 0.0.4 has requirement urllib3==1.24.1, but you'll have urllib3 1.25.3 which is incompatible.
ERROR: botocore 1.12.91 has requirement urllib3<1.25,>=1.20; python_version >= "3.4", but you'll have urllib3 1.25.3 which is incompatible.
ERROR: blinkpy 0.14.1 has requirement python-dateutil==2.7.5, but you'll have python-dateutil 2.8.0 which is incompatible.
ERROR: abodepy 0.15.0 has requirement colorlog==3.0.1, but you'll have colorlog 4.0.2 which is incompatible.
Installing collected packages: certifi, idna, chardet, urllib3, requests, evohomeclient
  Found existing installation: certifi 2019.6.16
    Uninstalling certifi-2019.6.16:
      Successfully uninstalled certifi-2019.6.16
  Found existing installation: idna 2.8
    Uninstalling idna-2.8:
      Successfully uninstalled idna-2.8
  Found existing installation: chardet 3.0.4
    Uninstalling chardet-3.0.4:
      Successfully uninstalled chardet-3.0.4
  Found existing installation: urllib3 1.25.3
    Uninstalling urllib3-1.25.3:
      Successfully uninstalled urllib3-1.25.3
  Found existing installation: requests 2.22.0
    Uninstalling requests-2.22.0:
      Successfully uninstalled requests-2.22.0
  Found existing installation: evohomeclient 0.3.3
    Uninstalling evohomeclient-0.3.3:
      Successfully uninstalled evohomeclient-0.3.3
Successfully installed certifi-2019.6.16 chardet-3.0.4 evohomeclient-0.3.3 idna-2.8 requests-2.22.0 urllib3-1.25.3

[zxdavb]

... and restart HA?

[bigbigblue]

Restart of HA results in :

2019-08-20 21:05:30 DEBUG (SyncWorker_14) [evohomeclient2] Debug mode is not explicitly enabled (but may be enabled elsewhere).
2019-08-20 21:05:30 DEBUG (SyncWorker_14) [evohomeclient2] No/Expired/Invalid access_token, re-authenticating...
2019-08-20 21:05:30 DEBUG (SyncWorker_14) [evohomeclient2] Trying refresh_token...
2019-08-20 21:05:31 ERROR (SyncWorker_14) [homeassistant.components.evohome] Failed to (re)authenticate with the vendor's server. Check that your username and password are correct. Message is: Unable to obtain an Access Token, hint: {"error":"invalid_grant"}

[bigbigblue]

If I understand correctly, HA is picking up the wrong version of the evohomeclient python code, even though the correct version is there?

[zxdavb]

@bigbigblue Yes, and no.

The log messages indicate that HA is using evohome-0.3.2 (Trying refresh_token...), which is persisting despite pip install --upgrade evohomeclient --force

You could try:

cd /usr/local/
rm -rf lib/python3.7/site-packages/evohomeclient2/__pycache__/

... but I suspect it won't fix your problem. I don't know where HASS.IO stores its python libraries - the ones it is using could be elsewhere in the filesystem.

Anyway, I am sorry, I cannot help you further - I am closing this issue.

[zxdavb]

If you do get HASS.IO to use version 0.3.3, then evohome should just start working again.

[bigbigblue]

If I invoke python from the command line, it tells me it is running Python 2.7.16 (default, Apr 6 2019, 01:42:57)

But evohomeclient2 is in the path for python 3.6

[zxdavb]

HASS.IO uses python 3.x, but several versions of python can exists on a single system, and several sets of libraries for each version... ... it's a hell.

try searching your entire file system for a folder called evohomeclient-0.3.2.dist-info.

[zxdavb]

sorry, typo: evohomeclient-0.3.2.dist-info

[bigbigblue]

For info : the find command found this :

/usr/share/hassio/homeassistant/deps/lib/python3.7/site-packages/evohomeclient
/usr/share/hassio/homeassistant/deps/lib/python3.7/site-packages/evohomeclient-0.3.2.dist-info
/usr/share/hassio/homeassistant/deps/lib/python3.7/site-packages/evohomeclient2

[bigbigblue]

but how to force an upgrade to 0.3.3?

[zxdavb]

Maybe ask on HASS.IO forum? https://community.home-assistant.io/c/hass-io

[bigbigblue]

Thanks for you help - much appreciated