search

letscontrolit / ESPEasy

Easy MultiSensor device based on ESP8266/ESP32
http://www.espeasy.com
Other
3.28k stars 2.22k forks source link

High Sysload on wifi lost ESP8266/ESP32 with releases 20220809 / 20221105 / 20221224 / Git from 23.01.22 #4485

Open tomcatxx opened 1 year ago

tomcatxx commented 1 year ago

I'm using an ESP32 to controll the flow of a waterpump over pwm in combination with a flowmeter (pulsecounter). The process is done by a PID controller rule. Everything works fine if the controller is connected to the wifi. If wifi get lost/turned off the sysload rises to 100 and the process stops working properly.

I tested what will hapen on clean flashed devices ESP8266 Nodemcu and ESP32-WROOM-32D with above mentioned builds. Here some logs:

643867 : Info   : WIFI : Connecting ACCESSP 26:5A:5A:11:01:8F Ch:6 (-60dBm) WPA2/PSK bgn attempt #9
643875 : Info   : WIFI : Arduino wifi status: WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
645467 : Info   : WD   : Uptime 11 ConnectFailures 0 FreeMem 210812 WiFiStatus WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
646362 : Debug  : LoopStats: shortestLoop: 72 longestLoop: 5838038 avgLoopDuration: 15809.73 loopCounterMax: 416666 loopCounterLast: 1896
646363 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 1896/1580/7/13.71
675467 : Info   : WD   : Uptime 11 ConnectFailures 0 FreeMem 210812 WiFiStatus WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
676362 : Debug  : LoopStats: shortestLoop: 72 longestLoop: 5838038 avgLoopDuration: 15795.73 loopCounterMax: 416666 loopCounterLast: 1898
676363 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 1898/1580/7/13.76
683871 : Info   : WIFI : Connecting ACCESSP 26:5A:4C:1C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn attempt #10
683879 : Info   : WIFI : Arduino wifi status: WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
683942 : Debug  : WIFI : Entering processConnect()
683944 : Info   : WIFI : Connected! AP: ACCESSP (26:5A:4C:1C:99:0D) Ch: 6 Duration: 64 ms
683965 : Debug  : WIFI : Entering processGotIP()
683966 : Info   : WIFI : DHCP IP: 192.168.1.20 (ESP-Easy) GW: 192.168.1.1 SN: 255.255.255.0   duration: 27 ms
683980 : Debug  : WiFi : WiFi services initialized
705454 : Info   : WD   : Uptime 12 ConnectFailures 0 FreeMem 210024 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
706343 : Debug  : LoopStats: shortestLoop: 51 longestLoop: 5838038 avgLoopDuration: 140.49 loopCounterMax: 588235 loopCounterLast: 211457
706345 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 211457/1880/7/60.63
735454 : Info   : WD   : Uptime 12 ConnectFailures 0 FreeMem 210024 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
736343 : Debug  : LoopStats: shortestLoop: 51 longestLoop: 5838038 avgLoopDuration: 104.59 loopCounterMax: 588235 loopCounterLast: 283073
736345 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 283073/1982/7/77.09

So even on clean flashed normal builds this high load problem exist.

Any ideas how to get rid of this problem?

TD-er commented 1 year ago

Can you enable "Collect Timing Statistics" on the tools->Advanced page? Then after a few minutes, please load the "Timing Stats" page (link on the Tools page) N.B. Each time this stats page is reloaded, the stats will be cleared.

If you could share the found stats, we can try to narrow it down What may cause your high load.

Also check whether you've enabled "Eco mode" and if you have, please try also with this mode disabled.

tomcatxx commented 1 year ago

TY for the fast reply :-)

Clean flashed 20221224 normal from https://td-er.nl/ESPEasy/ on ESP32-Wroom-32D. Only changes: WIFI connected Timing Stats enabled. Client IP block level: Allow all Stats after 5 mins:

Connected to wifi and idling: Serial logs:

1786499 : Info   : WD   : Uptime 29 ConnectFailures 0 FreeMem 209260 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
1787388 : Debug  : LoopStats: shortestLoop: 38 longestLoop: 7293151 avgLoopDuration: 65.58 loopCounterMax: 789473 loopCounterLast: 449022
1787390 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 449022/2131/6/92.94

new installation timingstats connected

Not connected to wifi (off) and idling:

345317 : Info   : WD   : Uptime 6 ConnectFailures 0 FreeMem 206196 WiFiStatus WL_NO_SSID_AVAIL 1 ESPeasy internal wifi status: DISCONNECTED
346191 : Debug  : LoopStats: shortestLoop: 28 longestLoop: 6265090 avgLoopDuration: 13532.56 loopCounterMax: 1071428 loopCounterLast: 2216
346193 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2216/1826/6/15.59

new installation timingstats after wifi not connected

The Pump Controller (ESP32-Wroom-32D): Connected to wifi and idling: controller timingstats connected

The Pump Controllern not connected to wifi (off) and idling: controller timingstats after wifi not connected

tonhuisman commented 1 year ago

Is there anything special in your rules? You should not use any delay command there, to start with, as at least some time is spent there, but the WiFi.isConnected() (fail) is the obvious candidate for further investigation.

tomcatxx commented 1 year ago

No noting special and no delays. I also simplified the rules as much as possible for testing and disabled all not directly nessesary tasks/sensors. It reduce the sysload a bit but as soon as wifi goes offline sysload goes up to 100 and its not longer controlling the pump propperly.

TD-er commented 1 year ago

So it looks like there is some reconnect attempt causing huge delays.

I think, given the affected builds, this might be related to the more dynamic timeout I made for the controllers. I did implement it around the end of the summer I think.

I will have a look.

tomcatxx commented 1 year ago

Hm I tested ESPEasy_ESP32_mega-20210802

393287 : Info   : WD   : Uptime 7 ConnectFailures 0 FreeMem 222128 WiFiStatus WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
394190 : Debug  : LoopStats: shortestLoop: 1505 longestLoop: 2919059 avgLoopDuration: 13626.29 loopCounterMax: 19933 loopCounterLast: 2201
394191 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2201/1650/7/20.17

Also around 80% Sysload after wifi goes down.

ESPEasy_ESP32_mega-20210802

TD-er commented 1 year ago

While you're at it, can you try one of the latest GH Action builds? For example this one: https://github.com/letscontrolit/ESPEasy/actions/runs/4019311623 That's the last one of the current 'mega' branch.

tomcatxx commented 1 year ago

Still 85% sysload after wifi is off.

495317 : Info   : WD   : Uptime 8 ConnectFailures 0 FreeMem 211808 WiFiStatus WL_CONNECT_FAILED 4 ESPeasy internal wifi status: DISCONNECTED
496209 : Debug  : LoopStats: shortestLoop: 40 longestLoop: 6273039 avgLoopDuration: 15066.17 loopCounterMax: 750000 loopCounterLast: 1989
496210 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 1989/1632/7/15.46

ESP_Easy_mega_20230127

TD-er commented 1 year ago

OK, so I need to look at the reconnect related code.

One thing I also see from your timing stats is that we can optimize P023 a bit more as it is loading the CustomTaskSettings every second while this does take quite a lot of time and can easily be cached.

tomcatxx commented 1 year ago

Ok. If you need furter testings or informations just let me know :)

TD-er commented 1 year ago

When I got something to test, I will let you know :)

TD-er commented 1 year ago

Could you test with one of the most recent GitHub Actions builds? For example this one: https://github.com/letscontrolit/ESPEasy/actions/runs/4540120477

tomcatxx commented 1 year ago

Hi, still same behavior with ESPEasy_mega_20230328_ESP32_PR#_4540120477 Screenshot 2023-03-29 195335

TD-er commented 1 year ago

There is always a high "load" when scanning, because performing a WiFi scan is blocking.

I have tried to make it async, but wasn't pleased with the results yet.

I can give it another try, by simply scanning per channel as we can do that now for ESP32 in the latest SDK code. But it will still take upto 300 msec per channel, for 12 (13?) channels.

tomcatxx commented 1 year ago

Yes but why is the Sysload that high?

412736 : Debug More : UDP  : 01:3B:F1:A1:E9:3F,192.168.10.17,0
518727 : Info   : WD   : Uptime 9 ConnectFailures 0 FreeMem 216608 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
519615 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 628675 avgLoopDuration: 105.83 loopCounterMax: 526315 loopCounterLast: 278689
519617 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 278689/2042/7/80.44
521243 : Error  : WiFi : Connecting not possible, unprocessed WiFi events:  disconn
521246 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: Conn. IP Init
521248 : Info   : WiFi : Event STA Stopped
521251 : Debug  : WIFI : Entering processDisconnect()
521251 : Info   : WIFI : Disconnected! Reason: '(4) Assoc expire' Connected for 8 m 29 s
521363 : Info   : WiFi : Event STA Started
521370 : Info   : WiFi : Start network scan all channels
527184 : Info   : WiFi : Scan finished, found: 5
527187 : Debug  : WiFi : Scan result: Test-1 26:5A:4C:2C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn
527188 : Debug  : WiFi : Scan result: Test-2 26:5A:4C:1C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn
527188 : Debug  : WiFi : Scan result: Test-3 26:1B:FF:20:01:8C Ch:6 (-71dBm) WPA2/PSK bgn
527189 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:04:8C Ch:6 (-69dBm) WPA2/PSK bgn
527190 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:05:8C Ch:6 (-71dBm) WPA2/PSK bgn
527190 : Info   : WiFi : Best AP candidate: Test-2 26:5A:4C:1C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn
527191 : Info   : WiFi : Added known candidate, try to connect
527192 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
527192 : Debug  : WIFI : Disconnected: WiFi.status() = DISCONNECTED RSSI: 0 status: WL_DISCONNECTED 6
548745 : Info   : WD   : Uptime 9 ConnectFailures 0 FreeMem 218260 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
549622 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 1828.98 loopCounterMax: 526315 loopCounterLast: 16384
549624 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 16382/1333/7/14.30
578731 : Info   : WD   : Uptime 10 ConnectFailures 0 FreeMem 218272 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
579622 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 14843.08 loopCounterMax: 526315 loopCounterLast: 2020
579624 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2020/1673/7/13.87
607199 : Info   : WIFI : Connecting Test-2 26:5A:4C:1C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn attempt #0
607208 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
608769 : Info   : WD   : Uptime 10 ConnectFailures 0 FreeMem 218264 WiFiStatus WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
609651 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 15346.61 loopCounterMax: 526315 loopCounterLast: 1955
609653 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 1951/1633/7/12.70
613046 : Debug  : WIFI : Disconnected: WiFi.status() = DISCONNECTED RSSI: 0 status: WL_NO_SSID_AVAIL 1
638731 : Info   : WD   : Uptime 11 ConnectFailures 0 FreeMem 218320 WiFiStatus WL_NO_SSID_AVAIL 1 ESPeasy internal wifi status: DISCONNECTED
639628 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 14394.87 loopCounterMax: 526315 loopCounterLast: 2082
639630 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2075/1628/7/16.51
641246 : Info   : WiFi : Event Lost IP
641258 : Debug  : WIFI : Disconnected: WiFi.status() = DISCONNECTED RSSI: 0 status: WL_IDLE_STATUS 0
647205 : Info   : WIFI : Connecting Test-2 26:5A:4C:1C:99:0D Ch:6 (-71dBm) WPA2/PSK bgn attempt #1
647213 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
668727 : Info   : WD   : Uptime 11 ConnectFailures 0 FreeMem 218356 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
669622 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 14146.93 loopCounterMax: 526315 loopCounterLast: 2119
669624 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2118/1669/7/17.92
687222 : Info   : WiFi : Start network scan all channels
693036 : Info   : WiFi : Scan finished, found: 10
693038 : Debug  : WiFi : Scan result: Test-1 26:1B:FF:20:01:8F Ch:6 (-61dBm) WPA2/PSK bgn
693039 : Debug  : WiFi : Scan result: Test-2 26:1B:FF:20:01:8A Ch:6 (-62dBm) WPA2/PSK bgn
693040 : Debug  : WiFi : Scan result: Test-3 26:1B:FF:20:01:8B Ch:6 (-63dBm) WPA2/PSK bgn
693041 : Debug  : WiFi : Scan result: Test-3 26:1B:FF:20:01:8C Ch:6 (-68dBm) WPA2/PSK bgn
693041 : Debug  : WiFi : Scan result: Test-2 26:5A:4C:1C:99:0D Ch:6 (-68dBm) WPA2/PSK bgn
693042 : Debug  : WiFi : Scan result: Test-1 26:5A:4C:2C:99:0D Ch:6 (-69dBm) WPA2/PSK bgn
693043 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:02:8C Ch:6 (-59dBm) WPA2/PSK bgn
693043 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:03:8C Ch:6 (-62dBm) WPA2/PSK bgn
693044 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:04:8C Ch:6 (-67dBm) WPA2/PSK bgn
693044 : Debug  : WiFi : Scan result: #Hidden# 26:1B:FF:20:05:8C Ch:6 (-68dBm) WPA2/PSK bgn
693045 : Info   : WiFi : Best AP candidate: Test-2 26:1B:FF:20:01:8A Ch:6 (-62dBm) WPA2/PSK bgn
693046 : Info   : WiFi : Added known candidate, try to connect
693046 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
698739 : Info   : WD   : Uptime 12 ConnectFailures 0 FreeMem 217848 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
699634 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 17937.23 loopCounterMax: 526315 loopCounterLast: 1672
699636 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 1670/1330/7/13.63
728744 : Info   : WD   : Uptime 12 ConnectFailures 0 FreeMem 217852 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
729625 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 14853.33 loopCounterMax: 526315 loopCounterLast: 2018
729627 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2018/1685/7/13.31
758746 : Info   : WD   : Uptime 13 ConnectFailures 0 FreeMem 217852 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
759627 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 14851.42 loopCounterMax: 526315 loopCounterLast: 2019
759629 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 2019/1684/7/13.40
773053 : Info   : WIFI : Connecting Test-2 26:1B:FF:20:01:8A Ch:6 (-62dBm) WPA2/PSK bgn attempt #2
773061 : Info   : WIFI : Arduino wifi status: WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
773621 : Debug  : WIFI : Entering processConnect()
773622 : Info   : WIFI : Connected! AP: Test-2 (26:1B:FF:20:01:8A) Ch: 6 Duration: 559 ms
773837 : Debug  : WIFI : Entering processGotIP()
773839 : Info   : WIFI : DHCP IP: 192.168.10.37 (ESP-Easy-Test) GW: 192.168.10.2 SN: 255.255.255.0 DNS: 192.168.10.10 / 192.168.10.11   duration: 223 ms
773850 : Debug  : WiFi : WiFi services initialized
788728 : Info   : WD   : Uptime 13 ConnectFailures 0 FreeMem 214972 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
789615 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 232.95 loopCounterMax: 526315 loopCounterLast: 127751
789617 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 127750/1807/7/47.89
818727 : Info   : WD   : Uptime 14 ConnectFailures 0 FreeMem 214972 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
819615 : Debug  : LoopStats: shortestLoop: 57 longestLoop: 5955068 avgLoopDuration: 117.03 loopCounterMax: 526315 loopCounterLast: 252366
819617 : Debug  : Scheduler stats: (called/tasks/max_length/idle%) 252366/2042/7/81.04

I just used this example: https://esp32.com/viewtopic.php?t=3851 slightly modifed to reduce spam in the terminal....

And this way to get load:


 void loop() { 
  timeStart = micros();
  uint64_t start_time = esp_timer_get_time();

Code from the example...


// start section for tasks which should run regardless of WiFi/MQTT
    uint64_t end_time = esp_timer_get_time();
    uint64_t elapsed_time = end_time - start_time;  
    uint8_t cpu_load = (elapsed_time * 100) / (1000 * 1000 * 10); // calculate CPU load percentage
    timeExecute = micros() - timeStart;
    if (millis() - lastTask_01sec_free > 100) {   
      Serial.println("Executiontime : "+ String(timeExecute)+" uS. CPU Load: "+String(cpu_load)+"%");
    lastTask_01sec_free = millis();
    }
// end of section for tasks which should run regardless of WiFi/MQTT

The logs look like this:

Executiontime : 131 uS. CPU Load: 0%
Executiontime : 135 uS. CPU Load: 0%
Executiontime : 135 uS. CPU Load: 0%
Executiontime : 131 uS. CPU Load: 0%
Executiontime : 190 uS. CPU Load: 0%
MQTT and WiFi down: start WiFi
Executiontime : 6 uS. CPU Load: 0%
E (58666) wifi:Set status to INIT
E (58698) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (58790) wifi:Set status to INIT
E (58822) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (58918) wifi:Set status to INIT
E (58950) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (59053) wifi:Set status to INIT
Executiontime : 113 uS. CPU Load: 0%
E (59093) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (59182) wifi:Set status to INIT
E (59213) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (59292) wifi:Set status to INIT
E (59324) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (59447) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (59475) wifi:Set status to INIT
E (59551) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (59581) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (59697) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (59781) wifi:Set status to INIT
E (59816) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (59903) wifi:Set status to INIT
E (59931) wifi:Set status to INIT
E (59963) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (60044) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (60082) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (60173) wifi:Set status to INIT
E (60265) wifi:Set status to INIT
Executiontime : 101 uS. CPU Load: 0%
E (60351) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (60380) wifi:Set status to INIT
E (60464) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (60553) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (60581) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (60696) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (60787) wifi:Set status to INIT
E (60874) wifi:Set status to INIT
Executiontime : 18 uS. CPU Load: 0%
E (60956) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (60988) wifi:Set status to INIT
E (61065) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (61095) wifi:Set status to INIT
E (61175) wifi:Set status to INIT
Executiontime : 7 uS. CPU Load: 0%
E (61202) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (61280) wifi:Set status to INIT
E (61358) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (61443) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (61522) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (61611) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (61700) wifi:Set status to INIT
E (61781) wifi:Set status to INIT
Executiontime : 92 uS. CPU Load: 0%
E (61858) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (61912) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (61994) wifi:Set status to INIT
E (62025) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62109) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62191) wifi:Set status to INIT
E (62224) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (62311) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62396) wifi:Set status to INIT
E (62432) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62522) wifi:Set status to INIT
E (62558) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62656) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62736) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (62821) wifi:Set status to INIT
E (62852) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (62935) wifi:Set status to INIT
E (62964) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (63047) wifi:Set status to INIT
E (63080) wifi:Set status to INIT
Executiontime : 17 uS. CPU Load: 0%
E (63161) wifi:Set status to INIT
E (63192) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (63278) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (63314) wifi:Set status to INIT
E (63346) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (63435) wifi:Set status to INIT
E (63471) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (63553) wifi:Set status to INIT
E (63587) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (63684) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (63760) wifi:Set status to INIT
E (63793) wifi:Set status to INIT
Executiontime : 19 uS. CPU Load: 0%
E (63871) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (63908) wifi:Set status to INIT
E (63987) wifi:Set status to INIT
Executiontime : 15 uS. CPU Load: 0%
E (64070) wifi:Set status to INIT
E (64102) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (64184) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (64263) wifi:Set status to INIT
E (64296) wifi:Set status to INIT
Executiontime : 7 uS. CPU Load: 0%
E (64378) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (64415) wifi:Set status to INIT
E (64499) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (64576) wifi:Set status to INIT
E (64610) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (64649) wifi:Set status to INIT
E (64684) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (64765) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (64850) wifi:Set status to INIT
E (64881) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (64970) wifi:Set status to INIT
E (65003) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (65087) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (65169) wifi:Set status to INIT
E (65201) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (65283) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (65386) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (65467) wifi:Set status to INIT
E (65497) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (65578) wifi:Set status to INIT
E (65606) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (65691) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (65776) wifi:Set status to INIT
E (65807) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (65893) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (65928) wifi:Set status to INIT
E (66002) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (66036) wifi:Set status to INIT
E (66103) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (66179) wifi:Set status to INIT
E (66217) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (66302) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (66329) wifi:Set status to INIT
E (66415) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (66453) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (66534) wifi:Set status to INIT
E (66617) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (66643) wifi:Set status to INIT
E (66724) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (66753) wifi:Set status to INIT
E (66834) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (66917) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (66999) wifi:Set status to INIT
E (67029) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (67114) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (67142) wifi:Set status to INIT
E (67224) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (67308) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (67351) wifi:Set status to INIT
E (67438) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (67474) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (67558) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (67654) wifi:Set status to INIT
E (67690) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (67768) wifi:Set status to INIT
E (67806) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (67890) wifi:Set status to INIT
E (67919) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (67971) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68055) wifi:Set status to INIT
E (68092) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68175) wifi:Set status to INIT
E (68210) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68289) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68374) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68459) wifi:Set status to INIT
E (68490) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68567) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68662) wifi:Set status to INIT
E (68752) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (68834) wifi:Set status to INIT
Executiontime : 14 uS. CPU Load: 0%
E (68870) wifi:Set status to INIT
E (68949) wifi:Set status to INIT
Executiontime : 13 uS. CPU Load: 0%
E (69034) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69071) wifi:Set status to INIT
E (69150) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69182) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (69277) wifi:Set status to INIT
E (69309) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69385) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69463) wifi:Set status to INIT
E (69495) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69582) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (69676) wifi:Set status to INIT
E (69752) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69802) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69888) wifi:Set status to INIT
E (69915) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (69994) wifi:Set status to INIT
E (70026) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (70107) wifi:Set status to INIT
E (70136) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (70221) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (70304) wifi:Set status to INIT
E (70332) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (70412) wifi:Set status to INIT
E (70447) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (70528) wifi:Set status to INIT
E (70567) wifi:Set status to INIT
Executiontime : 112 uS. CPU Load: 0%
E (70662) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (70743) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (70810) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (70885) wifi:Set status to INIT
E (70972) wifi:Set status to INIT
Executiontime : 98 uS. CPU Load: 0%
E (71013) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71090) wifi:Set status to INIT
E (71133) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71227) wifi:Set status to INIT
E (71253) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71330) wifi:Set status to INIT
E (71365) wifi:Set status to INIT
Executiontime : 17 uS. CPU Load: 0%
E (71446) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71486) wifi:Set status to INIT
E (71573) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71665) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (71774) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71856) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (71893) wifi:Set status to INIT
E (71972) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72005) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72088) wifi:Set status to INIT
E (72169) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72204) wifi:Set status to INIT
E (72286) wifi:Set status to INIT
Executiontime : 17 uS. CPU Load: 0%
E (72319) wifi:Set status to INIT
E (72355) wifi:Set status to INIT
Executiontime : 5 uS. CPU Load: 0%
E (72435) wifi:Set status to INIT
Executiontime : 16 uS. CPU Load: 0%
E (72515) wifi:Set status to INIT
E (72549) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72644) wifi:Set status to INIT
E (72673) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72757) wifi:Set status to INIT
E (72788) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72867) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (72896) wifi:Set status to INIT
E (72931) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (73013) wifi:Set status to INIT
E (73094) wifi:Set status to INIT
Executiontime : 17 uS. CPU Load: 0%
E (73125) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
E (73208) wifi:Set status to INIT
E (73231) wifi:Set status to INIT
Executiontime : 6 uS. CPU Load: 0%
Executiontime : 6 uS. CPU Load: 0%
Executiontime : 6 uS. CPU Load: 0%
Executiontime : 14 uS. CPU Load: 0%
Executiontime : 5 uS. CPU Load: 0%
Executiontime : 5 uS. CPU Load: 0%
[ 62292][E][ssl_client.cpp:37] _handle_error(): [data_to_read():361]: (-76) UNKNOWN ERROR CODE (004C)
WiFi up, MQTT down: start MQTT
Executiontime : 649482 uS. CPU Load: 6%
WiFi up, MQTT up: finish MQTT configuration
Executiontime : 139 uS. CPU Load: 0%
Executiontime : 131 uS. CPU Load: 0%
Executiontime : 130 uS. CPU Load: 0%
Executiontime : 130 uS. CPU Load: 0%
Executiontime : 130 uS. CPU Load: 0%
Executiontime : 138 uS. CPU Load: 0%
Executiontime : 138 uS. CPU Load: 0%

Non blocking to my opinion. Maybe it help you.