search

ldotlopez / ha-ideenergy

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

Historical sensors storing data with wrong timestamp #54

Closed kikediazfernandez closed 8 months ago

kikediazfernandez commented 11 months ago

Since ~ 9 september data from historical sensors is stored with an offset of 2 hours. The energy dashboard shows the consumption with that offset.

Environment

Expected behavior Data is shown with the same values as i-de application

Logs

2023-10-12 14:40:14.171 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalConsumption'
2023-10-12 14:40:14.172 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalPowerDemand'
2023-10-12 14:40:14.178 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: HISTORICAL_CONSUMPTION, HISTORICAL_POWER_DEMAND
2023-10-12 14:40:14.178 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_CONSUMPTION
2023-10-12 14:40:17.045 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update successful for HISTORICAL_CONSUMPTION
2023-10-12 14:40:17.045 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND
2023-10-12 14:40:20.223 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: **FIXME** handle HISTORICAL_POWER_DEMAND raised exception: AssertionError()
2023-10-12 14:40:20.223 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching kike.diazfdez@gmail.com/776833388 coordinator data in 6.045 seconds (success: True)
2023-10-12 14:40:20.471 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: 3384 historical states present in sensor
2023-10-12 14:40:20.471 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_power_demand: 0 historical states present in sensor
2023-10-12 14:40:20.536 DEBUG (DbWorker_1) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: cleaned 0 invalid states
2023-10-12 14:40:20.554 DEBUG (DbWorker_1) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: lastest state found at 2023-10-11 20:00:00+00:00 (0.466)
2023-10-12 14:40:20.561 DEBUG (DbWorker_0) [custom_components.ideenergy.fixes] sensor.esxxxxxxxxxxxxxxx_historical_consumption: no problems found
2023-10-12 14:40:20.563 WARNING (MainThread) [homeassistant.components.energy.sensor] Found unexpected state_class None for sensor.esxxxxxxxxxxxxxxx_historical_consumption
2023-10-12 14:40:20.569 DEBUG (DbWorker_1) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: no new states
2023-10-12 14:40:20.569 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: 0 states written into the database
2023-10-12 14:40:20.617 DEBUG (MainThread) [custom_components.ideenergy.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: calculating statistics using 1937.6460000000027 as base accumulated (registed at 2023-10-11 21:00:00+02:00)
2023-10-12 14:40:20.617 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: 0 statistics points written into database
2023-10-12 14:44:50.681 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: HISTORICAL_CONSUMPTION, HISTORICAL_POWER_DEMAND
2023-10-12 14:44:50.681 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:04:33.636475 <= 6:00:00)
2023-10-12 14:44:50.681 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND
2023-10-12 14:44:54.064 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: **FIXME** handle HISTORICAL_POWER_DEMAND raised exception: AssertionError()
2023-10-12 14:44:54.064 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching kike.diazfdez@gmail.com/776833388 coordinator data in 3.384 seconds (success: True)
2023-10-12 14:44:54.084 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: 3384 historical states present in sensor
2023-10-12 14:44:54.084 DEBUG (MainThread) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_power_demand: 0 historical states present in sensor
2023-10-12 14:44:54.108 DEBUG (DbWorker_1) [homeassistant_historical_sensor.sensor] sensor.esxxxxxxxxxxxxxxx_historical_consumption: cleaned 1 invalid states
...

Screenshots image

Additional context Exit from python -m ideenergy --get-historical-consumption -u xxx -p xxx i-de.json

dump of datebase: sqlite3 home-assistant_v2.db 'select * from statistics;' > statistics statistics.txt

ldotlopez commented 10 months ago

Hi,

Data from your logs seems correct

For example, last value from the json output

                {'end': datetime.datetime(2023, 10, 12, 0, 0),
                 'start': datetime.datetime(2023, 10, 11, 23, 0),
                 'value': 466.0}]}

matches this row in the database dump

3384||1697114295.03163|1||1697050800.0||||||0.466|1937.646

The 1697050800 timestamp is expressed in UTC in Home Assistant database (two hours offset in mainline Spain)

In [4]: datetime.fromtimestamp(1697050800)
Out[4]: datetime.datetime(2023, 10, 11, 21, 0)

1- The ideenergy module outputs datetime objects without timezone offsets, just parses the returned JSON from i-de API and converts it into a datetime object. This is by design. 2- The ideenergy integration adds timezone to those objects according to the timezone defined in home assistant.

Two questions:

kikediazfernandez commented 10 months ago

Timezone is correct: (GMT+1) Madrid The comparison between energy panel and i-de energy user panel has an offset of 2 hours. The last day panel shows values until 21-22:00, as you can see above in the screenshot. It should show the whole day.

If you put 1697050800 in epochconverter it says: Assuming that this timestamp is in seconds: GMT: Wednesday, 11 October 2023 19:00:00 Your time zone: miércoles, 11 de octubre de 2023 21:00:00 [GMT+02:00] DST

Just in case there is any doubt:

>>> datetime.fromtimestamp(1697050800)
datetime.datetime(2023, 10, 11, 21, 0)
>>> datetime.utcfromtimestamp(1697050800)
datetime.datetime(2023, 10, 11, 19, 0)

>>> MAINLAND_SPAIN_ZONEINFO = dtutil.zoneinfo.ZoneInfo("Europe/Madrid")
>>> datetime(2023, 10, 11, 23, 0).replace(tzinfo=MAINLAND_SPAIN_ZONEINFO).timestamp()
1697058000.0
ldotlopez commented 10 months ago

You were right about timestamps… but I can't reproduce the bug, I tried the docker version of hass, pip, etc…

I have imported your data into my db and I can see that data ends at the 21-22:00 interval yes, but after the next fetch from i-de API it gets filled up to yesterday's 23:00-00:00

Just to try things… can you test over a fresh database? (backup, remove home-assistant_v2.db file, test, restore…) Let's see if the problem is in the data or in the code.

kikediazfernandez commented 10 months ago

The dump was on a new database, because I have changed the database to mariadb, and after this error I changed back to sqlite again for this test. states table shows the same offset in last_changed_ts and last_updated_ts timestamps. I can't figure out what the problem is because you replace timezone in the data collected from API.

kikediazfernandez commented 8 months ago

It seems to happen only if you change the period, as I had done.