uvejota / homeassistant-edata

Home Assistant integration for spanish energy data providers (e.g., datadis)
GNU General Public License v3.0
260 stars 21 forks source link

Bug: error importing two years of data from Datadis #268

Open aritztg opened 1 week ago

aritztg commented 1 week ago

The integration was working flawlessly for weeks (if not months). It gathers data in a daily basis so it is perfect in that sense.

Today, I saw this option of "Importar todos los datos disponibles". And while I wasn't sure about the risk/reach of this action, I pressed it.

image

Because of the README.md file of this repo I understood this tried to get up to 2 years of data. So it sounded perfect as my integration was installed just few months ago.

But then all the data disappeared and nothing else happened. I checked the logs and saw this:

2024-10-18 10:08:39.670 WARNING (MainThread) [custom_components.edata.coordinator] Importing last two years of data from Datadis
2024-10-18 10:08:42.907 WARNING (MainThread) [custom_components.edata.coordinator] Running statistics integrity check
2024-10-18 10:08:56.964 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic is corrupt, its checksum is 1076.2699999999998, got 1729.8890000000022
2024-10-18 10:08:56.965 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic is corrupt, its checksum is 328.6099999999999, got 532.7400000000001
2024-10-18 10:08:56.965 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic is corrupt, its checksum is 289.0600000000001, got 465.3559999999995
2024-10-18 10:08:56.966 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic is corrupt, its checksum is 458.5700000000004, got 731.7930000000014
2024-10-18 10:08:56.967 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 4 corrupt statistics
2024-10-18 10:09:10.419 WARNING (MainThread) [custom_components.edata.coordinator] Clearing statistics for ['edata:br0f_consumption', 'edata:br0f_p1_consumption', 'edata:br0f_p2_consumption', 'edata:br0f_p3_consumption']
2024-10-18 10:30:53.415 WARNING (MainThread) [custom_components.edata.coordinator] Importing last two years of data from Datadis
2024-10-18 10:30:56.719 WARNING (MainThread) [custom_components.edata.coordinator] Running statistics integrity check

Nothing else happened. Then some minutes later, I enabled debugging in the integration, and pressed the same action again:

2024-10-18 10:31:11.085 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: performing integrity check since 2024-03-16 00:00:00+01:00
2024-10-18 10:31:11.259 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic not found
2024-10-18 10:31:11.259 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic is corrupt, its checksum is 1076.2699999999998, got 0
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic not found
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic is corrupt, its checksum is 328.6099999999999, got 0
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic not found
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic is corrupt, its checksum is 289.0600000000001, got 0
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic not found
2024-10-18 10:31:11.260 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic is corrupt, its checksum is 458.5700000000004, got 0
2024-10-18 10:31:11.260 DEBUG (MainThread) [custom_components.edata.coordinator] First evaluated sample of edata:br0f_surplus is 2024-03-16 01:00:00+01:00
2024-10-18 10:31:11.261 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 4 corrupt statistics
2024-10-18 10:31:11.262 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: rebuilding statistics
2024-10-18 10:31:24.866 WARNING (MainThread) [custom_components.edata.coordinator] %s: there are no corrupt statistics
2024-10-18 10:31:24.867 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: reducing cache items to last 13 months

And then again, nothing else. All previous consumption data gone. Have you faced some similar problem? I guess the root cause is in Datadis, or in that integrity check.

I guess the data clearing is somehow executed before the replacement and this happens after the data integrity check. Maybe the data clearing should be done only if the data integrity checks throws zero errors.

aritztg commented 1 week ago

I'd say the data comparison is made between the retrieved data and the previous existing data. I thought that maybe if there is no current data to check, then there wouldn't be any difference or conflict.

So just to check, I press the other action Restablecer:

2024-10-18 10:40:03.099 WARNING (SyncWorker_25) [custom_components.edata.coordinator] BR0F, soft wipe requested, preparing a backup
2024-10-18 10:40:03.099 WARNING (SyncWorker_25) [custom_components.edata.coordinator] BR0F: backup file is '/config/.storage/edata/edata_es0031405993491011br0f.json.bck', rename it back to '/config/.storage/edata/edata_es0031405993491011br0f.json' to restore it
2024-10-18 10:40:03.100 DEBUG (SyncWorker_25) [custom_components.edata.coordinator] BR0F: deleting mem cache

And executed again the two years data retrieval action:

2024-10-18 10:40:23.788 WARNING (MainThread) [custom_components.edata.coordinator] Importing last two years of data from Datadis
2024-10-18 10:40:52.048 WARNING (MainThread) [custom_components.edata.coordinator] Running statistics integrity check
2024-10-18 10:40:56.915 WARNING (MainThread) [custom_components.edata.coordinator] Running statistics integrity check
2024-10-18 10:41:18.921 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: performing integrity check since 2024-03-16 00:00:00+01:00
2024-10-18 10:41:19.247 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic not found
2024-10-18 10:41:19.248 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic is corrupt, its checksum is 1076.2699999999998, got 0
2024-10-18 10:41:19.248 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic not found
2024-10-18 10:41:19.248 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic is corrupt, its checksum is 328.6099999999999, got 0
2024-10-18 10:41:19.249 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic not found
2024-10-18 10:41:19.249 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic is corrupt, its checksum is 289.0600000000001, got 0
2024-10-18 10:41:19.249 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic not found
2024-10-18 10:41:19.249 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic is corrupt, its checksum is 458.5700000000004, got 0
2024-10-18 10:41:19.249 DEBUG (MainThread) [custom_components.edata.coordinator] First evaluated sample of edata:br0f_surplus is 2024-03-16 01:00:00+01:00
2024-10-18 10:41:19.250 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 4 corrupt statistics
2024-10-18 10:41:19.250 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: rebuilding statistics
2024-10-18 10:41:24.816 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: performing integrity check since 2024-03-16 00:00:00+01:00
2024-10-18 10:41:25.084 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic not found
2024-10-18 10:41:25.084 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_consumption' statistic is corrupt, its checksum is 1076.2699999999998, got 0
2024-10-18 10:41:25.084 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic not found
2024-10-18 10:41:25.084 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p1_consumption' statistic is corrupt, its checksum is 328.6099999999999, got 0
2024-10-18 10:41:25.084 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic not found
2024-10-18 10:41:25.085 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p2_consumption' statistic is corrupt, its checksum is 289.0600000000001, got 0
2024-10-18 10:41:25.085 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic not found
2024-10-18 10:41:25.085 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 'edata:br0f_p3_consumption' statistic is corrupt, its checksum is 458.5700000000004, got 0
2024-10-18 10:41:25.085 DEBUG (MainThread) [custom_components.edata.coordinator] First evaluated sample of edata:br0f_surplus is 2024-03-16 01:00:00+01:00
2024-10-18 10:41:25.086 WARNING (MainThread) [custom_components.edata.coordinator] BR0F: 8 corrupt statistics
2024-10-18 10:41:25.086 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: rebuilding statistics
2024-10-18 10:41:46.637 WARNING (MainThread) [custom_components.edata.coordinator] %s: there are no corrupt statistics
2024-10-18 10:41:50.489 WARNING (MainThread) [custom_components.edata.coordinator] %s: there are no corrupt statistics
2024-10-18 10:41:50.490 DEBUG (MainThread) [custom_components.edata.coordinator] BR0F: reducing cache items to last 13 months
aritztg commented 1 week ago

I added a simple early return in https://github.com/uvejota/homeassistant-edata/blob/7b7a2a6f2ed0bde229a521dc2fa6feaf042800be/custom_components/edata/coordinator.py#L357:

return True

Restarted HA. And the data was there. It looks OK to me, but I'm aware that may be some inconsistence. I don't know if I see data because the HA restart only, or because of that little hack skipping the data check.

Just sharing my experience if this can help others later. Feel free to close the ticket, @uvejota .