Recorder database failed migration from 0.50.2 to 0.52

Configuration
1

I was running a HA 0.50.2 and I upgraded to 0.52 and I had to go through the event database optimization step. I waited and waited for ~40 minutes but there was no visible progress and top reported a CPU core in 100% stuck on a kthread. Although the system was not sluggish, the system load was slowly increasing - it reached 82 in about 1 hour and then the system died and I was disconnected from ssh. Funny thing is - I couldn’t access the ~homeassistant/.homeassistant folder anymore, but other folders worked correctly - so there was something stuck in kernel space.

After a system reboot I get the following errors when starting HA:

Aug 31 13:00:58 bellatrix hass[12779]: INFO:homeassistant.setup:Setting up recorder
Aug 31 13:00:59 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:00:59 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:00:59 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:00:59 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:00:59 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:00:59 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:00:59 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:00:59 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:02 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:02 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:02 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:02 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:02 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:02 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:02 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:02 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:05 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:05 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:05 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:05 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:05 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:05 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:05 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:05 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:08 bellatrix hass[12779]: WARNING:homeassistant.setup:Setup of recorder is taking over 10 seconds.
Aug 31 13:01:08 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:08 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:08 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:08 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:08 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:08 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:08 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:08 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:11 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:11 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:11 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:11 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:11 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:11 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:11 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:11 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:14 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:14 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:14 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:14 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:14 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:14 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:14 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:14 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:17 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:17 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:17 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:17 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:17 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:17 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:17 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:17 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:20 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:20 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:20 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:20 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:20 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:20 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:20 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:20 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:24 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:24 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:24 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:24 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:24 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:24 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:24 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:24 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:27 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Upgrading recorder db schema to version 4
Aug 31 13:01:27 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_created_domain from table states. Schema Migration will continue; this is not a criti
cal operation.
Aug 31 13:01:27 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__state_changes from table states. Schema Migration will continue; this is not a critical
 operation.
Aug 31 13:01:27 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index states__significant_changes from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:27 bellatrix hass[12779]: WARNING:homeassistant.components.recorder.migration:Failed to drop index ix_states_entity_id_created from table states. Schema Migration will continue; this is not a cr
itical operation.
Aug 31 13:01:27 bellatrix hass[12779]: INFO:homeassistant.components.recorder.migration:Adding index `ix_states_entity_id_last_updated` to database. Note: this can take several minutes on large databases and
 slow computers. Please be patient!
Aug 31 13:01:27 bellatrix hass[12779]: ERROR:homeassistant.components.recorder.util:Error executing query: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE INDEX
 ix_states_entity_id_last_updated ON states (entity_id, last_updated)']
Aug 31 13:01:27 bellatrix hass[12779]: ERROR:homeassistant.components.recorder:Error during connection setup: (sqlite3.OperationalError) index ix_states_entity_id_last_updated already exists [SQL: 'CREATE IN
DEX ix_states_entity_id_last_updated ON states (entity_id, last_updated)'] (retrying in 3 seconds)
Aug 31 13:01:27 bellatrix hass[12779]: INFO:homeassistant.setup:Setup of domain recorder took 28.9 seconds.
Aug 31 13:01:27 bellatrix hass[12779]: ERROR:homeassistant.setup:Setup failed for recorder: Component failed to initialize.

HA starts, but without history, recorder and logbook components.
Most likely the database is corrupt (I’m guessing it’s home-assistant_v2.db). The file is quite large 995MB on my system.

Is there any procedure I could use to fix it, or should I just rename/delete it and let HA start with a fresh one (and lose history data)?

2

Update:

mv home-assistant_v2.db home-assistant_v2--corrupt.db

Causes the system to start with a fresh database, so it’s a workaround.

3

I’ve recently had the same corrupt database. Is the [ mv home-assistant_v2.db home-assistant_v2–corrupt.db ] a command or an entry for the configuration.yaml?

Thanks in advance.

4

It’s a command you have to run in the configuration directory under linux. You can remove the file as well since it won’t be used and may be difficult to fix anyway.

5

I have the same issue, Tried delete the db file without any result.

Also tried database purged in the /dev-service tab:

{
“keep_days”:“1”,
“repack”:“true”
}

I have 2 raspberry Pi with similar setup but only one is running at the time for testing issues. Both has the same issue so that is strange, can it be something with the network they are running on?

6

stop home assistant using SSH. Delete the file, start home assistant back up.

7

Thank you very mutch for taking your time to help, I still didn’t get it to work and not sure how the db file is created.

I think I followed your sugestion:

  1. I first go to putty and run the command: hassio ha stop
  2. I delete the \HASSIO\config\home-assistant_v2.db file dated ‎18. ‎oktober ‎2018, ‏‎14:23:47
  3. Then in putty I run the command: hassio ha start
  4. A new home-assistant_v2.db file is created but with the same date 18. ‎oktober ‎2018, ‏‎14:23:47.

Any idea why it get the same date and time, is it just copied from a buffer some where?

8

Nope, that information depends on the operating system in question.

9

I am using Raspberry PI 3B 32bit and Home Assistant 0.83.1

I finally got an error message in the log file:

2018-10-18 14:05:07 ERROR (Recorder) [homeassistant.components.recorder] Error in database connectivity: (sqlite3.OperationalError) no such table: events [SQL: 'INSERT INTO events (event_type, event_data, origin, time_fired, created, context_id, context_user_id) VALUES (?, ?, ?, ?, ?, ?, ?)'] [parameters: ('call_service', '{"domain": "recorder", "service": "purge", "service_data": {"keep_days": 5, "repack": true}, "service_call_id": "785254ced8ea465ca1ec6fa62ac0256e"}', 'LOCAL', '2018-10-18 11:44:11.359395', '2018-10-18 12:05:07.047724', '6b66315f5bd240ad9bc1971a4437d1fe', '51b05f893faf4549b8379f7ce98154d7')] (Background on this error at: http://sqlalche.me/e/e3q8). (retrying in 3 seconds)
2018-10-18 14:05:07 ERROR (Recorder) [homeassistant.components.recorder] Error in database update. Could not save after 11 tries. Giving up
2018-10-18 14:05:07 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) no such table: states [SQL: 'SELECT max(states.state_id) AS max_1 \nFROM states GROUP BY states.entity_id'] (Background on this error at: http://sqlalche.me/e/e3q8)

So if I can figure out how to force homeassistant recorder to re create the tables that would be good.

I have tried purge several times, but it didn’t help:

- id: '1542587033849'
- alias: Database Purge
  trigger:
    platform: time
    at: '12:45:00'
  action:
    - service: recorder.purge
      data:
        keep_days: 5
        repack: true
10

It recreates the table when the table doesn’t exist. You shouldn’t be having these problems. Your flash drive could be dying.

Also, you shouldn’t need to have that automation at all. The setup of the platform handles everything. By default, it will purge the database once per day.

recorder:
  db_url: ...
  purge_keep_days: 5
11

I have the same issue on two different Raspberry PI 3B.

The second PI was setup 2 month ago, and runs Duck DNS over https and Configurator fine.

The first PI is some how not able to run Duck DNS or Configurator, so that can be the same issue creating multible problems.

It is strange that the “recorder” has a problem on two different PI’s and two different installations

12

Ok it’s possible it’s a bug a PR can be written against the service. But again, why are you using the automation when the setup works exactly the same way as the automation you are trying to create?

13

I did do purge before from /dev-service and standard settings in configuration.yaml with out any changes.

The automation is just created today, based on a tip on this forum (sorry don’t remember the username), after I run that automation I started to get error log messages.

Any change is a good change :slight_smile:

14

It’s possible that the repack is causing your problem.

15

Is it possible to remove it completely, and then start it again?
Or do I need to format both of my PI’s and set up everything again from scratch including the z-wave setup.

If I just stop home-assistant and remove the db file, it will just be recreated with the same dates, but different file size.

16

So when it creates it again it populates it with the current state at startup. That new size is essentially empty but it won’t be zero. I really think you are over thinking this. I believe you are just running into an issue with the date modified or date created from your os. The file itself is doing what you want.