core: 0.103.1 Failed to start after upgrade - Traceback errors and Core errors

Home Assistant release with the issue:

0.103.1

Last working Home Assistant release (if known): 0.103.0

Operating environment (Hass.io/Docker/Windows/etc.):

Linux VM

Integration:

Description of problem: Frontend will not load… Service is running, just cannot log in. No changes were made prior to upgrade.

Did discover Cell phones via HA App so not sure if the old device name is the issue as I saw this was corrected in 0.103.1 ???

Log file attached: Log.txt

Didnt have the issue when upgrading to 0.103.0

—Restoring VM SnapShot to recover…

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

Traceback (if applicable):

● home-assistant@homeassistant.service - Home Assistant
   Loaded: loaded (/etc/systemd/system/home-assistant@homeassistant.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2019-12-18 16:54:32 CST; 3min 9s ago
 Main PID: 601 (hass)
    Tasks: 29 (limit: 4915)
   CGroup: /system.slice/system-home\x2dassistant.slice/home-assistant@homeassistant.service
           └─601 /srv/homeassistant/bin/python3.7 /srv/homeassistant/bin/hass

Dec 18 16:57:39 HA hass[601]: 2019-12-18 16:57:39 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Dec 18 16:57:39 HA hass[601]: Traceback (most recent call last):
Dec 18 16:57:39 HA hass[601]:   File "/srv/homeassistant/lib/python3.7/site-packages/zigpy/device.py", line 184, in request
Dec 18 16:57:39 HA hass[601]:     self.nwk, dst_ep, cluster
Dec 18 16:57:39 HA hass[601]: zigpy.exceptions.DeliveryError: [0xcaac:0:0x8000]: Message send failure
Dec 18 16:57:42 HA hass[601]: 2019-12-18 16:57:42 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Dec 18 16:57:42 HA hass[601]: Traceback (most recent call last):
Dec 18 16:57:42 HA hass[601]:   File "/srv/homeassistant/lib/python3.7/site-packages/zigpy/device.py", line 184, in request
Dec 18 16:57:42 HA hass[601]:     self.nwk, dst_ep, cluster
Dec 18 16:57:42 HA hass[601]: zigpy.exceptions.DeliveryError: [0xcaac:0:0x8000]: Message send failure
homeassistant@HA:~$

Additional information:

About this issue

Original URL
State: closed
Created 5 years ago
Reactions: 20
Comments: 32 (16 by maintainers)

Commits related to this issue

103.1 is broken home-assistant/home-assistant#30060 — committed to mdonoughe/home by mdonoughe 5 years ago

Most upvoted comments

Sorry about this. 103.2 has been released. Thanks to @panctronic for findig the fix.

+11

balloob on Dec 19, 2019

0.103.1 also stalls on start for me. Had to update docker-compose.yaml to:

image: "homeassistant/home-assistant:0.103.0"

jshank on Dec 19, 2019

Chiming in to say 0.103.0 worked in docker, while 0.103.1 seems to be stalling during startup. It’s been stuck at 100% CPU for ~2-3 minutes now. It starts a listener for tcp/1400 (SONOS discovery iirc), but not for tcp/80 (my configuration for Http listener).

It could be an infinite loop, given the look-a-like memory leak

Logs show no fun stuff that wasn’t in 0.103.0.

EDIT: I’ve been unsucessful in acquiring a stackdump of the python process. I’ve tried using pyrasite to no avail. I’ll be reverting to 0.103.0 before my server cries help. It’s at 1GB memory and rising now, after 14 minutes runtime, with cpu never dropping below 100%.

LordMike on Dec 19, 2019

@balloob is it possible to manually push the 0.103.2 to the docker hub? or do we have to wait until tomorrow?

nicx on Dec 19, 2019

+1, encountered the same startup issue with docker. Reverting to the 0.103.0 tag fixed it.

Please consider moving the stable tag back to this release until the problem can be diagnosed.

jheidel on Dec 19, 2019

Same thing as ocalvo, no cloud-polling integrations even after reverting to 0.103.0:

2019-12-18 21:04:37 ERROR (MainThread) [homeassistant.components.iqvia] Unable to get allergy_outlook data: Error requesting data from https://www.pollen.com/api/forecast/outlook: 500, message='Internal Server Error', url='https://www.pollen.com/api/forecast/outlook/94024
2019-12-18 21:04:50 ERROR (SyncWorker_35) [pyecobee] Error while refreshing tokens from ecobee: 400: {'error': 'invalid_grant', 'error_description': 'The authorization grant, token or credentials are invalid, expired, revoked, do not match the redirection URI used in the authorization request, or was issued to another client.', 'error_uri': 'https://tools.ietf.org/html/rfc6749#section-5.2'}
2019-12-18 21:04:50 ERROR (MainThread) [homeassistant.components.ecobee] Error updating ecobee tokens
2019-12-18 21:04:52 ERROR (SyncWorker_22) [homeassistant.components.ring] Unable to connect to Ring service: 401 Client Error: Unauthorized for url: https://api.ring.com/clients_api/session
2019-12-18 21:04:52 ERROR (MainThread) [homeassistant.setup] Setup failed for ring: Integration failed to initialize.

dooz127 on Dec 19, 2019

Same on my side, after upgrading to 0.103.1 (docker), HA isn’t starting anymore. No error in my log, just HA using 100% CPU and memory increase…

The previous 0.103.0 version works fine.

LucasJanin on Dec 19, 2019

Latest (0.103.2) docker image works OK.

daemongloom on Dec 19, 2019

It takes only 1h30m for a new release to be online. Almost all of them are done: https://dev.azure.com/home-assistant/Home Assistant/_build/results?buildId=20453&view=results

Depending on your timezone, that could be tomorrow though

balloob on Dec 19, 2019

Hang tight everyone; this is likely related to https://github.com/home-assistant/home-assistant/pull/29491 (released in 0.103.1). Will need @balloob to look into it once he returns.

bachya on Dec 19, 2019

@balloob Is this related to #29491 that was included in this release?

sqldiablo on Dec 19, 2019

The cloud-based integrations are still broken with 103.2:

SmartThings:

Thu Dec 19 2019 08:45:47 GMT-0500 (Eastern Standard Time)
Error setting up entry Home for smartthings
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 192, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/smartthings/__init__.py", line 110, in async_setup_entry
    entry.data[CONF_REFRESH_TOKEN],
  File "/usr/local/lib/python3.7/site-packages/pysmartthings/smartthings.py", line 202, in generate_tokens
    client_id, client_secret, refresh_token)
  File "/usr/local/lib/python3.7/site-packages/pysmartthings/api.py", line 417, in generate_tokens
    raise APIInvalidGrant(data.get('error_description'))
pysmartthings.errors.APIInvalidGrant: Invalid refresh token: bcc0f2ec-d5be-44f0-8a00-b8ce6738e5f5

Ring:

Thu Dec 19 2019 08:46:03 GMT-0500 (Eastern Standard Time)
Unable to connect to Ring service: 403 Client Error: Forbidden for url: https://api.ring.com/clients_api/session

Scope666 on Dec 19, 2019

I find hard to beleive that these 3 integrations failed at the same time: Ecobee:

2019-12-18 16:38:20 ERROR (SyncWorker_9) [pyecobee] Error while refreshing tokens from ecobee: 400: {'error': 'invalid_grant', 'error_description': 'The authorization grant, token or credentials are invalid, expired, revoked, do not match the redirection URI used in the authorization request, or was issued to another client.', 'error_uri': 'https://tools.ietf.org/html/rfc6749#section-5.2'}
2019-12-18 16:38:23 ERROR (MainThread) [homeassistant.components.ecobee] Error updating ecobee tokens

Smartthings

2019-12-18 16:38:31 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Duvall for smartthings
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 192, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/smartthings/__init__.py", line 110, in async_setup_entry
    entry.data[CONF_REFRESH_TOKEN],
  File "/usr/local/lib/python3.7/site-packages/pysmartthings/smartthings.py", line 202, in generate_tokens
    client_id, client_secret, refresh_token)
  File "/usr/local/lib/python3.7/site-packages/pysmartthings/api.py", line 417, in generate_tokens
    raise APIInvalidGrant(data.get('error_description'))
pysmartthings.errors.APIInvalidGrant: Invalid refresh token: d96d9ba4-eff7-4e68-909b-f4900d66ba1b

Ring:

2019-12-18 16:38:31 ERROR (SyncWorker_15) [homeassistant.components.ring] Unable to connect to Ring service: 401 Client Error: Unauthorized for url: https://api.ring.com/clients_api/session
2019-12-18 16:38:31 ERROR (MainThread) [homeassistant.setup] Setup failed for ring: Integration failed to initialize.

ocalvo on Dec 19, 2019

After the rollback my ecobee, smartthings and ring integrations cannot longer connect because of invalid credentials.

ocalvo on Dec 19, 2019

https://github.com/home-assistant/home-assistant/commit/ec8ea022731b762481c2c88e1b14b4c9561c0b19#diff-5d2c9ff6d430c1e32f280e40a3dc275a fixes this problem

panctronic on Dec 18, 2019

Seems like it’s getting stuck in a loop processing requirements:

When KeyboardInterrupting /srv/homeassistant/bin/hass --debug -c .

File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/requirements.py", line 49, in async_get_integration_with_requirements
    hass, integration.domain, integration.requirements
  File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/requirements.py", line 80, in async_process_requirements
    if pkg_util.is_installed(req):
  File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/util/package.py", line 45, in is_installed
    return version(req.project_name) in req
  File "/srv/homeassistant/lib/python3.7/site-packages/importlib_metadata/__init__.py", line 516, in version
    return distribution(distribution_name).version
  File "/srv/homeassistant/lib/python3.7/site-packages/importlib_metadata/__init__.py", line 489, in distribution
    return Distribution.from_name(distribution_name)
  File "/srv/homeassistant/lib/python3.7/site-packages/importlib_metadata/__init__.py", line 190, in from_name
    dist = next(dists, None)
  File "/srv/homeassistant/lib/python3.7/site-packages/importlib_metadata/__init__.py", line 460, in <genexpr>
    if cls._matches_info(normalized, item)
  File "/srv/homeassistant/lib/python3.7/site-packages/importlib_metadata/__init__.py", line 445, in _matches_info
    manifest = template.format(pattern=normalized)
KeyboardInterrupt

I added a bit of debug logging and it looks like async_process_requirements is being called repeatedly for name=http, requirements=aiohttp_cors.

2019-12-18 18:31:01 INFO (MainThread) [homeassistant.requirements] process req http ['aiohttp_cors==0.7.0']

panctronic on Dec 18, 2019