Database Errors - Unable to start Recorder, History, Logbook

Brett_C · January 17, 2019, 1:39am

Hi all,

Wondering if anyone may be able to help with some errors I’m getting. I noticed in my syslog similar write to database errors when hass was trying to update the time. The only thing that comes to mind that I’ve changed recently was to install Jupyter and start playing with that, but to my knowledge that is read-only and shouldn’t have impacted the db in anyway?

Appreciate any thoughts anyone may have! My searching didn’t come across anything similar, so I’m assuming this is unique to me

2019-01-16 20:31:22 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:31:27 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:31:27 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:31:30 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:31:31 WARNING (MainThread) [homeassistant.setup] Setup of recorder is taking over 10 seconds.
2019-01-16 20:31:35 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:31:35 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:31:38 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:31:43 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:31:43 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:31:46 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:31:51 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:31:51 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:31:54 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:31:59 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:31:59 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:02 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:32:07 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:32:07 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:10 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:32:15 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:32:15 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:18 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:32:23 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:32:23 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:26 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:32:31 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:32:31 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:34 WARNING (Recorder) [homeassistant.components.recorder] Ended unfinished session (id=139 from 2019-01-15 17:37:43.733553)
2019-01-16 20:32:39 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8)
2019-01-16 20:32:39 ERROR (Recorder) [homeassistant.components.recorder] Error during connection setup: (sqlite3.OperationalError) database is locked [SQL: 'UPDATE recorder_runs SET "end"=?, closed_incorrect=? WHERE recorder_runs.run_id = ?'] [parameters: ('2019-01-17 01:31:21.649060', 1, 139)] (Background on this error at: http://sqlalche.me/e/e3q8) (retrying in 3 seconds)
2019-01-16 20:32:39 ERROR (MainThread) [homeassistant.setup] Setup failed for recorder: Component failed to initialize.
2019-01-16 20:32:39 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of history. Setup failed for dependencies: recorder
2019-01-16 20:32:39 ERROR (MainThread) [homeassistant.setup] Setup failed for history: Could not set up all dependencies.
2019-01-16 20:32:39 ERROR (MainThread) [homeassistant.setup] Unable to set up dependencies of logbook. Setup failed for dependencies: recorder
2019-01-16 20:32:39 ERROR (MainThread) [homeassistant.setup] Setup failed for logbook: Could not set up all dependencies.

gpbenton · January 17, 2019, 6:55am

This happens to me every few months. I just stop HA, delete the database and restart.

It hasn’t happened since I switched to using postgres as the database, but that was only two months ago, so I can’t say if that’s a real solution.

Brett_C · January 17, 2019, 1:32pm

Thanks, will give that a shot.

Brett_C · January 18, 2019, 1:38pm

After deleting the database and restarting I was still seeing errors and the recorder, history, and logbook were again not started. I stopped the Jupyter service and restarted HA again and that actually did the trick, not sure if that is how it’s supposed to work or not… Perhaps I did something wrong when I set that up…

Thanks for the delete the DB tip though!

Enthral · September 9, 2019, 5:31pm

I had the same issue and turned out it was because i had viewed the database manually using the sqlite3 command but as a user other than the home assistant user. This cause the database swp file to have the wrong owner and hence homeassistant couldn’t access it. I could fix this by simply changing the ownership of the swp file to the homeassistant user. Hope this helps someone else who runs into this issue.