Hassio very slow boot

Hi All,

Have an issue with hassio taking over 20 minutes to boot. This has only been happening since moving to 99.x. I am on a new build of a linux machine with Hassio in docker.

I logged into the machine and got the docker logs, I get this over and over again, with a different entity listed as the cause each time.

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 346, in run
    session.flush()
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 2459, in flush
    self._flush(objects)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 2597, in _flush
    transaction.rollback(_capture_exception=True)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/util/langhelpers.py", line 68, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/util/compat.py", line 153, in reraise
    raise value
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 2557, in _flush
    flush_context.execute()
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/unitofwork.py", line 422, in execute
    rec.execute(self)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/unitofwork.py", line 589, in execute
    uow,
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/persistence.py", line 245, in save_obj
    insert,
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/persistence.py", line 1138, in _emit_insert_statements
    statement, params
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 988, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
    distilled_params,
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1253, in _execute_context
    e, statement, parameters, cursor, context
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1473, in _handle_dbapi_exception
    util.raise_from_cause(sqlalchemy_exception, exc_info)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/util/compat.py", line 398, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/util/compat.py", line 152, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1249, in _execute_context
    cursor, statement, parameters, context
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.DatabaseError: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO events (event_type, event_data, origin, time_fired, created, context_id, context_user_id) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('state_changed', '{"entity_id": "switch.lounge_chairs", "old_state": {"entity_id": "switch.lounge_chairs", "state": "on", "attributes": {"current_power_w": "1.45", "to ... (617 characters truncated) ... :00", "last_updated": "2019-09-22T10:54:32.936627+00:00", "context": {"id": "857ddc6bdd3c452f9ae98a566f895ac8", "parent_id": null, "user_id": null}}}', 'LOCAL', '2019-09-22 10:54:32.936677', '2019-09-22 10:54:32.954758', '857ddc6bdd3c452f9ae98a566f895ac8', None)]
(Background on this error at: http://sqlalche.me/e/4xp6)
2019-09-22 20:54:32 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.DatabaseError) database disk image is malformed
[SQL: INSERT INTO events (event_type, event_data, origin, time_fired, created, context_id, context_user_id) VALUES (?, ?, ?, ?, ?, ?, ?)]
[parameters: ('state_changed', '{"entity_id": "sensor.lch_current_w", "old_state": {"entity_id": "sensor.lch_current_w", "state": "1.45", "attributes": {"unit_of_measurement": "W",  ... (451 characters truncated) ... :00", "last_updated": "2019-09-22T10:54:32.947102+00:00", "context": {"id": "2bdd8074c3b84bda888130d0096f6460", "parent_id": null, "user_id": null}}}', 'LOCAL', '2019-09-22 10:54:32.947138', '2019-09-22 10:54:32.970807', '2bdd8074c3b84bda888130d0096f6460', None)]
(Background on this error at: http://sqlalche.me/e/4xp6)
2019-09-22 20:54:32 ERROR (Recorder) [homeassistant.components.recorder] Error saving event: <Event state_changed[L]: entity_id=sensor.lch_current_w, old_state=<state sensor.lch_current_w=1.45; unit_of_measurement=W, friendly_name=Lounge Chairs Current Watts @ 2019-09-22T20:54:01.947927+10:00>, new_state=<state sensor.lch_current_w=1.31; unit_of_measurement=W, friendly_name=Lounge Chairs Current Watts @ 2019-09-22T20:54:32.947102+10:00>>
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/base.py", line 1249, in _execute_context
    cursor, statement, parameters, context
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
    cursor.execute(statement, parameters)
sqlite3.DatabaseError: database disk image is malformed

Steps I have tried;

  1. searching for others having and resolving this issue, nothing seems to be relevant.

  2. Deleting the database, even though this seems to be the obvious issue, deleting and letting HA recreate the database hasn’t impacted the issue.

  3. Removing the google calendar integration does seem to impact the issue. Though removing supported integrations does not seem to be a reasonable answer to issues.

Any thoughts?

Try stopping HA and deleting the database file.

OK, I stopped HA and deleted the database file (I had done this previously but hadn’t stopped HA first).

This then meant that HA would not start/restart at all, when using the CLI (as the front end would not come up), it would return with error: see logs, and the logs would just get up to saying that google was taking longer than 10 seconds. (google is the calendar component).

I then removed google calendar from the configuration, and did a restart and it came up in less than 2 minutes. though I am getting a few of these messages:

ERROR (MainThread) [pyhaversion] Timeout error fetching version information from PyPi

Surely lots of people are using the google calendar configuration without issues?

I don’t use Google Calendar, but I do see that someone else was recently seeing long starts with it :==> A terrible week