value warnings (skipping, not increasing, ...)

emufan commented 2 weeks ago

System Health details

System Information

version	core-2024.11.1
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.12.4
os_name	Linux
os_version	6.6.54-haos
arch	aarch64
timezone	Europe/Berlin
config_dir	/config

Home Assistant Community Store

Home Assistant Cloud

Home Assistant Supervisor

Dashboards

Recorder

Checklist

[X] I have read the FAQ to see if there is a known solution to my problem.
[X] I have enabled debug logging for my installation.
[X] I have filled out the issue template to the best of my ability.
[X] This issue only contains 1 issue (if you have multiple issues, open one issue for each issue).
[X] This issue is not a duplicate issue of currently previous issues..

Describe the issue

Yesterday I updated to 2024.11.1 and newerst powercalc. Coming from older version 2024.6 (because of AMP problems until .11).

Until then, the powercalc sensors never had any issues. But after the updates I now get tons of waring messages. Over and over again.

Reproduction steps

1. 2. 3. ...

Debug logs

Entity sensor.flur_energy_counter from integration powercalc has state class total_increasing, but its state is not strictly increasing. Triggered by state 102437.0115 (102.43701159999999) with last_updated set to 2024-11-11T17:34:15.827418+00:00. Please create a bug report at https://github.com/bramstroker/homeassistant-powercalc/issues
Entity sensor.wohnzimmerschrank_energy_counter from integration powercalc has state class total_increasing, but its state is not strictly increasing. Triggered by state 60295.8292 (60.295829299999994) with last_updated set to 2024-11-11T18:39:15.890206+00:00. Please create a bug report at https://github.com/bramstroker/homeassistant-powercalc/issues
Entity sensor.rollladen_energy_counter from integration powercalc has state class total_increasing, but its state is not strictly increasing. Triggered by state 113682.0750 (113.6820751) with last_updated set to 2024-11-11T23:19:16.000900+00:00. Please create a bug report at https://github.com/bramstroker/homeassistant-powercalc/issues
Entity sensor.kaffeemaschine_energy_counter from integration powercalc has state class total_increasing, but its state is not strictly increasing. Triggered by state 165053.6017 (165.0536018) with last_updated set to 2024-11-12T07:14:18.034208+00:00. Please create a bug report at https://github.com/bramstroker/homeassistant-powercalc/issues

or

skipping state for sensor.badezimmer_hinten_rechts_energy_counter, probably erroneous value or sensor was reset
skipping state for sensor.roomba_energy_counter, probably erroneous value or sensor was reset
skipping state for sensor.nachttischschrank_links_energy_counter, probably erroneous value or sensor was reset

Diagnostics dump or YAML config

No response

bramstroker commented 2 weeks ago

Sorry you are experiencing issues after HA and integration upgrades.

Unfortunately I'm not sure, never seen this error before.

Looking at the code where this error is raised in HA it logs an error when the state of the sensor is decreasing. Triggered by state 113682.0750 (113.6820751) 113682.0750 is the newly received state, 113.6820751 latest recorded.

Seems to be some decimal issue going on where decimals have shifted 3 positions, but I assume the first value is the in Wh and the second one in kWh. It's only an issue in the logging. So that would mean 113.6820750 is the new value and 113.6820751 the old value, thus the energy sensor is decreasing.

That must be some bug in the rieman integral sensor code, as that's what powercalc is using under the hood for the energy sensor.

Very hard one to debug as I don't have this issue and never heard about is before, and it's only happening on your system.

Few ideas from the top of my head to debug:

Are you using mariaDB of mysqlite as DB engine? Would be nice if you can check out the states table where HA records all the states, to see what is exactly going on.
Might also be an idea to enable debug logging for integration integration (this is the rieman sum heloer)

logger:
  logs:
    homeassistant.components.integration: debug

Create an energy sensor using the core HA helper (Rieman sum), for one of the problematic sensors. for example sensor.flur_energy_counter. Let it run for a bit, and see if it gives the same error.

Could you also share how you configured sensor.flur_energy_counter in Powercalc? And also if you have any additional global configuration defined?

emufan commented 2 weeks ago

Thanks for the quick reply.

ad 1. mysqlite. I will try to finde the values.

ad 2. Will do it.

ad 3. Will try as well.

ad 3. Defined this way

    - name: Flur
      entity_id: light.flur
      standby_power: 0.3
      fixed:
        power: 175

Here some debug log for the second kind of errors above

2024-11-12 17:34:51.990 DEBUG (MainThread) [custom_components.powercalc.sensors.group.custom] delta for entity sensor.kinderzimmer_mitte_hinten_energy_counter: -0.0001, prev=8698.0752, cur=8698.0751
2024-11-12 17:34:51.991 WARNING (MainThread) [custom_components.powercalc.sensors.group.custom] skipping state for sensor.kinderzimmer_mitte_hinten_energy_counter, probably erroneous value or sensor was reset

defined this way

    - create_group: Kinderzimmerdecke
      unique_id: unique_id_powercalc_kinderzimmerdecke
      entities:
        - entity_id: light.kinderzimmer_vorn
        - entity_id: light.kinderzimmer_mitte_vorn
        - entity_id: light.kinderzimmer_mitte_hinten
        - entity_id: light.kinderzimmer_hinten

where the devices are hue lights.

bramstroker commented 2 weeks ago

Second one is related to powercalc group sensors. Log lines with custom_components.powercalc.sensors.group.custom That's calculation routine which is part of powercalc.

Might be a one time issue. as there were some changes few months ago as how the group sensors calculate. I suggest to monitor this a few days and after several reboots. If this issue persists please let me know, than I'll dig further.

emufan commented 2 weeks ago

Somehow curious.

Here one example

Entity sensor.sonos_schlafzimmer_energy_counter from integration powercalc has state class total_increasing, but its state is not strictly increasing. Triggered by state 54477.3155 (54.477315600000004) with last_updated set to 2024-11-13T00:49:50.415118+00:00. Please create a bug report at https://github.com/bramstroker/homeassistant-powercalc/issues

defined this way

    - entity_id: media_player.sonos_schlafzimmer
      standby_power: 4.2
      fixed:
        power: 4.2
        states_power:
          playing: 5.7

with this settings

powercalc:
  enable_autodiscovery: false

  #  force_update_frequency: 00:10:00 #Default
  force_update_frequency: 00:05:00

  power_sensor_naming: "{} power"
  power_sensor_friendly_naming: "{} POWER"

  create_energy_sensors: true
  energy_sensor_unit_prefix: none
  energy_integration_method: left
  energy_sensor_naming: "{} energy_counter"
  energy_sensor_friendly_naming: "{} ENERGY_COUNTER"

  create_utility_meters: true
  utility_meter_types:
    - daily
    - weekly
    - monthly
    - yearly

Powercalc created sensor sensor.sonos_schlafzimmer_power is stable:

247712208 | NULL | 4.20| NULL | NULL | NULL | 0 | AZL1vbR3UsmJkIUHW3n5vA== | NULL | NULL | 48
247713276 | NULL | 4.20| NULL | NULL | NULL | 0 | AZL1wkiABVY5akkRKqZx+Q== | NULL | NULL | 48

but here we go

250642590 | NULL | 54478.3656 | NULL | NULL | NULL | NULL | 1731459890.4247851 | NULL | 1731459890.4247851 | 250641590 | 41137989 | NULL | NULL | NULL | 0 | AZMjDTz437Bh6m91iumTVA== | NULL | NULL | 209
250641590 | NULL | 54478.0156 | NULL | NULL | NULL | NULL | 1731459590.4237404 | NULL | 1731459590.4221025 | 250640659 | 41137989 | NULL | NULL | NULL | 0 | AZMjCKkWzKoft+rsTPpFGw== | NULL | NULL | 209
250640659 | NULL | 54477.6655 | NULL | NULL | NULL | NULL | 1731459290.4148781 | NULL | 1731459290.4148781 | 250639802 | 41137989 | NULL | NULL | NULL | 0 | AZMjBBUunB1Rh8CY6ckAfg== | NULL | NULL | 209
250639802 | NULL | 54477.3155 | NULL | NULL | NULL | NULL | 1731458990.415118 | NULL | 1731458990.415118 | 250639698 | 41137989 | NULL | NULL | NULL | 0 | AZMi/4FPS6afXGlkWlB2Cg== | NULL | NULL | 209
250639698 | NULL | 54477.3156 | NULL | NULL | NULL | NULL | 1731458990.414866 | NULL | 1731458990.414866 | 250638769 | 41137989 | NULL | NULL | NULL | 0 | AZMi/4FOYgJJ2wf6QFSjvw== | NULL | NULL | 209
250638769 | NULL | 54476.9655 | NULL | NULL | NULL | NULL | 1731458690.4140928 | NULL | 1731458690.4140928 | 250637894 | 41137989 | NULL | NULL | NULL | 0 | AZMi+u1uh2KvJlt2OYpHlQ== | NULL | NULL | 209

Converted timestamps from the last 4 entries

Mittwoch, 13. November 2024 01:54:50.414 GMT+01:00
Mittwoch, 13. November 2024 01:49:50.415 GMT+01:00
Mittwoch, 13. November 2024 01:49:50.414 GMT+01:00
Mittwoch, 13. November 2024 01:44:50.414 GMT+01:00

So:

Yes it is decreasing but it should not
But this is then same measurement (milliseconds)
Where the others have 5 minutes frequency
And still there is no 54.477315600000004

bramstroker commented 1 week ago

Seems integration is calculated twice at the same time, which you already noticed. That would probably be the cause of the issue. Calculating new integration should be triggered each time the power sensor changes state. Could you have a look into state changes of the power sensor?

emufan commented 1 week ago

SELECT * FROM "states" where metadata_id = 48 and last_reported_ts >= 1731457800 and last_reported_ts <= 1731459890.4247851

250639697 | NULL | 4.20 | NULL | NULL | NULL | NULL | 1731458990.4145453 | NULL | 1731458990.4145453 | 250638768 | 52591169 | NULL | NULL | NULL | 0 | AZMi/4FOHNLYIlnHSmykhg== | NULL | NULL | 48
250640658 | NULL | 4.20 | NULL | NULL | NULL | NULL | 1731459290.414584 | NULL | 1731459290.414584 | 250639697 | 52591169 | NULL | NULL | NULL | 0 | AZMjBBUufHwrQbwFfdtqag== | NULL | NULL | 48
250641589 | NULL | 4.20 | NULL | NULL | NULL | NULL | 1731459590.4219007 | NULL | 1731459590.4219007 | 250640658 | 52591169 | NULL | NULL | NULL | 0 | AZMjCKkVlfu2lhP516GyRQ== | NULL | NULL | 48
250642589 | NULL | 4.20 | NULL | NULL | NULL | NULL | 1731459890.4239852 | NULL | 1731459890.4239852 | 250641589 | 52591169 | NULL | NULL | NULL | 0 | AZMjDTz3cyst3z2fge+Y8A== | NULL | NULL | 48
250640658 | NULL | 4.20 | NULL | NULL | NULL | NULL | 1731459290.414584 | NULL | 1731459290.414584 | 250639697 | 52591169 | NULL | NULL | NULL | 0 | AZMjBBUufHwrQbwFfdtqag== | NULL | NULL | 48

converted (and sorted)

Mittwoch, 13. November 2024 02:04:50.423 [GMT+01:00]
Mittwoch, 13. November 2024 01:59:50.421 [GMT+01:00]
Mittwoch, 13. November 2024 01:54:50.414 [GMT+01:00]
Mittwoch, 13. November 2024 01:49:50.414 [GMT+01:00}
Mittwoch, 13. November 2024 01:44:50.413 [GMT+01:00]

So no multiple updates.

bramstroker commented 1 week ago

Could you try to create energy sensor using Riemann sum helper using HA helpers and see how that one goes?

emufan commented 1 week ago

Here we go. The helper is updating more often as expected as well, but at least without decreasing problems. I wonder if your round is not fitting to all cases.

251278445 | 54658.9705 | 1731615189.3340845 | Thursday, 14. November 2024 20:13:09.334 | sensor.sonos_schlafzimmer_energy_counter -- | -- | -- | -- | -- 251278444 | 156.8047996538333334650772872 | 1731615189.3328927 | Thursday, 14. November 2024 20:13:09.332 | sensor.sonos_schlafzimmer_test 251278443 | 4.20 | 1731615189.3324125 | Thursday, 14. November 2024 20:13:09.332 | power 251277273 | 54658.6205 | 1731614889.337978 | Thursday, 14. November 2024 20:08:09.337 | sensor.sonos_schlafzimmer_energy_counter 251277344 | 156.4547985198333334765072103 | 1731614889.3370688 | Thursday, 14. November 2024 20:08:09.337 | sensor.sonos_schlafzimmer_test 251277272 | 156.4547997798333334765072264 | 1731614889.3322308 | Thursday, 14. November 2024 20:08:09.332 | sensor.sonos_schlafzimmer_test 251277271 | 4.20 | 1731614889.33144 | Thursday, 14. November 2024 20:08:09.331 | power 251276097 | 54658.2704 | 1731614589.326542 | Thursday, 14. November 2024 20:03:09.326 | sensor.sonos_schlafzimmer_energy_counter 251276096 | 156.1047934553333334618601174 | 1731614589.326352 | Thursday, 14. November 2024 20:03:09.326 | sensor.sonos_schlafzimmer_test 251275989 | 54658.2705 | 1731614589.3261008 | Thursday, 14. November 2024 20:03:09.326 | sensor.sonos_schlafzimmer_energy_counter 251275988 | 156.1047940841666667951934304 | 1731614589.3258154 | Thursday, 14. November 2024 20:03:09.325 | sensor.sonos_schlafzimmer_test 251275987 | 4.20 | 1731614589.3253853 | Thursday, 14. November 2024 20:03:09.325 | power 251274699 | 54657.9204 | 1731614289.3243916 | Thursday, 14. November 2024 19:58:09.324 | sensor.sonos_schlafzimmer_energy_counter 251274806 | 155.7547925605000001290106149 | 1731614289.324209 | Thursday, 14. November 2024 19:58:09.324 | sensor.sonos_schlafzimmer_test 251274698 | 155.7547931403333334623440018 | 1731614289.3237016 | Thursday, 14. November 2024 19:58:09.323 | sensor.sonos_schlafzimmer_test

bramstroker commented 1 week ago

Interesting. Main issue is the integral sensor is updating twice at the same time.

Did you also set precision to 4, similar as the precision in powercalc?

Then we have hopefully similar behaviour between the integral sensor created with powercalc and HA core helper.

When the same issue arrises with the HA core helper, we at least know it's not a powercalc specific issue and can focus specifically on the logic in the integral helper code.

emufan commented 1 week ago

No, left it as as. Will update to 4.

emufan commented 1 week ago

here we go

a | b | c | d | e -- | -- | -- | -- | -- 252468272 | 4.20 | 1731928784.5321531 | Monday, 18. November 2024 11:19:44.532 | power 252466974 | 55022.9477 | 1731928484.5401328 | Monday, 18. November 2024 11:14:44.540 | sonos_schlafzimmer_energy_counter 252466973 | 520.7820 | 1731928484.539946 | Monday, 18. November 2024 11:14:44.539 | sonos_schlafzimmer_test 252466972 | 4.20 | 1731928484.5309834 | Monday, 18. November 2024 11:14:44.530 | power 252465683 | 55022.5976 | 1731928184.531031 | Monday, 18. November 2024 11:09:44.531 | sonos_schlafzimmer_energy_counter 252465682 | 520.4319 | 1731928184.5308018 | Monday, 18. November 2024 11:09:44.530 | sonos_schlafzimmer_test 252465677 | 4.20 | 1731928184.5267663 | Monday, 18. November 2024 11:09:44.526 | power 252464669 | 55022.2476 | 1731927884.5352206 | Monday, 18. November 2024 11:04:44.535 | sonos_schlafzimmer_energy_counter 252464561 | 520.0819 | 1731927884.5347624 | Monday, 18. November 2024 11:04:44.534 | sonos_schlafzimmer_test 252464562 | 55022.2477 | 1731927884.528676 | Monday, 18. November 2024 11:04:44.528 | sonos_schlafzimmer_energy_counter 252464558 | 4.20 | 1731927884.5257766 | Monday, 18. November 2024 11:04:44.525 | power 252463197 | 55021.8976 | 1731927584.514563 | Monday, 18. November 2024 10:59:44.514 | sonos_schlafzimmer_energy_counter 252463196 | 519.7319 | 1731927584.5143423 | Monday, 18. November 2024 10:59:44.514 | sonos_schlafzimmer_test 252463193 | 4.20 | 1731927584.5135257 | Monday, 18. November 2024 10:59:44.513 | power

bramstroker commented 4 days ago

Looking at your screenshot, it's only happening once that calculation (and state change) is done double for the energy sensor. The power sensor changing state and that should cause both energy sensors to be recalculated once.

Strange thing is it's not happening everytime.

Looking at the code of the riemann sum helper it's listening to both state_change and state_report events. Not sure what state report is exactly. https://github.com/home-assistant/core/blob/dev/homeassistant/components/integration/sensor.py#L444 So it might be in some cases the power sensor is triggering both events causing the calculation to be triggered twice at the same time. So essentially I think the issue is here where potentially 2 simultaneuous calculationgs are happening and this must be prevented in the powercalc core core.

Did you have same negative reporting issue with the helper you have set up now you have changes to 4 decimals?

emufan commented 4 days ago

Did you have same negative reporting issue with the helper you have set up now you have changes to 4 decimals?

That one is in the table as well `sonos_schlafzimmer_test´ and is not showing that behavior. Neither at the points, where it is happening for the powercalc one, nor anytime else.

bramstroker commented 3 days ago

Was debugging for a 2 hours yesterday, but could not reproduce. Now looking at the code again of the integration helper and what has been changed I might have an idea about the cause.

Previously the integration helper was only calculating when the source entity (power sensor) actually changed state. To work around that in the past I have added some code to make the Powercalc virtual power sensor force a state change on certain intervals to force the integration helper to recalculate. However in recent version the integration helper got quite an overhaul and they also implemented recalculation at time interval.

Both powercalc power sensor and the energy sensor (integral helper) have the same interval and they potentially will be executed at the same time. When power sensor happens to be the first in line, it will cause state change on integration helper, and skip the time based, but in the other case both will be executed. So that's why I can't reproduce, and it's a hit and miss.

That being said I really hope this is the issue. You can easily test it out by commenting this line in config/custom_components/powercalc/sensors/power.py https://github.com/bramstroker/homeassistant-powercalc/blob/master/custom_components/powercalc/sensors/power.py#L470

Let me know how it goes.

emufan commented 3 days ago

Was debugging for a 2 hours yesterday, but could not reproduce.

Here it is happening for nearly every PC-Sensor once a day.

You can easily test it out by commenting this line

Did it and just restated. Well keep you informed.

bramstroker / homeassistant-powercalc