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.76k stars 30.87k forks source link

Setup of recorder is taking longer than 300 seconds. Startup will proceed without waiting any longer #102391

Closed Sticky12 closed 1 year ago

Sticky12 commented 1 year ago

The problem

Sometimes when restarting Home Assistant I get the message: Setup of recorder is taking longer than 300 seconds. Startup will proceed without waiting any longer and the following integrations will fail to start: Unable to set up dependencies of filter. Setup failed for dependencies: recorder Unable to set up dependencies of history. Setup failed for dependencies: recorder Unable to set up dependencies of logbook. Setup failed for dependencies: recorder Unable to set up dependencies of energy. Setup failed for dependencies: history, recorder Unable to set up dependencies of default_config. Setup failed for dependencies: energy, history, logbook

In this case I was restarting after installing an update through HACS and addinig a group in my groups.yaml file, both seems to work after restart, so does not seem to be related.

I was restarting through the Settings page.

I tried restarting shortly after, and the same thing happened again. I assume it is related to the MariaDB being locked for some reason.

What version of Home Assistant Core has the issue?

core-2023.10.3

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

recorder

Link to integration documentation on our website

https://www.home-assistant.io/integrations/recorder/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2023-10-20 14:39:28.172 WARNING (MainThread) [homeassistant.setup] Setup of recorder is taking over 10 seconds.
2023-10-20 14:40:16.393 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: recorder
2023-10-20 14:41:16.465 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: recorder
2023-10-20 14:42:16.530 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: recorder
2023-10-20 14:43:16.595 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: recorder
2023-10-20 14:44:16.657 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: recorder
2023-10-20 14:44:18.172 ERROR (MainThread) [homeassistant.setup] Setup of recorder is taking longer than 300 seconds. Startup will proceed without waiting any longer
2023-10-20 14:44:34.434 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of filter. Setup failed for dependencies: recorder
2023-10-20 14:44:34.434 ERROR (MainThread) [homeassistant.setup] Unable to prepare setup for platform filter.sensor: (DependencyError(...), 'Could not setup dependencies: recorder')
2023-10-20 14:44:36.594 ERROR (MainThread) [homeassistant.components.sensor] Error while setting up google_keep platform for sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 359, in _async_setup_platform
    await asyncio.shield(task)
  File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/google_keep/sensor.py", line 39, in setup_platform
    login_success = keep.login(username, password)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gkeepapi/__init__.py", line 693, in login
    ret = auth.login(username, password, get_mac())
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gkeepapi/__init__.py", line 59, in login
    raise exception.LoginException(
gkeepapi.exception.LoginException: ('BadAuthentication', None)
2023-10-20 14:44:36.613 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of history. Setup failed for dependencies: recorder
2023-10-20 14:44:36.614 ERROR (MainThread) [homeassistant.setup] Setup failed for history: (DependencyError(...), 'Could not setup dependencies: recorder')
2023-10-20 14:44:36.619 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of logbook. Setup failed for dependencies: recorder
2023-10-20 14:44:36.620 ERROR (MainThread) [homeassistant.setup] Setup failed for logbook: (DependencyError(...), 'Could not setup dependencies: recorder')
2023-10-20 14:44:37.014 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of energy. Setup failed for dependencies: history, recorder
2023-10-20 14:44:37.014 ERROR (MainThread) [homeassistant.setup] Setup failed for energy: (DependencyError(...), 'Could not setup dependencies: history, recorder')
2023-10-20 14:44:44.876 WARNING (MainThread) [homeassistant.setup] Setup of command_line is taking over 10 seconds.
2023-10-20 14:44:51.637 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Controller (192.168.1.188)' for heos integration not ready yet: [Errno 113] Connect call failed ('192.168.1.188', 1255); Retrying in background
2023-10-20 14:44:55.576 WARNING (MainThread) [custom_components.adaptive_lighting.switch] Bathroom light strip: Config mismatch: `detect_non_ha_changes` or `adapt_only_on_bare_turn_on` set to `true` requires `take_over_control` to be enabled. Adjusting config and continuing setup with `take_over_control: true`.
2023-10-20 14:44:57.470 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of default_config. Setup failed for dependencies: energy, history, logbook
2023-10-20 14:44:57.471 ERROR (MainThread) [homeassistant.setup] Setup failed for default_config: (DependencyError(...), 'Could not setup dependencies: energy, history, logbook')

Additional information

I am using MariaDB through Add-On version 2.6.1

Here is log information from MariaDB

[13:15:18] INFO: Start MariaDB client (to lock tables for backups) s6-rc: info: service mariadb-lock-core successfully started s6-rc: info: service mariadb-lock-post: starting [13:15:18] INFO: MariaDB tables locked s6-rc: info: service mariadb-lock-post successfully started s6-rc: info: service mariadb-lock-post: stopping [16:31:15] INFO: MariaDB tables unlocked s6-rc: info: service mariadb-lock-post successfully stopped s6-rc: info: service mariadb-lock-core: stopping [16:31:15] INFO: MariaDB client (to lock tables for backups) stopped s6-rc: info: service mariadb-lock-core successfully stopped s6-rc: info: service mariadb-lock-core: starting [13:15:15] INFO: Start MariaDB client (to lock tables for backups) s6-rc: info: service mariadb-lock-core successfully started s6-rc: info: service mariadb-lock-post: starting [13:15:15] INFO: MariaDB tables locked s6-rc: info: service mariadb-lock-post successfully started 2023-10-20 14:39:05 25 [Warning] Aborted connection 25 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 14:39:05 26 [Warning] Aborted connection 26 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 14:39:05 24 [Warning] Aborted connection 24 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 14:39:05 27 [Warning] Aborted connection 27 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 14:39:06 28 [Warning] Aborted connection 28 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got timeout reading communication packets) 2023-10-20 15:24:41 36 [Warning] Aborted connection 36 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 15:24:41 35 [Warning] Aborted connection 35 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 15:24:41 34 [Warning] Aborted connection 34 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 15:24:41 32 [Warning] Aborted connection 32 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 15:24:41 33 [Warning] Aborted connection 33 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got an error reading communication packets) 2023-10-20 15:24:41 31 [Warning] Aborted connection 31 to db: 'homeassistant' user: 'homeassistant' host: '172.30.32.1' (Got timeout reading communication packets)

home-assistant[bot] commented 1 year ago

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (recorder) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `recorder` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign recorder` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)

recorder documentation recorder source (message by IssueLinks)

joostlek commented 1 year ago

Seems to be related with the fact that HA can't reach the db

Sticky12 commented 1 year ago

Yes. I have restarted the MariaDB add-on and now Home Assistant can restart normally again.

joostlek commented 1 year ago

Good to hear! For next time, please use the support channels for this :)

Sticky12 commented 1 year ago

I still believe it is Home Assistant that somehow must have locked the tables at 13.15.

joostlek commented 1 year ago

The fact that the logs also indicate that this is because of a service in the addon, makes me believe its something else