tijsverkoyen / HomeAssistant-FusionSolar

Integrate FusionSolar into your Home Assistant.
MIT License
147 stars 27 forks source link

The Kiosk midnight glitch is back. #129

Closed AndersHoglund closed 8 months ago

AndersHoglund commented 8 months ago

Yesterday dec 6 and today I noticed the kiosk midnight glitch in lifetime energy is back. Days before was OK. Using the new Kiosk URL from Jan 1, by reinstalling and reconfiguring this kiosk integration at that time. All I can recall happening was two HA core updates on Dec 5 and 6. Screenshot 2024-01-07 at 12-42-03 History – Home Assistant Screenshot 2024-01-07 at 12-47-05 Settings – Home Assistant

AndersHoglund commented 8 months ago

It seems as the glitch-fix in energy_sensor.py is not triggered when realTimePower is zero. No debug log entry from that code. I only see this:

2024-01-07 15:11:26.156 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 15:11:26.156 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 15:11:26.454 DEBUG (SyncWorker_1) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 15:11:26.455 DEBUG (SyncWorker_1) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.061, 'cumulativeEnergy': 24653.96, 'monthEnergy': 8.41, 'dailyEnergy': 0.98, 'yearEnergy': 8.41} 2024-01-07 15:11:26.459 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.303 seconds (success: True) 2024-01-07 15:21:26.157 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 15:21:26.157 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 15:21:26.157 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 15:21:26.432 DEBUG (SyncWorker_5) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 15:21:26.432 DEBUG (SyncWorker_5) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 15:21:26.437 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.280 seconds (success: True) 2024-01-07 15:31:26.157 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 15:31:26.158 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 15:31:26.158 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 15:31:26.504 DEBUG (SyncWorker_2) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 15:31:26.505 DEBUG (SyncWorker_2) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 15:31:26.511 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.354 seconds (success: True) 2024-01-07 15:41:26.157 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 15:41:26.158 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 15:41:26.158 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 15:41:26.447 DEBUG (SyncWorker_0) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 15:41:26.447 DEBUG (SyncWorker_0) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 15:41:26.453 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.296 seconds (success: True)

AndersHoglund commented 8 months ago

I am stumped... All of a sudden it all starts working. I was playing with _LOGGER in energy:sensor.py trying to trace what was going on, and I got nothing out. And then it started to work. Began removing my _LOGGER statements, one by one. Still worked. Now I am back to untouched original code, still seems to work:

2024-01-07 17:43:23.069 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 17:43:23.069 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 17:43:23.069 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 17:43:23.368 DEBUG (SyncWorker_6) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 17:43:23.368 DEBUG (SyncWorker_6) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 17:43:23.373 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.305 seconds (success: True) 2024-01-07 17:43:23.374 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.energy_sensor] 0.0 2024-01-07 17:43:23.374 INFO (MainThread) [custom_components.fusion_solar.fusion_solar.energy_sensor] sensor.kronkarrs_huawei_vr_jrlnjclj3daml24an4f45piilxw36xax_total_lifetime_energy: not producing any power, so not updating to prevent positive glitched.

One thing I also did play with was the if realtime_power == '0.00': -statement. Comparing float equality is a classic problem. I tried to use the math function isclose(), no difference, no working fix. Now back to original code, and it all works again.

We will see after midnight if it still works.

AndersHoglund commented 8 months ago

Rebooted HA and the issue is back, no INFO log message .....not producing any power..... to be found :

2024-01-07 21:16:36.347 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 21:16:36.347 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 21:16:36.347 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 21:16:36.698 DEBUG (SyncWorker_0) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 21:16:36.698 DEBUG (SyncWorker_0) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 21:16:36.704 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.358 seconds (success: True)

AndersHoglund commented 8 months ago

I was fooled by slow logger updates, multiple async tasks and python caching when I did not see what was going on in the logs. It seems it actually is the float comparison causing trouble. I changed line 68 in energy_sensor.py to:

if math.isclose(realtime_power, 0, abs_tol = 0.001):

After HA restart I get those log entries:

2024-01-07 23:58:09.323 DEBUG (MainThread) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk] calculated API base url for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: https://uni002eu5.fusionsolar.huawei.com 2024-01-07 23:58:09.323 DEBUG (MainThread) [custom_components.fusion_solar.sensor] fusion_solar 2024-01-07 23:58:09.323 DEBUG (MainThread) [custom_components.fusion_solar.sensor] JrlNJcLJ3daMl24aN4F45PIiLxw36xax 2024-01-07 23:58:09.628 DEBUG (SyncWorker_1) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] Received data for JrlNJcLJ3daMl24aN4F45PIiLxw36xax: 2024-01-07 23:58:09.629 DEBUG (SyncWorker_1) [custom_components.fusion_solar.fusion_solar.kiosk.kiosk_api] {'realTimePower': 0.0, 'cumulativeEnergy': 24653.98, 'monthEnergy': 8.43, 'dailyEnergy': 1.0, 'yearEnergy': 8.43} 2024-01-07 23:58:09.635 DEBUG (MainThread) [custom_components.fusion_solar.sensor] Finished fetching FusionSolarKiosk data in 0.312 seconds (success: True) 2024-01-07 23:58:09.636 INFO (MainThread) [custom_components.fusion_solar.fusion_solar.energy_sensor] sensor.kronkarrs_huawei_vr_jrlnjclj3daml24an4f45piilxw36xax_total_lifetime_energy: not producing any power, so not updating to prevent positive glitched.

In an hour or two we will see what the energy tab looks like....