Core: Extremely slow to restart by clicking Restart in the interface

[i00]

The problem

Now when I select Restart under config the server goes offline and never comes back ... when I restart the container it all works without issue...
There are no errors in the log as such ... I have placed the docker console output in the Traceback

Environment

• Home Assistant release with the issue: 0.105.2
  (I skipped the previous 105 versions ... but I am guessing it started with the safe mode)
• Last working Home Assistant release (if known): 0.104.3
• Operating environment (Hass.io/Docker/Windows/etc.): Docker
• Integration causing this issue: Core?
• Link to integration documentation on our website: N/A

Problem-relevant configuration.yaml

N/A

Traceback/Error logs

Docker console output is below after the restart button is clicked:

2020-02-07 18:58:57 WARNING (MainThread) [homeassistant.components.device_tracker] The 'hide_if_away' option (with value 'False') is deprecated, please remove it from your configuration. This option will become invalid in version 0.107.0
2020-02-07 18:58:57 WARNING (MainThread) [homeassistant.components.device_tracker] The 'hide_if_away' option (with value 'False') is deprecated, please remove it from your configuration. This option will become invalid in version 0.107.0
2020-02-07 18:58:57 INFO (SyncWorker_24) [homeassistant.loader] Loaded homekit from homeassistant.components.homekit
2020-02-07 18:58:57 INFO (MainThread) [homeassistant.components.stream] Stopped stream workers.
2020-02-07 18:58:57 INFO (SyncWorker_13) [homeassistant.components.xiaomi_aqara] Shutting down Xiaomi Hub
2020-02-07 18:58:57 INFO (SyncWorker_13) [xiaomi_gateway] Closing multisocket
2020-02-07 18:58:57 INFO (MainThread) [homeassistant.components.websocket_api.http.connection.140011379229200] Connection closed by client
2020-02-07 18:58:57 INFO (MainThread) [homeassistant.components.websocket_api.http.connection.140011379567120] Connection closed by client
2020-02-07 18:58:57 INFO (Thread-7) [pychromecast.socket_client] [Kitchen display:8009] Stopped while reading message, disconnecting.

Additional information

Config validates ... and like I said, if I reboot the docker container all works well again.

[i00]

Ok ... I started with a clean docker image and started merging things until it started not restarting ... something in the config folder ... will post more as I know more...

[i00]

Ok ... it does restart ... just takes 11 mins 52 seconds :(...

[jes1417]

I have noticed my instance takes way longer to test config and restart. I can click restart and want the the pop-up of it being offline till over a minute after on 104. It was instantaneous.

[Martinvdm]

Same issue , is there for some longer time already. Pressing restart seems to do nothing and after a couple of minutes there is eventuality a reboot.

[Tosko4]

Same here. Before, the check config took 5-8 minutes as where to before it was done within 1 minute. And also when rebooting. The device only reboots after a few minutes of waiting. The actual boot time is equal between 0.104x and 0.105.x

This happened after installing 105.x. Running 0.105.2 atm.

How can i measure what it causing this delay? As there’s no error.. but for some reason needs so much more time to proces certain stuff. I went back to 104.x just to test and it was fast again. Upon upgrading again, same slow experience as before

[Mariusthvdb]

Yes, as reported in the community, I’m forced to using ssh again for restarts... been a long time for the need for that, but using the configuration option doesn’t seem to work ?

[oncleben31]

On my configuration the restart is not consistent too. Sometimes it seems the system ignore the command.
The duration is longer than with 104.x but seems related to a custom component which use a different versions of spotipy

[Mariusthvdb]

Might be that it is the config check which is taking extremely long.

When clicking that in the Ha interface it never seems to finish.

Hence causing restart to take forever, since that first does a config check

When using ssh Hassio Ha check it is as swift as before.
Never sure if it is as safe but it works at least

[i00]

@Mariusthvdb
Nope ... config check is fine when I click the button ... only takes a few seconds

[Mariusthvdb]

updating to supervisor 200 made it behave again on this side

[mvoort1337]

Running RPI 3 Model B+ with Home Assistant (formerly Hass.IO).
Have had very stable Home Assistant experiences up to 0.104.3

When upgrading to 0.105.x I started getting roll-backs, with the upgrade failing to upgrade from 0.104.3 to 0.105.x
At first I thought it may had to do with my config, so I removed the netatmo integration from the config file because others were reporting success with that.
No luck.
Then I decided to start a fresh installation with a new SD card and clean hassos 3.10 install.
Added only the deconz add-on and restored from backup, then did a reboot to get all the lights from DeConz into Home Assistant.
This took much longer than I was used with prior to 0.105.x. The logs reported about 940 seconds of boot time for HA Core.

When doing the HA (Hass.IO) upgrade from 0.104.3 to 0.105.x I noticed that the logs were indicating a timeout and that it did not want to wait longer and was therefor falling back to the 0.104.3 install.
Other in the forum were reporting the same thing, these are logs I just copied from the forum:
20-02-06 14:11:25 INFO (MainThread) [hassio.homeassistant] Home Assistant pip installation in progress
20-02-06 14:14:35 INFO (MainThread) [hassio.homeassistant] Home Assistant pip installation done
20-02-06 14:24:39 WARNING (MainThread) [hassio.homeassistant] Don't wait anymore of Home Assistant startup!
20-02-06 14:24:39 CRITICAL (MainThread) [hassio.homeassistant] HomeAssistant update fails -> rollback!

Notice that the timeout occurs after about 10 minutes.

Then look at the logs from my reboot of the clean 0.105.4 installation with only DeConz, SSH and Configuratorenator running:

[...]
2020-02-18 20:09:02 INFO (MainThread) [homeassistant.setup] Setup of domain default_config took 0.6 seconds.
2020-02-18 20:09:02 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 2.1 seconds.
2020-02-18 20:09:02 INFO (SyncWorker_15) [homeassistant.loader] Loaded google_translate from homeassistant.components.google_translate
2020-02-18 20:09:03 INFO (MainThread) [homeassistant.setup] Setting up tts
2020-02-18 20:09:03 INFO (MainThread) [homeassistant.setup] Setup of domain tts took 0.1 seconds.
2020-02-18 20:24:26 INFO (MainThread) [homeassistant.components.cloud.account_link] Timeout fetching tokens for flow a8097fb3fb2647a19456b570d8258b31
2020-02-18 20:24:26 INFO (MainThread) [homeassistant.components.cloud.account_link] Timeout fetching tokens for flow 2ebd84ef805841b48e848907ba8f2c97
2020-02-18 20:24:26 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 945.19s
2020-02-18 20:24:26 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2020-02-18 20:24:26 INFO (SyncWorker_17) [homeassistant.components.zeroconf] Starting Zeroconf broadcast
2020-02-18 20:24:26 INFO (MainThread) [homeassistant.core] Timer:starting
2020-02-18 20:24:26 INFO (SyncWorker_3) [homeassistant.loader] Loaded deconz from homeassistant.components.deconz
2020-02-18 20:24:29 INFO (SyncWorker_0) [homeassistant.loader] Loaded plaato from homeassistant.components.plaato
2020-02-18 20:24:29 INFO (SyncWorker_14) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt

I am suspecting that there is a 15 minute timeout occuring against the cloud component (which hasn't been configured yet in my near clean installation) while the HA upgrade stops after 10 minutes.

Is there a possibility that these are interconnected and the one issue is causing the next?
Should I wait for a resolution of this slow restart or start from a clean install?

Looking forward to your thoughts.
Kind regards,
Mats

[mvoort1337]

This is the code that generates the error message (from homeassistant.components.cloud.account_link).

        except asyncio.TimeoutError:
            _LOGGER.info("Timeout fetching tokens for flow %s", flow_id)
        except account_link.AccountLinkException as err:
            _LOGGER.info(
                "Failed to fetch tokens for flow %s: %s", flow_id, err.code
            )
        else:
            await self.hass.config_entries.flow.async_configure(
                flow_id=flow_id, user_input=tokens
            )

I'm not a programmer, but is this a timeout relating to home assistant trying to get a token from nabu casa related to it's unique URL?
I haven't touched much of the configuration in this relatively clear setup, the cloud component hasn't been setup yet.

[JumpMaster]

I'm using HA core and have been having restart issues since 104 I believe. I restarted via the web UI and left it for two hours before I was forced to perform a docker restart as the lights were not coming on. The final output from the logs seem to be during shutdown.

2020-02-19 13:42:32 INFO (MainThread) [snitun.utils.aiohttp_client] AioHTTP snitun client disconnected from: eu-central-1.ui.nabu.casa:443
2020-02-19 13:42:32 INFO (MainThread) [snitun.utils.aiohttp_client] AioHTTP snitun client closed

[JumpMaster]

This no longer seems to be a problem in 106.

[i00]

Seems somewhat better ... but still takes a lot longer to check the configs and restart compared to 104

[PorreKaj]

Finally something I can add to.

From time to time my HA suddenly takes 15 minutes to boot, and everytime, it has something to do with Netatmo and Nabu Casa.

Sometimes the +15minutes is permanent, and the only solution is removing netatmo and signing in and out of cloud 2 times.

Whenever 15 minutes are added, i get 3 of these these in my logs, which coincides with the 3 times the netatmo integration is discovered when I set it up anew.
2020-04-15 20:16:11 INFO (MainThread) [homeassistant.components.cloud.account_link] Timeout fetching tokens for flow [GUIDsomethinghere]

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[i00]

Yep fixed in latest versions @PorreKaj ... if you still have issues you should open issues for those integrations that are slow.