ldotlopez / ha-ideenergy

ideenergy integration for home-assistant
GNU General Public License v3.0
73 stars 13 forks source link

Database corrupted after activating historical sensors. #59

Closed Anacletus closed 8 months ago

Anacletus commented 9 months ago

First, I would like to thank the author for this wonderful integration. I installed it and the two active sensors worked perfectly (accumulated consumption and instant power).
After enabled the three historical sensors and waiting some time, the database got corrupted. After restarting ha, it worked well, without historical data. I have disabled the historical sensors and got no more database corrupteion.

logs: ` 2023-12-12 07:50:46.771 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-12-12 07:50:46.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for MEASURE 2023-12-12 07:50:47.361 INFO (MainThread) [ideenergy] : '987654321' contract selected 2023-12-12 07:50:47.361 INFO (MainThread) [ideenergy] : successful authentication 2023-12-12 07:50:47.361 DEBUG (MainThread) [ideenergy] Requesting data to the ICP, may take up to a minute. 2023-12-12 07:52:18.217 DEBUG (MainThread) [ideenergy] Got reply, raw data: {'valMagnitud': 'XXXX', 'valInterruptor': 'X', 'valEstado': 'XX', 'valLecturaContador': 'XXXX', 'codSolicitudTGT': 'XXXXXXXX', 'tipPot': ''} 2023-12-12 07:52:18.217 INFO (MainThread) [ideenergy] : ICP measure reading successful 2023-12-12 07:52:18.217 DEBUG (MainThread) [custom_components.ideenergy.barrier] success registered 2023-12-12 07:52:18.217 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update successful for MEASURE 2023-12-12 07:52:18.218 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 91.446 seconds (success: True) 2023-12-12 07:56:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-12-12 07:56:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: last success is too recent (269.554893 seconds, min: 540 seconds) 2023-12-12 07:56:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 0.001 seconds (success: True) 2023-12-12 08:01:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-12-12 08:01:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-12-12 08:01:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 0.001 seconds (success: True) 2023-12-12 08:05:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-12-12 08:05:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-12-12 08:05:47.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 0.001 seconds (success: True) 2023-12-12 08:10:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-12-12 08:10:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-12-12 08:10:17.772 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 0.001 seconds (success: True) 2023-12-12 08:13:52.939 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'AccumulatedConsumption' 2023-12-12 08:13:52.940 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'InstantPowerDemand' 2023-12-12 08:13:53.545 INFO (MainThread) [ideenergy] : '987654321' contract selected 2023-12-12 08:13:53.545 INFO (MainThread) [ideenergy] : successful authentication 2023-12-12 08:13:53.692 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000004673459jv_historical_consumption: cleaned 0 invalid states 2023-12-12 08:13:53.692 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalConsumption' 2023-12-12 08:13:53.692 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: HISTORICAL_CONSUMPTION 2023-12-12 08:13:53.692 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_CONSUMPTION 2023-12-12 08:13:53.694 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000004673459jv_historical_power_demand: cleaned 0 invalid states 2023-12-12 08:13:53.694 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalPowerDemand' 2023-12-12 08:13:53.699 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000004673459jv_historical_generation: cleaned 0 invalid states 2023-12-12 08:13:53.699 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalGeneration' 2023-12-12 08:13:53.705 DEBUG (DbWorker_0) [custom_components.ideenergy.fixes] sensor.es0021000004673459jv_historical_generation: no statistics found, nothing to fix 2023-12-12 08:13:53.722 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000004673459jv_accumulated_consumption: cleaned 1 invalid states 2023-12-12 08:13:53.722 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'AccumulatedConsumption' 2023-12-12 08:13:53.725 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000004673459jv_instant_power_demand: cleaned 1 invalid states 2023-12-12 08:13:53.726 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'InstantPowerDemand' 2023-12-12 08:13:54.122 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update successful for HISTORICAL_CONSUMPTION 2023-12-12 08:13:54.123 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxxxxxxx@gmail.com/987654321 coordinator data in 0.430 seconds (success: True) 2023-12-12 08:13:54.133 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: 144 historical states present in sensor 2023-12-12 08:13:54.133 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_power_demand: 0 historical states present in sensor 2023-12-12 08:13:54.134 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_generation: 0 historical states present in sensor 2023-12-12 08:13:54.139 DEBUG (DbWorker_2) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: cleaned 0 invalid states 2023-12-12 08:13:54.147 DEBUG (DbWorker_3) [custom_components.ideenergy.fixes] sensor.es0021000004673459jv_historical_consumption: no statistics found, nothing to fix 2023-12-12 08:13:54.155 DEBUG (DbWorker_2) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: no previous state found 2023-12-12 08:13:54.155 DEBUG (DbWorker_2) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: found 144 new states 2023-12-12 08:13:54.399 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: 144 states written into the database 2023-12-12 08:13:54.403 DEBUG (MainThread) [custom_components.ideenergy.sensor] sensor.es0021000004673459jv_historical_consumption: calculating statistics using 0 as base accumulated (registed at 1970-01-01 01:00:00+01:00) 2023-12-12 08:13:54.406 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.es0021000004673459jv_historical_consumption: 144 statistics points written into database 2023-12-12 08:13:54.411 ERROR (Recorder) [homeassistant.components.recorder.core] Unrecoverable sqlite3 database corruption detected: (sqlite3.IntegrityError) UNIQUE constraint failed: states_meta.entity_id [SQL: INSERT INTO states_meta (entity_id) VALUES (?) RETURNING metadata_id] [parameters: ('sensor.es0021000004673459jv_historical_consumption',)] (Background on this error at: https://sqlalche.me/e/20/gkpj) Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2112, in _exec_insertmany_context dialect.do_execute( File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 922, in do_execute cursor.execute(statement, parameters) sqlite3.IntegrityError: UNIQUE constraint failed: states_meta.entity_id

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

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 911, in _process_one_task_or_recover self._commit_event_session_or_retry() File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 1163, in _commit_event_session_or_retry self._commit_event_session() File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 1183, in _commit_event_session session.commit() File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1969, in commit trans.commit(_to_root=True) File "", line 2, in commit File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/state_changes.py", line 139, in _go ret_value = fn(self, *arg, *kw) ^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1256, in commit self._prepare_impl() File "", line 2, in _prepare_impl File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/state_changes.py", line 139, in _go ret_value = fn(self, arg, **kw) ^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1231, in _prepare_impl self.session.flush() File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 4312, in flush self._flush(objects) File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 4447, in _flush with util.safe_reraise(): File "/usr/local/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 146, in exit raise exc_value.with_traceback(exc_tb) File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 4408, in _flush flush_context.execute() File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/unitofwork.py", line 463, in execute n.executeaggregate(self, set) File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/unitofwork.py", line 567, in execute_aggregate self.execute(uow) File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/unitofwork.py", line 642, in execute util.preloaded.orm_persistence.save_obj( File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/persistence.py", line 93, in save_obj _emit_insert_statements( File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/persistence.py", line 1136, in _emit_insert_statements result = connection.execute( ^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1416, in execute return meth( ^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/sql/elements.py", line 516, in _execute_on_connection return connection._execute_clauseelement( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1639, in _execute_clauseelement ret = self._execute_context( ^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1843, in _execute_context return self._exec_insertmany_context( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2120, in _exec_insertmany_context self._handle_dbapi_exception( File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2343, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2112, in _exec_insertmany_context dialect.do_execute( File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 922, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.IntegrityError: (sqlite3.IntegrityError) UNIQUE constraint failed: states_meta.entity_id [SQL: INSERT INTO states_meta (entity_id) VALUES (?) RETURNING metadata_id] [parameters: ('sensor.es0021000004673459jv_historical_consumption',)] (Background on this error at: https://sqlalche.me/e/20/gkpj) 2023-12-12 08:13:54.499 ERROR (Recorder) [homeassistant.components.recorder.util] The system will rename the corrupt database file //config/home-assistant_v2.db to //config/home-assistant_v2.db.corrupt.2023-12-12T07:13:54.498962+00:00 in order to allow startup to proceed 2023-12-12 08:18:23.634 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-12-12 08:18:23.635 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed`

feserdel commented 8 months ago

In my case, after updating to last version v2.1.0, everything still working, but when trying to modify historical sensors from a second contract, database corruption has happened.

Fortunately, this time I was using a "DEV" server for HA, (previously I had a corruption and lost data on my Main HA server, but this time my main HA server is not affected), but ALL historical data of ALL my sensor was lost.

I found in the LOG this error:

2023-12-29 14:16:45.293 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'HistoricalConsumption'
2023-12-29 14:16:45.294 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'HistoricalGeneration'
2023-12-29 14:16:45.294 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'HistoricalPowerDemand'
2023-12-29 14:16:46.040 ERROR (Recorder) [homeassistant.components.recorder.core] Unrecoverable sqlite3 database corruption detected: (sqlite3.IntegrityError) FOREIGN KEY constraint failed
[SQL: INSERT INTO states (entity_id, state, attributes, event_id, last_changed, last_changed_ts, last_updated, last_updated_ts, old_state_id, attributes_id, context_id, context_user_id, context_parent_id, origin_idx, context_id_bin, context_user_id_bin, context_parent_id_bin, metadata_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) RETURNING state_id]
[parameters: (None, 'unavailable', None, None, None, None, None, 1703855805.294143, 5656304, 3428, None, None, None, 0, <memory at 0x7fd868276200>, None, None, 456)]
(Background on this error at: https://sqlalche.me/e/20/gkpj)
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2112, in _exec_insertmany_context
    dialect.do_execute(
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 922, in do_execute
    cursor.execute(statement, parameters)
sqlite3.IntegrityError: FOREIGN KEY constraint failed

I think that may be some problem on the database design of this integration, in particular when managing several contracts.

Le agradezco sinceramente todo el esfuerzo, pero por el momento no puedo usar la integracion en mi entorno real, por el riesgo de corrupción de la base de datos de sensores históricos

Las versiones usadas en el entorno:

Core 2023.12.4 Supervisor 2023.12.0 Operating System 11.2 Frontend 20231208.2

ldotlopez commented 8 months ago

Moving to discussion to #58