openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.88k stars 3.59k forks source link

[dsmr] ONLINE <-> OFFLINE #3920

Closed martinvw closed 6 years ago

martinvw commented 6 years ago

@Hilbrand I see some strange logs appearing:

2018-09-12 23:25:49.364 [hingStatusInfoChangedEvent] - 'dsmr:electricity_v5_0:0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Geen gegevens ontvangen van de meter.
2018-09-12 23:25:49.396 [vent.ItemStateChangedEvent] - Todays_Usage_kWH changed from 0.172 to -7124.750
2018-09-12 23:25:49.939 [hingStatusInfoChangedEvent] - 'dsmr:electricity_v5_0:0' changed from OFFLINE (COMMUNICATION_ERROR): Geen gegevens ontvangen van de meter. to ONLINE
2018-09-12 23:25:49.939 [vent.ItemStateChangedEvent] - Todays_Usage_kWH changed from -7124.750 to -3882.418
2018-09-12 23:25:49.942 [vent.ItemStateChangedEvent] - Todays_Usage_kWH changed from -3882.418 to 0.172

Please let me know whether you would prefer any other information :-)

martinvw commented 6 years ago

Never mind the negative values are not relevant the alternation between ONLINE and OFFLINE looks like a real bug though

Hilbrand commented 6 years ago

It happens when the no new values for the specific electricity_V5_0 thing are available. It could be the meter actually does not return values for this meter all the time. But I think this can also happen if you set your refresh rate higher than the actual timeframe the values are given by the meter. You can enable TRACE logging to get more detailed (but be warned, it will give a lot of data...so don't forget to set if off!) Based on this information I can see how I can improve this.

martinvw commented 6 years ago

And I see the cause of the negatives, one of values goes to 0 instead of NULL:

2018-09-12 23:52:16.702 [hingStatusInfoChangedEvent] - 'dsmr:electricity_v5_0:0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Geen gegevens ontvangen van de meter.
2018-09-12 23:52:16.709 [vent.ItemStateChangedEvent] - P1_Equipment_Id changed from E0034006756180616 to NULL
2018-09-12 23:52:16.711 [vent.ItemStateChangedEvent] - P1_Meter_DeliveryLow changed from 3242.471 to NULL
2018-09-12 23:52:16.712 [GroupItemStateChangedEvent] - E_Usage changed from 7125.061 to 3882.590 through P1_Meter_DeliveryLow
2018-09-12 23:52:16.713 [vent.ItemStateChangedEvent] - P1_Meter_DeliveryNormal changed from 3882.590 to NULL
----> 2018-09-12 23:52:16.713 [GroupItemStateChangedEvent] - E_Usage changed from 3882.590 to 0 through P1_Meter_DeliveryNormal
2018-09-12 23:52:16.713 [vent.ItemStateChangedEvent] - P1_Actual_Delivery changed from 0.221 to NULL
2018-09-12 23:52:16.714 [vent.ItemStateChangedEvent] - P1_Instant_Current_L1 changed from 0 to NULL
2018-09-12 23:52:16.715 [vent.ItemStateChangedEvent] - P1_Instant_Current_L2 changed from 0 to NULL
2018-09-12 23:52:16.715 [vent.ItemStateChangedEvent] - P1_Instant_Current_L3 changed from 0 to NULL
2018-09-12 23:52:16.715 [vent.ItemStateChangedEvent] - P1_Instant_Power_Delivery_L1 changed from 0.065 to NULL
2018-09-12 23:52:16.716 [vent.ItemStateChangedEvent] - P1_Instant_Power_Delivery_L2 changed from 0.091 to NULL
2018-09-12 23:52:16.716 [vent.ItemStateChangedEvent] - P1_Instant_Power_Delivery_L3 changed from 0.063 to NULL
2018-09-12 23:52:16.716 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L1 changed from 229.0 to NULL
2018-09-12 23:52:16.716 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L2 changed from 229.2 to NULL
2018-09-12 23:52:16.716 [vent.ItemStateChangedEvent] - Todays_Usage_kWH changed from 0.060 to -7125.001
2018-09-12 23:52:16.717 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L3 changed from 230.4 to NULL
2018-09-12 23:52:16.818 [vent.ItemStateChangedEvent] - P1_Equipment_Id changed from NULL to E0034006756180616
2018-09-12 23:52:16.819 [vent.ItemStateChangedEvent] - P1_Meter_DeliveryLow changed from NULL to 3242.471
2018-09-12 23:52:16.820 [GroupItemStateChangedEvent] - E_Usage changed from 0 to 3242.471 through P1_Meter_DeliveryLow
2018-09-12 23:52:16.821 [vent.ItemStateChangedEvent] - P1_Meter_DeliveryNormal changed from NULL to 3882.590
2018-09-12 23:52:16.821 [GroupItemStateChangedEvent] - E_Usage changed from 3242.471 to 7125.061 through P1_Meter_DeliveryNormal
2018-09-12 23:52:16.821 [vent.ItemStateChangedEvent] - P1_Actual_Delivery changed from NULL to 0.227
2018-09-12 23:52:16.822 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L1 changed from NULL to 228.9
2018-09-12 23:52:16.824 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L2 changed from NULL to 229.2
2018-09-12 23:52:16.826 [vent.ItemStateChangedEvent] - P1_Instant_Voltage_L3 changed from NULL to 230.5
2018-09-12 23:52:16.827 [vent.ItemStateChangedEvent] - P1_Instant_Current_L2 changed from NULL to 0
2018-09-12 23:52:16.827 [vent.ItemStateChangedEvent] - P1_Instant_Current_L1 changed from NULL to 0
2018-09-12 23:52:16.828 [vent.ItemStateChangedEvent] - Todays_Usage_kWH changed from -7125.001 to 0.060
2018-09-12 23:52:16.828 [hingStatusInfoChangedEvent] - 'dsmr:electricity_v5_0:0' changed from OFFLINE (COMMUNICATION_ERROR): Geen gegevens ontvangen van de meter. to ONLINE
martinvw commented 6 years ago

It only happens twice a minute, so normally it has fresh data every second, but sometimes not.

Lowering it to 2 seconds already made it less frequent I will test 3 and 5 seconds to be sure.

Should I keep it open or is it a configuration error?

Hilbrand commented 6 years ago

Currently it clears the data after reading, assuming the refresh rate is much higher then the actual data provided rate by the meter (I use 1 minute, and the meter sends data every 10 seconds). The binding doesn't make a difference between if the data was re-read or if no data was available so it reports the same: assuming it's the last case, so it reports it as an error. I'm going to think about how this can be improved.

Hilbrand commented 6 years ago

One additional question. What is your reason to set the refresh to 1 second? (Other than: because you can :smile: and it's the speed with which the data is send by the meter) Do use use these kind of detailed timeframes for some purpose?

martinvw commented 6 years ago

Other than I like the numbers to actually move... not yet

But I want to start monitoring my frying pan (frituur) for automatic reminders and I doubt whether I can pinpoint the exact moment its turned on (because the temperature dropped because I put the fries in...) if I go to a 1 minute resolution and I should not burn my fries of course :-D

Hilbrand commented 6 years ago

I'm not sure that is a really reliable safe way to monitor your frying pan :fire: Better use something like a wall plug that can monitor energy, like the tp-link hs110. I happen to know that one is supported by a binding :wink: