In Energy Dashboard, first hour of days importedby running the 'Octopus Energy: Refresh previous consumption data' service show negative bar in first hour

[emulti]

Describe the bug

First of all I set up the Integration as per docs, taking care to put the 'external statistics' rather than the 'sensor' versions of 'Previous Accumulative cost' on the Energy dashboard. Everything seemd t work fine, I had sane-looking hourly consumption data appearing for the previous day some time during each day.

Then I tried to run the 'Octopus Energy: Refresh previous consumption data' service to pull in a month's worth of historical data. I ran it on the two sensor entities.

The service call completed, but the 'historical' days (those prior to setting up the Integration that I had tried to pull in, and also previously-logged data starting two days prior to the current day) have a negative bar for the first hourly period of the day. The size of this bar for each day appears to be equal to the total of the day prior's consumption. Example:

Reproduction steps

Run the 'Refresh Previous Consumption Data' service on the Previous Accumulative Consumption entities.

Expected behaviour

Energy dashboard shows correct data, as is occurring on a day-by-day basis.

Tariff Code

E-1R-SILVER-FLEX-22-11-25-A, likewise Gas

Integration Version

10.0.3

Home Assistant Version

2024.01 core

Fresh Install?

Fresh install

Home Assistant Logs

Jan 26 14:23:46 pihole hass[71002]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 26 14:23:46 pihole hass[71002]:   File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 907, in entity_service_call
Jan 26 14:23:46 pihole hass[71002]:     raise result from None
Jan 26 14:23:46 pihole hass[71002]:   File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/entity.py", line 1493, in async_request_call
Jan 26 14:23:46 pihole hass[71002]:     return await coro
Jan 26 14:23:46 pihole hass[71002]:            ^^^^^^^^^^
Jan 26 14:23:46 pihole hass[71002]:   File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 943, in _handle_entity_call
Jan 26 14:23:46 pihole hass[71002]:     partial(getattr(entity, func), **data)  # type: ignore[arg-type]
Jan 26 14:23:46 pihole hass[71002]:             ^^^^^^^^^^^^^^^^^^^^^
Jan 26 14:23:46 pihole hass[71002]: AttributeError: 'OctopusEnergyPreviousAccumulativeGasConsumptionKwh' object has no attribute 'async_refresh_previous_consumption_data'

Confirmation

• [X] I confirm that I cannot find my solution within the documentation
• [X] I confirm that I cannot find my solution within the FAQ

[FireFury0]

I'm seeing the same negative consumption in the first hour for the peak and off-peak accumulative consumption sensors (but in my case I'm not refreshing the data). The octopus_energy_electricity_xxx_xxx_current_accumulative_consumption sensor works ok.

[emulti]

I tried deleting the sources for the energy dashboard and creating them again, making doubly sure to select the right entities. But the issue is still there. Is there a way to delete the historical data so I can try refreshing again? Inspecting the data for octopus_energy_electricity_xxx_xxx_current_accumulative_consumption shows that the negative value exists in the database.

[emulti]

I created a new database in the Mariadb backend, let the Integration populate the previous day's data, which it does correctly, and then ran the service again against the Electricity Meter entity. The result was the same- all days prior to the populated day show a negative first bar equal to the prior day' total consumption. So, it does look like the service has a problem creating the external statistics data. I can see in statistics/consumption.py and statistics/cost.py the calculation involves getting the prior day's total by calling the function async_get_last_sum. , then calling build_consumption_statistics . But I don't know enough about the internals of Hass Energy dashboard to follow it further.

[BottlecapDave]

Hello. I am unable to recreate this locally. Please follow the FAQ to start logs in debug mode, run the service again and then stop and submit the logs.

[emulti]

Thanks for responding! Debug log attached for service run from 1 January 2024 on 29 January 2024 on the Gas Meter entity. Result produces incorrect Energy Dashboard results from 27th back to 1st January. home-assistant_octopus_energy_2024-01-29T21-00-57.240Z.log

[emulti]

Screenshots of the resulting graphs. 27th Jan

26th Jan (1st-25th are similar)

Since original report HA has been upgraded to 2024-1-3 from 2024-1-0 with no change in behaviour.

[BottlecapDave]

Sorry, I'm struggling to follow what you're seeing. If you ran a service import from 01-01-2024 to 28-01-2024 (based on your logs), what day(s) are you seeing the negative bar?

1) 00:00 every day between 01st to 28th 2) 00:00 on 01-01-2024 3) 00:00 on 31-12-2023 4) 00:00 pm 29-01-2024 5) Something else

Are you providing a single or multiple entities into the service?

The data in the logs look correct and perform the same function as when the previous consumption sensor gets populated normally every day. The consumption is always the accumulated total up to that point, hence why it retrieves the last sum before creating the calculations. I also use the standard database, not MariaDB so not sure if there is something wrong with the adapter.

[emulti]

Sorry, I will try to be more clear. To produce the logs, the service was runon 29th January with a start date of 01/01/2024. It was applied to the 'gas meter' device.

The resulting Energy Dashboard graphs for Gas show a negative bar at 00.00 for each day from 01/01/24 to 27/01/24. From 01/01/24 to 26/01/24 the negative bar appears to be equal in size to the total of the previous day's consumption. A typical example is in the second image of my previous post. The days from 01/01 to 26/01 are all similar. On 27/01/24 the negative bar at 00:00 is very large (first image in my previous post). Perhaps it's the total of all the days from 01/01 to 26/01? The graphs for 28/01/24 and now, a day later, 29/01/24 are normal. In other ords the data for 28/01/24 was not affected by running the service.

Am I running the service against the wrong entity? This is what I ran:

If I try to run it against the 'Previous Accumulative Consumption' entity for Gas or Electricity, I get an error "Failed to call service octopus_energy.refresh_previous_consumption_data. Unknown error" and the service doesn't run.

There are a number of errors recorded at the end of the log, of the form

2024-01-29 20:56:40.084 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: 'OctopusEnergyPreviousAccumulativeGasConsumptionKwh' object has no attribute 'async_refresh_previous_consumption_data'
Traceback (most recent call last):
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 713, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/entity_platform.py", line 831, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 907, in entity_service_call
    raise result from None
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/entity.py", line 1497, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 943, in _handle_entity_call
    partial(getattr(entity, func), **data)  # type: ignore[arg-type]
            ^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'OctopusEnergyPreviousAccumulativeGasConsumptionKwh' object has no attribute 'async_refresh_previous_consumption_data'
2024-01-29 20:56:40.253 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [546606533056] Error handling message: Unknown error (unknown_error) [name redacted] from [ip redacted] (Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36)
Traceback (most recent call last):
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/components/websocket_api/decorators.py", line 26, in _handle_async_response
    await func(hass, connection, msg)
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/components/websocket_api/commands.py", line 782, in handle_execute_script
    script_result = await script_obj.async_run(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 1587, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 426, in async_run
    await self._async_step(log_exceptions=False)
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 479, in _async_step
    self._handle_exception(
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 502, in _handle_exception
    raise exception
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 713, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/entity_platform.py", line 831, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 907, in entity_service_call
    raise result from None
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/entity.py", line 1497, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/var/lib/hass/.venv/lib/python3.11/site-packages/homeassistant/helpers/service.py", line 943, in _handle_entity_call
    partial(getattr(entity, func), **data)  # type: ignore[arg-type]
            ^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'OctopusEnergyPreviousAccumulativeGasConsumptionKwh' object has no attribute 'async_refresh_previous_consumption_data'

[BottlecapDave]

I believe if you're running it against the device, it might be tripping over itself as it's running it against all entities in parallel. If you could try the m3 version of the gas entity. I'll try and find some examples or better docs at restricting the service, but the HA dev docs are minimal.

[emulti]

I just reverted to the SQLite backend to eliminate that from the equation. You are correct, running against the electricity_previous_accumulative_consumption or gas_previous_accumulative_consumption entities allow the service to run, whereas the gas_previous_accumulative_consumption_kWh entity gives the error AttributeError: 'OctopusEnergyPreviousAccumulativeGasConsumptionKwh' object has no attribute 'async_refresh_previous_consumption_data'

But, sad to report, the resulting graphs in the Energy dashboard are still incorrect. It's slightly different this time, however. Days where previous consumption had already been logged in that database on a day-by-day basis are OK- but all the other graphs from 01/01 to 29/01 have the negative bar at 0:00.

Now I am going to try running against a clean database (which is easier to do with MariaDB I think)

[emulti]

Hmm. Result of running the service using a clean database on Gas [xxx] [yyy] Previous Accumulative Consumption entity:

01/01/24: correct 02: negative bar at 0:00 03: 60kWh positive bar at 0:00 04, 05: negative bar at 0:00 06: correct 07, 08, 09, 10: negative bar at 0:00 11: correct 12-29 inclusive: negative bar at 0:00

Maybe the information is hitting the Home Assistant web service backend faster than it can properly handle it, and effectively we have a 'race condition'? Is it possible to 'slug' the writes to happen, say, every few seconds to see if this is the case?

Running the same service call again produces a different set of incorrect results. What I am suggesting, with my very limited understanding of async prgramming in Python, is that if an 'async_get_last_sum' call has not returned a result by the time the next bit of data is written, then the results will be wrong, and the errors will cascade down the dates.

[emulti]

I did some further experiments. This does indeed seem to be a result of cascading errors related to API performance when getting the previous day's sum. It doesn't seem to make a difference whether SQlite or Mariadb is used as the back end. This system is not a low-performance one, with an 8-core Arm64 processor and an EMMC for storage. CPU usage is 3-6% for Hass on a single core. Other applications I have run on the same hardware in the past seemed to have no problem with database latency, so I am assuming it's a question of latency in the Recorder API. By repeated runs of the service with an increasingly-short timeframe to update, I found it's possible to 'push' the 'wrong' days up to 'yesterday' and obtain a set of good data, eventually. Therefore I tentatively suggest adding delay to the refresh logic, to ensure all updates for a given day are committed to the database before the next days' values are sent. The default commit_interval in Home Assistant is 5s to limit writes on SDcards, so it might be worth trying.

[emulti]

More testing. Results do differ depending on the database backend used. I ran the service with a start date of 20th December, about 40 days ago. Results seem repeatable. commit_interval was set to 0 rather than the default 5 seconds but this parameter seems to make no difference to results. CPU and RAM usage was minimal throughout.

Mariadb: Running the service against one only of the Electricity or Gas entities produces correct results for the first 1-3 days of the requested period only. All dates after that up to yesterday have a negative bar at 00:00. From the debug logs, the Integration is sending the correct data to Home Assistant for the first period (00:00) of each day. However, the value actually recorded in the database is incorrect, a negative value which seems related to the total consumption the previous day. If the start date is adjusted to the first incorrect day, and the service run again, the first 1-3 days are OK, then incorrect data is recorded for 00:00 again for that day up to yesterday.

Sqlite: Running against both electricty and gas entities produced the same results as Mariadb. But running against only one entity first produced 2-3 days of correct results, followed by the remainder with the negative bar. When running again, the correct data is obtained for that entity up to yesterday. Two runs were necessary.

A possible explanation might be that the Mariadb integration suffers latency that is less apparent with SQLite, at least with smaller databases. I have never seen incorrect data recorded for either backend for the day-by-day statistics recording, however. It might be worth rate-limiting the calls to the Recorder API to see if this effect can be mitigated.

[BottlecapDave]

Thanks for the investigation. I'm wanting to avoid rate limiting or waiting arbitrary amounts of time as this is prone to error if HA ever tweaks their processes or it's a hardware influence which can change. I think what I can probably do is only look up the initial sum value in the first processing, and then rely on initial values for each day being passed by the previous loop.

I'll try and find some time within the next couple of weeks to take a look at it.

[BottlecapDave]

I've updated the service to keep track of previous totals and only go to the database on the first addition. This update is present in v10.1.0. Hopefully this will fix your issue.

[emulti]

Thanks very much for the fix! I tested this with both the Mariadb and SQLite backends, and it worked correctly. HA version Core2024.2.0, Frontend 20240207.0 Test periods used- 10 and 60 days. It takes a minute or so for the Energy Dashboard to collate the new data for display.

[BottlecapDave]

Excellent. Thanks for the report and the testing. Hopefully someone in the future won't face the same issue.