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.43k stars 30.67k forks source link

Unable to boot HASS after upgrade #18468

Closed araa47 closed 5 years ago

araa47 commented 5 years ago

Home Assistant release with the issue: 0.82.0

Last working Home Assistant release (if known): 0.7.. if not wrong

Operating environment (Hass.io/Docker/Windows/etc.): raspberry pi 3, following these instructions: https://www.home-assistant.io/docs/installation/raspberry-pi/

Component/platform: Empty config file. Allowing hass to generate its own config.

Description of problem: Unable to boot hass frontend even with a completely blank configuration file which is auto-populated when hass is run. No errors on Log file too.

Traceback (if applicable): Hass doesn't crash, only frontend doesn't seem to load up.

Additional information: I have updated python to the latest version and all the packages too but cant seem to get hass to start. I have also tried deleting the .db and .storage files however even this doesn't seem to help.

When I try my old configuration, same problem occurs, however some of my automations seem to be working, just no front-end or api.

cgarwood commented 5 years ago

Could you copy the console output when you manually run hass from within the venv?

araa47 commented 5 years ago

Just logged back in after waiting 5 hours and finally see some errors.

Traceback (if applicable):

2018-11-14 23:45:10 INFO (MainThread) [homeassistant.setup] Setting up light
2018-11-14 23:45:10 INFO (MainThread) [homeassistant.setup] Setup of domain light took 0.0 seconds.
2018-11-14 23:45:10 INFO (MainThread) [homeassistant.loader] Loaded light.nanoleaf_aurora from homeassistant.components.light.nanoleaf_aurora
2018-11-14 23:45:10 INFO (MainThread) [homeassistant.components.light] Setting up light.nanoleaf_aurora
2018-11-14 23:45:10 INFO (MainThread) [homeassistant.components.light] Setting up light.nanoleaf_aurora
2018-11-14 23:45:10 INFO (Thread-5) [homeassistant.components.light.nanoleaf_aurora] Discovered a new Aurora: {'hostname': 'Nanoleaf-Aurora-52-3d-60.local.', 'host': '192.168.0.22', 'properties': {'srcvers': '3.0.5', 'id': 'A4:7B:01:86:7A:56', 'md': 'NL22'}, 'port': 16021}
2018-11-14 23:45:10 INFO (Thread-16) [homeassistant.components.light.nanoleaf_aurora] Discovered a new Aurora: {'hostname': 'Nanoleaf-Aurora-52-3d-5c.local.', 'host': '192.168.0.23', 'properties': {'srcvers': '3.0.5', 'id': 'E1:BE:C4:CB:6D:25', 'md': 'NL22'}, 'port': 16021}
Forbidden! Press and hold the power button for 5-7 seconds first! (Light will begin flashing)
2018-11-14 23:45:10 ERROR (Thread-16) [homeassistant.components.light.nanoleaf_aurora] Could not generate the auth token, did you press and hold the power button on Nanoleaf-Aurora-52-3d-5c.local.for 5-7 seconds?
Forbidden! Press and hold the power button for 5-7 seconds first! (Light will begin flashing)
2018-11-14 23:45:10 ERROR (Thread-5) [homeassistant.components.light.nanoleaf_aurora] Could not generate the auth token, did you press and hold the power button on Nanoleaf-Aurora-52-3d-60.local.for 5-7 seconds?
2018-11-15 00:44:52 INFO (MainThread) [homeassistant.loader] Loaded hassio from homeassistant.components.hassio
2018-11-15 00:44:53 INFO (MainThread) [homeassistant.components.updater] Submitted analytics to Home Assistant servers. Information submitted includes {'distribution': 'raspbian', 'dev': False, 'virtualenv': True, 'docker': False, 'python_version': '3.5.3', 'os_version': '9', 'hassio': False, 'arch': 'armv7l', 'version': '0.82.0', 'timezone': 'UTC', 'huuid': '9d507f78adef4176b42fd968549eca86', 'os_name': 'Linux'}
2018-11-15 00:44:53 ERROR (MainThread) [homeassistant.components.updater] Got unexpected response: None
2018-11-15 00:57:49 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 00:57:49 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 01:17:33 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 02:59:06 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 04:10:28 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 04:32:34 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 05:05:47 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 06:42:59 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2018-11-15 08:14:55 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/aiohttp/web_protocol.py", line 242, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp\_http_parser.pyx", line 523, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
cgarwood commented 5 years ago

First thing I notice is it looks like Nanoleaf is blocking startup for just shy of an hour:

2018-11-14 23:45:10 ERROR (Thread-5) [homeassistant.components.light.nanoleaf_aurora] Could not generate the auth token, did you press and hold the power button on Nanoleaf-Aurora-52-3d-60.local.for 5-7 seconds?
2018-11-15 00:44:52 INFO (MainThread) [homeassistant.loader] Loaded hassio from homeassistant.components.hassio

I would have expected hassio component to load shortly after the nanoleaf error, not an hour later.

The invalid HTTP method lines IIRC usually mean someone or something is trying to access HASS over HTTP when it has SSL certificates setup, or trying to access it over HTTPS when it doesn't have SSL set up.

I'd try commenting out the nanoleaf lines in your config and see if it restarts any faster

araa47 commented 5 years ago

This console output is from deleting the config file. If I use my old config where I have the old nanoleaf credentials they seem to set up without any issues, however the frontend still does not boot. Console output does not seem to have any errors, only info statements. The last statements are starting timer from main thread and then one of the threads continually checks my ps4 status every 30 seconds.

Are there any other files I could delete or reinstall to try to get the front end to boot as a completely new hass instance? Running pip uninstall home assistant and reinstalling still runs into the same issues.

cgarwood commented 5 years ago

I'm not familiar with hass.io, but the .storage folder and configuration.yaml should be all that you need to delete to get a completely fresh config.

Are you accessing the frontend via IP or hostname, and are you using http:// or https://`?

araa47 commented 5 years ago

Sorry for the confusion, I'm running homeassistant on a python virtual environment not hass.io. I've tried both methods but cant seem to reach it. I've also re enabled port forwarding for 8123 , 80, 443 and tried both local ip address with empty config and also my duck dns address but cant seem to reach frontend

araa47 commented 5 years ago 
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setup of domain cloud took 0.0 seconds.
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setting up automation
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setup of domain automation took 0.0 seconds.
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setting up config
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setting up tts
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.auth from homeassistant.components.config.auth
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.automation from homeassistant.components.config.automation
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.device_registry from homeassistant.components.config.device_registry
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.entity_registry from homeassistant.components.config.entity_registry
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.group from homeassistant.components.config.group
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.customize from homeassistant.components.config.customize
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.config_entries from homeassistant.components.config.config_entries
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.hassbian from homeassistant.components.config.hassbian
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.script from homeassistant.components.config.script
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.core from homeassistant.components.config.core
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.loader] Loaded config.auth_provider_homeassistant from homeassistant.components.config.auth_provider_homeassistant
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.1 seconds.
2018-11-24 18:37:34 INFO (MainThread) [homeassistant.setup] Setup of domain tts took 0.1 seconds.
2018-11-24 18:37:35 INFO (MainThread) [homeassistant.setup] Setup of domain sensor took 2.2 seconds.
2018-11-24 18:37:35 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 5.80s
2018-11-24 18:37:35 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2018-11-24 18:37:35 INFO (MainThread) [homeassistant.core] Timer:starting
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: homekit {'host': '192.168.0.22', 'port': 6517, 'name': 'Nanoleaf Aurora 52:3d:60', 'hostname': 'Nanoleaf-Aurora-52-3d-60.local.', 'properties': {'sf': '1', 'md': 'NL22', 'ci': '5', 'ff': '1', 'pv': '1.1', 'id': 'A4:7B:01:86:7A:56', 'sh': 'tooaWQ==', 's#': '1', 'c#': '6'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: homekit {'host': '192.168.0.23', 'port': 6517, 'name': 'Nanoleaf Aurora 52:3d:5c', 'hostname': 'Nanoleaf-Aurora-52-3d-5c.local.', 'properties': {'sf': '1', 'md': 'NL22', 'ci': '5', 'ff': '1', 'pv': '1.1', 'id': 'E1:BE:C4:CB:6D:25', 'sh': '/JZzLQ==', 's#': '1', 'c#': '6'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: dlna_dmr {'ssdp_description': 'http://192.168.0.30:2870/dmr.xml', 'upnp_device_type': 'urn:schemas-upnp-org:device:MediaRenderer:1', 'manufacturer': 'LG Electronics', 'name': 'Music Flow SJ8(CE:73)', 'host': '192.168.0.30', 'port': 2870, 'model_number': '1.0', 'model_name': 'LG Music Flow', 'udn': 'uuid:140479c0-58f3-1cef-84bf-b4e62aad78fb', 'serial': None}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: spotify_connect {'host': '192.168.0.30', 'port': 9876, 'hostname': 'Chromecast.local.', 'properties': {'VERSION': '1.0', 'CPath': '/goform/spotifyConnect'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: spotify_connect {'host': '192.168.0.90', 'port': 41800, 'hostname': 'PS4-93DD0B.local.', 'properties': {'CPath': '/spConn'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Unknown service discovered: igd {'ssdp_description': 'http://192.168.0.1:1900/igd.xml', 'upnp_device_type': 'urn:schemas-upnp-org:device:InternetGatewayDevice:1', 'manufacturer': 'TP-LINK', 'name': 'Wireless Router Archer C7', 'host': '192.168.0.1', 'port': 1900, 'model_number': '2.0', 'model_name': 'Archer C7', 'udn': 'uuid:060b7353-fca6-4070-85f4-1fbfb9add62c', 'serial': 'none'}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Found new service: nanoleaf_aurora {'host': '192.168.0.23', 'port': 16021, 'hostname': 'Nanoleaf-Aurora-52-3d-5c.local.', 'properties': {'id': 'E1:BE:C4:CB:6D:25', 'md': 'NL22', 'srcvers': '3.0.5'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.discovery] Found new service: nanoleaf_aurora {'host': '192.168.0.22', 'port': 16021, 'hostname': 'Nanoleaf-Aurora-52-3d-60.local.', 'properties': {'id': 'A4:7B:01:86:7A:56', 'md': 'NL22', 'srcvers': '3.0.5'}}
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.loader] Loaded cast from homeassistant.components.cast
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.loader] Loaded light from homeassistant.components.light
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.setup] Setting up light
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.setup] Setup of domain light took 0.0 seconds.
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.loader] Loaded light.nanoleaf_aurora from homeassistant.components.light.nanoleaf_aurora
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.light] Setting up light.nanoleaf_aurora
2018-11-24 18:37:49 INFO (MainThread) [homeassistant.components.light] Setting up light.nanoleaf_aurora
2018-11-24 18:37:49 INFO (Thread-2) [homeassistant.components.light.nanoleaf_aurora] Discovered a new Aurora: {'host': '192.168.0.23', 'port': 16021, 'hostname': 'Nanoleaf-Aurora-52-3d-5c.local.', 'properties': {'id': 'E1:BE:C4:CB:6D:25', 'md': 'NL22', 'srcvers': '3.0.5'}}
2018-11-24 18:37:49 INFO (Thread-16) [homeassistant.components.light.nanoleaf_aurora] Discovered a new Aurora: {'host': '192.168.0.22', 'port': 16021, 'hostname': 'Nanoleaf-Aurora-52-3d-60.local.', 'properties': {'id': 'A4:7B:01:86:7A:56', 'md': 'NL22', 'srcvers': '3.0.5'}}
Forbidden! Press and hold the power button for 5-7 seconds first! (Light will begin flashing)
2018-11-24 18:37:49 ERROR (Thread-2) [homeassistant.components.light.nanoleaf_aurora] Could not generate the auth token, did you press and hold the power button on Nanoleaf-Aurora-52-3d-5c.local.for 5-7 seconds?
Forbidden! Press and hold the power button for 5-7 seconds first! (Light will begin flashing)
2018-11-24 18:37:49 ERROR (Thread-16) [homeassistant.components.light.nanoleaf_aurora] Could not generate the auth token, did you press and hold the power button on Nanoleaf-Aurora-52-3d-60.local.for 5-7 seconds?

Just upgraded to the latest version and still can't boot. Home assistant just gets stuck after this. If i enter the nanoleaf credentials in the config file, i run into the same issue, without the error showing up in command line.

abmantis commented 5 years ago

I was having this problem and found since 0.83 out it was owntracks! I've forgot to remove it from the "device_tracker" platform and HA won't boot. There was no error at all in the logs, but somehow it wasn't finishing booting up.

araa47 commented 5 years ago

Hey, I tried with a completely empty config but still cant boot up on a pi. Temporarily rolled back to an older version since it works.

abmantis commented 5 years ago

@araa47 have you deleted the "deps" folder?

araa47 commented 5 years ago

yep I've tried deleting the deps folder in the config directory too

araa47 commented 5 years ago

This seems to be solved in version 0.84.6