UtilitechAS / amsreader-firmware

ESP8266 and ESP32 compatible firmware to read, interpret and publish data to MQTT from smart electrical meters, both DLMS and DSMR is supported
Other
389 stars 73 forks source link

Wrong (truncated) prices / cheapest hours list sent on MQTT at reboot #457

Closed arghle closed 1 year ago

arghle commented 1 year ago

Describe the bug Recently upgraded to 2.2.8. My home assitant automation that relies on the "cheapest 3hr ahead" sent over mqtt is going haywire. I installed mqtt explorer and it seems to be ping-ponging between a truncated list of prices and the full list:

{"id":"58:CF:79:A0:D9:1E","prices":{"0":0.5547,"1":0.6029,"2":0.6129,"3":0.5087,"4":0.4289,"5":0.4076,"6":0.3555,"7":0.3121,"8":0.3657,"9":0.4100,"10":0.5119,"11":0.5806,"min":0.3121,"max":0.6420,"cheapest1hr":"2023-02-20T03:00:00Z","cheapest3hr":"2023-02-20T02:00:00Z","cheapest6hr":"2023-02-20T00:00:00Z"}}

vs

{"id":"58:CF:79:A0:D9:1E","prices":{"0":0.5547,"1":0.6029,"2":0.6129,"3":-127.0000,"4":-127.0000,"5":-127.0000,"6":-127.0000,"7":-127.0000,"8":-127.0000,"9":-127.0000,"10":-127.0000,"11":-127.0000,"min":0.5547,"max":0.6129,"cheapest1hr":"2023-02-19T20:00:00Z","cheapest3hr":"2023-02-19T20:00:00Z","cheapest6hr":""}}

This seems to happen about once per minute, with the "wrong"/"truncated" version coming 2 seconds before the correct version. "Enable price fetch from remote server" is enabled. I also noticed that the "uptime" counter in the upper-left part of the gui seems to be resetting every minute, so maybe this is all a consequence of a reboot loop?

To Reproduce Steps to reproduce the behavior:

  1. Start mqtt explorer
  2. Click on AMSData -> Prices
  3. See "wrong data" coming in about 2s before correct data

Expected behavior Price data sent over mqtt is stable, only changes every top-of-the-hour, and always has all data available.

Hardware information:

Relevant firmware information:

Additional context Add any other context about the problem here.

arghle commented 1 year ago

Changed title to inclide "at reboot". Looks like this was caused by rebooting every minute. Added external power to the powu and now it stopped sending the truncated prices list. I guess this might be a thing to look into anyway, if rebooting makes it first send a truncated list then the whole list.

Using an entso-e api key by the way.

ArnieO commented 1 year ago

Pow-U on Kaifa should not need external power - so there is something wrong here. From your name (comes up in the email notification I received), I find your board is layout version 1.6. You HAN GPIO is then GPIO16.

What are your Wifi settings, in particular these two? image

arghle commented 1 year ago

I had: power saving: minimum, auto reboot: true. Then I changed it to power saving: maximum, auto reboot: false - but it still kept rebooting. Will collect more data this evening.

ArnieO commented 1 year ago

As explained in this blogpost, we recommend setting Power saving to Maximum on Pow-U. You did that now, and it still reboots - which it should not.

Is the voltage dropping before it reboots?

This could be a problem with your Pow-U, in which case we will send you a replacement. If you are still seeing weird things this evening, please download a config file (info screen), and email it to me on post@amsleser.no.

gskjold commented 1 year ago

Keep in mind that it could also be traffic on the network keeping the device awake. Ex something constantly running a ping on the device to check if it is up will keep it awake. Or multicast traffic from another device on the network.

Regarding the two different price payloads, this is a result of the device fetching prices by date. It first gets todays price whick triggers an update to mqtt before fetching next date which triggers the second message.

arghle commented 1 year ago

Keep in mind that it could also be traffic on the network keeping the device awake. Ex something constantly running a ping on the device to check if it is up will keep it awake. Or multicast traffic from another device on the network.

Maybe two stats: (wake-ups from direct traffic, wake-ups from multicast traffic) could be something to track as well. I'm not aware of any such traffic on my network but I'm guessing many would not be aware either.

Regarding the two different price payloads, this is a result of the device fetching prices by date. It first gets todays price whick triggers an update to mqtt before fetching next date which triggers the second message.

Yep, I was assuming as much. Would it be possible to change that to not trigger the mqtt update before it has data for the full prices array? It shouldn't normally be a problem but maybe it can trip up someone else who use the "cheapest hour" or prices array info after a more legitimate reboot.

gskjold commented 1 year ago

Yep, I was assuming as much. Would it be possible to change that to not trigger the mqtt update before it has data for the full prices array? It shouldn't normally be a problem but maybe it can trip up someone else who use the "cheapest hour" or prices array info after a more legitimate reboot.

Probably, but will have to look at that at a later time.

gskjold commented 1 year ago

In any case, having the config file rewieved as @ArnieO suggested is a good call to rule out hardware config issues

arghle commented 1 year ago

Disconnecting external power with it being on maximum + don't-reboot-on-errors (which field are these in the config file btw?) put it back to rebooting, with voltage fluctuating between 2.9 and 3.1. But - I set up a guest network for it and moved it over there as suggested by the user guide, and now it seems to be behaving much better, with a pretty constant 3.2v and nice uptime. (wifi is google wifi, set up a guest network and let it talk to the rpi running mqtt+etc.) ... now the only problem is I can't access the web UI from any other device without switching to the guest network. But that's ok.

So I think the reboot loop was caused by more multicasty traffic than I had expected on my network. For me it seems to be coming from Sonos devices (as opposed to chromecasty traffic). Got to play with wireshark again for the first time in many years. (=

I'm OK with this issue being closed or kept open until someone has the time to make it not trigger mqtt sending for the first of two price gathering queries.

gskjold commented 1 year ago

OK, good to hear that you figured it out. I will put sonos on my list of possible sources of noisy traffic :)

gskjold commented 1 year ago

Btw, good point about the reboot on error in cfg file, it does not exist there. Will have to fix that.

ArnieO commented 1 year ago

But this is strange. The "Maximum" setting is expected to give the ESP32 "earplugs" so that it can sleep even if there is Broadcast/Multicast activity on the network. The downside being a less "snappy" user interface, we've heard. Was something done in this section of the code between 2.1 and 2.2 that could have affected the functionality? I have not retested this on v2.2.

gskjold commented 1 year ago

The section of the code dealing with power saving is identical in 2.1.17 and 2.2.8

General changes for WiFi between these versions:

Depending on what kind of traffic is on the network, there will still be types of traffic that could affect the ESP, it just depends on how the sender targets it's receiver(s).

ArnieO commented 1 year ago

Depending on what kind of traffic is on the network, there will still be types of traffic that could affect the ESP, it just depends on how the sender targets it's receiver(s).

OK, so this is more complex than previously assumed. This is the first time I have heard of a Pow-U set to Maximum power saving that is not able to avoid voltage loss reboots due to Wifi traffic (which seems quite clearly to be the case here).

arghle commented 1 year ago

I'm happy to test various ideas and fw builds if that helps.

gskjold commented 1 year ago

You mentioned wireshark, I am curious what the traffic from Sonos was targeted at, was it directly targeted at the IP address or was it to a multicast address? If so, which multicast address?

arghle commented 1 year ago

This was multicast, possibly upnp related? I can find the address later.

gskjold commented 1 year ago

Next version will only publish one payload with prices when fetching for both today and tomorrow at the same time