home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.66k stars 30.8k forks source link

Recorder: connecting to External PostgreSQL database generates Error #44595

Closed borpin closed 3 years ago

borpin commented 3 years ago

The problem

When connecting to an external PostgreSQL instance with the Recorder integration, an exception is generated.

DETAIL:  Key (old_state_id)=(12846) is not present in table "states"

Environment

version: 0.118.4

installation_type: Home Assistant Supervised dev: false hassio: true docker: true virtualenv: false python_version: 3.8.6 os_name: Linux os_version: 4.19.97-v7l+ arch: armv7l timezone: Europe/London

Home Assistant Supervisor

host_os: Raspbian GNU/Linux 10 (buster) update_channel: stable supervisor_version: 2020.12.7 docker_version: 19.03.8 disk_total: 219.0 GB disk_used: 29.4 GB healthy: true supported: failed to load: Unsupported supervisor_api: ok version_api: ok installed_addons: Terminal & SSH (8.10.0), Home Assistant Google Drive Backup (0.101.3), Samba share (9.3.0), AppDaemon 4 (0.3.2), NGINX Home Assistant SSL proxy (3.0.1), Node-RED (7.2.11), InfluxDB (3.7.9), Let's Encrypt (4.11.0), Mosquitto broker (5.1), Grafana (5.3.6), Zigbee2mqtt (1.15.0), Glances (0.9.1), AdGuard Home (2.6.1)

Problem-relevant configuration.yaml

To make it work without the exceptions, it is necessary to exclude all sensors.

recorder:
  purge_keep_days: 5
  db_url: postgresql://homeassistant:homeassistant@192.168.7.18/homeassistant
#  exclude:
#    domains:
#      - sensor

Traceback/Error logs

2020-12-20 18:03:30 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(12846) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'switch', 'entity_id': 'switch.sonoffpow1', 'state': 'on', 'attributes': '{"friendly_name": "SonoffPow1"}', 'event_id': 24744, 'last_changed': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'old_state_id': 12846}]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
2020-12-20 18:03:30 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(12846) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'switch', 'entity_id': 'switch.sonoffpow1', 'state': 'on', 'attributes': '{"friendly_name": "SonoffPow1"}', 'event_id': 24744, 'last_changed': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'old_state_id': 12846}]
(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 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
    cursor.execute(statement, parameters)
psycopg2.errors.ForeignKeyViolation: insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(12846) is not present in table "states".

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 454, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 509, in _commit_event_session
    self.event_session.flush()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2536, in flush
    self._flush(objects)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2678, in _flush
    transaction.rollback(_capture_exception=True)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/langhelpers.py", line 68, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2638, in _flush
    flush_context.execute()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 419, in execute
    n.execute_aggregate(self, set_)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 697, in execute_aggregate
    persistence.save_obj(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 239, in save_obj
    _emit_insert_statements(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 1135, in _emit_insert_statements
    result = cached_connections[connection].execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1011, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 298, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1124, in _execute_clauseelement
    ret = self._execute_context(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1316, in _execute_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1510, in _handle_dbapi_exception
    util.raise_(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.IntegrityError: (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(12846) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'switch', 'entity_id': 'switch.sonoffpow1', 'state': 'on', 'attributes': '{"friendly_name": "SonoffPow1"}', 'event_id': 24744, 'last_changed': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 20, 18, 3, 29, 160592, tzinfo=datetime.timezone.utc), 'old_state_id': 12846}]
(Background on this error at: http://sqlalche.me/e/13/gkpj)

Additional information

Although this is not the latest version (there are breaking changes I need to fix), it does not appear any changes have been made to the recorder integration that would solve this issue.

I understand this is not a 'supported' method for install.

This is a fresh PostgreSQL install - database was not migrated.

probot-home-assistant[bot] commented 3 years ago

recorder documentation recorder source (message by IssueLinks)

borpin commented 3 years ago

Digging a little into this, and I can see Recorder is working for other entity types.

My suspicion is that, as this is a new database instance, on the first insertion, there is no old_state_id. Other Recorder domains handle that, but sensor does not.

borpin commented 3 years ago

Updated to 2020.12.2 and reenabled all domains.

I now get 2 errors on every restart (different sensors each time)

2020-12-30 17:16:24 ERROR (Recorder) [homeassistant.components.recorder] Error executing query: 'ascii' codec can't encode character '\U0001f4aa' in position 25: ordinal not in range(128)
2020-12-30 17:16:24 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: 'ascii' codec can't encode character '\U0001f4aa' in position 25: ordinal not in range(128)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 454, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 509, in _commit_event_session
    self.event_session.flush()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2536, in flush
    self._flush(objects)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2678, in _flush
    transaction.rollback(_capture_exception=True)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/langhelpers.py", line 68, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2638, in _flush
    flush_context.execute()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 419, in execute
    n.execute_aggregate(self, set_)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 697, in execute_aggregate
    persistence.save_obj(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 239, in save_obj
    _emit_insert_statements(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 1135, in _emit_insert_statements
    result = cached_connections[connection].execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1011, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 298, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1124, in _execute_clauseelement
    ret = self._execute_context(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1316, in _execute_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1514, in _handle_dbapi_exception
    util.raise_(exc_info[1], with_traceback=exc_info[2])
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
    cursor.execute(statement, parameters)
UnicodeEncodeError: 'ascii' codec can't encode character '\U0001f4aa' in position 25: ordinal not in range(128)
2020-12-30 17:16:24 ERROR (Recorder) [homeassistant.components.recorder] Integrity error executing query (database likely deleted out from under us): (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(62149) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'media_player', 'entity_id': 'media_player.samsung_ue22f5400', 'state': 'off', 'attributes': '{"source_list": ["TV", "HDMI"], "friendly_name": "Samsung UE22F5400", "supported_features": 20281, "device_class": "tv"}', 'event_id': 219803, 'last_changed': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'old_state_id': 62149}]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
2020-12-30 17:16:24 ERROR (Recorder) [homeassistant.components.recorder] Error saving events: (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(62149) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'media_player', 'entity_id': 'media_player.samsung_ue22f5400', 'state': 'off', 'attributes': '{"source_list": ["TV", "HDMI"], "friendly_name": "Samsung UE22F5400", "supported_features": 20281, "device_class": "tv"}', 'event_id': 219803, 'last_changed': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'old_state_id': 62149}]
(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 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
    cursor.execute(statement, parameters)
psycopg2.errors.ForeignKeyViolation: insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(62149) is not present in table "states".

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 454, in _commit_event_session_or_retry
    self._commit_event_session()
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 509, in _commit_event_session
    self.event_session.flush()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2536, in flush
    self._flush(objects)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2678, in _flush
    transaction.rollback(_capture_exception=True)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/langhelpers.py", line 68, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 2638, in _flush
    flush_context.execute()
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 422, in execute
    rec.execute(self)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/unitofwork.py", line 586, in execute
    persistence.save_obj(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 239, in save_obj
    _emit_insert_statements(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/orm/persistence.py", line 1135, in _emit_insert_statements
    result = cached_connections[connection].execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1011, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 298, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1124, in _execute_clauseelement
    ret = self._execute_context(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1316, in _execute_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1510, in _handle_dbapi_exception
    util.raise_(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
    cursor.execute(statement, parameters)
sqlalchemy.exc.IntegrityError: (psycopg2.errors.ForeignKeyViolation) insert or update on table "states" violates foreign key constraint "states_old_state_id_fkey"
DETAIL:  Key (old_state_id)=(62149) is not present in table "states".

[SQL: INSERT INTO states (domain, entity_id, state, attributes, event_id, last_changed, last_updated, created, old_state_id) VALUES (%(domain)s, %(entity_id)s, %(state)s, %(attributes)s, %(event_id)s, %(last_changed)s, %(last_updated)s, %(created)s, %(old_state_id)s) RETURNING states.state_id]
[parameters: {'domain': 'media_player', 'entity_id': 'media_player.samsung_ue22f5400', 'state': 'off', 'attributes': '{"source_list": ["TV", "HDMI"], "friendly_name": "Samsung UE22F5400", "supported_features": 20281, "device_class": "tv"}', 'event_id': 219803, 'last_changed': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'last_updated': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'created': datetime.datetime(2020, 12, 30, 17, 16, 17, 57907, tzinfo=datetime.timezone.utc), 'old_state_id': 62149}]
(Background on this error at: http://sqlalche.me/e/13/gkpj)
bdraco commented 3 years ago

It looks like we aren't creating the tables in the right charset which means the old state id insert fails and then the next one fails because it references one that failed to insert.

UnicodeEncodeError: 'ascii' codec can't encode character '\U0001f4aa' in position 25: ordinal not in range(128)

bdraco commented 3 years ago

https://stackoverflow.com/questions/14783505/encoding-error-with-sqlalchemy-and-postgresql

bdraco commented 3 years ago

You might need to add ?client_encoding=utf8 to the db url

If that fixes it, we probably need to update the docs here https://www.home-assistant.io/integrations/recorder/

borpin commented 3 years ago

You might need to add ?client_encoding=utf8 to the db url

Using the following string appears to solve the issue. I have not yet dropped the database and started afresh yet.

db_url: postgresql://homeassistant:homeassistant@192.168.7.18/homeassistant?client_encoding=utf8

I wonder if the documentation should specify the character encoding that HA uses i.e. UTF8 and warn that external databases should be setup in that way.

Thanks for your help. I'll recreate the database and start afresh (I'm not that precious about the history) and report back.

[edit] I note some of the other supported database engines use utf8mb4 - is using just utf8 going to pose any issues?

bdraco commented 3 years ago

You might need to add ?client_encoding=utf8 to the db url

Using the following string appears to solve the issue. I have not yet dropped the database and started afresh yet.

db_url: postgresql://homeassistant:homeassistant@192.168.7.18/homeassistant?client_encoding=utf8

I wonder if the documentation should specify the character encoding that HA uses i.e. UTF8 and warn that external databases should be setup in that way.

Seems like a good idea to me. Would you please make the change: https://github.com/home-assistant/home-assistant.io/blob/current/source/_integrations/recorder.markdown

Thanks for your help. I'll recreate the database and start afresh (I'm not that precious about the history) and report back.

[edit] I note some of the other supported database engines use utf8mb4 - is using just utf8 going to pose any issues?

postgres' utf8 is 4 bytes so only utf8 is needed unlikely mysql: https://www.postgresql.org/docs/9.3/multibyte.html#:~:text=The%20character%20set%20support%20in,8%2C%20and%20Mule%20internal%20code.

borpin commented 3 years ago

Modifying the createdb command to use utf8 encoding, and removing the instruction from the db_url seems to have stopped the errors when I started from scratch.

@bdraco - can you remind me which branch of the documentation to add this to? As this is a change to existing I think current but got caught out before.

My suggested change is to say that the database created in PostgreSQL is created with utf8 encoding rather than suggest using the db_url option.

[edit] I see you pointed me to current.

bdraco commented 3 years ago

Closing this since https://github.com/home-assistant/home-assistant.io/pull/16077 is now merged