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
22.26k stars 4.81k forks source link

DualR3 Power Monitoring only shows 0-Values #13815

Closed joba-1 closed 2 years ago

joba-1 commented 3 years ago

PROBLEM DESCRIPTION

A clear and concise description of what the problem is. I upgraded my DualR3 from 9.3.1.2 where power readings where ok to release 10.0.0 and dev 10.0.0.1-3 (as of now). All 10.x versions show power readings, but all are zero (web, mqtt, log). The device C61 is detected (or implied by template?), but never answers on the first (reset) command. I discussed this on discord. It seems to be a known issue, suspecting serial does not work properly in the used esp32 framework. Since it persists for some days now and might hit others, I thought it would be nice to track it here.

REQUESTED INFORMATION

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

none

- [ ] Provide the output of this command: `Status 0`:
```lua
  STATUS 0 output here:

17:48:05.903 CMD: Status 0
17:48:05.924 MQT: stat/dualr3/STATUS = {"Status":{"Module":0,"DeviceName":"DualR3","FriendlyName":["PowerMoni","Gefriertruhe"],"Topic":"dualr3","ButtonTopic":"0","Power":3,"PowerOnState":1,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0}}
17:48:05.979 MQT: stat/dualr3/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/tasmota32-bluetooth.bin","RestartReason":"Software reset CPU","Uptime":"0T00:26:43","StartupUTC":"2021-11-26T16:21:22","Sleep":10,"CfgHolder":4617,"BootCount":116,"BCResetTime":"2021-04-03T18:52:24","SaveCount":4125}}
17:48:06.032 MQT: stat/dualr3/STATUS2 = {"StatusFWR":{"Version":"10.0.0.3(bluetooth)","BuildDateTime":"2021-11-26T14:01:47","Core":"2_0_1_1","SDK":"v4.4-dev-3728-g7cac8278e","CpuFrequency":80,"Hardware":"ESP32-D0WD-V3","CR":"446/699"}}
17:48:06.054 MQT: stat/dualr3/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":4,"LogHost":"192.168.1.4","LogPort":514,"SSId":["job.iot.ssid","job.fritz.ssid"],"TelePeriod":60,"Resolution":"558180C0","SetOption":["00008009","2805C80001000680003C5A0A000000000000","00000480","00006000","0000C002"]}}
17:48:06.093 MQT: stat/dualr3/STATUS4 = {"StatusMEM":{"ProgramSize":1473,"Free":1984,"Heap":77,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashFrequency":40,"FlashMode":3,"Features":["00000809","8F9AC787","00140001","000000CF","010013C0","40000981","00004080","00200000","0000082C"],"Drivers":"1,2,3,4,5,7,8,9,10,12,20,21,24,26,27,29,38,50,52,59,79","Sensors":"1,2,3,5,6,52,62,127"}}
17:48:06.147 MQT: stat/dualr3/STATUS5 = {"StatusNET":{"Hostname":"dualr3","IPAddress":"192.168.1.164","Gateway":"192.168.1.221","Subnetmask":"255.255.255.0","DNSServer1":"192.168.1.236","DNSServer2":"0.0.0.0","Mac":"94:B9:7E:68:2B:78","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}}
17:48:06.185 MQT: stat/dualr3/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.1.4","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_682B78","MqttUser":"DVES_USER","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
17:48:06.221 MQT: stat/dualr3/STATUS7 = {"StatusTIM":{"UTC":"2021-11-26T16:48:06","Local":"2021-11-26T17:48:06","StartDST":"2021-03-28T02:00:00","EndDST":"2021-10-31T03:00:00","Timezone":"+01:00","Sunrise":"08:16","Sunset":"16:58"}}
17:48:06.242 MQT: stat/dualr3/STATUS9 = {"StatusPTH":{"PowerDelta":[0,0,0],"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
17:48:06.274 MQT: stat/dualr3/STATUS10 = {"StatusSNS":{"Time":"2021-11-26T17:48:06","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2021-04-03T18:52:24","Total":[0.000,0.000],"Yesterday":[0.000,0.000],"Today":[0.000,0.000],"Power":[ 0, 0],"ApparentPower":[ 0, 0],"ReactivePower":[ 0, 0],"Factor":[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":56.1},"TempUnit":"C"}}
17:48:06.335 MQT: stat/dualr3/STATUS11 = {"StatusSTS":{"Time":"2021-11-26T17:48:06","Uptime":"0T00:26:44","UptimeSec":1604,"Heap":80,"SleepMode":"Normal","Sleep":10,"LoadAvg":99,"MqttCount":1,"Berry":{"HeapUsed":4,"Objects":62},"POWER1":"ON","POWER2":"ON","Wifi":{"AP":1,"SSId":"job.iot.ssid","BSSId":"28:D1:27:4E:56:75","Channel":5,"Mode":"11n","RSSI":42,"Signal":-79,"LinkCount":1,"Downtime":"0T00:00:05"}}}

2021-11-26T17:21:21.304280+01:00 dualr3 ESP-HTP: Restart 2021-11-26T17:21:21.307939+01:00 dualr3 ESP-SRC: WebGui from 192.168.1.4 2021-11-26T17:21:27+01:00 ax1 dnsmasq-dhcp[1]: DHCPACK(br-lan) 192.168.1.164 94:b9:7e:68:2b:78 dualr3 2021-11-26T17:21:28.577838+01:00 dualr3 ESP-HDW: ESP32-D0WD-V3 2021-11-26T17:21:28.582016+01:00 dualr3 ESP-HDW: FoundPSRAM=0 CanUsePSRAM=0 2021-11-26T17:21:28.603372+01:00 dualr3 ESP-UFS: FlashFS mounted with 40 kB free 2021-11-26T17:21:28.637861+01:00 dualr3 ESP-BRY: GC from 3614 to 3036 bytes, objects freed 5/29 (in 0 ms) 2021-11-26T17:21:28.639592+01:00 dualr3 ESP-BRY: GC from 5322 to 4638 bytes, objects freed 6/61 (in 1 ms) 2021-11-26T17:21:28.644329+01:00 dualr3 ESP-BRY: Berry initialized, RAM used=4638 2021-11-26T17:21:28.647653+01:00 dualr3 ESP-BRY: no 'preinit.be' 2021-11-26T17:21:28.655182+01:00 dualr3 ESP-SRC: Restart 2021-11-26T17:21:28.657989+01:00 dualr3 ESP-Project tasmota - DualR3 Version 10.0.0.3(bluetooth)-2_0_1_1(2021-11-26T14:01:47) 2021-11-26T17:21:28.661831+01:00 dualr3 ESP-M32: init: request callbacks 2021-11-26T17:21:28.679881+01:00 dualr3 ESP-BRY: no 'autoexec.be' 2021-11-26T17:21:28.679881+01:00 dualr3 ESP-WIF: Checking connection... 2021-11-26T17:21:28.679881+01:00 dualr3 ESP-WIF: Attempting connection... 2021-11-26T17:21:28.679881+01:00 dualr3 ESP-WIF: Connecting to AP1 job.iot.ssid Channel 5 BSSId 28:D1:27:4E:56:75 in mode 11n as dualr3... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Checking connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Attempting connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-C61: Tx A5EA96DA 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Checking connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Attempting connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Checking connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-WIF: Attempting connection... 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-C61: Tx A500 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-C61: Rx none 2021-11-26T17:21:28.680071+01:00 dualr3 ESP-C61: Tx A500 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-C61: Rx none 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-C61: Tx A500 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-C61: Rx none 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-WIF: Checking connection... 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-WIF: Connected 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-CMD: 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-SRC: Serial 2021-11-26T17:21:28.680236+01:00 dualr3 ESP-HTP: Web server active on dualr3 with IP address 192.168.1.164 2021-11-26T17:21:29.977799+01:00 dualr3 ESP-NTP: Synch time... 2021-11-26T17:21:29.985853+01:00 dualr3 ESP-RTC: UTC 2021-11-26T16:21:28, DST 2021-03-28T02:00:00, STD 2021-10-31T03:00:00 2021-11-26T17:21:29.998093+01:00 dualr3 ESP-NTP: Synched 2021-11-26T17:21:30.000189+01:00 dualr3 ESP-BLE: MasterEnable->1 2021-11-26T17:21:30.001766+01:00 dualr3 ESP-BLE: BLETask:Starting NimBLE 2021-11-26T17:21:30.075650+01:00 dualr3 ESP-MQT: Attempting connection... 2021-11-26T17:21:30.086916+01:00 dualr3 ESP-MQT: Connected 2021-11-26T17:21:30.094242+01:00 dualr3 ESP-MQT: tele/dualr3/LWT = Online (retained) 2021-11-26T17:21:30.097387+01:00 dualr3 ESP-MQT: cmnd/dualr3/POWER = 2021-11-26T17:21:30.099662+01:00 dualr3 ESP-MQT: Subscribe to cmnd/dualr3/# 2021-11-26T17:21:30.181225+01:00 dualr3 ESP-MQT: Subscribe to cmnd/tasmotas/# 2021-11-26T17:21:30.190661+01:00 dualr3 ESP-MQT: Subscribe to cmnd/DVES_682B78_fb/# 2021-11-26T17:21:30.196639+01:00 dualr3 ESP-MQT: tele/dualr3/INFO1 = {"Info1":{"Module":"Sonoff Dual R3","Version":"10.0.0.3(bluetooth)","FallbackTopic":"cmnd/DVES_682B78_fb/","GroupTopic":"cmnd/tasmotas/"}} 2021-11-26T17:21:30.198895+01:00 dualr3 ESP-MQT: tele/dualr3/INFO2 = {"Info2":{"WebServerMode":"Admin","Hostname":"dualr3","IPAddress":"192.168.1.164"}} 2021-11-26T17:21:30.203649+01:00 dualr3 ESP-MQT: tele/dualr3/INFO3 = {"Info3":{"RestartReason":"Software reset CPU"}} 2021-11-26T17:21:30.218678+01:00 dualr3 ESP-MQT: stat/dualr3/RESULT = {"POWER1":"ON"} 2021-11-26T17:21:30.283105+01:00 dualr3 ESP-MQT: stat/dualr3/POWER1 = ON 2021-11-26T17:21:30.288195+01:00 dualr3 ESP-MQT: stat/dualr3/RESULT = {"POWER2":"ON"} 2021-11-26T17:21:30.302697+01:00 dualr3 ESP-MQT: stat/dualr3/POWER2 = ON 2021-11-26T17:21:30.608682+01:00 dualr3 ESP-SRC: File 2021-11-26T17:21:30.615328+01:00 dualr3 ESP-CMD: Grp 0, Cmnd 'IBEACON', Idx 1, Len 1, Data '1' 2021-11-26T17:21:30.619526+01:00 dualr3 ESP-MQT: stat/dualr3/RESULT = {"IBEACON":1} 2021-11-26T17:21:30.621782+01:00 dualr3 ESP-SRC: MQTT 2021-11-26T17:21:30.625985+01:00 dualr3 ESP-CMD: Grp 0, Cmnd 'STATUS', Idx 1, Len 0, Data '' 2021-11-26T17:21:30.627982+01:00 dualr3 ESP-MQT: stat/dualr3/STATUS = {"Status":{"Module":0,"DeviceName":"DualR3","FriendlyName":["PowerMoni","Gefriertruhe"],"Topic":"dualr3","ButtonTopic":"0","Power":3,"PowerOnState":1,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0}} 2021-11-26T17:21:30.691124+01:00 dualr3 ESP-QPC: Reset 2021-11-26T17:21:32.163755+01:00 dualr3 ESP-HTP: Main Menu 2021-11-26T17:21:32.562327+01:00 dualr3 ESP-NRG: Energy reset by invalid data 2021-11-26T17:21:32.566865+01:00 dualr3 ESP-APP: Boot Count 116 2021-11-26T17:21:33.577760+01:00 dualr3 ESP-CFG: Saved, Count 4125, Bytes 4096 2021-11-26T17:21:35.836152+01:00 dualr3 ESP-BRY: GC from 6884 to 4557 bytes, objects freed 14/62 (in 1 ms) 2021-11-26T17:21:35.841635+01:00 dualr3 ESP-MQT: tele/dualr3/STATE = {"Time":"2021-11-26T17:21:32","Uptime":"0T00:00:10","UptimeSec":10,"Heap":86,"SleepMode":"Normal","Sleep":10,"LoadAvg":99,"MqttCount":1,"Berry":{"HeapUsed":4,"Objects":62},"POWER1":"ON","POWER2":"ON","Wifi":{"AP":1,"SSId":"job.iot.ssid","BSSId":"28:D1:27:4E:56:75","Channel":5,"Mode":"11n","RSSI":46,"Signal":-77,"LinkCount":1,"Downtime":"0T00:00:05"}} 2021-11-26T17:21:35.917444+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2021-11-26T17:21:32","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2021-04-03T18:52:24","Total":[0.000,0.000],"Yesterday":[0.000,0.000],"Today":[0.000,0.000],"Period":[ 0, 0],"Power":[ 0, 0],"ApparentPower":[ 0, 0],"ReactivePower":[ 0, 0],"Factor":[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":56.7},"TempUnit":"C"} 2021-11-26T17:21:35.922442+01:00 dualr3 ESP-MQT: tele/dualr3/BLE = {"Time":"2021-11-26T17:21:34","BLEDevices":{"total":0}} 2021-11-26T17:21:35.924197+01:00 dualr3 ESP-MQT: tele/dualr3/BLE = {"Time":"2021-11-26T17:21:34","BLE":{"scans":0,"adverts":17,"devices":0,"resets":0}}


### TO REPRODUCE
_Steps to reproduce the behavior:_

upgrade a dual r3 to 10.x

### EXPECTED BEHAVIOUR
_A clear and concise description of what you expected to happen._

power readings not zero

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

![image](https://user-images.githubusercontent.com/32450554/143612090-86532bf5-94a0-4a2f-92ef-d17c0c020aab.png)

### ADDITIONAL CONTEXT
_Add any other context about the problem here._

Start of discord discussion (is-that-a-bug):

joba-1 — 10.11.2021 Hi, I have updated a Sonoff Dual R3 (V1) from 9.3.1.2 to 10.0.0.2 (tasmota32-bluetooth) and lost power monitoring ...



**(Please, remember to close the issue when the problem has been addressed)**
arendst commented 3 years ago

Solution: Power cycle once.

joba-1 commented 3 years ago

Magic! I did that several times before (read that hint for a shelly) and it never worked. Of course I did NOT powercycle today when I upgraded and decided to open the issue :D

Is it normal that the first channel is displayed but zero (consumption could be very low right now, driving an esp8266)? The second channel looks reasonable now.

arendst commented 3 years ago

Yes. It needs some load

joba-1 commented 3 years ago

Gave it some load - all fine now. Thanks!

joba-1 commented 2 years ago

issue reappeared out of nowhere (no update, no restart, no powercycle. I usually sleep at that time...)

it happily records different energy values until it gets stuck at the same non null value:

2022-01-05T01:34:52.311188+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-05T01:34:51","Switch1":"ON","Switch2":"ON","ENERGY":{...:[0.00,0.64],"Frequency":50.016,"Voltage":224,"Current":[0.000,0.188]},"ESP32":{"Temperature":59.4},"TempUnit":"C"}
2022-01-05T01:35:52.324966+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-05T01:35:51","Switch1":"ON","Switch2":"ON","ENERGY":{...:[0.00,0.64],"Frequency":49.994,"Voltage":224,"Current":[0.000,0.187]},"ESP32":{"Temperature":58.9},"TempUnit":"C"}
2022-01-05T01:38:52.413906+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-05T01:38:51","Switch1":"ON","Switch2":"ON","ENERGY":{...:[0.00,0.64],"Frequency":50.016,"Voltage":225,"Current":[0.000,0.187]},"ESP32":{"Temperature":61.1},"TempUnit":"C"}

for quite a long time, until I noticed and rebooted the device (not powercycle). After that it was stuck at 0 V again.

2022-01-07T03:49:21.686137+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-07T03:49:20","Switch1":"ON","Switch2":"ON","ENERGY":{...:[0.00,0.64],"Frequency":50.016,"Voltage":225,"Current":[0.000,0.187]},"ESP32":{"Temperature":64.4},"TempUnit":"C"}
2022-01-07T05:56:06.689184+01:00 dualr3 ESP-MQT: tele/dualr3/INFO1 = {"Info1":{"Module":"Sonoff Dual R3","Version":"2022.01.1(bluetooth)","FallbackTopic":"cmnd/DVES_682B78_fb/","GroupTopic":"cmnd/tasmotas/"}}
2022-01-07T05:56:06.758139+01:00 dualr3 ESP-MQT: tele/dualr3/INFO3 = {"Info3":{"RestartReason":"Software reset CPU"}}
2022-01-07T05:56:11.580466+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"1970-01-01T00:13:53","Switch1":"ON","Switch2":"ON","ENERGY":{...:[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":62.2},"TempUnit":"C"}

until I upgraded to latest dev and powercycled. All good for now. Looks like I need to think about how to notify me if values are not changing for some time?

arendst commented 2 years ago

You might want to watch for too many CRC errors like:

16:28:25.392 CMD: weblog 3
16:28:25.396 SRC: WebConsole from 192.168.2.1
16:28:25.399 CMD: Grp 0, Cmnd 'WEBLOG', Idx 1, Len 1, Data '3'
16:28:25.415 MQT: stat/dualr3c/RESULT = {"WebLog":3}
16:28:26.387 C61: Rx FF, CRC error 2E

Considering you're using the BLE image it wouldn't surprise me if that's the culprit.

joba-1 commented 2 years ago

correct, about 250 of those per day:

2022-01-05T07:04:57.650374+01:00 dualr3 ESP-C61: Rx 00, CRC error 2D
2022-01-05T07:04:58.625719+01:00 dualr3 ESP-C61: Rx 00, CRC error 34
2022-01-05T07:08:43.619920+01:00 dualr3 ESP-C61: Rx 00, CRC error 35

any idea what I can do about them? Other than removing bluetooth functionality, if possible...

barbudor commented 2 years ago

As suggested by @arendst this may be related to Bluetooth Disable BLE with Setoption115 0 If confirmed, you will have to separate the usage on 2 different devices

joba-1 commented 2 years ago

I had these messages yesterday and the day before. But nothing in todays current log so far. So I can't confirm right now that disabling BLE will "fix" it. I'll try when it shows up again.

And when I do, I'd rather help working on a fix than using a second device. I don't really "need" any of the two features, both are just nice to have, but serial comms is a very basic task that even an 8MHz ATTiny can do correctly with 115200bps (given proper know how). I'm sure a dual core cpu with 160MHz or more that can stream megapixel videos can somehow manage to do serial right even while listening for bluetooth messages and serving favicons :)

Slightly related: when voltage is 0 the frequency field dissapears from the SENSOR message. Intentional?

2022-01-08T11:27:09.973186+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-08T11:27:08","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2021-04-03T18:52:24","Total":[0.005,1.326],"Yesterday":[0.000,0.015],"Today":[0.000,0.000],"Period":[ 0, 0],"Power":[ 0, 0],"ApparentPower":[ 0, 0],"ReactivePower":[ 0, 0],"Factor":[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":59.4},"TempUnit":"C"}

2022-01-07T19:43:26.321755+01:00 dualr3 ESP-MQT: tele/dualr3/SENSOR = {"Time":"2022-01-07T19:43:24","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2021-04-03T18:52:24","Total":[0.005,1.507],"Yesterday":[0.000,0.648],"Today":[0.000,0.197],"Period":[ 0, 0],"Power":[ 0,26],"ApparentPower":[ 0,43],"ReactivePower":[ 0,33],"Factor":[0.00,0.62],"Frequency":50.016,"Voltage":225,"Current":[0.000,0.189]},"ESP32":{"Temperature":65.6},"TempUnit":"C"}
sfromis commented 2 years ago

With voltage 0, the switch has no power, and cannot do anything at all. If you instead mean relays switched off, see SetOption21.

What is reliably feasible on serial is not a question of CPU speed available.

joba-1 commented 2 years ago

regarding frequency: I'm not expecting a meaningful value, I just noticed it is not printed while all other also not meaningful values are. Not bad, but inconsistent, and if there is no reason for that, I probably could do a PR.

regarding cpu speed: of course it is relevant, along with what else you want to do with the cycles, how efficient the interrupt handling is and if you use it, if you can receive into a buffer without cpu intervention or not and how big that buffer is. My point was just that given up to 60 times the cpu cycles it should be possible to do it even in non optimal circumstances. Basically, all I'm saying is, it might be worth trying.

arendst commented 2 years ago

While you're considering a frequency PR please keep in mind a simple rule: Default float frequency is set to NAN. Once this variable has been filled with a non-NAN value it is displayed. So a 0 (which is not a NAN) should still be displayed.

If it doesn't show in your lists then that's a good starting point to investigate why.

arendst commented 2 years ago

BTW if I do SO21 0 and turn all switches off I still see frequency albeit at zero:

15:37:35.763-150/28 MQT: tele/dualr3a/STATE = {"Time":"2022-01-08T15:37:35","Uptime":"3T17:59:44","UptimeSec":323984,"Heap":152,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":2,"Berry":{"HeapUsed":3,"Objects":35},"POWER1":"OFF","POWER2":"OFF","Wifi":{"AP":1,"SSId":"indebuurt_IoT","BSSId":"18:E8:29:CA:17:C1","Channel":11,"Mode":"11n","RSSI":100,"Signal":-29,"LinkCount":1,"Downtime":"0T00:00:04"}}
15:37:35.790-150/29 MQT: tele/dualr3a/SENSOR = {"Time":"2022-01-08T15:37:35","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2021-11-22T17:03:49","Total":[15.67,15.58],"Yesterday":[0.14,0.00],"Today":[0.12,0.00],"Period":[0.00,0.00],"Power":[0.00,0.00],"ApparentPower":[0.00,0.00],"ReactivePower":[0.00,0.00],"Factor":[0.00,0.00],"Frequency":0.00,"Voltage":0.0,"Current":[0.000,0.000]},"ESP32":{"Temperature":71.7},"TempUnit":"C"}
sfromis commented 2 years ago

I did not say that CPU speed is "not relevant", but instead that the reasons why some chars may be lost is not a question of CPU speed, more likely due to blocking code hindering other things from happening while waiting for something. In this case, CPU speed can't make much difference. Arguably, blocking code should not occur, but .....

joba-1 commented 2 years ago

While you're considering a frequency PR please keep in mind a simple rule: Default float frequency is set to NAN. Once this variable has been filled with a non-NAN value it is displayed. So a 0 (which is not a NAN) should still be displayed.

If it doesn't show in your lists then that's a good starting point to investigate why.

understood, and matches my logs:

joba-1 commented 2 years ago

I must admit, I dont see where the problem with serial could be. If I understand the code correctly,

sfromis commented 2 years ago

Not sure if I'm reading this right, but glancing a bit into TasmotaSerial.cpp shows that while the default buffer size is 64, it will only be passed to setRxBufferSize if it is larger than 256. While I do not know if there is some sort of underlying default buffer size taking effect when TasmotaSerial does not set another, I do tend to worry if this means that there is no hardware serial receive buffer.

arendst commented 2 years ago

No need to worry about the buffer of 64 bytes. That buffer is used when SOFTWARE serial is selected. Tasmota does not support software serial on ESP32. Instead it uses one of the three available HARDWARE uarts as Tasmota is just wrapper around esp32 hardware serial.

ESP32 (and ESP8266) hardware serial uses a default buffer size of 256 bytes and therefore Tasmota serial does not allow buffers smaller than 256 bytes.

In short, it's not Tasmota faults it's losing serial bytes; It' espressive IDF and the core handling the serial comms on the Sonoff dualR3 (esp32 based).

joba-1 commented 2 years ago

ok, I see now where the 256 bytes come in with platform code HardwareSerial constructor and the 256 byte threshold in TasmotaSerial::begin(uint32_t speed, uint32_t config).

Looks like even 512 bytes are used in the framework: ESP_ERROR_CHECK(uart_driver_install(uart_nr, 2*queueLen, 0, 0, NULL, 0));

not sure why arduino framework decided not to use events queue. Looks like this might be able to deliver some error information. But I must agree: nothing that tasmota can do here :(

joba-1 commented 2 years ago

I checked the source code down to idf uart code. The code path is pretty simple for ESP32. I dont see a reason why communication could fail. Even very long delays do not matter. The chip only returns a very limited amount of data for all commands tasmota sends, or actually all commands in the datasheet. Never enough to overflow a buffer.

That means it is either

None of them can be fixed easily, But from the pattern I always see (long stable operation -> CRC errors -> dead -> powercycle -> back to square 1) maybe it helps to send a software reset (EA 96) and reinit the c61 after seeing a certain amount of CRC errors?

joba-1 commented 2 years ago

...But from the pattern I always see (long stable operation -> CRC errors -> dead -> powercycle -> back to square 1) maybe it helps to send a software reset (EA 96) and reinit the c61 after seeing a certain amount of CRC errors?

Forget this pattern, please. It just showed up due to me using a wrong search parameter. CRC start showing up after ~0-80min of normal operation after reboots and so far never twice in a row. Last two days this never lead to a non responsive C61. Apart from CRC errors all works fine.

I looked a bit closer at the faulty data: Nearly always it is a zero byte in front of the regular data (that can be seen on the retry that succeeds). So it is not some flipped bits as noise would produce. Maybe a missing flush of the rx buffer when tx'ing?

Following syslogs filtered for 'C61: Rx' lines:

2022-01-10T12:01:48.511039+01:00 dualr3 ESP-C61: Rx 00000284
2022-01-10T12:01:48.514720+01:00 dualr3 ESP-C61: Rx 00000284, CRC error 34
2022-01-10T12:01:48.536959+01:00 dualr3 ESP-C61: Rx 000284B0

One other result is this: also a CRC due to a leading zero, next try: one byte missing, third try succeeds

2022-01-10T12:14:22.117889+01:00 dualr3 ESP-C61: Rx 0022F2
2022-01-10T12:14:22.121387+01:00 dualr3 ESP-C61: Rx 0022F2, CRC error 15
2022-01-10T12:14:22.129090+01:00 dualr3 ESP-C61: Rx 22F2
2022-01-10T12:14:22.138544+01:00 dualr3 ESP-C61: Rx 22F2, CRC error 15
2022-01-10T12:14:22.256189+01:00 dualr3 ESP-C61: Rx 22F223

EDIT: So far the only occurrence (only with debug or info level, so only errors are reported) where the C61 got stuck completely, All C61 messages from boot until first Rx 00 CRC error that repeat until power cycle

2022-01-07T16:03:36.206713+01:00 dualr3 ESP-C61: CSE7761 found
2022-01-07T16:03:55.876809+01:00 dualr3 ESP-MQT: tele/dualr3/INFO3 = {"Info3":{"RestartReason":"Vbat power on reset"}}
2022-01-07T16:06:39.683760+01:00 dualr3 ESP-C61: Rx 1F, CRC error 2D
2022-01-07T16:06:39.693207+01:00 dualr3 ESP-C61: Rx 22F0, CRC error 15
2022-01-07T16:48:11.186811+01:00 dualr3 ESP-C61: Rx FFFFA2, CRC error 30
2022-01-07T17:33:48.807792+01:00 dualr3 ESP-C61: Rx 00, CRC error 2D
2022-01-07T17:38:44.639135+01:00 dualr3 ESP-C61: Rx 00, CRC error 2E
...
joba-1 commented 2 years ago

Found something that does not look right in the code:

https://github.com/arendst/Tasmota/blob/development/tasmota/xnrg_19_cse7761.ino#L105

void Cse7761Write(uint32_t reg, uint32_t data) {

reg can be a 1-4 byte register, so I think it should write 1-4 bytes, depending on reg. Current implementation uses data to decide how much is written.

EDIT: actually used data values when calling the function are always constant and are in the right range to trigger the correct behaviour. So, maybe not nice for code maintenance, but works. Going back to check if rx buffer flush might help...

EDIT2: Ok, there is a kind of flush() emulation already in place, good. But...

Holy crap! Who designed the arduino uart interface? How do you know if uartRead() failed? In that case it returns a 0, just like it would if there was a valid 0 transfered. And that looks suspiciously like the extra 0's in the logs. I must admit, that the HardwareSerial code checks if there is something in the buffer before calling uartRead(), so there is not much that could fail, but the check uses the closed source uart_get_buffered_data_len() from the IDF and does not check the error code of it. And the 0's are there, so...

perrotekel commented 2 years ago

Hello, i flash my dual r3 this morning and values of power monitorin are always 0.

I executed "Power cycle once"

Cut power from the device completely for 30 seconds.
Power the device on and off six times with intervals lower than 10 seconds and leave it on after seventh time.
Fast power cycle device recovery should activate and the device should be reset to firmware defaults.

But not solved problem.

Any idea?

imagen

ascillato commented 2 years ago

Your version is old. Several fixes has been applied since your version. Please update to latest and try again. Remember that after updating you must remove the electricity from the device. Please, leave it without energy for few seconds and then reconnect it.

adelafug commented 2 years ago

With last version, firmware upgrade, resete and remove power. Same result!

imagen

ascillato commented 2 years ago

Please, share the console output of the command:

backlog Backlog Template; Module; GPIO 255; Status 0

And please, also set weblog to 4 and share the output of the console when the device starts to up to 1 minute. Thanks.

adelafug commented 2 years ago

This?

With all off!

19:01:11.474 CMD: backlog Backlog Template; Module; GPIO 255; Status 0
19:01:11.532 MQT: stat/tasmota_DAA58C/RESULT = {"NAME":"SonOffDualCaldera","GPIO":[32,0,0,0,0,0,0,0,0,576,225,0,0,0,0,0,0,0,0,0,0,7296,7328,224,0,0,0,0,160,161,0,0,0,0,0,0],"FLAG":0,"BASE":1}
19:01:11.788 MQT: stat/tasmota_DAA58C/RESULT = {"Module":{"0":"SonOffDualCaldera"}}
19:01:12.024 MQT: stat/tasmota_DAA58C/RESULT = {"GPIO0":{"32":"Button1"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO6":{"0":"None"},"GPIO7":{"0":"None"},"GPIO8":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO11":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"576":"LedLink_i"},"GPIO14":{"225":"Relay2"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"},"GPIO18":{"0":"None"},"GPIO19":{"0":"None"},"GPIO20":{"0":"None"},"GPIO21":{"0":"None"},"GPIO22":{"0":"None"},"GPIO23":{"0":"None"},"GPIO24":{"0":"None"},"GPIO25":{"7296":"CSE7761 Tx"},"GPIO26":{"7328":"CSE7761 Rx"},"GPIO27":{"224":"Relay1"},"GPIO32":{"160":"Switch1"},"GPIO33":{"161":"Switch2"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO37":{"0":"None"},"GPIO38":{"0":"None"},"GPIO39":{"0":"None"}}
19:01:12.252 MQT: stat/tasmota_DAA58C/STATUS = {"Status":{"Module":0,"DeviceName":"Sonoff Caldera","FriendlyName":["Sonoff Caldera","Sonoff Caldera2"],"Topic":"tasmota_DAA58C","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0}}
19:01:12.305 MQT: stat/tasmota_DAA58C/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32.bin","RestartReason":"Vbat power on reset","Uptime":"0T00:09:34","StartupUTC":"2022-01-14T17:51:38","Sleep":50,"CfgHolder":4617,"BootCount":2,"BCResetTime":"2022-01-14T18:51:05","SaveCount":11}}
19:01:12.355 MQT: stat/tasmota_DAA58C/STATUS2 = {"StatusFWR":{"Version":"2022.01.2(tasmota)","BuildDateTime":"2022-01-14T05:56:58","Core":"2_0_2","SDK":"v4.4-2.0.2","CpuFrequency":80,"Hardware":"ESP32-D0WD-V3","CR":"456/699"}}
19:01:12.379 MQT: stat/tasmota_DAA58C/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["FUECAM",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C80001000600003C5A0A000000000000","00000080","00006000","00004000"]}}
19:01:12.427 MQT: stat/tasmota_DAA58C/STATUS4 = {"StatusMEM":{"ProgramSize":1398,"Free":1856,"Heap":155,"StackLowMark":4,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashFrequency":40,"FlashMode":2,"Features":["00000809","9FDAC7C7","0015A001","B7F7BFCF","05DA9BC0","E0360DC7","000840D2","20200000","0000482D"],"Drivers":"1,2,3,4,5,7,8,9,10,11,12,14,16,17,20,21,24,26,27,29,34,35,38,50,52,59","Sensors":"1,2,3,5,6,7,8,9,10,11,12,13,14,15,17,18,19,20,21,22,26,28,31,34,37,39,40,42,43,45,51,52,55,56,58,59,64,66,67,74,85,92,127"}}
19:01:12.485 MQT: stat/tasmota_DAA58C/STATUS5 = {"StatusNET":{"Hostname":"son-calderar3","IPAddress":"192.168.1.60","Gateway":"192.168.1.1","Subnetmask":"255.255.255.0","DNSServer1":"192.168.1.1","DNSServer2":"0.0.0.0","Mac":"C4:DD:57:DA:A5:8C","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}}
19:01:12.519 MQT: stat/tasmota_DAA58C/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.1.5","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_DAA58C","MqttUser":"DVES_USER","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
19:01:12.557 MQT: stat/tasmota_DAA58C/STATUS7 = {"StatusTIM":{"UTC":"2022-01-14T18:01:12","Local":"2022-01-14T19:01:12","StartDST":"2022-03-27T02:00:00","EndDST":"2022-10-30T03:00:00","Timezone":"+01:00","Sunrise":"08:39","Sunset":"17:19"}}
19:01:12.582 MQT: stat/tasmota_DAA58C/STATUS9 = {"StatusPTH":{"PowerDelta":[0,0,0],"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
19:01:12.617 MQT: stat/tasmota_DAA58C/STATUS10 = {"StatusSNS":{"Time":"2022-01-14T19:01:12","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2022-01-14T18:51:05","Total":0.000,"Yesterday":0.000,"Today":0.000,"Power":[ 0, 0],"ApparentPower":[ 0, 0],"ReactivePower":[ 0, 0],"Factor":[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":51.1},"TempUnit":"C"}}
19:01:12.670 MQT: stat/tasmota_DAA58C/STATUS11 = {"StatusSTS":{"Time":"2022-01-14T19:01:12","Uptime":"0T00:09:34","UptimeSec":574,"Heap":157,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":47,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":39},"POWER1":"OFF","POWER2":"OFF","Wifi":{"AP":1,"SSId":"FUECAM","BSSId":"62:8E:29:25:EE:D1","Channel":6,"Mode":"11n","RSSI":88,"Signal":-56,"LinkCount":1,"Downtime":"0T00:00:04"}}}

And on buttons!

19:02:23.214 MQT: stat/tasmota_DAA58C/RESULT = {"POWER1":"ON"}
19:02:23.222 MQT: stat/tasmota_DAA58C/POWER1 = ON
19:02:24.605 MQT: stat/tasmota_DAA58C/RESULT = {"POWER2":"ON"}
19:02:24.613 MQT: stat/tasmota_DAA58C/POWER2 = ON
19:03:22.949 MQT: stat/tasmota_DAA58C/RESULT = {"NAME":"SonOffDualCaldera","GPIO":[32,0,0,0,0,0,0,0,0,576,225,0,0,0,0,0,0,0,0,0,0,7296,7328,224,0,0,0,0,160,161,0,0,0,0,0,0],"FLAG":0,"BASE":1}
19:03:23.188 MQT: stat/tasmota_DAA58C/RESULT = {"Module":{"0":"SonOffDualCaldera"}}
19:03:23.449 MQT: stat/tasmota_DAA58C/RESULT = {"GPIO0":{"32":"Button1"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO6":{"0":"None"},"GPIO7":{"0":"None"},"GPIO8":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO11":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"576":"LedLink_i"},"GPIO14":{"225":"Relay2"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"},"GPIO18":{"0":"None"},"GPIO19":{"0":"None"},"GPIO20":{"0":"None"},"GPIO21":{"0":"None"},"GPIO22":{"0":"None"},"GPIO23":{"0":"None"},"GPIO24":{"0":"None"},"GPIO25":{"7296":"CSE7761 Tx"},"GPIO26":{"7328":"CSE7761 Rx"},"GPIO27":{"224":"Relay1"},"GPIO32":{"160":"Switch1"},"GPIO33":{"161":"Switch2"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO37":{"0":"None"},"GPIO38":{"0":"None"},"GPIO39":{"0":"None"}}
19:03:23.651 MQT: stat/tasmota_DAA58C/STATUS = {"Status":{"Module":0,"DeviceName":"Sonoff Caldera","FriendlyName":["Sonoff Caldera","Sonoff Caldera2"],"Topic":"tasmota_DAA58C","ButtonTopic":"0","Power":3,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0}}
19:03:23.696 MQT: stat/tasmota_DAA58C/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32.bin","RestartReason":"Vbat power on reset","Uptime":"0T00:11:45","StartupUTC":"2022-01-14T17:51:38","Sleep":50,"CfgHolder":4617,"BootCount":2,"BCResetTime":"2022-01-14T18:51:05","SaveCount":13}}
19:03:23.739 MQT: stat/tasmota_DAA58C/STATUS2 = {"StatusFWR":{"Version":"2022.01.2(tasmota)","BuildDateTime":"2022-01-14T05:56:58","Core":"2_0_2","SDK":"v4.4-2.0.2","CpuFrequency":80,"Hardware":"ESP32-D0WD-V3","CR":"456/699"}}
19:03:23.760 MQT: stat/tasmota_DAA58C/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["FUECAM",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C80001000600003C5A0A000000000000","00000080","00006000","00004000"]}}
19:03:23.803 MQT: stat/tasmota_DAA58C/STATUS4 = {"StatusMEM":{"ProgramSize":1398,"Free":1856,"Heap":154,"StackLowMark":4,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashFrequency":40,"FlashMode":2,"Features":["00000809","9FDAC7C7","0015A001","B7F7BFCF","05DA9BC0","E0360DC7","000840D2","20200000","0000482D"],"Drivers":"1,2,3,4,5,7,8,9,10,11,12,14,16,17,20,21,24,26,27,29,34,35,38,50,52,59","Sensors":"1,2,3,5,6,7,8,9,10,11,12,13,14,15,17,18,19,20,21,22,26,28,31,34,37,39,40,42,43,45,51,52,55,56,58,59,64,66,67,74,85,92,127"}}
19:03:23.861 MQT: stat/tasmota_DAA58C/STATUS5 = {"StatusNET":{"Hostname":"son-calderar3","IPAddress":"192.168.1.60","Gateway":"192.168.1.1","Subnetmask":"255.255.255.0","DNSServer1":"192.168.1.1","DNSServer2":"0.0.0.0","Mac":"C4:DD:57:DA:A5:8C","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}}
19:03:23.894 MQT: stat/tasmota_DAA58C/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.1.5","MqttPort":1883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_DAA58C","MqttUser":"DVES_USER","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
19:03:23.931 MQT: stat/tasmota_DAA58C/STATUS7 = {"StatusTIM":{"UTC":"2022-01-14T18:03:23","Local":"2022-01-14T19:03:23","StartDST":"2022-03-27T02:00:00","EndDST":"2022-10-30T03:00:00","Timezone":"+01:00","Sunrise":"08:39","Sunset":"17:19"}}
19:03:23.952 MQT: stat/tasmota_DAA58C/STATUS9 = {"StatusPTH":{"PowerDelta":[0,0,0],"PowerLow":0,"PowerHigh":0,"VoltageLow":0,"VoltageHigh":0,"CurrentLow":0,"CurrentHigh":0}}
19:03:23.986 MQT: stat/tasmota_DAA58C/STATUS10 = {"StatusSNS":{"Time":"2022-01-14T19:03:23","Switch1":"ON","Switch2":"ON","ENERGY":{"TotalStartTime":"2022-01-14T18:51:05","Total":0.000,"Yesterday":0.000,"Today":0.000,"Power":[ 0, 0],"ApparentPower":[ 0, 0],"ReactivePower":[ 0, 0],"Factor":[0.00,0.00],"Voltage": 0,"Current":[0.000,0.000]},"ESP32":{"Temperature":51.1},"TempUnit":"C"}}
19:03:24.034 MQT: stat/tasmota_DAA58C/STATUS11 = {"StatusSTS":{"Time":"2022-01-14T19:03:24","Uptime":"0T00:11:46","UptimeSec":706,"Heap":156,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":41,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":39},"POWER1":"ON","POWER2":"ON","Wifi":{"AP":1,"SSId":"FUECAM","BSSId":"62:8E:29:25:EE:D1","Channel":6,"Mode":"11n","RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:04"}}}
ascillato2 commented 2 years ago

Thanks,

Please, also enter weblog 4, then restart the device (you can use the command restart 1) and share the output of the console when the device starts to up to 1 minute. Thanks.

ascillato2 commented 2 years ago

Which device do you have?

There are 3 different Sonoff Dual R3 with different GPIO assigment:

https://templates.blakadder.com/sonoff_DUALR3.html https://templates.blakadder.com/sonoff_DUALR3_v2.html https://templates.blakadder.com/sonoff_DUALR3L.html

If using the wrong template, the device won't work.

adelafug commented 2 years ago

My Devices is a Sonoff Dual R3 v2

And the problem is template :-( sorry!!!

I activate template from page https://templates.blakadder.com/sonoff_DUALR3_v2.html and works perfect!!!

Thanks!!!

imagen

ascillato commented 2 years ago

Great!!! those are excellent news!

adelafug commented 2 years ago

Sorry, how I can send power from second button to domoticz? In domoticz screen config only have "Sensor idx 4 Power,Energy" for first button, but not have nothing for second button.

Thanks.

barbudor commented 2 years ago

@adelafug Do not hijack an Issue with help questions that are not related to the issue Please openned a new discussion in Q& A section

joba-1 commented 2 years ago

I don't know, but maybe you find it here: https://tasmota.github.io/docs/Commands/#domoticz or on discord

Or you could use my domoticz plugin tasmoticz. Just put it in the plugin folder of domoticz (e.g. git clone it there), create the "Autodiscovery of Tasmota Devices" hardware in domoticz and tell it where your mqtt broker is as described in the readme.

Then every power switch and sensor should show up in domoticz automagically. No domoticz support from tasmota side needed.

image

EDIT: or listen to barbudor, he knows better than me :)

adelafug commented 2 years ago

@adelafug Do not hijack an Issue with help questions that are not related to the issue Please openned a new discussion in Q& A section

Open!! Thanks!

ascillato2 commented 2 years ago

Hi, any news on this? The issue is solved with latest changes?

joba-1 commented 2 years ago

No freezes during my pr test runs so far

joba-1 commented 2 years ago

Out of the blue the device stopped responding. It did not react, not to (lots of) toggling power on/off and not to very long button presses. No AP and no connect as STA. Only a dimm blue led

I disconnected it from mains and plugged in a 2.5A power source and a serial adapter.

Ping is possible now, but no ports are open, no syslog and no mqtt.

I see this serial log now. NTP works! But nothing else. Any idea what's going on there?

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12352
load:0x40080400,len:2912
0x40080400: _init at ??:?

entry 0x400805c4

00:00:00.003 HDW: ESP32-D0WD-V3 
00:00:00.068 UFS: FlashFS mounted with 304 kB free
00:00:00.143 CFG: Loaded from File, Count 327
00:00:00.159 QPC: Count 2
00:00:00.165 ROT: Mode 1
00:00:00.168 BRY: GC from 1435 to 1435 bytes, objects freed 0/1 (in 0 ms)
00:00:00.182 BRY: GC from 3601 to 3033 bytes, objects freed 5/20 (in 0 ms)
00:00:00.250 BRY: GC from 4359 to 3813 bytes, objects freed 3/35 (in 1 ms)
00:00:00.251 BRY: Berry initialized, RAM used=3813
00:00:00.276 BRY: no 'preinit.be'
00:00:00.279 Project tasmota - Dual R3 Version 2022.01.2(bluetooth)-2_0_2(2022-01-16T17:44:10)
00:00:00.280 iBeacon register for advert callbacks
00:00:00.291 M32: init: request callbacks
00:00:00.478 BRY: no 'autoexec.be'
00:00:00.806 WIF: Checking connection...
00:00:00.807 WIF: Attempting connection...
00:00:01.055 WIF: Connecting to AP1 job.iot.ssid Channel 11 BSSId 28:D1:27:4E:6B:9F in mode 11n as dualr3...
00:00:01.100 WIF: Checking connection...
00:00:01.102 WIF: Attempting connection...
00:00:03.247 WIF: Checking connection...
00:00:03.249 WIF: Connected
00:00:03.510 UPP: Multicast (re)joined
00:00:03.759 NTP: Synch time...
00:00:03.816 RTC: UTC 2022-02-02T13:18:07, DST 2023-01-14T08:00:00, STD 2023-07-08T07:00:00
18:33:07.000 NTP: Synched
18:33:08.526 RSL: INFO1 = {"Info1":{"Module":"ESP32-DevKit","Version":"2022.01.2(bluetooth)","FallbackTopic":"cmnd/DVES_682B78_fb/","GroupTopic":"cmnd/tasmotas/"}}
18:33:08.541 RSL: INFO3 = {"Info3":{"RestartReason":"Vbat power on reset"}}
18:33:08.554 TFS: File 'autoexec.bat' not found
18:33:10.830 QPC: Reset
18:33:12.862 APP: Boot Count 29
18:33:13.668 CFG: Saved, Count 328, Bytes 4096
18:33:17.993 RSL: config = {"ip":"192.168.1.165","dn":"Dual R3","fn":["PowerMoni",null,null,null,null,null,null,null],"hn":"dualr3","mac":"94B97E682B78","md":"ESP32-DevKit","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"2022.01.2","t":"dualr3","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":1,"114":0,"117":0},"lk":0,"lt_st":0,"sho":[50,45,98,108],"ver":1}
18:33:18.061 RSL: sensors = {"sn":{"Time":"2022-02-02T18:33:18.057"},"ver":1}
18:33:22.816 EQ3 poll cycle starting
18:33:28.676 UDP: Packet (119/173)
18:33:29.444 WIF: Checking connection...
18:33:29.696 UDP: Packet (119/173)
18:33:30.716 UDP: Packet (119/173)
18:33:31.736 UDP: Packet (119/173)
18:33:49.844 WIF: Checking connection...
18:34:08.966 UDP: Packet (119/167)
18:34:09.731 UDP: Packet (119/167)
18:34:10.244 WIF: Checking connection...
18:34:11.771 UDP: Packet (119/167)
18:34:30.645 WIF: Checking connection...
18:34:51.046 WIF: Checking connection...
18:35:11.446 WIF: Checking connection...
18:35:28.783 UDP: Packet (119/173)
18:35:29.803 UDP: Packet (119/173)
18:35:30.823 UDP: Packet (119/173)
18:35:31.843 UDP: Packet (119/173)
18:35:31.849 WIF: Checking connection...
18:35:52.246 WIF: Checking connection...
18:35:57.343 UDP: Packet (119/125)
18:35:57.598 UDP: Packet (119/125)
...
sfromis commented 2 years ago

After successful wifi connection, before trying to connect to MQTT, the log should show : HTP: Web server active on xxxxxxxx with IP address xxxxxxxx Without that, I'd not expect the Tasmota web server to be there. What is the output of the command WebServer?

Something looks odd in your log, I see INFO1 and INFO3, but no INFO2 or other common messages at restart time, like STATE or POWER.

arendst commented 2 years ago

INFO2 isn't there when there is no webserver. More info should be available from status 0 as always. I guess the dualr3 template isn't active anymore.

joba-1 commented 2 years ago

Thanks for confirming that looked very odd. Since I couldn't connect to it to do any commands, I decided to erase all and reflash (with latest pull). Looks normal again. Hope that was a one-time hickup

joba-1 commented 2 years ago

Current version under test:

Program Version 11.0.0(tasmota) Build Date & Time 2022-02-12T14:14:12 Core/SDK Version 2_0_2_2/v4.4-3-g6afb23d90a Uptime 1T13:50:43

Showing zeros again...

joba-1 commented 2 years ago

Updated to latest dev now. This did not resolve the issue in itself. A power cycle was necessary (as usual) to get power values again.

Overall I do not see a big difference in reliability when running with or without my pr :(

arendst commented 2 years ago

Regarding ESP32 hardware serial and event queues, from the latest core version they switch to idf queues for hardware serial. It's not released yet and TasmotaSerial hasn't changed too but this might solve your issue.

I'll keep an eye on it.

BTW my non-BLE dualR3s are running for over 60 days without any issue.

joba-1 commented 2 years ago

Nice. I do not really depend on these power values - so no urgency for me. Will gladly test if there is something new.

Until then, feel free to close this and my related pr - I am reminded about the issue by my device. And if not, all the better :)

arendst commented 2 years ago

I'll close it for now.

joba-1 commented 2 years ago

Are you aware of this?

https://github.com/platformio/platform-espressif32/issues/746

seems worth to check…

Jason2866 commented 2 years ago

@joba-1 We do not use this old core. Tasmota is based on actual IDF44 and Arduino

joba-1 commented 2 years ago

the fix just got included in 4.4 but in testing, not officially released yet (afaik)

Jason2866 commented 2 years ago

@joba-1 Every fix done in IDF44 and Arduino ESP32 is in Tasmota Arduino ESP32 framework. It is this commit https://github.com/espressif/esp-idf/commit/1e117f2f83e200f4fb6fd9452a0d8485a29d2a62 We do not use anything official 😎