search

arendst / Tasmota

Alternative firmware for ESP8266 and ESP32 based devices with easy configuration using webUI, OTA updates, automation using timers or rules, expandability and entirely local control over MQTT, HTTP, Serial or KNX. Full documentation at
https://tasmota.github.io/docs
GNU General Public License v3.0
21.98k stars 4.77k forks source link

Energy calculation resets from time to time without device restart #10541

Closed hacksics closed 3 years ago

hacksics commented 3 years ago

PROBLEM DESCRIPTION

I have flashed nodemcu with tasmota and using PZEM-004T V3 for energy monitor. I've switched off energy monitor counter with SetOption72 0. However it appears that energy calculation reset time or show incorrect values time to time.

Please see the console output below.

I'm not using TX/RX and currently PZEM is connected with software serial emulation as below: GPIO4 -> PZEM16 RX GPIO5 -> PZEM0XX TX

13:34:47 MQT: stat/enregy_mt_floor2/STATUS10 = {"StatusSNS":{"Time":"2021-01-13T13:34:47","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":0.002,"Yesterday":0.000,"Today":0.002,"Power":450,"ApparentPower":528,"ReactivePower":275,"Factor":0.85,"Frequency":50,"Voltage":238,"Current":2.214}}}
13:39:33 MQT: tele/enregy_mt_floor2/STATE = {"Time":"2021-01-13T13:39:33","Uptime":"0T02:11:23","UptimeSec":7883,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"Redmi_CE97","BSSId":"9C:9D:7E:E2:07:64","Channel":2,"RSSI":100,"Signal":-30,"LinkCount":1,"Downtime":"0T00:01:00"}}
13:39:33 MQT: tele/enregy_mt_floor2/SENSOR = {"Time":"2021-01-13T13:39:33","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":0.038,"Yesterday":0.000,"Today":0.038,"Period":42949244,"Power":449,"ApparentPower":524,"ReactivePower":271,"Factor":0.86,"Frequency":50,"Voltage":239,"Current":2.198}}
13:44:33 MQT: tele/enregy_mt_floor2/STATE = {"Time":"2021-01-13T13:44:33","Uptime":"0T02:16:23","UptimeSec":8183,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"Redmi_CE97","BSSId":"9C:9D:7E:E2:07:64","Channel":2,"RSSI":100,"Signal":-30,"LinkCount":1,"Downtime":"0T00:01:00"}}
13:44:33 MQT: tele/enregy_mt_floor2/SENSOR = {"Time":"2021-01-13T13:44:33","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":0.075,"Yesterday":0.000,"Today":0.075,"Period":37,"Power":431,"ApparentPower":500,"ReactivePower":254,"Factor":0.86,"Frequency":50,"Voltage":238,"Current":2.101}}
13:46:15 MQT: stat/enregy_mt_floor2/STATUS10 = {"StatusSNS":{"Time":"2021-01-13T13:46:15","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":0.087,"Yesterday":0.000,"Today":0.087,"Power":434,"ApparentPower":505,"ReactivePower":258,"Factor":0.86,"Frequency":50,"Voltage":238,"Current":2.125}}}

REQUESTED INFORMATION

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

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

- [ ] Set `weblog` to 4 and then, when you experience your issue, provide the output of the Console log:
```lua
  Console output here:

TO REPRODUCE

Steps to reproduce the behavior:

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen.

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.

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

ascillato2 commented 3 years ago

The requested template is incomplete, so we don't have enough information for helping you. Your seriallog is 2. It should be 0 if you are using TX RX pins with your PZEM. Using TX and RX pins is recommended for PZEM, due to those are hardware serial and not software serial.

Please, could you be so kind on completing the troubleshooting template in order to have more information so as to properly help you?

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

hacksics commented 3 years ago

Sorry @ascillato2 for the trouble. I've gathered all the information I could at the time when I was able to reproduce the issue. I'm not using TX/RX and currently PZEM is connected with software serial emulation as below: GPIO4 -> PZEM16 RX GPIO5 -> PZEM0XX TX

The reason I choose GPIO pins because I wanted to make 3P power monitor with 3 PZEM devices and utilise all GPIO pins available.

This is another example of wrong total energy being sent. You can see Total has reduced from 1.459KWh to 1.184KWh between 18:16:20 and 18:21:20

I'm collecting this logs from syslogd and current Syslog Level configuration is set to 3-Debug. I cannot see any error or additional information printed to understand what is going on. 

Jan 13 18:16:20 enregy_mt_floor2-8108 ESP-MQT: tele/enregy_mt_floor2/SENSOR = {"Time":"2021-01-13T18:16:20","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":1.459,"Yesterday":0.000,"Today":1.459,"Period":21,"Power":257,"ApparentPower":339,"ReactivePower":222,"Factor":0.76,"Frequency":50,"Voltage":239,"Current":1.423}}
Jan 13 18:21:20 enregy_mt_floor2-8108 ESP-MQT: tele/enregy_mt_floor2/STATE = {"Time":"2021-01-13T18:21:20","Uptime":"0T01:20:11","UptimeSec":4811,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"Redmi_CE97","BSSId":"9C:9D:7E:E2:07:64","Channel":2,"RSSI":100,"Signal":-30,"LinkCount":1,"Downtime":"0T00:00:05"}}
Jan 13 18:21:20 enregy_mt_floor2-8108 ESP-MQT: tele/enregy_mt_floor2/SENSOR = {"Time":"2021-01-13T18:21:20","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":1.184,"Yesterday":0.000,"Today":1.184,"Period":42949400,"Power":253,"ApparentPower":333,"ReactivePower":217,"Factor":0.76,"Frequency":50,"Voltage":239,"Current":1.395}}
Jan 13 18:26:20 enregy_mt_floor2-8108 ESP-MQT: tele/enregy_mt_floor2/STATE = {"Time":"2021-01-13T18:26:20","Uptime":"0T01:25:11","UptimeSec":5111,"Heap":21,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"Redmi_CE97","BSSId":"9C:9D:7E:E2:07:64","Channel":2,"RSSI":100,"Signal":-30,"LinkCount":1,"Downtime":"0T00:00:05"}}
Jan 13 18:26:20 enregy_mt_floor2-8108 ESP-MQT: tele/enregy_mt_floor2/SENSOR = {"Time":"2021-01-13T18:26:20","ENERGY":{"TotalStartTime":"2021-01-13T12:14:48","Total":1.206,"Yesterday":0.000,"Today":1.206,"Period":22,"Power":268,"ApparentPower":351,"ReactivePower":226,"Factor":0.76,"Frequency":50,"Voltage":240,"Current":1.464}}
ascillato commented 3 years ago

How are you powering the 5V to your PZEM? The totals (as you have configured) are the ones from the PZEM and not the ones from Tasmota. So your PZEM is informing those. Seems that the 5V power is insufficient.

For testing purposes, please move to hardware serial and add a better power source for the 5V of the PZEM.

Anyway, If you use the Totals from Tasmota, you shouldn't see that, but the problem in your PZEM of losing totals is not normal.

hacksics commented 3 years ago

I'm powering the PZEM from NodeMCU 5v out. NodeMCU is powered by USB cable and USB Adapter is 5V/1000mA adaptor. How do you say that I'm using the total from PZEM? I've already set the option "SetOption72 0" so tasmota will use the software calculation.

ascillato commented 3 years ago

"SetOption72 0" so tasmota will use the software calculation.

Oh, you are right. Sorry. I saw it wrongly in your description.

So, Tasmota today's totals are resetted only if your device is restarting. From your lasts logs, seems that is not resetting (the uptime is increasing).

I have several PZEMs and I never saw this behavior.

Please, try using Hardware Serial just for testing.

hacksics commented 3 years ago

So, Tasmota today's totals are resetted only if your device is restarting. From your lasts logs, seems that is not resetting (the uptime is increasing).

Correct. It looks like a bug isn't it?

Please, try using Hardware Serial just for testing.

I will try this out. Can you tell me the connection mapping? Will it be PZEM TX to NodeMCU RX and PZEM RX to NodeMCU TX. And in Tasmota, GPIO3 -> PZEM0XX TX and GPIO 1 -> PZEM16 RX

hacksics commented 3 years ago

Also is this the source code for tasmota energy calculation? xdrv_03_energy.ino

ascillato commented 3 years ago

It looks like a bug isn't it?

I really don't know. I can't reproduce it. That is why I asked you if you can test Hardware Serial. With all your latest information, your issue is unique. We never saw this. (I have removed the duplicated label as now it is clear that is not the same report as older issues).

this the source code for tasmota energy calculation xdrv_03_energy.ino

Yes, exactly.

hacksics commented 3 years ago

I've done some digging on this.

Can someone tell me the reason to reset Energy.start_energy to zero in function EnergyEverySecond in the file xdrv_03_energy.ino?

I need to dig in to more details but it looks like ENERGY_WATCHDOG timer expires (possibily pzem is not sending data during the timeframe defined in ENERGY_WATCHDOG) and when Energy.start_energy sets to zero, Energy.kWhtoday starts from the beginning.

Since I'm not using sdm120 or le01mr, can I just comment out Energy.start_energy = 0; and use it with PZEM? Any thoughts? 

  // Invalid data reset
  uint32_t data_valid = Energy.phase_count;
  //AddLog_P(LOG_LEVEL_INFO, PSTR("NRG: phase_count: %d"), Energy.phase_count);
  for (uint32_t i = 0; i < Energy.phase_count; i++) {
    if (Energy.data_valid[i] <= ENERGY_WATCHDOG) {
      Energy.data_valid[i]++;
      if (Energy.data_valid[i] > ENERGY_WATCHDOG) {
        // Reset energy registers
        Energy.voltage[i] = 0;
        Energy.current[i] = 0;
        Energy.active_power[i] = 0;
        if (!isnan(Energy.apparent_power[i])) { Energy.apparent_power[i] = 0; }
        if (!isnan(Energy.reactive_power[i])) { Energy.reactive_power[i] = 0; }
        if (!isnan(Energy.frequency[i])) { Energy.frequency[i] = 0; }
        if (!isnan(Energy.power_factor[i])) { Energy.power_factor[i] = 0; }
        if (!isnan(Energy.export_active[i])) { Energy.export_active[i] = 0; }

        data_valid--;
        AddLog_P(LOG_LEVEL_INFO, PSTR("NRG: Energy Register Reset: %d, %d"), data_valid, Energy.data_valid[i]);
      }
    }
  }
  if (!data_valid) {
    Energy.start_energy = 0;
    AddLog_P(LOG_LEVEL_INFO, PSTR("NRG: start_energy reset to 0"));
    XnrgCall(FUNC_ENERGY_RESET);
  }
hacksics commented 3 years ago

An update on this:

I've commented out the Energy.start_energy = 0; as below and running the new build without energy being reset randomly. But I don't know any other consequence of not resetting start_energy when ENERGY_WATCHDOG times out. I looked through the code but I didn't see any reason to reset the start_energy to 0. 

  if (!data_valid) {
    //Energy.start_energy = 0;
    AddLog_P(LOG_LEVEL_INFO, PSTR("NRG: start_energy reset to 0"));
    XnrgCall(FUNC_ENERGY_RESET);
  }
arendst commented 3 years ago

If communication is lost between the PZEM and Tasmota for a prolonged time users requested to see a value of zero here. In the past I left it as it was but then they complained that they couldn't detect a broken PZEM or diconnected.

So it seems your comms between the PZEM and Tasmota fails sometimes for a number of retries and therefor resets total energy.

hacksics commented 3 years ago

Thanks now it's clear..

I've tested this with ENERGY_WATCHDOG = 9 (10 seconds) but I can still see data_valid = 0 entries in my log. If this is for the purpose of identifying broken/disconnected PZEM only, is there any downside if we increase the ENERGY_WATCHDOG to higher value, say 300 seconds?

arendst commented 3 years ago

Give it a try and let us know what happens

ascillato commented 3 years ago

So it seems your comms between the PZEM and Tasmota fails sometimes for a number of retries and therefor resets total energy.

We should add an entry in the console log when this reset is applied in order to help the troubleshooting. What do you think?

hacksics commented 3 years ago

I will check this on Sunday and let you guys know. I’m not at home during the weekend

I agree that it would be nice to print this as console log error.

ascillato2 commented 3 years ago

Theo have added the console log error message.

Please try it in latest version from development branch.

Thanks.

hacksics commented 3 years ago

Can the message be INFO or ERROR so it’s visible in lower log level ?

arendst commented 3 years ago

Enable higher log for now and see if it occurs.

hacksics commented 3 years ago 
#grep "Energy reset by" /var/log/syslog*
/var/log/syslog:Jan 18 02:09:34 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog:Jan 18 04:21:06 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog:Jan 18 06:32:37 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog:Jan 18 06:46:56 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog.1:Jan 17 18:16:24 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog.1:Jan 17 19:20:39 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog.1:Jan 17 21:32:11 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog.1:Jan 17 23:43:43 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data
/var/log/syslog.1:Jan 17 23:58:02 tasmota_08DFAC-8108 ESP-NRG: Energy reset by 4 seconds invalid data