0.103.1 Failed to start after upgrade - Traceback errors and Core errors #30060

WedHumpDay · 2019-12-18T23:06:40Z

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:

The text was updated successfully, but these errors were encountered:

VDRainer · 2019-12-18T23:18:04Z

I have, except of two kodi's that are off, absolute no errors in debug log.

arsaboo · 2019-12-18T23:19:13Z

Experiencing the same on venv (Python 3.7).

DavidFW1960 · 2019-12-18T23:35:55Z

same with hassio... the NUC image and also qemux86 image (HassOS in Proxmox)
Logs
Proxmox HassOS https://codeshare.io/24LBzd
NUC Hassio https://codeshare.io/alVOmD

panctronic · 2019-12-18T23:36:55Z

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 · 2019-12-18T23:42:41Z

ec8ea02#diff-5d2c9ff6d430c1e32f280e40a3dc275a fixes this problem

home-assistant/core#30060

LordMike · 2019-12-19T00:27:08Z

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%.

ocalvo · 2019-12-19T00:33:09Z

My update was reverted back:

19-12-19 00:16:09 WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!
19-12-19 00:16:09 CRITICAL (MainThread) [hassio.homeassistant] HomeAssistant update fails -> rollback!
19-12-19 00:16:09 INFO (MainThread) [hassio.homeassistant] Update Home Assistant to version 0.103.0
19-12-19 00:16:09 INFO (SyncWorker_18) [hassio.docker.interface] Update image homeassistant/raspberrypi4-homeassistant:0.103.1 to homeassistant/raspberrypi4-homeassistant:0.103.0

sqldiablo · 2019-12-19T00:34:57Z

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

ocalvo · 2019-12-19T00:41:56Z

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

jshank · 2019-12-19T00:44:37Z

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

image: "homeassistant/home-assistant:0.103.0"

ocalvo · 2019-12-19T00:51:09Z

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.

bachya · 2019-12-19T00:52:32Z

Hang tight everyone; this is likely related to #29491 (released in 0.103.1). Will need @balloob to look into it once he returns.

ocalvo · 2019-12-19T01:14:25Z

I think I screw myself, I cannot re add smartthings after removing it.
Here is an new thread.

tomikazi · 2019-12-19T03:17:43Z

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. [deletia]

I am seeing the same thing after upgrading to 0.103.1. Previous 0.103.0 version works fine.

LucasJanin · 2019-12-19T04:21:02Z

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.

kquinsland · 2019-12-19T04:41:50Z

Am chiming in to indicate a +1 for the same issue. Symptoms are about the same

the ha container has been "running" for about 5 min and nothing bound, but i do see the MQTT container has been able to bind.

root@ha-host:/opt/home_automation # netstat -tulnp | grep 1883 | wc -l
2
root@ha-host:/opt/home_automation # netstat -tulnp | grep 8123 | wc -l
0

And the home assistant container has pegged one of my four cores...

root@ha-host:/opt/home_automation # ps aux | grep homeassistant
root      3719 99.9  3.2 156888 129664 ?       Rsl  04:23   8:09 /usr/local/bin/python3 -m homeassistant --config /config

No errors in the log, even w/ logging set to debug level. I was unable to get any meaningful dump from the process :(, but the fact that no ERROR level statements made it into the log + the single core pegged + no HTTP server binding would really seem to match w/ what @panctronic was seeing.

Am currently rolling back to 0.103.0

dooz127 · 2019-12-19T05:09:41Z

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.

jheidel · 2019-12-19T05:33:22Z

+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.

Scope666 · 2019-12-19T05:54:59Z

+1 Ring and SmartThings hosed after upgrade.

Error: 401 Client Error: Unauthorized for url: https://api.ring.com/clients_api/session
You will need to restart hass after fixing.

The following components and platforms could not be set up:

ring
ring.binary_sensor
ring.camera
Please check your config.

Restoring a known working Hassio snapshot does NOT fix the problem.

Error executing query: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO events (event_type, event_data, origin, time_fired, created, context_id, context_user_id) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('state_changed', '{"entity_id": "remote.living_room", "old_state": null, "new_state": {"entity_id": "remote.living_room", "state": "off", "attributes": {"current_activ ... (121 characters truncated) ... :00", "last_updated": "2019-12-19T05:57:31.359903+00:00", "context": {"id": "e43488a67bdb44d987c56efbfed03cb4", "parent_id": null, "user_id": null}}}', 'LOCAL', '2019-12-19 05:57:31.359931', '2019-12-19 05:57:31.372188', 'e43488a67bdb44d987c56efbfed03cb4', None)]
(Background on this error at: http://sqlalche.me/e/4xp6)

ocalvo · 2019-12-19T05:58:39Z

Do not try to recover SmartThings,the cloud service is down at the moment and you will end up with a bad state. I am reaching to SmartThings support.

I was able to recover ecobee. Don't know how to recover ring

ZetaPhoenix · 2019-12-19T06:32:21Z

+1 also seeing the no load condition on homeassistant/raspberrypi3-homeassistant. Reverting back to 0.103.0 has fixed it for me.

balloob · 2019-12-19T07:05:08Z

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

ualex73 · 2019-12-19T07:12:00Z

+1 Ring and SmartThings hosed after upgrade.

Error: 401 Client Error: Unauthorized for url: https://api.ring.com/clients_api/session
You will need to restart hass after fixing.

The following components and platforms could not be set up:

ring
ring.binary_sensor
ring.camera
Please check your config.

Restoring a known working Hassio snapshot does NOT fix the problem.

Error executing query: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO events (event_type, event_data, origin, time_fired, created, context_id, context_user_id) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('state_changed', '{"entity_id": "remote.living_room", "old_state": null, "new_state": {"entity_id": "remote.living_room", "state": "off", "attributes": {"current_activ ... (121 characters truncated) ... :00", "last_updated": "2019-12-19T05:57:31.359903+00:00", "context": {"id": "e43488a67bdb44d987c56efbfed03cb4", "parent_id": null, "user_id": null}}}', 'LOCAL', '2019-12-19 05:57:31.359931', '2019-12-19 05:57:31.372188', 'e43488a67bdb44d987c56efbfed03cb4', None)]
(Background on this error at: http://sqlalche.me/e/4xp6)

The ring seems to be unrelated to the 0.103.1 upgrade, the website/api stopped working from me - 6-7 hours before i upgraded from 0.103.0.

Scope666 · 2019-12-19T07:18:17Z

Ring and SmartThings both died for me (and others in this thread) right after attempting the 103.1 upgrade.

nicx · 2019-12-19T07:41:14Z

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

noohi · 2019-12-19T08:32:15Z

In case they don't update fast enough, you could switch to a Dev branch docker:
image: homeassistant/home-assistant:dev
then tomorrow back to:
image: homeassistant/home-assistant:stable
Been using Dev docker today during the 0.103.1 issue, works fine.

balloob · 2019-12-19T08:42:56Z

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

Depending on your timezone, that could be tomorrow though

daemongloom · 2019-12-19T09:20:57Z

Latest (0.103.2) docker image works OK.

LucasJanin · 2019-12-19T09:41:29Z

I confirm the Latest (0.103.2) docker image fixe the problem.

Thanks

WedHumpDay · 2019-12-19T13:06:58Z

Morning everyone.. Thanks for the quick turn-around.

I can confirm 0.103.2 resolved the upgrade issue. Upgraded successfully from 0.103.0 -> 0.103.2

Scope666 · 2019-12-19T13:51:53Z

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

balloob · 2019-12-19T16:26:14Z

That's a different issue. This issue is resolved. You should create a new issue for that if it doesn't exist yet.

mdonoughe added a commit to mdonoughe/home that referenced this issue Dec 18, 2019

103.1 is broken

57004b9

home-assistant/core#30060

ocalvo mentioned this issue Dec 19, 2019

Recorder not working with MS SQL Database #29837

Closed

kquinsland mentioned this issue Dec 19, 2019

exceptions config does not appear to work maykar/custom-header#50

Closed

balloob closed this as completed Dec 19, 2019

CheeseySandal mentioned this issue Dec 19, 2019

Chromecast blocks startup #30065

Closed

home-assistant locked as resolved and limited conversation to collaborators Dec 19, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

0.103.1 Failed to start after upgrade - Traceback errors and Core errors #30060

0.103.1 Failed to start after upgrade - Traceback errors and Core errors #30060

WedHumpDay commented Dec 18, 2019

VDRainer commented Dec 18, 2019

arsaboo commented Dec 18, 2019

DavidFW1960 commented Dec 18, 2019

panctronic commented Dec 18, 2019

panctronic commented Dec 18, 2019

LordMike commented Dec 19, 2019 •

edited

Loading

ocalvo commented Dec 19, 2019

sqldiablo commented Dec 19, 2019

ocalvo commented Dec 19, 2019

jshank commented Dec 19, 2019

ocalvo commented Dec 19, 2019

bachya commented Dec 19, 2019 •

edited

Loading

ocalvo commented Dec 19, 2019

tomikazi commented Dec 19, 2019

LucasJanin commented Dec 19, 2019 •

edited

Loading

kquinsland commented Dec 19, 2019

dooz127 commented Dec 19, 2019

jheidel commented Dec 19, 2019

Scope666 commented Dec 19, 2019 •

edited

Loading

ocalvo commented Dec 19, 2019

ZetaPhoenix commented Dec 19, 2019

balloob commented Dec 19, 2019

ualex73 commented Dec 19, 2019

Scope666 commented Dec 19, 2019

nicx commented Dec 19, 2019

noohi commented Dec 19, 2019

balloob commented Dec 19, 2019 •

edited

Loading

daemongloom commented Dec 19, 2019

LucasJanin commented Dec 19, 2019 •

edited

Loading

WedHumpDay commented Dec 19, 2019

Scope666 commented Dec 19, 2019 •

edited

Loading

balloob commented Dec 19, 2019

0.103.1 Failed to start after upgrade - Traceback errors and Core errors #30060

0.103.1 Failed to start after upgrade - Traceback errors and Core errors #30060

Comments

WedHumpDay commented Dec 18, 2019

VDRainer commented Dec 18, 2019

arsaboo commented Dec 18, 2019

DavidFW1960 commented Dec 18, 2019

panctronic commented Dec 18, 2019

panctronic commented Dec 18, 2019

LordMike commented Dec 19, 2019 • edited Loading

ocalvo commented Dec 19, 2019

sqldiablo commented Dec 19, 2019

ocalvo commented Dec 19, 2019

jshank commented Dec 19, 2019

ocalvo commented Dec 19, 2019

bachya commented Dec 19, 2019 • edited Loading

ocalvo commented Dec 19, 2019

tomikazi commented Dec 19, 2019

LucasJanin commented Dec 19, 2019 • edited Loading

kquinsland commented Dec 19, 2019

dooz127 commented Dec 19, 2019

jheidel commented Dec 19, 2019

Scope666 commented Dec 19, 2019 • edited Loading

ocalvo commented Dec 19, 2019

ZetaPhoenix commented Dec 19, 2019

balloob commented Dec 19, 2019

ualex73 commented Dec 19, 2019

Scope666 commented Dec 19, 2019

nicx commented Dec 19, 2019

noohi commented Dec 19, 2019

balloob commented Dec 19, 2019 • edited Loading

daemongloom commented Dec 19, 2019

LucasJanin commented Dec 19, 2019 • edited Loading

WedHumpDay commented Dec 19, 2019

Scope666 commented Dec 19, 2019 • edited Loading

balloob commented Dec 19, 2019

LordMike commented Dec 19, 2019 •

edited

Loading

bachya commented Dec 19, 2019 •

edited

Loading

LucasJanin commented Dec 19, 2019 •

edited

Loading

Scope666 commented Dec 19, 2019 •

edited

Loading

balloob commented Dec 19, 2019 •

edited

Loading

LucasJanin commented Dec 19, 2019 •

edited

Loading

Scope666 commented Dec 19, 2019 •

edited

Loading