Tasmota: kWh today is wrong

Created on 23 Aug 2020  路  14Comments  路  Source: arendst/Tasmota

PROBLEM DESCRIPTION

EnergyToday counter is way off on calibrated HiHome WPP-16S1 smart plug
2 examples when charging car (Tasmota shows slowly increasing power, maybe heat. Let us ignore that hardware problem).

Start 02:00:47 End: 04:18:47
Using 3458W at start, 3533 at end.

Expected value is around (2 + 18/60) * 3500W = 8050W.
But energy Today goes from 0.053 -> 9.856, so shows 9803W. So 21% too much.
EnergiTotal has same values.

Another sample lower load.
Start @ 922W, 59 minutes later 1004W.
Let us assume 965W * (59/60) hours = 948W.

Today is 9.902 - > 11.108 so 1.206. 1206/928 = 1.27x - So 27% too much.

I looked a bit around in the code (xnrg_14_bl0940.ino)

I can see each second this is done:

cf_pulses = (0x1000000 - Bl0940.cf_pulses_last_time) + Bl0940.cf_pulses;
...
uint32_t delta = (cf_pulses * watt256) / 36;
...
Energy.kWhtoday_delta += delta;

So I can not really see the cuase. Issue #7155 is some of the same, but my code has 4000W as the max. So it is not fixed by that. My values are also way further off. And much higher.

Though it might be cause by always rounding up, but can't find much rounding browsing the sources.

Not having any hardware experience with these units, I am really at a loss here. 1 hour @ 1kW load should give me 1kWh extra.

And code indicates that number og pulses is read from a chip, it is not only interrupt driven pulses that gets missed once in a while.

REQUESTED INFORMATION

_Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!_

  • [ x] Read the Contributing Guide and Policy and the Code of Conduct
  • [ x] Searched the problem in issues
  • [ x] Searched the problem in the docs
  • [ x] Searched the problem in the forum
  • [ x] Searched the problem in the chat
  • [x ] Device used (e.g., Sonoff Basic): HiHome WPP-16S1
  • [ ] Tasmota binary firmware version number used: _____

    • [x ] Pre-compiled

    • [ ] Self-compiled

    • [ ] IDE / Compiler used: _____

  • [ ] Flashing tools used: _____
  • [x] Provide the output of command: Backlog Template; Module; GPIO 255:
  11:54:29 CMD: Backlog Template; Module; GPIO 255
11:54:29 MQT: stat/tasmota/RESULT = {"NAME":"HIhome WPP-16S","GPIO":[17,0,0,0,134,132,0,0,131,56,21,0,0],"FLAG":0,"BASE":49}
11:54:29 MQT: stat/tasmota/RESULT = {"Module":{"0":"HIhome WPP-16S"}}
11:54:30 MQT: stat/tasmota/RESULT = {"GPIO0":{"17":"Button1"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"134":"BL0937 CF"},"GPIO5":{"132":"HLWBL CF1"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"131":"HLWBL SELi"},"GPIO13":{"56":"Led1i"},"GPIO14":{"21":"Relay1"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"}}

  • [ ] If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:
  Rules output here:


  • [ ] Provide the output of this command: Status 0:
11:55:11 MQT: stat/tasmota/STATUS = {"Status":{"Module":0,"DeviceName":"Schuko","FriendlyName":["Schuko"],"Topic":"tasmota","ButtonTopic":"0","Power":1,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0}}
11:55:11 MQT: stat/tasmota/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://thehackbox.org/tasmota/release/tasmota.bin","RestartReason":"Software/System restart","Uptime":"0T00:01:00","StartupUTC":"2020-08-24T10:54:11","Sleep":50,"CfgHolder":4617,"BootCount":49,"BCResetTime":"2020-07-06T19:47:42","SaveCount":242,"SaveAddress":"F6000"}}
11:55:11 MQT: stat/tasmota/STATUS2 = {"StatusFWR":{"Version":"8.4.0.3(tasmota)","BuildDateTime":"2020-08-24T12:05:13","Boot":31,"Core":"2_7_4_1","SDK":"2.2.2-dev(38a443e)","CpuFrequency":80,"Hardware":"ESP8266EX","CR":"386/699"}}
11:55:11 MQT: stat/tasmota/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["P28_24GHz","PHP-XR"],"TelePeriod":60,"Resolution":"558180C0","SetOption":["000A8009","2805C8000100060000005A00000000000000","00000200","00006000","00000000"]}}
11:55:11 MQT: stat/tasmota/STATUS4 = {"StatusMEM":{"ProgramSize":582,"Free":420,"Heap":24,"ProgramFlashSize":1024,"FlashSize":1024,"FlashChipId":"146085","FlashFrequency":40,"FlashMode":3,"Features":["00000809","8FDAE797","04360001","000000CD","010013C0","C000C981","00004004","00000000"],"Drivers":"1,2,3,4,5,7,8,9,10,12,18,19,20,21,22,24,26,27,29,30,35,37","Sensors":"1,2,3,5,6"}}
11:55:11 MQT: stat/tasmota/STATUS5 = {"StatusNET":{"Hostname":"tasmota-0722","IPAddress":"192.168.1.161","Gateway":"192.168.1.254","Subnetmask":"255.255.255.0","DNSServer":"192.168.1.203","Mac":"A4:CF:12:CB:22:D2","Webserver":2,"WifiConfig":2,"WifiPower":17.0}}
11:55:11 MQT: stat/tasmota/STATUS6 = {"StatusMQT":{"MqttHost":"MQTT.lan","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_CB22D2","MqttUser":"hass","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30}}
11:55:11 MQT: stat/tasmota/STATUS7 = {"StatusTIM":{"UTC":"2020-08-24T10:55:11","Local":"2020-08-24T11:55:11","StartDST":"2020-03-29T02:00:00","EndDST":"2020-10-25T03:00:00","Timezone":"+01:00","Sunrise":"05:56","Sunset":"19:47"}}
11:55:11 MQT: stat/tasmota/STATUS9 = {"StatusPTH":{"PowerDelta":[0,0,0],"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
11:55:11 MQT: stat/tasmota/STATUS10 = {"StatusSNS":{"Time":"2020-08-24T11:55:11","ENERGY":{"TotalStartTime":"2020-07-06T17:48:09","Total":4.503,"Yesterday":12.664,"Today":4.503,"Power":1023,"ApparentPower":1023,"ReactivePower":0,"Factor":1.00,"Voltage":230,"Current":4.445}}}
11:55:11 MQT: stat/tasmota/STATUS11 = {"StatusSTS":{"Time":"2020-08-24T11:55:11","Uptime":"0T00:01:00","UptimeSec":60,"Heap":24,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"POWER":"ON","Wifi":{"AP":1,"SSId":"P28_24GHz","BSSId":"14:CC:20:BE:7F:B6","Channel":13,"RSSI":72,"Signal":-64,"LinkCount":1,"Downtime":"0T00:00:04"}}}
11:55:13 MQT: tele/tasmota/HASS_STATE = {"Version":"8.4.0.3(tasmota)","BuildDateTime":"2020-08-24T12:05:13","Module or Template":"HIhome WPP-16S","RestartReason":"Software/System restart","Uptime":"0T00:01:02","Hostname":"tasmota-0722","IPAddress":"192.168.1.161","RSSI":"74","Signal (dBm)":"-63","WiFi LinkCount":1,"WiFi Downtime":"0T00:00:04","MqttCount":1,"LoadAvg":24}



  • [ ] Provide the output of the Console log output when you experience your issue; if applicable:
    _(Please use_ weblog 4 _for more debug information)_
  Console output here:


TO REPRODUCE

Record power consumption with the HiHome WiFi switch

EXPECTED BEHAVIOUR

Power Today should show power consumption, that is more or less correct. Now the Power Today is about 20-30% too high

SCREENSHOTS

_If applicable, add screenshots to help explain your problem._

ADDITIONAL CONTEXT

Using high load on the Tasmota, lowest tested = 1kW, highest ~ 3.5kW.

(Please, remember to close the issue when the problem has been addressed)

enhancement fixed

All 14 comments

Can see I am using the HLW instead I guess. My template says both BL0937 and HLWBL.
If that is the case, we are talking interrupt driven measurements.
Guess I have to try my own compile with HLW_DEBUG to get any further.

Did not recompile. Looked at code.
Every second we call EnergyUpdateToday(); from HlwEverySecond
The delta kWh is in
Energy.kWhtoday_delta which is a long int, but 10^-5 (deca-micro-Wh) , so pretty high precision 0.00001W. So even 1 off every second will not give an error larger than 0.036Wh.

My expected values is (3500 / 60 / 60 * 10^5) which is just around 100.000 deca-micro-Wh per second. So I do not really see any errors.

I am likely not missing any interrupts, as higher pulse length = lower I and U and P (called w in code).

Still do not understand then where the fun values are coming from.

Please, could you be so kind on completing the troubleshooting template in order to have more information so as to properly help you? We don't know which Tasmota version are you using.

Remember to read the Contributing Guideline and Policy. Thanks.


Support Information

See Docs for more information.
See Chat for more user experience.
See Community for forum.
See Code of Conduct

Here is some logging:
kWhtoday_delta is before calling EnergyUpdateToday() in HlwEverySecond().
For 1000W I would expect it to be 1000/60/60*10^5 = 27777.
So it is the hlw8012.ino that pushes wrong value up - Will try to print out more debug values.
My charger now writes 223.5V, 4.4A - But it may be off on calibration as well.

Or is the problem here, that my calibration is off ? kWhToday uses the CF, and current Power uses CF1 voltage and current ?
I have a good multimeter, used it to measure voltage and resistance over my 3000W electric kettle (really just 11.4A / 19.5Ohm).
Used that to calibrate volt, amps, and power. Current Power matches my official meter within acceptable values @ 3.5kW.

One more, the HiHome Template uses HLWBL CF1, but BL0937 CF. Maybe that is the problem here ?
Changed CF to HLW8012 CF, did rough calibration (now sometimes shows 0 Shows 1000W, and kWhToday is still showing delta values around 30000, so better, but still almost 10% over.

Car charger is basicly just sending AC thru to a DC converter inside the car (switching psu?), delivering 400V to the car battery. So not sure it is a resistive load. Passed though power can be limited in the charger.

07:51:56 NRG: kWhtoday_delta 33952
07:51:56 NRG: power 1496, ui 0, cnt 10, smpl 572 577 572 576 572 577 572 577 572 572, sum 5739, mean 573, median 572
07:51:57 NRG: kWhtoday_delta 34812
07:51:57 NRG: power 1496, ui 1, cnt 10, smpl 2622 2621 2618 2617 2621 2622 2617 2617 2622 2621, sum 26198, mean 2619, median 2621
07:51:58 NRG: kWhtoday_delta 34672
07:51:58 NRG: power 1493, ui 0, cnt 10, smpl 572 580 569 576 572 577 572 572 576 573, sum 5739, mean 573, median 573
07:51:59 NRG: kWhtoday_delta 34532
07:51:59 NRG: power 1496, ui 1, cnt 10, smpl 2626 2621 2622 2626 2622 2621 2622 2626 2626 2622, sum 26234, mean 2623, median 2622

image

Hi,
Sorry but we need also the requested information in the template in order to debug your issue. Please, provide the required information in the template. Thanks.

If duplicate, please give me a reference to other ticket, so I can figure out the issue.
I have done a custom built - and on next charge this evening, I plan to calibrate power until I see the Today_Delta giving me what I need. And then live with VA being off. The charger here might not be a 100% resistive load like my water cooker.

One thing for calibration guide, is it better with a large load (like I picked) or a smaller load ? Or load close to measurement target ? I wondered this when calibrating. And picked largest possible load @ home, since I expect to measure 1kW-3.5kW.

One thing for calibration guide, is it better with a large load (like I picked) or a smaller load ?

Large load will result in a more precise measurement in all the range.

Running my own debug software - extra log.
hlw_w lines from HlwEvery200ms() - Just in front of Hlw.power_retry = 1; // Workaround issue #5161
kWhtoday_delta from just before EnergyUpdateToday() in HlwEverySecond(void)

hlw_w is now correct, about 1000W. But the kWhtoday_delta is still too large.
1000/60/60*10^5 = 27777. Not sure why hlw_w and kWhtoday_delta are differing by 5-10% ?

Energy.kWhtoday_delta is based on 10000 / Hlw.energy_period_counter; (number of interrupts in a second)
hlw_w / 10 = Energy.active_power[0] aka current power is based on cf_power_pulse_length - Length of the latest pulse.

But length of latest pulse does not have that much variation. Out of 5000 samples (from the 200ms loop), I have values from 1478-1515, but clustered around center, so not a single value 5% off.

Maybe the code should be changed, such that the 250ms values are not based on latest pulse length, but rather something like 2500 / Hlw.energy_period_counter - But need to take into account if it is 1st, 2nd, 3rd or 4th quarter second. But getting it synced up might be difficult.
Then both values should be in sync. And 250ms average as current iinstant power would fine for most users.

15:26:30 NRG: kWhtoday_delta 29765, pr 1362, cal 10990, len 14
15:26:30 NRG:        hlw_w 10005, pr 1362, cal 10990, len 1496
15:26:30 NRG: power 1496, ui 0, cnt 10, smpl 577 577 577 577 578 576 577 576 577 577, sum 5769, mean 576, median 577
15:26:30 NRG:        hlw_w 9998, pr 1362, cal 10990, len 1497
15:26:30 NRG:        hlw_w 9998, pr 1362, cal 10990, len 1497
15:26:30 NRG:        hlw_w 10032, pr 1362, cal 10990, len 1492
15:26:30 NRG:        hlw_w 10005, pr 1362, cal 10990, len 1496
15:26:30 NRG: power 1496, ui 1, cnt 10, smpl 2619 2614 2614 2619 2618 2614 2619 2619 2618 2614, sum 26168, mean 2616, median 2618
15:26:31 NRG: kWhtoday_delta 30464, pr 1362, cal 10990, len 14

Suggestion:
In void HlwEverySecond(void)
after Hlw.energy_period_counter = 0;
assign new variable Hlw.cf_pulse_last_reset = micros();

Then early in void HlwEvery200ms(void)
pwr_interval = micros() - Hlw.cf_pulse_last_reset
Hlw.cf_power_pulse_length = pwr_interval / Hlw.energy_period_counter

This can be a problem if the HlwEvery200ms and HlwEverySecond are called in wrong order / from each their interrupt loop. Not sure how the trigger of these are done.

Then we use same method in both cases, and are not sensitive to a single interrupt and its precision timing.

Tried this method. Got values from 1391 to 2775 as 0.25s averages. So much more variation. Out of 764 values, no value with more than 10 hits above 1503 and below 1481. But still the large difference between the 1s and the 0.25s measurements people use to calibrate.

Hold for update. I am 95% sure I have the solution.

Problem is in void HlwEverySecond(void)
Result of the division hlw_len = 10000 / Hlw.energy_period_counter; is 14 with 1kW load.
Since this is used as a divisor a bit later, we introduce up to 7% rounding @1kW - That is unacceptable. For 3.5kW it might be 20%.

My suggestion is to keep hlw_len 100 time bigger to not lose precision too early, and then multiply the dividend by 100 as well. Then the precision should go from + 20% down to + 0.2%.
since hlw_len is an integet division result, it is always rounded down, so kWhtoday_delta will only be too large (which is likely acceptable, as the tasmota uses uses a bit itself).

    if (Hlw.energy_period_counter) {
      hlw_len = 10000 * 100 / Hlw.energy_period_counter;
      Hlw.energy_period_counter = 0;
      if (hlw_len) {
        Energy.kWhtoday_delta += ((Hlw.power_ratio * Settings.energy_power_calibration) * 100 / hlw_len) / 36;
        AddLog_P2(LOG_LEVEL_DEBUG, PSTR("NRG:   Delta: %d   -  hlw_len: %d"), Energy.kWhtoday_delta, hlw_len);
        EnergyUpdateToday();

Here is the result of this change:

19:08:26 NRG:   Delta: 28655   -  hlw_len: 1494   -   Counter: 669
19:08:26 NRG: 200ms  hlw_w: 10031   -  pulse_len: 1486 
19:08:26 NRG: 200ms  hlw_w: 9998   -  pulse_len: 1491 
19:08:26 NRG: 200ms  hlw_w: 9991   -  pulse_len: 1492 
19:08:26 NRG: 200ms  hlw_w: 9991   -  pulse_len: 1492 
19:08:26 NRG: 200ms  hlw_w: 9964   -  pulse_len: 1496 
19:08:27 NRG:   Delta: 28445   -  hlw_len: 1490   -   Counter: 671
19:08:27 NRG: 200ms  hlw_w: 10045   -  pulse_len: 1484 
19:08:27 NRG: 200ms  hlw_w: 9998   -  pulse_len: 1491 
19:08:27 NRG: 200ms  hlw_w: 9998   -  pulse_len: 1491 
19:08:27 NRG: 200ms  hlw_w: 9998   -  pulse_len: 1491 
19:08:27 NRG: 200ms  hlw_w: 9998   -  pulse_len: 1491 
19:08:28 NRG:   Delta: 28273   -  hlw_len: 1488   -   Counter: 672

So now we are much closer. Still a bit off, but this might be related to 200ms measurements being single pulse measurements, while the delta is based on counts over 1 second.

Going from 32000 -> 28000 is a major improvement.

After 1 hour, EnergyToday went from 6701W -> 7703W. So now we are at pretty good precision.

Will try to implement the 200ms averages and see if it helps.

Pull request submitted for the single scaling by 1000 fix of dividend and divisor (above I used 100) before doing the division.
Eliminates the potential 20% off on kWhToday.
Due to memory consideration, I am not sure if it makes sense to include the 0.2s average

Pull request accepted. #9160

Thanks

Was this page helpful?
0 / 5 - 0 ratings

Related issues

TylerDurden23 picture TylerDurden23  路  3Comments

Vujagig picture Vujagig  路  3Comments

jensuffhaus picture jensuffhaus  路  3Comments

abzman picture abzman  路  3Comments

ximonline picture ximonline  路  3Comments