My hassio web page is down this morning, how to troubleshoot it?

SpikeyGG · August 11, 2019, 3:25pm

This morning my wife mentioned that our front outdoor post light was still on after the sun came up, should be off. I tried to pull up home assistant via my phone and it brought up the blue banner but no content. I swiped down on the screen and it came back with “site cannot be reached”.

I went to my computer and found that I couldn’t pull it up on Chrome there either. I cannot navigate to the IP in Chrome, it does the same thing. I can ping the IP address and hassio machine name. I have the samba share addon and the ssh addon and surprisingly both of those are fully operational! I can ssh into the machine’s ssh docker addon but I cannot figure out how to get home assistant back online.

When I connect via ssh and issue the command “hassio su logs” it spits out a bunch of stuff that looks pretty normal, I can even do that with “hassio ha logs” and everything appears to be working. It seems like everything is functioning correctly. I can pull up the samba share and everything looks fine in there. I just cannot get to the web service. I checked my duckdns.org account and it has my external IP loaded correctly.

I tried to issue “hassio ha restart” and it seems to hang, no output. After waiting a few minutes I pulled the plug on the raspberry pi gave it a few seconds and plugged it back in. The system took a minute or two and came back to where it was before:

No web service (can’t navigate to my duckdns address)
ssh works fine
samba works fine
all logs look okay

This system has been running great for months, I’m not sure why all of the sudden the web server is gone. I just tried to restart home assistant again in two steps this time, 1st issuing hassio ha stop then issuing hassio ha start and it came back like this:

core-ssh:~# hassio ha start
Error: Unknown Error, see logs
core-ssh:~#

Oooh! I found a problem. So I want to look at the logs…
I pulled up the “hassio ha logs” and it shows this (just warnings and info):

core-ssh:~# hassio ha logs
2019-08-11 08:00:09 WARNING (MainThread) [homeassistant.components.template.sensor] Template sensor weekday has no entity ids configured to track nor were we able to extract the entities to track from the value template(s). This entity will only be able to be updated manually.
2019-08-11 08:29:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded timer from homeassistant.components.timer
2019-08-11 08:29:37 INFO (SyncWorker_4) [homeassistant.loader] Loaded hassio from homeassistant.components.hassio
2019-08-11 08:29:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded discovery from homeassistant.components.discovery
2019-08-11 08:29:37 INFO (SyncWorker_4) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
2019-08-11 08:29:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded zone from homeassistant.components.zone
2019-08-11 08:29:37 INFO (SyncWorker_9) [homeassistant.loader] Loaded updater from homeassistant.components.updater
2019-08-11 08:29:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded sonos from homeassistant.components.sonos
2019-08-11 08:29:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
2019-08-11 08:29:37 INFO (SyncWorker_9) [homeassistant.loader] Loaded cover from homeassistant.components.cover
2019-08-11 08:29:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded history from homeassistant.components.history
2019-08-11 08:29:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded light from homeassistant.components.light
2019-08-11 08:29:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded binary_sensor from homeassistant.components.binary_sensor
2019-08-11 08:29:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded input_number from homeassistant.components.input_number
2019-08-11 08:29:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded group from homeassistant.components.group
2019-08-11 08:29:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded input_select from homeassistant.components.input_select
2019-08-11 08:29:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded map from homeassistant.components.map
2019-08-11 08:29:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
2019-08-11 08:29:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
2019-08-11 08:29:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded nest from homeassistant.components.nest
2019-08-11 08:29:37 INFO (SyncWorker_12) [homeassistant.loader] Loaded zoneminder from homeassistant.components.zoneminder
2019-08-11 08:29:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
2019-08-11 08:29:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded tts from homeassistant.components.tts
2019-08-11 08:29:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
2019-08-11 08:29:37 INFO (SyncWorker_1) [homeassistant.loader] Loaded asuswrt from homeassistant.components.asuswrt
2019-08-11 08:29:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded http from homeassistant.components.http
2019-08-11 08:29:37 INFO (SyncWorker_14) [homeassistant.loader] Loaded cast from homeassistant.components.cast
2019-08-11 08:29:37 INFO (SyncWorker_15) [homeassistant.loader] Loaded automation from homeassistant.components.automation
2019-08-11 08:29:37 INFO (SyncWorker_16) [homeassistant.loader] Loaded sun from homeassistant.components.sun
2019-08-11 08:29:37 INFO (SyncWorker_10) [homeassistant.loader] Loaded switch from homeassistant.components.switch
2019-08-11 08:29:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded notify from homeassistant.components.notify
2019-08-11 08:29:37 INFO (SyncWorker_11) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-08-11 08:29:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded person from homeassistant.components.person
2019-08-11 08:29:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded python_script from homeassistant.components.python_script
2019-08-11 08:29:37 INFO (SyncWorker_9) [homeassistant.loader] Loaded input_text from homeassistant.components.input_text
2019-08-11 08:29:37 INFO (SyncWorker_7) [homeassistant.loader] Loaded cloud from homeassistant.components.cloud
2019-08-11 08:29:37 INFO (SyncWorker_18) [homeassistant.loader] Loaded sense from homeassistant.components.sense
2019-08-11 08:29:37 INFO (SyncWorker_4) [homeassistant.loader] Loaded esphome from homeassistant.components.esphome
2019-08-11 08:29:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded camera from homeassistant.components.camera
2019-08-11 08:29:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
2019-08-11 08:29:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded conversation from homeassistant.components.conversation
2019-08-11 08:29:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded script from homeassistant.components.script
2019-08-11 08:29:37 INFO (SyncWorker_19) [homeassistant.loader] Loaded logger from homeassistant.components.logger
2019-08-11 08:29:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded weather from homeassistant.components.weather
2019-08-11 08:29:37 INFO (SyncWorker_14) [homeassistant.loader] Loaded homeassistant from homeassistant.components.homeassistant
2019-08-11 08:29:37 INFO (SyncWorker_16) [homeassistant.loader] Loaded api from homeassistant.components.api
2019-08-11 08:29:37 INFO (SyncWorker_10) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
2019-08-11 08:29:37 INFO (SyncWorker_12) [homeassistant.loader] Loaded config from homeassistant.components.config
2019-08-11 08:29:37 INFO (SyncWorker_1) [homeassistant.loader] Loaded input_boolean from homeassistant.components.input_boolean
2019-08-11 08:29:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded panel_custom from homeassistant.components.panel_custom
2019-08-11 08:29:37 INFO (SyncWorker_15) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.setup] Setting up homeassistant
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.setup] Setup of domain homeassistant took 0.0 seconds.
2019-08-11 08:29:37 INFO (SyncWorker_11) [homeassistant.loader] Loaded auth from homeassistant.components.auth
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.setup] Setting up persistent_notification
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.setup] Setup of domain persistent_notification took 0.0 seconds.
2019-08-11 08:29:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
2019-08-11 08:29:37 INFO (SyncWorker_7) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
2019-08-11 08:29:37 INFO (SyncWorker_4) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
2019-08-11 08:29:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.bootstrap] Setting up {'system_log', 'logger'}
2019-08-11 08:29:37 INFO (MainThread) [homeassistant.setup] Setting up logger
2019-08-11 08:29:39 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=74 from 2019-08-11 13:59:34)
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:176: CryptographyDeprecationWarning: encode_point has been deprecated on EllipticCurvePublicNumbers and will be removed in a future version. Please use EllipticCurvePublicKey.public_bytes to obtain both compressed and uncompressed point encoding.
  return pub.encode_point()
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:182: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
  self._priv_key.curve, peer_public).public_key(backend)
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:144: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
  public_value)
2019-08-11 08:29:53 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2019-08-11 08:29:53 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2019-08-11 08:29:53 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2019-08-11 08:29:53 WARNING (MainThread) [homeassistant.setup] Setup of asuswrt is taking over 10 seconds.
2019-08-11 08:29:54 WARNING (MainThread) [homeassistant.setup] Setup of person is taking over 10 seconds.
2019-08-11 08:30:02 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2019-08-11 08:30:02 WARNING (MainThread) [homeassistant.setup] Setup of sense is taking over 10 seconds.
2019-08-11 08:30:02 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2019-08-11 08:30:04 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of platform template is taking over 10 seconds.
2019-08-11 08:30:04 WARNING (MainThread) [homeassistant.components.weather] Setup of platform darksky is taking over 10 seconds.
2019-08-11 08:30:09 WARNING (MainThread) [homeassistant.components.template.sensor] Template sensor weekday has no entity ids configured to track nor were we able to extract the entities to track from the value template(s). This entity will only be able to be updated manually.
core-ssh:~#

The “hassio su logs” look like this (just warnings and info too):

core-ssh:~# hassio supervisor logs
19-08-11 14:50:59 INFO (MainThread) [hassio.api.security] /homeassistant/restart access from core_ssh
19-08-11 14:50:59 INFO (SyncWorker_8) [hassio.docker.interface] Restart homeassistant/raspberrypi3-homeassistant
19-08-11 14:51:30 INFO (MainThread) [hassio.auth] Auth request from core_mosquitto for mqttuser
19-08-11 14:51:30 ERROR (MainThread) [hassio.homeassistant] Error on call https://172.30.32.1:8123/api/: Cannot connect to host 172.30.32.1:8123 ssl:None [Connection refused]
19-08-11 14:51:30 INFO (MainThread) [hassio.auth] Home Assistant not running, check cache
19-08-11 14:51:30 INFO (MainThread) [hassio.auth] Cache hit for mqttuser
19-08-11 15:03:23 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-11 15:07:41 WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!
19-08-11 15:07:51 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
core-ssh:~#

I’m not sure why the times don’t line up but 14:30 in the su log is the same as 8:30, apparently. This however doesn’t help me figure out what went wrong. Where can I go from here? Is that connection refused error a problem? How can I fix it or gather more information about it?

tom_l · August 11, 2019, 3:43pm

Do you have another power supply you can try?

SpikeyGG · August 11, 2019, 3:52pm

I found this thread and tried renaming my core.config_entries file but that didn’t help.

I also tried downgrading my 0.97.1 to 0.97.0 and the problem persists:

core-ssh:~# hassio ha info
arch: armv7
boot: true
custom: false
image: homeassistant/raspberrypi3-homeassistant
ip_address: 172.30.32.1
last_version: 0.97.1
machine: raspberrypi3
port: 8123
ssl: true
version: 0.97.1
wait_boot: 400
watchdog: true
core-ssh:~# hassio homeassistant update --version=0.97.1
ok
core-ssh:~# hassio homeassistant update --version=0.97.0
Error: Unknown Error, see logs
core-ssh:~#

I looked through my power supplies, the one I’m using with my raspberry pi is a 2.5A 5V and the best I could find loose in my house is a 2.1A 5V, I’ll try it.

flamingm0e · August 11, 2019, 3:54pm

That’s definitely not enough power

SpikeyGG · August 11, 2019, 3:55pm

Well, the one I’m using is 2.5A 5V so that should be enough.

tom_l · August 11, 2019, 4:07pm

Sure. If it’s working correctly. Your log has no errors listed that would stop it working like that topic you posted. It is not relevant.

It has a template you should fix but that won’t prevent startup.

Your startup is just taking a long time, like the Pi is power or temperature throttling the cpu.

This could be due to something else but power would be an easy thing to eliminate if you had another.

SpikeyGG · August 11, 2019, 4:08pm

Just for fun, I decided to try the 2.1A supply and the system booted up the same way, no web UI but everything else seems to be working.

Here’s the ha and su logs for reference:

core-ssh:~# hassio ha logs
2019-08-11 09:55:03 INFO (SyncWorker_16) [homeassistant.loader] Loaded cover from homeassistant.components.cover
2019-08-11 09:55:03 INFO (SyncWorker_11) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-08-11 09:55:03 INFO (SyncWorker_15) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
2019-08-11 09:55:03 INFO (SyncWorker_3) [homeassistant.loader] Loaded config from homeassistant.components.config
2019-08-11 09:55:03 INFO (SyncWorker_13) [homeassistant.loader] Loaded notify from homeassistant.components.notify
2019-08-11 09:55:03 INFO (SyncWorker_2) [homeassistant.loader] Loaded discovery from homeassistant.components.discovery
2019-08-11 09:55:03 INFO (SyncWorker_7) [homeassistant.loader] Loaded automation from homeassistant.components.automation
2019-08-11 09:55:03 INFO (SyncWorker_1) [homeassistant.loader] Loaded input_boolean from homeassistant.components.input_boolean
2019-08-11 09:55:03 INFO (SyncWorker_0) [homeassistant.loader] Loaded sense from homeassistant.components.sense
2019-08-11 09:55:03 INFO (SyncWorker_19) [homeassistant.loader] Loaded history from homeassistant.components.history
2019-08-11 09:55:03 INFO (SyncWorker_10) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
2019-08-11 09:55:03 INFO (SyncWorker_4) [homeassistant.loader] Loaded map from homeassistant.components.map
2019-08-11 09:55:03 INFO (SyncWorker_5) [homeassistant.loader] Loaded weather from homeassistant.components.weather
2019-08-11 09:55:03 INFO (SyncWorker_14) [homeassistant.loader] Loaded sun from homeassistant.components.sun
2019-08-11 09:55:03 INFO (SyncWorker_8) [homeassistant.loader] Loaded timer from homeassistant.components.timer
2019-08-11 09:55:03 INFO (SyncWorker_6) [homeassistant.loader] Loaded light from homeassistant.components.light
2019-08-11 09:55:03 INFO (SyncWorker_3) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
2019-08-11 09:55:03 INFO (SyncWorker_9) [homeassistant.loader] Loaded cloud from homeassistant.components.cloud
2019-08-11 09:55:03 INFO (SyncWorker_15) [homeassistant.loader] Loaded logger from homeassistant.components.logger
2019-08-11 09:55:03 INFO (SyncWorker_18) [homeassistant.loader] Loaded switch from homeassistant.components.switch
2019-08-11 09:55:03 INFO (SyncWorker_2) [homeassistant.loader] Loaded http from homeassistant.components.http
2019-08-11 09:55:03 INFO (SyncWorker_17) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
2019-08-11 09:55:03 INFO (SyncWorker_13) [homeassistant.loader] Loaded input_number from homeassistant.components.input_number
2019-08-11 09:55:03 INFO (SyncWorker_7) [homeassistant.loader] Loaded tts from homeassistant.components.tts
2019-08-11 09:55:03 INFO (SyncWorker_11) [homeassistant.loader] Loaded updater from homeassistant.components.updater
2019-08-11 09:55:03 INFO (SyncWorker_12) [homeassistant.loader] Loaded esphome from homeassistant.components.esphome
2019-08-11 09:55:03 INFO (SyncWorker_16) [homeassistant.loader] Loaded input_text from homeassistant.components.input_text
2019-08-11 09:55:03 INFO (SyncWorker_1) [homeassistant.loader] Loaded sonos from homeassistant.components.sonos
2019-08-11 09:55:03 INFO (SyncWorker_0) [homeassistant.loader] Loaded python_script from homeassistant.components.python_script
2019-08-11 09:55:03 INFO (SyncWorker_19) [homeassistant.loader] Loaded zone from homeassistant.components.zone
2019-08-11 09:55:03 INFO (SyncWorker_10) [homeassistant.loader] Loaded zoneminder from homeassistant.components.zoneminder
2019-08-11 09:55:03 INFO (SyncWorker_4) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
2019-08-11 09:55:03 INFO (SyncWorker_14) [homeassistant.loader] Loaded binary_sensor from homeassistant.components.binary_sensor
2019-08-11 09:55:03 INFO (SyncWorker_5) [homeassistant.loader] Loaded nest from homeassistant.components.nest
2019-08-11 09:55:03 INFO (SyncWorker_8) [homeassistant.loader] Loaded input_select from homeassistant.components.input_select
2019-08-11 09:55:03 INFO (SyncWorker_15) [homeassistant.loader] Loaded cast from homeassistant.components.cast
2019-08-11 09:55:03 INFO (SyncWorker_3) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
2019-08-11 09:55:03 INFO (SyncWorker_9) [homeassistant.loader] Loaded script from homeassistant.components.script
2019-08-11 09:55:03 INFO (SyncWorker_6) [homeassistant.loader] Loaded group from homeassistant.components.group
2019-08-11 09:55:03 INFO (SyncWorker_17) [homeassistant.loader] Loaded camera from homeassistant.components.camera
2019-08-11 09:55:03 INFO (SyncWorker_12) [homeassistant.loader] Loaded homeassistant from homeassistant.components.homeassistant
2019-08-11 09:55:03 INFO (SyncWorker_18) [homeassistant.loader] Loaded person from homeassistant.components.person
2019-08-11 09:55:03 INFO (SyncWorker_2) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
2019-08-11 09:55:03 INFO (SyncWorker_7) [homeassistant.loader] Loaded hassio from homeassistant.components.hassio
2019-08-11 09:55:03 INFO (SyncWorker_11) [homeassistant.loader] Loaded asuswrt from homeassistant.components.asuswrt
2019-08-11 09:55:03 INFO (SyncWorker_13) [homeassistant.loader] Loaded conversation from homeassistant.components.conversation
2019-08-11 09:55:03 INFO (SyncWorker_16) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
2019-08-11 09:55:03 INFO (SyncWorker_1) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
2019-08-11 09:55:03 INFO (MainThread) [homeassistant.setup] Setting up homeassistant
2019-08-11 09:55:03 INFO (MainThread) [homeassistant.setup] Setup of domain homeassistant took 0.0 seconds.
2019-08-11 09:55:03 INFO (SyncWorker_0) [homeassistant.loader] Loaded api from homeassistant.components.api
2019-08-11 09:55:03 INFO (SyncWorker_19) [homeassistant.loader] Loaded panel_custom from homeassistant.components.panel_custom
2019-08-11 09:55:04 INFO (MainThread) [homeassistant.setup] Setting up persistent_notification
2019-08-11 09:55:04 INFO (MainThread) [homeassistant.setup] Setup of domain persistent_notification took 0.0 seconds.
2019-08-11 09:55:04 INFO (SyncWorker_4) [homeassistant.loader] Loaded auth from homeassistant.components.auth
2019-08-11 09:55:04 INFO (SyncWorker_5) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
2019-08-11 09:55:04 INFO (SyncWorker_15) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
2019-08-11 09:55:04 INFO (SyncWorker_9) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
2019-08-11 09:55:04 INFO (SyncWorker_17) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
2019-08-11 09:55:04 INFO (MainThread) [homeassistant.bootstrap] Setting up {'logger', 'system_log'}
2019-08-11 09:55:04 INFO (MainThread) [homeassistant.setup] Setting up logger
2019-08-11 09:55:05 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=79 from 2019-08-11 15:34:52)
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:176: CryptographyDeprecationWarning: encode_point has been deprecated on EllipticCurvePublicNumbers and will be removed in a future version. Please use EllipticCurvePublicKey.public_bytes to obtain both compressed and uncompressed point encoding.
  return pub.encode_point()
2019-08-11 09:55:21 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2019-08-11 09:55:21 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2019-08-11 09:55:21 WARNING (MainThread) [homeassistant.setup] Setup of sense is taking over 10 seconds.
2019-08-11 09:55:21 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2019-08-11 09:55:21 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2019-08-11 09:55:22 WARNING (MainThread) [homeassistant.setup] Setup of python_script is taking over 10 seconds.
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:182: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
  self._priv_key.curve, peer_public).public_key(backend)
/usr/local/lib/python3.7/site-packages/asyncssh/crypto/ec.py:144: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
  public_value)
2019-08-11 09:55:22 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2019-08-11 09:55:26 WARNING (MainThread) [homeassistant.setup] Setup of person is taking over 10 seconds.
2019-08-11 09:55:26 WARNING (MainThread) [homeassistant.setup] Setup of asuswrt is taking over 10 seconds.
2019-08-11 09:55:34 WARNING (MainThread) [homeassistant.components.template.sensor] Template sensor weekday has no entity ids configured to track nor were we able to extract the entities to track from the value template(s). This entity will only be able to be updated manually.
core-ssh:~# hassio su logs
19-08-11 15:53:09 INFO (MainThread) [__main__] Initialize Hass.io setup
19-08-11 15:53:09 INFO (SyncWorker_0) [hassio.docker.supervisor] Attach to Supervisor homeassistant/armv7-hassio-supervisor with version 173
19-08-11 15:53:10 INFO (MainThread) [__main__] Setup HassIO
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Introspect org.freedesktop.systemd1 on /org/freedesktop/systemd1
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Connect to dbus: org.freedesktop.systemd1 - /org/freedesktop/systemd1
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Introspect org.freedesktop.hostname1 on /org/freedesktop/hostname1
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Connect to dbus: org.freedesktop.hostname1 - /org/freedesktop/hostname1
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Introspect de.pengutronix.rauc on /
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Connect to dbus: de.pengutronix.rauc - /
19-08-11 15:53:10 INFO (MainThread) [hassio.host.info] Update local host information
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Call org.freedesktop.DBus.Properties.GetAll on /org/freedesktop/hostname1
19-08-11 15:53:10 INFO (MainThread) [hassio.host.services] Update service information
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Call org.freedesktop.systemd1.Manager.ListUnits on /org/freedesktop/systemd1
19-08-11 15:53:10 INFO (MainThread) [hassio.host.apparmor] Load AppArmor Profiles: {'hassio-supervisor'}
19-08-11 15:53:10 INFO (MainThread) [hassio.host.services] Reload local service hassos-apparmor.service
19-08-11 15:53:10 INFO (MainThread) [hassio.utils.gdbus] Call org.freedesktop.systemd1.Manager.ReloadOrRestartUnit on /org/freedesktop/systemd1
19-08-11 15:53:10 INFO (SyncWorker_2) [hassio.docker.interface] Attach to homeassistant/raspberrypi3-homeassistant with version 0.97.0
19-08-11 15:53:10 INFO (MainThread) [hassio.hassos] Detect HassOS 2.12 on host system
19-08-11 15:53:10 INFO (SyncWorker_0) [hassio.docker.hassos_cli] Found HassOS CLI homeassistant/armv7-hassio-cli with version 11
19-08-11 15:53:11 INFO (MainThread) [hassio.store.git] Load add-on /data/addons/core repository
19-08-11 15:53:11 INFO (MainThread) [hassio.store] Load add-ons from store: 19 all - 19 new - 0 remove
19-08-11 15:53:11 INFO (MainThread) [hassio.addons] Found 7 installed add-ons
19-08-11 15:53:11 INFO (SyncWorker_3) [hassio.docker.interface] Attach to homeassistant/armv7-addon-configurator with version 3.4
19-08-11 15:53:11 INFO (SyncWorker_8) [hassio.docker.interface] Attach to hassioaddons/ssh-armv7 with version v6.2.1
19-08-11 15:53:11 INFO (SyncWorker_4) [hassio.docker.interface] Attach to homeassistant/armv7-addon-ssh with version 6.0
19-08-11 15:54:23 INFO (SyncWorker_2) [hassio.docker.interface] Attach to homeassistant/armv7-addon-samba with version 8.1
19-08-11 15:54:24 INFO (SyncWorker_9) [hassio.docker.interface] Attach to esphome/esphome-hassio-armv7 with version 1.13.6
19-08-11 15:54:24 INFO (SyncWorker_6) [hassio.docker.interface] Attach to homeassistant/armv7-addon-duckdns with version 1.9
19-08-11 15:54:24 INFO (SyncWorker_0) [hassio.docker.interface] Attach to homeassistant/armv7-addon-mosquitto with version 5.0
19-08-11 15:54:24 INFO (MainThread) [hassio.updater] Fetch update data from https://version.home-assistant.io/stable.json
19-08-11 15:54:24 INFO (MainThread) [hassio.snapshots] Found 5 snapshot files
19-08-11 15:54:24 INFO (MainThread) [hassio.discovery] Load 1 messages
19-08-11 15:54:24 INFO (MainThread) [hassio.ingress] Load 0 ingress session
19-08-11 15:54:24 INFO (MainThread) [__main__] Run Hass.io
19-08-11 15:54:24 INFO (MainThread) [hassio.misc.dns] Start DNS port forwarding for host add-ons
19-08-11 15:54:24 INFO (MainThread) [hassio.api] Start API on 172.30.32.2
19-08-11 15:54:24 INFO (MainThread) [hassio.addons] Phase 'initialize' start 0 add-ons
19-08-11 15:54:24 INFO (MainThread) [hassio.addons] Phase 'system' start 1 add-ons
19-08-11 15:54:24 WARNING (MainThread) [hassio.addons.validate] Unknown options quiet_logs
19-08-11 15:54:27 INFO (SyncWorker_3) [hassio.docker.addon] Start Docker add-on homeassistant/armv7-addon-mosquitto with version 5.0
19-08-11 15:54:30 INFO (MainThread) [hassio.services.modules.mqtt] Set core_mosquitto as service provider for mqtt
19-08-11 15:54:32 INFO (MainThread) [hassio.addons] Phase 'services' start 4 add-ons
19-08-11 15:54:32 INFO (MainThread) [hassio.host.alsa] Update ALSA device list
19-08-11 15:54:33 INFO (SyncWorker_2) [hassio.docker.interface] Clean addon_a0d7b954_ssh application
19-08-11 15:54:34 INFO (SyncWorker_9) [hassio.docker.addon] Start Docker add-on homeassistant/armv7-addon-samba with version 8.1
19-08-11 15:54:35 INFO (SyncWorker_2) [hassio.docker.addon] Start Docker add-on hassioaddons/ssh-armv7 with version v6.2.1
19-08-11 15:54:37 INFO (SyncWorker_4) [hassio.docker.addon] Start Docker add-on homeassistant/armv7-addon-duckdns with version 1.9
19-08-11 15:54:38 INFO (SyncWorker_5) [hassio.docker.addon] Start Docker add-on homeassistant/armv7-addon-ssh with version 6.0
19-08-11 15:54:40 INFO (MainThread) [hassio.auth] Auth request from core_mosquitto for mqttuser
19-08-11 15:54:40 ERROR (MainThread) [hassio.homeassistant] Error on call https://172.30.32.1:8123/api/: Cannot connect to host 172.30.32.1:8123 ssl:None [Connection refused]
19-08-11 15:54:40 INFO (MainThread) [hassio.auth] Home Assistant not running, check cache
19-08-11 15:54:40 INFO (MainThread) [hassio.auth] Cache hit for mqttuser
19-08-11 15:54:40 INFO (MainThread) [hassio.api.security] /host/info access from a0d7b954_ssh
19-08-11 15:54:43 INFO (SyncWorker_15) [hassio.docker.interface] Clean homeassistant application
19-08-11 15:54:44 INFO (SyncWorker_15) [hassio.docker.homeassistant] Start homeassistant homeassistant/raspberrypi3-homeassistant with version 0.97.0
19-08-11 15:55:01 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-11 15:56:44 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-11 15:56:51 INFO (MainThread) [hassio.api.security] /homeassistant/logs access from core_ssh
19-08-11 15:57:17 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-11 15:58:00 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-11 15:58:03 INFO (MainThread) [hassio.api.security] /homeassistant/logs access from core_ssh
19-08-11 16:01:26 WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!
19-08-11 16:01:26 INFO (MainThread) [hassio.addons] Phase 'application' start 2 add-ons
19-08-11 16:01:28 INFO (SyncWorker_13) [hassio.docker.addon] Start Docker add-on esphome/esphome-hassio-armv7 with version 1.13.6
19-08-11 16:01:30 INFO (SyncWorker_17) [hassio.docker.addon] Start Docker add-on homeassistant/armv7-addon-configurator with version 3.4
19-08-11 16:01:30 INFO (MainThread) [hassio.api.security] /host/info access from 15ef4d2f_esphome
19-08-11 16:01:35 INFO (MainThread) [hassio.tasks] All core tasks are scheduled
19-08-11 16:01:35 INFO (MainThread) [hassio.core] Hass.io is up and running
19-08-11 16:04:20 INFO (MainThread) [hassio.api.security] /homeassistant/logs access from core_ssh
19-08-11 16:04:24 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
core-ssh:~#

SpikeyGG · August 11, 2019, 4:10pm

I tried increasing the wait_time to 1000 (16.6 minutes) and it still timed out with the message:

Error: Unknown Error, see logs

and the log showed:

WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!

Which sounds like it is giving up on loading the web UI. It never had this issue before this morning on restart.

When downgrading to 0.97.0 it gave me the same error:

core-ssh:~# hassio homeassistant update --version=0.97.0
Error: Unknown Error, see logs
core-ssh:~# hassio

SpikeyGG · August 11, 2019, 4:26pm

OMG, I downgraded to 0.96.5 and it worked!!!

core-ssh:~# hassio ha update --version 0.96.5
ok
core-ssh:~#

finity · August 11, 2019, 10:54pm

Doesn’t really seem to be a true “fix” tho. If you ever want to update to v97 you’re going to have to figure out the real reason it’s failing.

SpikeyGG · August 12, 2019, 12:56am

Would if I could. Looking at all the debug info I could find, nothing pointed me in the direction of the root cause. It’s really strange that it worked for a whole day and then died. Any ideas on how to get to the bottom? I’m all ears.

I’m kinda bummed because the Enphase Envoy addition was fixed in 0.97 and I really like the entities it adds.

finity · August 12, 2019, 1:34am

If you do the update again and it fails then go to your config directory and open the homeassistant.log file there and see if there is anything more informative.

ronschaeffer · August 12, 2019, 11:32am

I had almost exactly the same situation on Sunday morning. Was on 0.96.5. Hassio in Docker container on Ubuntu 18.04.

Couldn’t open the frontend
Automations apparently not running
SSH, Samba working
Logs looked fine except, similarly to @SpikeyGG, the supervisor and HA log time differed–by one hour in my case. Maybe significantly, the supervisor is at GMT (is it always?) while HA has the correct current local time of British Summer Time.

I restarted many times. After some of the restarts, the frontend would appear, and one or two interactions would work. For example, using Google Assistant to turn on a light via HA worked, but trying to turn out off less than a minute later failed with a “not available” message and the frontend was frozen again. Other times, the UI sort of worked, but a page would take 5 minutes or more to load.

I tried restoring snapshots from 1, 2 and 3 days, but the behavior was the same.

I then upgraded via SSH to 0.97.2, and all is now working. The log times, however, are still out by an hour.

I can’t help but think that the problem is going to reoccur. Upgrading when there had been no problem prior to Sunday doesn’t feel like a real fix.

tom_l · August 12, 2019, 12:15pm

Yes. HA uses UTC in the back end but converts it to local for display in the front end.

ronschaeffer · August 12, 2019, 12:36pm

Ah, a red herring then. Thanks.

SpikeyGG · August 12, 2019, 1:46pm

Good call finity.

ronschaeffer, I tried to upgrade this morning from 0.96.5 to 0.97.2 and the problem continues on my raspberry pi.

Here is the output of hassio su logs:

19-08-12 13:24:38 INFO (MainThread) [hassio.homeassistant] Update Home Assistant to version 0.97.2
19-08-12 13:24:38 INFO (SyncWorker_1) [hassio.docker.interface] Update image homeassistant/raspberrypi3-homeassistant:0.96.5 to homeassistant/raspberrypi3-homeassistant:0.97.2
19-08-12 13:24:38 INFO (SyncWorker_1) [hassio.docker.interface] Pull image homeassistant/raspberrypi3-homeassistant tag 0.97.2.
19-08-12 13:28:20 INFO (SyncWorker_1) [hassio.docker.interface] Stop homeassistant application
19-08-12 13:29:22 INFO (SyncWorker_1) [hassio.docker.interface] Clean homeassistant application
19-08-12 13:29:23 INFO (SyncWorker_17) [hassio.docker.homeassistant] Start homeassistant homeassistant/raspberrypi3-homeassistant with version 0.97.2
19-08-12 13:29:50 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-12 13:29:56 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-12 13:29:57 INFO (MainThread) [hassio.auth] Auth request from core_mosquitto for mqttuser
19-08-12 13:29:57 ERROR (MainThread) [hassio.homeassistant] Error on call https://172.30.32.1:8123/api/: Cannot connect to host 172.30.32.1:8123 ssl:None [Connection refused]
19-08-12 13:29:57 INFO (MainThread) [hassio.auth] Home Assistant not running, check cache
19-08-12 13:29:57 INFO (MainThread) [hassio.auth] Cache hit for mqttuser
19-08-12 13:30:59 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-12 13:33:35 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh
19-08-12 13:34:25 WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!
19-08-12 13:34:25 CRITICAL (MainThread) [hassio.homeassistant] HomeAssistant update fails -> rollback!
19-08-12 13:34:25 INFO (MainThread) [hassio.homeassistant] Update Home Assistant to version 0.96.5
19-08-12 13:34:25 INFO (SyncWorker_3) [hassio.docker.interface] Update image homeassistant/raspberrypi3-homeassistant:0.97.2 to homeassistant/raspberrypi3-homeassistant:0.96.5
19-08-12 13:34:25 INFO (SyncWorker_3) [hassio.docker.interface] Pull image homeassistant/raspberrypi3-homeassistant tag 0.96.5.
19-08-12 13:34:26 INFO (SyncWorker_3) [hassio.docker.interface] Stop homeassistant application
19-08-12 13:34:27 INFO (SyncWorker_3) [hassio.docker.interface] Clean homeassistant application
19-08-12 13:34:28 INFO (SyncWorker_18) [hassio.docker.homeassistant] Start homeassistant homeassistant/raspberrypi3-homeassistant with version 0.96.5
19-08-12 13:35:00 INFO (MainThread) [hassio.auth] Auth request from core_mosquitto for mqttuser
19-08-12 13:35:00 ERROR (MainThread) [hassio.homeassistant] Error on call https://172.30.32.1:8123/api/: Cannot connect to host 172.30.32.1:8123 ssl:None [Connection refused]
19-08-12 13:35:00 INFO (MainThread) [hassio.auth] Home Assistant not running, check cache
19-08-12 13:35:00 INFO (MainThread) [hassio.auth] Cache hit for mqttuser
19-08-12 13:35:18 INFO (MainThread) [hassio.homeassistant] Detect a running Home Assistant instance
19-08-12 13:35:18 INFO (MainThread) [hassio.homeassistant] Successful run Home Assistant 0.96.5
19-08-12 13:35:18 INFO (SyncWorker_8) [hassio.docker.interface] Cleanup images: ['homeassistant/raspberrypi3-homeassistant:0.97.2']
19-08-12 13:35:19 INFO (MainThread) [hassio.api.security] /supervisor/logs access from core_ssh

Looks like the devs included an automatic rollback on upgrade failure as my system automatically rolled back to 0.96.5 and came back to life thereafter. I pulled open the home-assistant.log while I was waiting the five minutes for the system to come back and the only error thing in there was the google maps tracker (because of them dropping password support). I had previously solved this error when upgraded to 0.97.1 and reverted because I went back to 0.96.5. That error wouldn’t be holding up the show for the home assistant frontend, I remember it showed me a notification on the frontend the first time I upgraded.

Emphyrio · August 12, 2019, 5:00pm

By any chance are you using the Breaking Changes custom component? It caused slow downs for a lot of people since this Sunday, when the source website for the component went down.

ashfaaaa · August 12, 2019, 5:18pm

i had same issue this morning i removed breaking changes then everything worked fine.

anyone of you guys have issue with mosquitto mqtt ? my clients are unable to connect and i get below in log

[INFO] found hassio on local database
[INFO] found HassNodeRed on local database
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found HassNodeRed on local database
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe

ronschaeffer · August 12, 2019, 5:25pm

I saw your other thread a couple of hours ago and updated Breaking Changes as a result. The symptoms do indeed sound the same. Fingers crossed. Thanks.

SpikeyGG · August 13, 2019, 3:44am

Thanks for the suggestion but I’m not aware of that custom component. I don’t think I have that one installed on my system.