core: UNIQUE constraint failed, recorder not working

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

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 17 (4 by maintainers)

Most upvoted comments

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 on Oct 8, 2020

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.

rccoleman on Oct 8, 2020

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.