Skipping hour reading

[SVH-Powel]

Describe the bug
Tonight at 02:00 an hour reading was skipped. That is not a huge problem, but I find it irritating that the monthly max values are destroyed for the rest of the month.

I found no messages sent on mqtt either. And as you can see from the screenshot, there was no booting. The powu+ is on usb power and signal strength is -64dbm. Cable length to HAN interface is 1m.

Screenshots

Hardware information:

• Country: Norway
• Meter: Aidon
• Encryption enabled no
• AMS reader: Pow-U+

Relevant firmware information:

• Version: 2.2.28
• MQTT: yes
• MQTT payload type: Raw
• HAN baud and parity: 2400 8E1
• ENTSO-E API enabled: no

[SVH-Powel]

Additional info, but perhaps completely irrelevant:

It was running for 3 weeks in february with maximum power saving and on only HAN power. But it was booting often, probably because of low power available, but I don't know.

1st of march I got it connected to USB power and I also turned power saving off. 5 days later, this happens, but of course, a coincidence.

[ArnieO]

Interesting, as we had a similar bug report very recently.
When a whole-hour reading is skipped, the reader should average when it receives the next whole-hour reading with accumulated energy [kWh]. That did not happen here, it seems to have logged "zero" first, then the consumption for two hours.

Can you post what you get when you add "monthplot.json" to the URL?
That will show the numbers behind that graph. I want to see if the value is 0.00 for that period, or if there is some small number (for some reason).

Then we need to figure out why the averaging in some cases fails. -> @gskjold

[stigvi]

Interesting, as we had a similar bug report very recently. When a whole-hour reading is skipped, the reader should average when it receives the next whole-hour reading with accumulated energy [kWh]. That did not happen here, it seems to have logged "zero" first, then the consumption for two hours.

Can you post what you get when you add "monthplot.json" to the URL? That will show the numbers behind that graph. I want to see if the value is 0.00 for that period, or if there is some small number (for some reason).

Then we need to figure out why the averaging in some cases fails. -> @gskjold

There does not seem to be any problem with the daily data for the whole month. It is only one hour missing.

[ArnieO]

There does not seem to be any problem with the daily data for the whole month. It is only one hour missing.

Sorry, my bad.
Please add "/dayplot.json" to the URL and post the output.

[stigvi]

{
"i00": 8.17,
"i01": 4.78,
"i02": 4.81,
"i03": 4.75,
"i04": 4.36,
"i05": 2.86,
"i06": 2.54,
"i07": 2.93,
"i08": 3.08,
"i09": 3.01,
"i10": 2.72,
"i11": 2.39,
"i12": 4.75,
"i13": 4.3,
"i14": 3.25,
"i15": 3.84,
"i16": 3.42,
"i17": 2.64,
"i18": 2.07,
"i19": 2.16,
"i20": 2.76,
"i21": 4.21,
"i22": 3.84,
"i23": 0,
"e00": 0,
"e01": 0,
"e02": 0,
"e03": 0,
"e04": 0,
"e05": 0,
"e06": 0,
"e07": 0,
"e08": 0,
"e09": 0,
"e10": 0,
"e11": 0,
"e12": 0,
"e13": 0,
"e14": 0,
"e15": 0,
"e16": 0,
"e17": 0,
"e18": 0,
"e19": 0,
"e20": 0,
"e21": 0,
"e22": 0,
"e23": 0
}

[ArnieO]

Thank you - this confirms the registered value is 0.00.
Then @gskjold needs to figure out what happens here, as normal behavior is averaging (periods 00 and 01 should be identical, at 4.09).

[ArnieO]

Similar issue reported by email from a customer.
In this case, the consumption in the skipped hour seems to have been moved from "21" to "00".
I believe this is an old version Pow-U with ESP8266.

[ArnieO]

See update on #717.
Potentially linked.

[stigvi]

Happened again last evening. I am not sure how useful these reports are. You have to make some sort of better debugging to catch errors like this which happens each 14+++ days. Since the last time this happened in the beginning of march, I increased the buffer from 256 to 512. But that didn't help.

Device is a Pow-U+ on usb power and good wifi. Cable length to meter is 0.5m and the meter is an Aidon 6534.

[ArnieO]

You have to make some sort of better debugging to catch errors like this which happens each 14+++ days.

Yes, the fact that it appears very seldom amongst very few users makes it difficult to debug.
Your idea is to implement some kind of debug sensor that would forward some kind of debug data to HA.
Let us hear what @gskjold thinks about that proposition.

[stigvi]

3rd time this month. And this time it really messes up the tariff peaks.

I set the power saving to off a few days ago and I have a feeling that this happens more often when this setting is off.

[stigvi]

Question:

If I use "Default" as setting on Power Saving, does that mean that wifi.setsleep is not called / used in this code section?

if(WiFi.begin(wifi.ssid, wifi.psk)) {
if(wifi.sleep <= 2) {
switch(wifi.sleep) {
case 0:
WiFi.setSleep(WIFI_PS_NONE);
break;
case 1:
WiFi.setSleep(WIFI_PS_MIN_MODEM);
break;
case 2:
WiFi.setSleep(WIFI_PS_MAX_MODEM);
break;
}
}

Edit: I see that it changes to "Minimum" when set to "Default"

[stigvi]

According to the documentation for the espressif library, WiFi.setSleep() only accept a boolean as a parameter, but that is not how it is used in your code. But there is a lot of code here, so I might have overlooked something.....

[gskjold]

There are two ways of setting sleep, one with boolean and one with wifi_ps_type_t:
https://github.com/espressif/arduino-esp32/blob/abc01331a272663cbd596e7d2a28dd31b491d265/libraries/WiFi/src/WiFiGeneric.cpp#L1377

Default will not call setsleep in our code, which will default to whatever is standard in arduino. Currently that is minimum, as you already pointed out.

[gskjold]

I don't know how often this issue is presenting itself, but I have made some adjustments in the latest development build that may fix it, see #738

[gskjold]

For anyone who have upgraded to 2.3, have you experience this since?

[stigvi]

For anyone who have upgraded to 2.3, have you experience this since?

It happened 2-3 times each month so too soon to tell. After the summer, I can give you an answer if it doesn't happen before that.

[stigvi]

No, it has not changed to anything better. I wish you could have some sort of resetting the month max values manually because they are useless now until they are reset automatically on 1st of may.

[stigvi]

It look like I am in fact receiving data on the mqtt interface for the missing hour. The reported value is identical to the last hours value.

from_state:
    entity_id: sensor.klepp_energi_total_energi
    state: '109241.592'
    attributes:
      state_class: total_increasing
      unit_of_measurement: kWh
      device_class: energy
      friendly_name: Klepp Energi Total Energi
    last_changed: '2024-04-13T04:00:12.261360+00:00'
    last_reported: '2024-04-13T04:00:12.261360+00:00'
    last_updated: '2024-04-13T04:00:12.261360+00:00'
    context:
      id: 01HVASSRF5DM1GVZFR7E4EWVPH
      parent_id: null
      user_id: null
to_state:
    entity_id: sensor.klepp_energi_total_energi
    state: '109241.592'
    attributes:
      state_class: total_increasing
      unit_of_measurement: kWh
      device_class: energy
      friendly_name: Klepp Energi Total Energi
    last_changed: '2024-04-13T05:00:12.396898+00:00'
    last_reported: '2024-04-13T05:00:12.396898+00:00'
    last_updated: '2024-04-13T05:00:12.396898+00:00'
    context:
      id: 01HVAX7M7CBFMR4948DGDZ97JK
      parent_id: null
      user_id: null

[gskjold]

This has happened to me during the night. I have two devices connected to my meter which both lost the hourly update at 06:00:

This should have resulted in an calculated average for both hours, but instead all of it was set on the last hour. Most likely a code issue here which I will try to reproduce somehow. I have some ideas.

[gskjold]

Interesting discovery, one of these devices are sending data to a cloud server for testing, and the graph is exactly the same! Lucky for me, I have full debug logging enabled on that service, so I have extracted the JSON received at 05:00 and 06:00.

05:00 CEST:
{
   "data":{
      "clock":1713495611,
      "up":493841,
      "lastUpdate":493841,
      "est":false,
      "import":{
         "P":784,
         "Q":0,
         "tP":89074.328,
         "tQ":104.340
      },
      "export":{
         "P":0,
         "Q":447,
         "tP":0.000,
         "tQ":12022.860
      },
      "phases":{
         "1":{
            "u":233.30,
            "i":0.20
         },
         "2":{
            "u":233.20,
            "i":2.50
         },
         "3":{
            "u":232.10,
            "i":1.30
         }
      }
   }
}

06:00 CEST
{
   "data":{
      "clock":1713499212,
      "up":497441,
      "lastUpdate":497441,
      "est":false,
      "import":{
         "P":581,
         "Q":0,
         "tP":89074.328,
         "tQ":104.340
      },
      "export":{
         "P":0,
         "Q":455,
         "tP":0.000,
         "tQ":12022.860
      },
      "phases":{
         "1":{
            "u":232.00,
            "i":0.20
         },
         "2":{
            "u":230.40,
            "i":1.70
         },
         "3":{
            "u":228.70,
            "i":1.30
         }
      }
   }
}

"est":false means that the value sent is not estimated, but a real value received from the meter. And as you can see, import.tP is on both hours the same.

I am not sure what to think about this... I'd like to blame Aidon, but at the same time I find it hard to believe that the meter is sending the same data after an hour.. But I have also been digging through the code for the last hour, and I cannot see any reason why the data should get tainted internally.. This issue remains a mystery for me...

[stigvi]

If the meter is in fact sending the same value twice, it is not much to do about that. But you could make sure the month max values are not set to a false value and you could also make sure the estimated energy usage for current hour and current day based on integrating power is not reset to a false value.
If that is solved, it would be really great and a lot of code in my own system to get around this could be sent to the trash bin.

[gskjold]

For anyone who have ever experienced this, I'd like to know if you have a Aidon meter, and also I'd like to know the model of the meter as well as the communication module. Please see photo below how to find both:

[stigvi]

Aidon 6534
Aidon 6483SE
RF500

[gskjold]

Aidon 6534
Aidon 6475ME

[stigvi]

Happened this evening, but now I am able to handle it in Home Assistant and are also calculating a reasonable correct value for the missing hour and the next erronous hour

Amsreader:

Home Assistant:

[gskjold]

Although this is Aidons "fault", I have added a workaround in the code that will use the calculated value for that hour

[SVH-Powel]

Although this is Aidons "fault", I have added a workaround in the code that will use the calculated value for that hour

In the current version or the next one?

[ArnieO]

In the current version or the next one?

Next release