Core: UNIQUE constraint failed, recorder not working

[McGiverGim]

The problem

The history does not update in any of my sensors since the update to 0.116.0. Looking at the log I see a log of UNIQUE constraint failed violations, so it seems it can't insert into DB the updated values.

Maybe I simply need to remove the db file and start again, but I waited to see if this can be a bigger error and you need more info.

Environment

• Home Assistant Core release with the issue: 0.116.0
• Last working Home Assistant Core release (if known): 0.115.x
• Operating environment (OS/Container/Supervised/Core): OS
• Integration causing this issue: All Recorder
• Link to integration documentation on our website: https://www.home-assistant.io/integrations/recorder/

Problem-relevant configuration.yaml

Traceback/Error logs

The log is full of errors like this:

sqlalchemy.exc.IntegrityError: (sqlite3.IntegrityError) UNIQUE constraint failed: events.event_id
[SQL: INSERT INTO events (event_id, event_type, event_data, origin, time_fired, created, context_id, context_user_id, context_parent_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: ((5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:47:10.076142', '2020-10-08 07:47:11.105438', '7895a738093a11ebbe3e63be720c0cdb', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:10.078009', '2020-10-08 07:47:11.107464', '54d2acf3093a11eb9ecf0d62b8d62f71', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:10.073209', '2020-10-08 07:46:11.110063', '54d1ed71093a11eb8d3ae93ddcddf586', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:45:10.054592', '2020-10-08 07:45:11.104150', '310bd5b1093a11eb868b41868857ecb7', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:10.052681', '2020-10-08 07:45:11.106869', '0d48455d093a11eb9789ed91cee7ec34', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:10.050600', '2020-10-08 07:44:11.106758', '0d47f403093a11eb98eb190150285a99', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:43:10.041821', '2020-10-08 07:44:11.109169', 'e983556c093911ebba0599e8d3f24f7a', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:43:10.034315', '2020-10-08 07:43:11.103587', 'e9823091093911eb93c3bb29a9cd8bfa', None, None)  ... displaying 10 of 555 total bound parameter sets ...  (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 02:13:09.234765', '2020-10-08 02:13:10.007768', 'cf4ff5c5090b11ebac6f85b9a4f3bc78', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 02:13:09.233084', '2020-10-08 02:13:10.005244', 'cf4fb279090b11eb8d812f21fac1a131', None, None))]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
2020-10-08 09:48:12 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:12 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: Instance <States at 0x7f8a7e62b0> is not present in this Session
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 442, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 497, in _commit_event_session
    self.event_session.expunge(dbstate)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 1854, in expunge
    raise sa_exc.InvalidRequestError(
sqlalchemy.exc.InvalidRequestError: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:13 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:13 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: Instance <States at 0x7f8a7e62b0> is not present in this Session
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 442, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 497, in _commit_event_session
    self.event_session.expunge(dbstate)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 1854, in expunge
    raise sa_exc.InvalidRequestError(
sqlalchemy.exc.InvalidRequestError: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:14 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:14 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: Instance <States at 0x7f8a7e62b0> is not present in this Session
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 442, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 497, in _commit_event_session
    self.event_session.expunge(dbstate)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 1854, in expunge
    raise sa_exc.InvalidRequestError(
sqlalchemy.exc.InvalidRequestError: Instance <States at 0x7f8a7e62b0> is not present in this Session
2020-10-08 09:48:15 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: (sqlite3.IntegrityError) UNIQUE constraint failed: events.event_id
[SQL: INSERT INTO events (event_id, event_type, event_data, origin, time_fired, created, context_id, context_user_id, context_parent_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: ((5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:47:30.975109', '2020-10-08 07:47:31.265627', '850a9967093a11ebbcb063f78914389e', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.079907', '2020-10-08 07:47:31.268031', '569cbb44093a11ebae590933bd841309', None, None), (5030651, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.068833', '2020-10-08 07:47:31.268965', '569b0a33093a11eb984a47bb1da95097', None, None), (5030652, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.045575', '2020-10-08 07:47:31.269540', '56977fad093a11ebb06f6f6cf3e4a732', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.041540', '2020-10-08 07:46:14.133587', '5696e134093a11eb931aa128209ed5e1', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.474699', '2020-10-08 07:46:14.136006', '23966abd093a11eb9c6a3186588b3c31', None, None), (5030651, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.463903', '2020-10-08 07:46:14.137045', '2394c35a093a11eba6a6e9f02d84a95f', None, None), (5030652, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.438372', '2020-10-08 07:46:14.137468', '2390df3d093a11ebabf9db0a74b90669', None, None)  ... displaying 10 of 210 total bound parameter sets ...  (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 04:36:51.263236', '2020-10-08 04:36:52.120302', 'e27115fb091f11ebaf8f25a695e827b7', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 03:36:15.931778', '2020-10-08 03:36:16.009746', '6b9d8930091711eb85d699ec80604cf6', None, None))]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
2020-10-08 09:48:15 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: (sqlite3.IntegrityError) UNIQUE constraint failed: events.event_id
[SQL: INSERT INTO events (event_id, event_type, event_data, origin, time_fired, created, context_id, context_user_id, context_parent_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: ((5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:47:30.975109', '2020-10-08 07:47:31.265627', '850a9967093a11ebbcb063f78914389e', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.079907', '2020-10-08 07:47:31.268031', '569cbb44093a11ebae590933bd841309', None, None), (5030651, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.068833', '2020-10-08 07:47:31.268965', '569b0a33093a11eb984a47bb1da95097', None, None), (5030652, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.045575', '2020-10-08 07:47:31.269540', '56977fad093a11ebb06f6f6cf3e4a732', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:46:13.041540', '2020-10-08 07:46:14.133587', '5696e134093a11eb931aa128209ed5e1', None, None), (5030650, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.474699', '2020-10-08 07:46:14.136006', '23966abd093a11eb9c6a3186588b3c31', None, None), (5030651, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.463903', '2020-10-08 07:46:14.137045', '2394c35a093a11eba6a6e9f02d84a95f', None, None), (5030652, 'state_changed', '{}', 'LOCAL', '2020-10-08 07:44:47.438372', '2020-10-08 07:46:14.137468', '2390df3d093a11ebabf9db0a74b90669', None, None)  ... displaying 10 of 210 total bound parameter sets ...  (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 04:36:51.263236', '2020-10-08 04:36:52.120302', 'e27115fb091f11ebaf8f25a695e827b7', None, None), (5030649, 'state_changed', '{}', 'LOCAL', '2020-10-08 03:36:15.931778', '2020-10-08 03:36:16.009746', '6b9d8930091711eb85d699ec80604cf6', None, None))]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1256, in _execute_context

Additional information

[McGiverGim]

Looking more to the history, it did not start with the update to 0.116.0, it started some hours later, at 04:12h. At 04:00h I have a programmed snapshot, I don't know if this matters.

[McGiverGim]

A restart of Home Assistant fixed the issue, without deleting the db file, but I will let this open if nobody says to close it, it seems there is some kind of bug that produced all of this.

[McGiverGim]

I can confirm the problem started with the snapshot. Maybe is a coincidence:

[probot-home-assistant[bot]]

recorder documentation
recorder source
_{^{(message by IssueLinks)}}

[irekzielinski]

have the same issue, updated to 0.116 yesterday.
Noticed sensor history not beign updated from 4:12 am - around same time as you!
Is 4am some special time for HA (does it do some maintenance at that time)?

Restart of HA solved the issue, will see if it re-appears tomorrow at 4am.

ps. I have InfluxDb confiured as well - and senor data has been pushed without any problems to it.

[McGiverGim]

I have manually launched a snapshot and seems all ok, so is clear that it has nothing to do with it, seeing that you have exactly the same problem at 04:12.
I'm sure something happens just at this hour :)

[McGiverGim]

Found:

auto_purge boolean (optional, default: true)
Automatically purge the database every night at 04:12 local time. Purging keeps the database from growing indefinitely, which takes up disk space and can make Home Assistant slow. If you disable auto_purge it is recommended that you create an automation to call the recorder.purge periodically.

[McGiverGim]

It was very evident, but to be sure, I have executed manually the service recorder.purge with keep_days: 10 and the problem is here again.
This happens to everybody or only to some of us? Is there people not suffering this problem?

[Skeletorjus]

Experiencing the same. I'm recording to MariaDB, so this issue isn't limited to the default SQLite database.

[seymourddr]

It was very evident, but to be sure, I have executed manually the service recorder.purge with keep_days: 10 and the problem is here again.
This happens to everybody or only to some of us? Is there people not suffering this problem?

i have same issue

[bdraco]

https://github.com/home-assistant/core/pull/41426 will probably fix it, but UNIQUE constraint failed is something I've not seen before.

Is there an error before that which lead to that specific failure?

[michaelwoods]

There's no error prior to the 4:12 start of database errors:

2020-10-08 04:12:17 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: Instance <States at 0x7fee8a1494c0> is not pres
ent in this Session
2020-10-08 04:12:17 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: Instance <States at 0x7fee8a1494c0> is not present in this Session

There's no mention of 'UNIQUE' in my logs.

[McGiverGim]

I have lost the logs restarting so I can't verify... and now I can't reproduce it ??????? I have reproduced it before without problem. I don't know if I have changed something at some place that can make things different...

[zvldz]

41426 will probably fix it, but UNIQUE constraint failed is something I've not seen before.

I put the fixed recorder in custom_components a few hours ago. Errors are missing.
Tested with recorder.purge service.

[rccoleman]

I woke up to lots and lots of errors identical to @michaelwoods and I haven't seen any after pulling in https://github.com/home-assistant/core/pull/41426. I see it was just tagged for 0.116.1.

[bdraco]

This should be fixed by #41426 which is in 0.1161.

If you can reproduce after 0.116.1, please open another issue with the error that happens before the UNIQUE constraint gets out of sync.

[tescher]

Saw the same behavior in 0.116.4 yesterday after a restore. Maybe it's not fixed?