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
72.67k stars 30.42k forks source link

Automation integration not starting #45487

Closed PierreScerri closed 2 years ago

PierreScerri commented 3 years ago

The problem

The automation integration is failing to start, especially after an HA update.

Environment

Problem-relevant configuration.yaml

Traceback/Error logs

2021-01-24 11:24:47 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: automation
2021-01-24 11:25:34 INFO (SyncWorker_8) [homeassistant.util.package] Attempting install of retry==0.9.2
2021-01-24 11:25:47 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: automation
2021-01-24 11:25:50 ERROR (MainThread) [homeassistant.setup] Setup of automation is taking longer than 300 seconds. Startup will proceed without waiting any longer

Additional information

Restarting Home Assistant usually, but not always, resolves the issue.

probot-home-assistant[bot] commented 3 years ago

automation documentation automation source (message by IssueLinks)

PierreScerri commented 3 years ago

This is still happening when HA restarts (not always)

pove commented 3 years ago

It always happens to me when I update to new version.

2021-03-05 14:39:27 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: automation
2021-03-05 14:43:32 ERROR (MainThread) [homeassistant.setup] Setup of automation is taking longer than 300 seconds. Startup will proceed without waiting any longer

Is there a way to debug/log this deeper?

gin23 commented 3 years ago

It always happens to me when I update to new version.

Same for me. During the update to version core-2021.4.4 as well...

PierreScerri commented 3 years ago

Also, HA will take forever to complete startup if it ever does complete it.

I end up rebooting the host to get it running.

sylvaindd commented 3 years ago

Having the same issue on my Synology as well. Rebooting the host doesn't even work every times Reverting back to 2021.3.4 seems to fix the issue though.

menzy81 commented 3 years ago

I am also seeing this same issue on 2021.5.4 and previous versions since about 2021.4.0. Rebooting the host fixes it for me.

vlumikero commented 3 years ago

In the same boat. Looking for ways to troubleshoot.

remcomeer89 commented 3 years ago

Same over here, used to run on linux with superviser, now on homeassistant blue and takes forever to boot sometimes, most of the time reboot before it ever boots after 30 min or so. That fixes it most of the time. Waiting on integrations to complete setup: automation Waiting on integrations to complete setup: steam_wishlist, influxdb Waiting on integrations to complete setup: shelly, tts, homekit_controller, esphome

The automation has almost nothing in it.. use most of the automation via nodered

pove commented 3 years ago

I have enabled debug logs in configuration:

logger:
  default: info
  logs:
    homeassistant.core: debug
    homeassistant.setup: debug

Then I have updated from core-2021.7.3 to core-2021.7.4.

I can see automation waiting for blueprint and trace, and then I can see them both loaded (I put the important staff in bold):

2021-07-23 07:13:30 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 2: {'map', 'blueprint', 'mobile_app', 'device_tracker', 'input_select', 'trace', 'forecast_solar', 'cast', 'telegram_bot', 'proximity', 'input_text', 'google_domains', 'mqtt', 'pvpc_hourly_pricing', 'alexa_media', 'timer', 'python_script', 'adguard', 'esphome', 'rpi_power', 'persistent_notification', 'input_boolean', 'scene', 'alarm_control_panel', 'rest_command', 'shelly', 'shopping_list', 'nut', 'hacs', 'input_number', 'utility_meter', 'input_datetime', 'sun', 'sensor', 'switch', 'tts',
'script', 'binary_sensor', 'light', 'conversation', 'history', 'tag', 'notify', 'zone', 'automation', 'ambee', 'ytube_music_player', 'system_health', 'shell_command', 'logbook', 'speedtestdotnet', 'panel_iframe', 'group', 'updater'}
2021-07-23 07:13:30 INFO (SyncWorker_4) [homeassistant.loader] Loaded workday from homeassistant.components.workday
2021-07-23 07:13:30 INFO (SyncWorker_1) [homeassistant.loader] Loaded systemmonitor from homeassistant.components.systemmonitor
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up map
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event panels_updated[L]>
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setup of domain map took 0.0 seconds
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up blueprint
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setup of domain blueprint took 0.0 seconds
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.setup] Dependency mobile_app will wait for dependencies ['tag']
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.setup] Dependency mobile_app will wait for after dependencies ['notify']
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.setup] Dependency device_tracker will wait for dependencies ['zone']
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up input_select
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up trace
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setup of domain trace took 0.0 seconds
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up forecast_solar
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setup of domain forecast_solar took 0.0 seconds
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.setup] Dependency cast will wait for after dependencies ['tts']
2021-07-23 07:13:30 DEBUG (MainThread) [homeassistant.setup] Dependency proximity will wait for dependencies ['device_tracker', 'zone']
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up input_text
2021-07-23 07:13:30 INFO (MainThread) [homeassistant.setup] Setting up google_domains
2021-07-23 07:13:31 INFO (MainThread) [homeassistant.setup] Setting up pvpc_hourly_pricing
2021-07-23 07:13:31 INFO (MainThread) [homeassistant.setup] Setup of domain pvpc_hourly_pricing took 0.0 seconds
2021-07-23 07:13:33 INFO (SyncWorker_3) [homeassistant.util.package] Attempting install of alexapy==1.25.1
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up timer
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.setup] Dependency esphome will wait for after dependencies ['tag']
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up input_boolean
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up scene
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.components.scene] Setting up scene.homeassistant
2021-07-23 07:13:33 INFO (SyncWorker_2) [homeassistant.loader] Loaded manual from homeassistant.components.manual
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up rest_command
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=rest_command, service=googledomain_updateip>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain rest_command took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up shopping_list
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain shopping_list took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up input_number
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up utility_meter
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up input_datetime
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up sun
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event state_changed[L]: entity_id=sun.sun, old_state=None, new_state=>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain sun took 0.1 seconds
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.setup] Dependency script will wait for dependencies ['blueprint', 'trace']
2021-07-23 07:13:33 INFO (SyncWorker_1) [homeassistant.loader] Loaded wake_on_lan from homeassistant.components.wake_on_lan
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up light
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up conversation
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=conversation, service=process>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain conversation took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up history
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event panels_updated[L]>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain history took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up tag
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up zone
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.setup] Dependency automation will wait for dependencies ['blueprint', 'trace']
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up system_health
2021-07-23 07:13:33 INFO (SyncWorker_0) [homeassistant.loader] Loaded telegram from homeassistant.components.telegram
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up shell_command
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=shell_command, service=sleep_on_lan_pove_desktop>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain shell_command took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up logbook
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event panels_updated[L]>
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=logbook, service=log>
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up panel_iframe
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setup of domain panel_iframe took 0.0 seconds
2021-07-23 07:13:33 INFO (MainThread) [homeassistant.setup] Setting up group
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event component_loaded[L]: component=map>
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event component_loaded[L]: component=blueprint>
2021-07-23 07:13:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event component_loaded[L]: component=trace>

It says it is starting with automation:

2021-07-23 07:13:37 INFO (MainThread) [homeassistant.setup] Setting up automation
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event state_changed[L]: entity_id=utility_meter.monthly_energy, old_state=None, new_state=>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=reload>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=select_option>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=select_next>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=select_previous>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=select_first>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=select_last>
2021-07-23 07:13:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event service_registered[L]: domain=input_select, service=set_options>
2021-07-23 07:13:37 INFO (MainThread) [homeassistant.setup] Setup of domain input_select took 7.3 seconds

Still waiting:

2021-07-23 07:13:39 INFO (MainThread) [homeassistant.setup] Setup of domain script took 0.6 seconds
2021-07-23 07:13:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling Event component_loaded[L]: component=script>
2021-07-23 07:14:31 INFO (SyncWorker_6) [homeassistant.util.package] Attempting install of packaging~=20.3
2021-07-23 07:14:32 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: automation
2021-07-23 07:15:15 INFO (MainThread) [homeassistant.setup] Setting up python_script
2021-07-23 07:15:15 INFO (MainThread) [homeassistant.setup] Setting up adguard
2021-07-23 07:15:15 INFO (MainThread) [homeassistant.setup] Setup of domain adguard took 0.0 seconds
2021-07-23 07:15:15 INFO (MainThread) [homeassistant.setup] Setting up rpi_power
2021-07-23 07:15:15 INFO (MainThread) [homeassistant.setup] Setup of domain rpi_power took 0.0 seconds
2021-07-23 07:15:17 INFO (MainThread) [homeassistant.setup] Setting up alexa_media
2021-07-23 07:15:17 INFO (MainThread) [homeassistant.setup] Setup of domain alexa_media took 0.0 seconds
2021-07-23 07:15:17 INFO (MainThread) [homeassistant.setup] Setting up notify

And after a while:

2021-07-23 07:18:37 ERROR (MainThread) [homeassistant.setup] Setup of automation is taking longer than 300 seconds. Startup will proceed without waiting any longer

Now HA does not work 100% until I reboot Host. After rebooting, everything goes as expected, including automations:

2021-07-23 08:00:04 INFO (MainThread) [homeassistant.setup] Setup of domain automation took 7.6 seconds
birdie60 commented 3 years ago

+1 I still have the same issues in Home Assistant 2021.7.4 on docker.

Techwolf12 commented 3 years ago

Still having the same issues with 2021.9.3 on Docker. It just seems to happen on every upgrade

jabetcha commented 2 years ago

Still happening on 2021.11.1 Is there a CLI command to restart manually?

LukaszP2 commented 2 years ago

some to me. it is only after every upgrade. I just upgrade to 2021.1.3. How can I help to find error?

tokyotexture commented 2 years ago

Happened on 2021.12.1 to me today...

github-actions[bot] commented 2 years ago

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

LukaszP2 commented 2 years ago

I still have a problem with this...

pove commented 2 years ago

I still have a problem with this...

What version and setup? I do not have this problem since several versions ago.

LukaszP2 commented 2 years ago

I still have a problem with this...

What version and setup? I do not have this problem since several versions ago.

version | core-2022.7.0b2 installation_type | Home Assistant Supervised dev | false hassio | true docker | true user | root virtualenv | false python_version | 3.10.5 os_name | Linux os_version | 5.4.0-105-generic arch | x86_64

pove commented 2 years ago

Perhaps you should upgrade to a stable version. They have been working on yaml tooling on 2022.7, so it could be not fine on the beta version.

I am still on 2022.6, so I could not tell. I had this issue in the past with older versions, and I had to reboot host to have it working again, but definitely working well on latest releases.

LukaszP2 commented 2 years ago

I do upgrade to 2022.08b and it working!