Possible bug after upgrade from old version

ldotlopez commented 1 year ago

I have detected some problems with dirty (vs. fresh installs) due new statistics calculation method. This error is related to upgraded installations from previous version, not fresh ones.

Errors logs shows exceptions like KeyError related to 'sum' or incompatible types in '+' operator.

While I work on a stable solution here are some tips if you're confident with command line. Each one is individual, if option A works for you just stop mangling things. If not, try next option if you understand what are you doing.

Remember to backup everything before proceed. I can't give support beyond fixing the upgrade path, recovering from failed attempt to fix is outside limits.

A. Try to update to v2.0.1

B. Clean up your database:

Write down related historical sensors: everything like sensor.esXXXX_historical
Stop homeassistant
Open the sqlite prompt
sqlite 'config/home-assistant_v2.db'
Get the metadata_id of each sensor:
select id from statistics_meta where statistic_id = 'sensor.esXXXXX_historical;' (mine is 114)
Update statistics_meta:
update statistics_meta set has_mean=1, has_sum=1 where id = <your_id>; (remember to replace with yours)
Delete incorrect values from statistics:
delete from statistics where (mean is null or sum is null or state is null) and metadata_id = <your_id>;
Start home-assistant

C. Wipe database: Just delete (ore temporally rename) the config/home-assistant_v2.db file, you will lose some history and stats, but anything else will stay.

D. Wait. Statistics are a complex stuff and importing data from past makes it worse. I'm trying my best to fix upgrade path

sirdir1972 commented 1 year ago

I think you are missing a ‘ in the select id line? Anyways I don‘t even get there because: Unable to open database "home-assistant_v2.db": file is encrypted or is not a database I thought it might be corrupted and did ‚C‘, but so far it still doesn‘t seem to work. And I get the same message when I try to open the db with sqlite.

ldotlopez commented 1 year ago

Hi @sirdir1972

I pushed a commit into main that incorporates all that stuff into the integration and warns about the fixes. It doesn't fixes it yet, I need to confirm some stuff.

Can you try the "v2.0.2a1" following these instructions?

Before upgrade please add those lines to your configuration.yaml:

logger:
logs:
homeassistant_historical_sensor: debug
custom_components.ideenergy: debug
custom_components.ideenergy.fixes: debug

Download the beta release "v2.0.2a0"
Post log lines with 'custom_components.ideenergy' or 'homeassistant_historical_sensor'

Thanks

sirdir1972 commented 1 year ago

Hi!

For now, I see only this (before the update I saw a 403 access denied error in the same spot):

2023-06-25 20:05:05.163 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-06-25 20:05:05.163 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed

sirdir1972 commented 1 year ago

same btw if I delete the db: 2023-06-25 20:13:04.301 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'AccumulatedConsumption' 2023-06-25 20:13:04.304 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-06-25 20:13:04.305 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-25 20:13:04.305 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xx/xxx coordinator data in 0.001 seconds (success: True)

sirdir1972 commented 1 year ago

Later: 2023-06-25 20:53:34.433 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: MEASURE 2023-06-25 20:53:34.434 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for MEASURE 2023-06-25 20:53:35.294 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for MEASURE: Forbidden (403) 2023-06-25 20:53:35.294 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxx coordinator data in 0.861 seconds (success: True)

ldotlopez commented 1 year ago

Some tips:

I think you don't have the historical consumption sensor enabled. There should be a "HISTORICAL_CONSUMPTION" request in the logs.
You have to configure energy panel to use some of the i-de sensor as source, i.e. sensor.es0022xxxxx_historical
Historical data is updated at startup and after 6 hours, also, i-de website can have a delay up to 24h for historical data.

sirdir1972 commented 1 year ago

Hi!

I think it was disabled when I re-installed the integration and I left it this way because the only one I really need is accumulated consumption. I’ve enabled them all now. Log says this now: 2023-06-26 11:12:13.948 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'AccumulatedConsumption' 2023-06-26 11:12:15.240 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_consumption: cleaned 0 invalid states 2023-06-26 11:12:15.240 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalConsumption' 2023-06-26 11:12:15.241 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.241 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.247 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_generation: cleaned 0 invalid states 2023-06-26 11:12:15.247 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalGeneration' 2023-06-26 11:12:15.248 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_power_demand: cleaned 0 invalid states 2023-06-26 11:12:15.248 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalPowerDemand' 2023-06-26 11:12:15.249 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_instant_power_demand: cleaned 0 invalid states 2023-06-26 11:12:15.249 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'InstantPowerDemand' 2023-06-26 11:12:15.263 DEBUG (DbWorker_2) [custom_components.ideenergy.fixes] sensor.es0021000000823349bs_historical_generation: no statistics 2023-06-26 11:12:15.270 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_accumulated_consumption: cleaned 1 invalid states 2023-06-26 11:12:15.271 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'AccumulatedConsumption' 2023-06-26 11:12:15.810 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update successful for HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.811 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 0.570 seconds (success: True) 2023-06-26 11:12:15.820 DEBUG (DbWorker_3) [custom_components.ideenergy.fixes] sensor.es0021000000823349bs_historical_consumption: no statistics 2023-06-26 11:16:45.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:04:29.343584 <= 6:00:00) 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:16:46.382 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:16:46.382 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:16:55.923 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:16:55.924 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.771 seconds (success: True) 2023-06-26 11:21:25.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:09:09.342619 <= 6:00:00) 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:21:26.521 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:21:26.521 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:21:36.105 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:21:36.106 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.953 seconds (success: True) 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:13:50.342039 <= 6:00:00) 2023-06-26 11:26:06.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:26:07.353 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:26:07.354 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:26:16.743 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:26:16.743 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.592 seconds (success: True)

I have the accumulated consumption as a source in energy…

Regards Patrick

On Jun 26, 2023, at 09:39, Luis López @.***> wrote:

Some tips:

I think you don't have the historical consumption sensor enabled. There should be a "HISTORICAL_CONSUMPTION" request in the logs. You have to configure energy panel to use some of the i-de sensor as source, i.e. sensor.es0022xxxxx_historical Historical data is updated at startup and after 6 hours, also, i-de website can have a delay up to 24h for historical data. — Reply to this email directly, view it on GitHub https://github.com/ldotlopez/ha-ideenergy/issues/50#issuecomment-1606887476, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADATTZHCBIRFZQ74OPN7R33XNE4CNANCNFSM6AAAAAAZTGEZOE. You are receiving this because you were mentioned.

sirdir1972 commented 1 year ago

It seems the historical consumption works fine, it’s the accumulated consumption and instant power that don’t update.

sirdir1972 commented 1 year ago

I think it is working now, no idea why.Sent from my iPhoneOn 26 Jun 2023, at 11:33, Patrick Kormann @.> wrote:Hi!I think it was disabled when I re-installed the integration and I left it this way because the only one I really need is accumulated consumption. I’ve enabled them all now. Log says this now: 2023-06-26 11:12:13.948 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Unregistered sensor 'AccumulatedConsumption' 2023-06-26 11:12:15.240 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_consumption: cleaned 0 invalid states 2023-06-26 11:12:15.240 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalConsumption' 2023-06-26 11:12:15.241 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.241 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.247 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_generation: cleaned 0 invalid states 2023-06-26 11:12:15.247 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalGeneration' 2023-06-26 11:12:15.248 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_historical_power_demand: cleaned 0 invalid states 2023-06-26 11:12:15.248 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'HistoricalPowerDemand' 2023-06-26 11:12:15.249 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_instant_power_demand: cleaned 0 invalid states 2023-06-26 11:12:15.249 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'InstantPowerDemand' 2023-06-26 11:12:15.263 DEBUG (DbWorker_2) [custom_components.ideenergy.fixes] sensor.es0021000000823349bs_historical_generation: no statistics 2023-06-26 11:12:15.270 DEBUG (MainThread) [custom_components.ideenergy.entity] sensor.es0021000000823349bs_accumulated_consumption: cleaned 1 invalid states 2023-06-26 11:12:15.271 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Registered sensor 'AccumulatedConsumption' 2023-06-26 11:12:15.810 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update successful for HISTORICAL_CONSUMPTION 2023-06-26 11:12:15.811 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 0.570 seconds (success: True) 2023-06-26 11:12:15.820 DEBUG (DbWorker_3) [custom_components.ideenergy.fixes] sensor.es0021000000823349bs_historical_consumption: no statistics 2023-06-26 11:16:45.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:04:29.343584 <= 6:00:00) 2023-06-26 11:16:45.154 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:16:46.382 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:16:46.382 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:16:55.923 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:16:55.924 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.771 seconds (success: True) 2023-06-26 11:21:25.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:09:09.342619 <= 6:00:00) 2023-06-26 11:21:25.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:21:26.521 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:21:26.521 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:21:36.105 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:21:36.106 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.953 seconds (success: True) 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Request update for datasets: ALL 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for MEASURE: update window is closed 2023-06-26 11:26:06.152 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update denied for HISTORICAL_CONSUMPTION: no max_age reached (0:13:50.342039 <= 6:00:00) 2023-06-26 11:26:06.153 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_GENERATION 2023-06-26 11:26:07.353 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_GENERATION: Forbidden (403) 2023-06-26 11:26:07.354 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update allowed for HISTORICAL_POWER_DEMAND 2023-06-26 11:26:16.743 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] update error for HISTORICAL_POWER_DEMAND: FIXME handle HISTORICAL_POWER_DEMAND raised exception: AssertionError() 2023-06-26 11:26:16.743 DEBUG (MainThread) [custom_components.ideenergy.datacoordinator] Finished fetching xxxyyy coordinator data in 10.592 seconds (success: True)I have the accumulated consumption as a source in energy… RegardsPatrickOn Jun 26, 2023, at 09:39, Luis López @.> wrote:Some tips:

I think you don't have the historical consumption sensor enabled. There should be a "HISTORICAL_CONSUMPTION" request in the logs. You have to configure energy panel to use some of the i-de sensor as source, i.e. sensor.es0022xxxxx_historical Historical data is updated at startup and after 6 hours, also, i-de website can have a delay up to 24h for historical data. —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: @.***>

ldotlopez commented 1 year ago

Hi,

I'm actively working on this.

I just pushed some changes into 'main' that should log some warning messages if your stats are broken. If you are affected by this bug, check the 'main' version and post your logs.

Warning: there are lots of situations where you are not getting statistics but not because of this bug. Check:

You have enabled historical sensors
Historical states can have a 24h delay, go one or two days back in the graphs to check it.
Historical states are refreshed at startup and each 6 hours.
Enable debug logs for this integration, check if there are errors
"HISTORICAL_GENERATION: Forbidden (403)" it's OK, i-de.es website is picky.
"MEASURE: update window is closed" it's OK.

gaRFio01 commented 1 year ago

Same problem here…

gaRFio01 commented 1 year ago

Creo que el problema está en la lectura desde el contador. Hace algún tiempo que no puedo recoger datos ni desde la propia aplicación de i-DE. He abierto una incidencia e indican que hay problemas de comunicación con el contador… Es posible que tenga algo que ver?

ldotlopez / ha-ideenergy

Possible bug after upgrade from old version #50