Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ESP32 crash when can't connect to WIFI #3079

Closed
fmuntean opened this issue May 19, 2020 · 45 comments
Closed

ESP32 crash when can't connect to WIFI #3079

fmuntean opened this issue May 19, 2020 · 45 comments
Labels
Category: Stabiliy Things that work, but not as long as desired Category: Wifi Related to the network connectivity Type: Bug Considered a bug

Comments

@fmuntean
Copy link
Contributor

INIT : Booting version: MFD-mega-2020_05_15 (ESP32 SDK v3.2.3-14-gd3e562907)
45 : Info : INIT : Free RAM:291676
46 : Info : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
47 : Info : FS : Mounting...
79 : Info : CRC : No program memory checksum found. Check output of crc2.py
90 : Info : CRC : SecuritySettings CRC ...OK
161 : Info : INIT : Free RAM:285984
164 : Info : INIT : I2C
165 : Info : INIT : SPI not enabled
175 : Info : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
177 : Info : EVENT: System#Wake
285 : Info : WIFI : Set WiFi to STA
472 : Info : WIFI : Start network scan
473 : Info : WIFI : Connecting Howard attempt #0
476 : Info : WIFI : WiFi.status() = WL_DISCONNECTED SSID: Howard
480 : Info : Webserver: start
485 : Info : OTA : Arduino OTA enabled on port 3232
498 : Info : EVENT: System#Boot
2094 : Info : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 1508 ms
2108 : Info : EVENT: WiFi#Disconnected
2125 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 218460 WiFiStatus 255
5582 : Info : WIFI : Set WiFi to STA
5696 : Info : WIFI : Start network scan
5697 : Info : WIFI : Connecting Howard attempt #1
5700 : Info : WIFI : WiFi.status() = WL_DISCONNECTED SSID: Howard
10707 : Info : WIFI : Connecting Howard attempt #2
10709 : Info : WIFI : No SSID found matching: Howard
20195 : Info : WIFI : Set WiFi to AP+STA
20295 : Info : WIFI : Set WiFi to AP+STA
20395 : Info : WIFI : Set WiFi to AP+STA
20495 : Info : WIFI : Set WiFi to AP+STA
20595 : Info : WIFI : Set WiFi to AP+STA
20695 : Info : WIFI : Set WiFi to AP+STA
20795 : Info : WIFI : Set WiFi to AP+STA
20895 : Info : WIFI : Set WiFi to AP+STA
20995 : Info : WIFI : Set WiFi to AP+STA
21095 : Info : WIFI : Set WiFi to AP+STA
21195 : Info : WIFI : Set WiFi to AP+STA
21295 : Info : WIFI : Set WiFi to AP+STA
21395 : Info : WIFI : Set WiFi to AP+STA
21495 : Info : WIFI : Set WiFi to AP+STA
21595 : Info : WIFI : Set WiFi to AP+STA
21695 : Info : WIFI : Set WiFi to AP+STA
21795 : Info : WIFI : Set WiFi to AP+STA
21895 : Info : WIFI : Set WiFi to AP+STA
21995 : Info : WIFI : Set WiFi to AP+STA
22095 : Info : WIFI : Set WiFi to AP+STA
22195 : Info : WIFI : Set WiFi to AP+STA
22295 : Info : WIFI : Set WiFi to AP+STA
22395 : Info : WIFI : Set WiFi to AP+STA
22495 : Info : WIFI : Set WiFi to AP+STA
22595 : Info : WIFI : Set WiFi to AP+STA
22695 : Info : WIFI : Set WiFi to AP+STA
22795 : Info : WIFI : Set WiFi to AP+STA
22895 : Info : WIFI : Set WiFi to AP+STAGuru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x40085ea0 PS : 0x00060233 A0 : 0x80085f30 A1 : 0x3ffbdcc0
A2 : 0x00000050 A3 : 0x00001800 A4 : 0x00000050 A5 : 0x00000000
A6 : 0x00060120 A7 : 0x3ffbe818 A8 : 0x00000000 A9 : 0x3ffbdca0
A10 : 0xfffffff9 A11 : 0x00000000 A12 : 0x00060c23 A13 : 0x00000000
A14 : 0x00000000 A15 : 0x00000001 SAR : 0x00000013 EXCCAUSE: 0x0000001c
EXCVADDR: 0x0000006c LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Core 0 was running in ISR context:
EPC1 : 0x40085ea0 EPC2 : 0x00000000 EPC3 : 0x00000000 EPC4 : 0x00000000

Backtrace: 0x40085ea0:0x3ffbdcc0 0x40085f2d:0x3ffbdce0 0x400863f1:0x3ffbdd00 0x4000beaf:0x3ffbdd20 0x4008991e:0x3ffbdd40 0x40089b64:0x3ffbdd60 0x400864c4:0x3ffbdd80 0x400864f4:0x3ffbdda0 0x40086645:0x3ffbddd0 0x401811df:0x3ffbddf0 0x4017bb7d:0x3ffbe0b0 0x40179081:0x3ffbe100 0x4008b0dd:0x3ffbe130 0x40089ccd:0x3ffbe160 0x40083b88:0x3ffbe180 0x40082e2d:0x3ffbe1b0 0x40085c55:0x3ffbe1d0 0x401c0907:0x3ffbc5b0 0x4013dfde:0x3ffbc5d0 0x4008b8a9:0x3ffbc5f0 0x4008a085:0x3ffbc610

Rebooting...
ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U45 : Info :

INIT : Booting version: MFD-mega-2020_05_15 (ESP32 SDK v3.2.3-14-gd3e562907)

@TungstenE2
Copy link
Contributor

TungstenE2 commented May 20, 2020

I also see mega-20200426 on D1 mini rebooting sometimes, when wifi is not available.
May be this is connected?

@TD-er
Copy link
Member

TD-er commented May 21, 2020

I also see mega-20200426 on D1 mini rebooting sometimes, when wifi is not available.
May be this is connected?

I know there is a version of the ESP32 that looks very similar to the Wemos D1 mini, but then with 2 rows on each side.
Is that the version you are referring to?

About the logs in the topic start.

20195 : Info : WIFI : Set WiFi to AP+STA
20295 : Info : WIFI : Set WiFi to AP+STA
20395 : Info : WIFI : Set WiFi to AP+STA
20495 : Info : WIFI : Set WiFi to AP+STA
...

This I find quite strange. Why should it switch on AP+STA mode every 100 msec?

@TD-er TD-er added Category: Stabiliy Things that work, but not as long as desired Category: Wifi Related to the network connectivity Type: Bug Considered a bug labels May 21, 2020
@fmuntean
Copy link
Contributor Author

fmuntean commented May 22, 2020

Yes. this is what I see very rapid connect failure then exception.
Maybe there is something happening 10times per second loop that trigger this?
I have MQTT enabled on my board.

@TungstenE2
Copy link
Contributor

but then with 2 rows on each side.

you mean 2 soldering pad rows each side? no, only one each side.

@TD-er
Copy link
Member

TD-er commented May 22, 2020

but then with 2 rows on each side.

you mean 2 soldering pad rows each side? no, only one each side.

That's an ESP8266 module.
The ESP32 version has roughly double the number of pin header holes.

Which doesn't mean by the way, it can't be related.

@TD-er TD-er changed the title ESP32 chash when can't connect to WIFI ESP32 crash when can't connect to WIFI May 22, 2020
@uzi18
Copy link
Contributor

uzi18 commented May 24, 2020

@fmuntean do you have error log?

@fmuntean
Copy link
Contributor Author

@fmuntean do you have error log?

I can reproduce the issue by removing the WiFi Antenna on a Wroover board.
Please let me know exactly what you need and I can provide.
Thanks for your help.

@TD-er
Copy link
Member

TD-er commented May 25, 2020

I can reproduce the issue by removing the WiFi Antenna on a Wroover board.
[...]

Is that the only way to reproduce it?
If so, then I don't think it is a bug in ESPEasy, but something related to RF interference flipping bits in the processor.
Without an antenna connected, you will transmit almost all RF power back into the processor, which may cause all kinds of strange things.

See also this issue: esp8266/Arduino#6471

@uzi18
Copy link
Contributor

uzi18 commented May 25, 2020

@fmuntean @TD-er will try first to change SSID on my own unit

@fmuntean
Copy link
Contributor Author

I can reproduce the issue by removing the WiFi Antenna on a Wroover board.
[...]

Is that the only way to reproduce it?
If so, then I don't think it is a bug in ESPEasy, but something related to RF interference flipping bits in the processor.
Without an antenna connected, you will transmit almost all RF power back into the processor, which may cause all kinds of strange things.

See also this issue: esp8266/Arduino#6471

Nope. It does the same when not finding the SSID for some reason or not being able to connect to it. I said the easiest way to reproduce is to remove the antenna.

@uzi18
Copy link
Contributor

uzi18 commented May 28, 2020

@fmuntean @TD-er cannot reproduce, have 20s periods between reconnections on esp32 and AP+STA only once in log

@fmuntean
Copy link
Contributor Author

fmuntean commented Jun 1, 2020

thanks @uzi18:
I just retested on my side with another board and no external antenna.
The board is stable with no issues or reboots.
Then I changed the SSID password in order to not let the board connect to Wifi then reboot and the problem surfaced immediatelly.


>reboot
300769 : Info  : Command: reboot
301774 : Error : MQTT : Connection lost, state: Disconnected
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U36 : Info  : 

INIT : Booting version: MFD-mega-2020_05_15 (ESP32 SDK v3.2.3-14-gd3e562907)
36 : Info  : INIT : Free RAM:295192
37 : Info  : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
38 : Info  : FS   : Mounting...
64 : Info  : CRC  : No program memory checksum found. Check output of crc2.py
75 : Info  : CRC  : SecuritySettings CRC   ...OK
144 : Info  : INIT : Free RAM:289456
147 : Info  : INIT : I2C
148 : Info  : INIT : SPI Init (without CS)
153 : Info  : MFRC522: Init
155 : Info  : MFRC522: Reset on pin: 25
368 : Info  : MFRC522: Software Version:  = v2.0
425 : Info  : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
427 : Info  : EVENT: System#Wake
552 : Info  : WIFI : Set WiFi to STA
738 : Info  : WIFI  : Start network scan
740 : Info  : WIFI : Connecting Howard attempt #0
743 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
749 : Info  : Webserver: start
762 : Info  : EVENT: System#Boot
770 : Info  : ACT  : NOTIFY,1
772 : Info  : Command: NOTIFY
902 : Info  : WIFI  : Scan finished, found: 1
2184 : Info  : WIFI  : Start network scan
2186 : Info  : WIFI : Connecting Howard attempt #1
2188 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
2200 : Error : WiFi  : Scan failed
2301 : Info  : WIFI : Set WiFi to STA
2413 : Info  : WIFI : Connecting Linksys attempt #2
2415 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
2515 : Info  : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 1 ms
2517 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
2545 : Info  : SYS  : 0.00,0.00,100.00,-1.00
3679 : Info  : EVENT: WiFi#Disconnected
4188 : Info  : WD   : Uptime 0 ConnectFailures 0 FreeMem 225520 WiFiStatus 6
4531 : Info  : EVENT: SYSTEM#Uptime=0.00
4896 : Info  : EVENT: SYSTEM#WiFi=0.00
5385 : Info  : EVENT: SYSTEM#Load=100.00
5634 : Info  : EVENT: SYSTEM#=-1.00
12600 : Info  : WIFI : Connecting Linksys attempt #3
12603 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
12722 : Info  : WIFI : Connecting Howard attempt #4
12725 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
20246 : Info  : WIFI : Set WiFi to AP+STA
20346 : Info  : WIFI : Set WiFi to AP+STA
20446 : Info  : WIFI : Set WiFi to AP+STA
20546 : Info  : WIFI : Set WiFi to AP+STA
20646 : Info  : WIFI : Set WiFi to AP+STA
20746 : Info  : WIFI : Set WiFi to AP+STA
20846 : Info  : WIFI : Set WiFi to AP+STA
20946 : Info  : WIFI : Set WiFi to AP+STA
21046 : Info  : WIFI : Set WiFi to AP+STA
21146 : Info  : WIFI : Set WiFi to AP+STA
21246 : Info  : WIFI : Set WiFi to AP+STA
21346 : Info  : WIFI : Set WiFi to AP+STA
21446 : Info  : WIFI : Set WiFi to AP+STA
21546 : Info  : WIFI : Set WiFi to AP+STA
21646 : Info  : WIFI : Set WiFi to AP+STA
21746 : Info  : WIFI : Set WiFi to AP+STA
21846 : Info  : WIFI : Set WiFi to AP+STA
21946 : Info  : WIFI : Set WiFi to AP+STA
22046 : Info  : WIFI : Set WiFi to AP+STA
22146 : Info  : WIFI : Set WiFi to AP+STA
22246 : Info  : WIFI : Set WiFi to AP+STA
22346 : Info  : WIFI : Set WiFi to AP+STA
22446 : Info  : WIFI : Set WiFi to AP+STA
22546 : Info  : WIFI : Set WiFi to AP+STA
22646 : Info  : WIFI : Set WiFi to AP+STA
22746 : Info  : WIFI : Set WiFi to AP+STA
22846 : Info  : WIFI : Set WiFi to AP+STA
22946 : Info  : WIFI : Set WiFi to AP+STAGuru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4008d1eb  PS      : 0x00060830  A0      : 0x8008d898  A1      : 0x3ffaf140  
A2      : 0xfffffff9  A3      : 0x00060823  A4      : 0x00060820  A5      : 0x00000001
A6      : 0x00060623  A7      : 0x00000000  A8      : 0x3ffb5b14  A9      : 0x0000cdcd  
A10     : 0x3f41f424  A11     : 0x3ffb85dc  A12     : 0x3ffb5a7c  A13     : 0x00000000
A14     : 0x00000001  A15     : 0xfffffd01  SAR     : 0x0000001c  EXCCAUSE: 0x0000001c
EXCVADDR: 0xfffffff9  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

Backtrace: 0x4008d1eb:0x3ffaf140 0x4008d895:0x3ffaf160 0x40086022:0x3ffaf180 0x40086429:0x3ffaf1a0 0x4000bec7:0x3ffaf1c0 0x4018e75b:0x3ffaf1e0 0x4018e7df:0x3ffaf200 0x4018e827:0x3ffaf220 0x40190516:0x3ffaf240 0x401906d8:0x3ffaf260 0x40189280:0x3ffaf280 0x4008a0b1:0x3ffaf2b0

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U35 : Info  : 

INIT : Booting version: MFD-mega-2020_05_15 (ESP32 SDK v3.2.3-14-gd3e562907)
35 : Info  : INIT : Free RAM:295192
36 : Info  : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
37 : Info  : FS   : Mounting...
63 : Info  : CRC  : No program memory checksum found. Check output of crc2.py
74 : Info  : CRC  : SecuritySettings CRC   ...OK
143 : Info  : INIT : Free RAM:289468
146 : Info  : INIT : I2C
147 : Info  : INIT : SPI Init (without CS)
152 : Info  : MFRC522: Init
153 : Info  : MFRC522: Reset on pin: 25
366 : Info  : MFRC522: Software Version:  = v2.0
424 : Info  : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
425 : Info  : EVENT: System#Wake
550 : Info  : WIFI : Set WiFi to STA
736 : Info  : WIFI  : Start network scan
737 : Info  : WIFI : Connecting Howard attempt #0
740 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
745 : Info  : Webserver: start
758 : Info  : EVENT: System#Boot
766 : Info  : ACT  : NOTIFY,1
768 : Info  : Command: NOTIFY
2303 : Info  : SYS  : 0.00,-70.00,100.00,-1.00
2663 : Info  : EVENT: SYSTEM#Uptime=0.00
3173 : Info  : WD   : Uptime 0 ConnectFailures 0 FreeMem 226324 WiFiStatus 6
3517 : Info  : EVENT: SYSTEM#WiFi=-70.00
4121 : Info  : EVENT: SYSTEM#Load=100.00
4370 : Info  : EVENT: SYSTEM#=-1.00
5879 : Info  : WIFI  : Start network scan
5880 : Info  : WIFI : Connecting Howard attempt #1
5882 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
5894 : Error : WiFi  : Scan failed
5997 : Info  : WIFI : Set WiFi to STA
6109 : Info  : WIFI : Connecting Linksys attempt #2
6111 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
6211 : Info  : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 1 ms
6213 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
7264 : Info  : EVENT: WiFi#Disconnected
16218 : Info  : WIFI : Connecting Linksys attempt #3
16221 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
16340 : Info  : WIFI : Connecting Howard attempt #4
16343 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
20181 : Info  : WIFI : Set WiFi to AP+STA
20281 : Info  : WIFI : Set WiFi to AP+STA
20381 : Info  : WIFI : Set WiFi to AP+STA
20481 : Info  : WIFI : Set WiFi to AP+STA
20581 : Info  : WIFI : Set WiFi to AP+STA
20681 : Info  : WIFI : Set WiFi to AP+STA
20781 : Info  : WIFI : Set WiFi to AP+STA
20881 : Info  : WIFI : Set WiFi to AP+STA
20981 : Info  : WIFI : Set WiFi to AP+STA
21081 : Info  : WIFI : Set WiFi to AP+STA
21181 : Info  : WIFI : Set WiFi to AP+STA
21281 : Info  : WIFI : Set WiFi to AP+STA
21381 : Info  : WIFI : Set WiFi to AP+STA
21481 : Info  : WIFI : Set WiFi to AP+STA
21581 : Info  : WIFI : Set WiFi to AP+STA
21681 : Info  : WIFI : Set WiFi to AP+STA
21781 : Info  : WIFI : Set WiFi to AP+STA
21881 : Info  : WIFI : Set WiFi to AP+STA
21981 : Info  : WIFI : Set WiFi to AP+STA
22081 : Info  : WIFI : Set WiFi to AP+STA
22181 : Info  : WIFI : Set WiFi to AP+STA
22281 : Info  : WIFI : Set WiFi to AP+STA
22381 : Info  : WIFI : Set WiFi to AP+STA
22481 : Info  : WIFI : Set WiFi to AP+STA
22581 : Info  : WIFI : Set WiFi to AP+STA
22681 : Info  : WIFI : Set WiFi to AP+STA
22781 : Info  : WIFI : Set WiFi to AP+STA
22881 : Info  : WIFI : Set WiFi to AP+STAGuru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4008d1eb  PS      : 0x00060630  A0      : 0x8008d898  A1      : 0x3ffaf140  
A2      : 0xfffffff9  A3      : 0x00060623  A4      : 0x00060620  A5      : 0x00000001  
A6      : 0x00060423  A7      : 0x00000000  A8      : 0x3ffb5b1c  A9      : 0x0000cdcd  
A10     : 0x3f41f424  A11     : 0x3ffb877c  A12     : 0x3ffb5a84  A13     : 0x00000000  
A14     : 0x00000001  A15     : 0xfffffd01  SAR     : 0x00000008  EXCCAUSE: 0x0000001c  
EXCVADDR: 0xfffffff9  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000

Backtrace: 0x4008d1eb:0x3ffaf140 0x4008d895:0x3ffaf160 0x40086022:0x3ffaf180 0x40086429:0x3ffaf1a0 0x4000bec7:0x3ffaf1c0 0x4018e75b:0x3ffaf1e0 0x4018e7df:0x3ffaf200 0x4018e827:0x3ffaf220 0x40190516:0x3ffaf240 0x401906d8:0x3ffaf260 0x40189280:0x3ffaf280 0x4008a0b1:0x3ffaf2b0

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U35 : Info  : 

INIT : Booting version: MFD-mega-2020_05_15 (ESP32 SDK v3.2.3-14-gd3e562907)
35 : Info  : INIT : Free RAM:295192
36 : Info  : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
37 : Info  : FS   : Mounting...
63 : Info  : CRC  : No program memory checksum found. Check output of crc2.py
74 : Info  : CRC  : SecuritySettings CRC   ...OK
143 : Info  : INIT : Free RAM:289468
146 : Info  : INIT : I2C
147 : Info  : INIT : SPI Init (without CS)
152 : Info  : MFRC522: Init
153 : Info  : MFRC522: Reset on pin: 25
366 : Info  : MFRC522: Software Version:  = v2.0
424 : Info  : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
425 : Info  : EVENT: System#Wake
550 : Info  : WIFI : Set WiFi to STA
740 : Info  : WIFI  : Start network scan
741 : Info  : WIFI : Connecting Howard attempt #0
744 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
750 : Info  : Webserver: start
763 : Info  : EVENT: System#Boot
771 : Info  : ACT  : NOTIFY,1
774 : Info  : Command: NOTIFY
903 : Info  : WIFI  : Scan finished, found: 1
2185 : Info  : WIFI  : Start network scan
2188 : Info  : WIFI : Connecting Howard attempt #1
2190 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
2202 : Error : WiFi  : Scan failed
2407 : Info  : WIFI : Set WiFi to STA
2519 : Info  : WIFI : Connecting Linksys attempt #2
2521 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
2621 : Info  : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 1 ms
2623 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
2652 : Info  : SYS  : 0.00,0.00,100.00,-1.00
3912 : Info  : EVENT: WiFi#Disconnected
4421 : Info  : WD   : Uptime 0 ConnectFailures 0 FreeMem 225520 WiFiStatus 6
4878 : Info  : EVENT: SYSTEM#Uptime=0.00
5129 : Info  : EVENT: SYSTEM#WiFi=0.00
5492 : Info  : EVENT: SYSTEM#Load=100.00
5981 : Info  : EVENT: SYSTEM#=-1.00

@fmuntean
Copy link
Contributor Author

fmuntean commented Jun 1, 2020

@uzi18: let me know if you need something else from me.
Regarding the power supply stability I have two decoupling caps: one 22uF tantalum (which should suffice) and added one 100uF tantalum close to the board. The power supply is also stable and noise free.
Been using this board in testing for a while now with no issues.

@uzi18
Copy link
Contributor

uzi18 commented Jun 1, 2020

@fmuntean Have used without any additional capacitor with usb connection from computer.
Only difference have changed ssid not password, so this time will try with your hint to change it, will report later. Thanks

@TD-er
Copy link
Member

TD-er commented Jun 1, 2020

On the ESP8266, the WiFi settings needed to be set "non persistent".
If you don't set it to "non persistent", the ESP8266 Arduino implementation does store the WiFi settings in an area on the flash outside of our storage area.
When these are stored there, the ESP8266 does immediately try to reconnect on reboot.

So maybe something similar is also happening here? The system keeps firing "disconnect" events and our sketch reacts to that.

@fmuntean
Copy link
Contributor Author

fmuntean commented Jun 12, 2020

ou don't set it to "non

@TD-er : where we can check that the settings are "non persistent" ?
Also where are the "disconnect" events so I can put some logs in that area?

@TD-er
Copy link
Member

TD-er commented Jun 13, 2020

@TD-er : where we can check that the settings are "non persistent" ?

Well I thought wel set it to non persistent.
But a simple way to test if it may be related to that is to completely erase the flash and/or start from a fresh clean flash storage.

Also where are the "disconnect" events so I can put some logs in that area?

See the ESPEasyWiFi_ProcessEvent.ino file.
The events themselves are dealt with in ESPEasyWiFiEvent.h/.cpp but those are called from callbacks so you should not try to log there. The functions there are only storing data and setting a flag.

@fmuntean
Copy link
Contributor Author

Any update on this issue ?
I just test it with the 20200721 release and still exists.

What i found so far is that if I send the wifiapmode command, from serial connection, it works with no issues until the ap mode gets disabled.

@TD-er
Copy link
Member

TD-er commented Jul 27, 2020

I've changed a lot on the WiFi code, including some parts about the frequent wifi mode changing.
So that part should be fixed (including a crash that could occur with specific logs, which happens to be one of them in that situation you had)
If you're now still seeing crashes, I would like to see your logs.

@fmuntean
Copy link
Contributor Author

fmuntean commented Jul 28, 2020

here are the logs:

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U36 : Info  : 

INIT : Booting version: MFD-mega-2020_07_21 (ESP32 SDK v3.2.3-14-gd3e562907)
37 : Info  : INIT : Free RAM:294940
37 : Info  : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
38 : Info  : FS   : Mounting...
67 : Info  : CRC  : No program memory checksum found. Check output of crc2.py
77 : Info  : CRC  : SecuritySettings CRC   ...OK
143 : Info  : INIT : Free RAM:289256
145 : Info  : INIT : I2C
146 : Info  : INIT : SPI Init (without CS)
160 : Info  : MFRC522: Init
161 : Info  : MFRC522: Reset on pin: 25
374 : Info  : MFRC522: Software Version:  = v2.0
431 : Info  : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
433 : Info  : EVENT: System#Wake
563 : Info  : WIFI : Set WiFi to STA
750 : Info  : WIFI  : Start network scan
2860 : Info  : WIFI : Connecting Howard attempt #1
2862 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Howard
2866 : Info  : Webserver: start
2880 : Info  : EVENT: System#Boot
2888 : Info  : ACT  : NOTIFY,1
2891 : Info  : Command: NOTIFY
2931 : Info  : WIFI  : Scan finished, found: 49
2933 : Info  : WIFI  : Selected: Linksys 00:1E:E5:2D:4C:87 Ch:1 (-62dBm) WPA2/PSK
3480 : Info  : SYS  : 0.00,0.00,100.00,-1.00
4323 : Info  : EVENT: SYSTEM#Uptime=0.00
4475 : Info  : WD   : Uptime 0 ConnectFailures 0 FreeMem 221868 WiFiStatus WL_DISCONNECTED
4502 : Info  : EVENT: SYSTEM#WiFi=0.00
4575 : Info  : EVENT: SYSTEM#Load=100.00
4646 : Info  : EVENT: SYSTEM#=-1.00
12422 : Info  : WIFI : Disconnected! Reason: '(15) 4way handshake timeout' Connected for 9450 ms
12539 : Info  : WIFI : Set WiFi to STA
12651 : Info  : WIFI  : Start network scan
14760 : Info  : WIFI : Connecting Linksys attempt #2
14763 : Info  : WIFI : WiFi.status() = WL_DISCONNECTED  SSID: Linksys
14775 : Info  : WIFI  : Scan finished, found: 44
14777 : Info  : WIFI  : Selected: Linksys 00:1E:E5:2D:4C:87 Ch:1 (-62dBm) WPA2/PSK
14808 : Info  : EVENT: WiFi#Disconnected
20180 : Info  : WIFI : Set WiFi to AP+STA
20280 : Info  : WIFI : Set WiFi to AP+STA
20380 : Info  : WIFI : Set WiFi to AP+STA
20480 : Info  : WIFI : Set WiFi to AP+STA
20580 : Info  : WIFI : Set WiFi to AP+STA
20680 : Info  : WIFI : Set WiFi to AP+STA
20780 : Info  : WIFI : Set WiFi to AP+STA
20880 : Info  : WIFI : Set WiFi to AP+STA
20980 : Info  : WIFI : Set WiFi to AP+STA
21080 : Info  : WIFI : Set WiFi to AP+STA
21180 : Info  : WIFI : Set WiFi to AP+STA
21280 : Info  : WIFI : Set WiFi to AP+STA
21380 : Info  : WIFI : Set WiFi to AP+STA
21480 : Info  : WIFI : Set WiFi to AP+STA
21580 : Info  : WIFI : Set WiFi to AP+STA
21680 : Info  : WIFI : Set WiFi to AP+STA
21780 : Info  : WIFI : Set WiFi to AP+STA
21880 : Info  : WIFI : Set WiFi to AP+STA
21980 : Info  : WIFI : Set WiFi to AP+STA
22080 : Info  : WIFI : Set WiFi to AP+STAGuru Meditation Error: Core  1 panic'ed (Unhandled debug exception)
Debug exception reason: Stack canary watchpoint triggered (loopTask) 
Core 1 register dump:
PC      : 0x4008cad4  PS      : 0x00060836  A0      : 0x40085c30  A1      : 0x3ffb0040  
A2      : 0x3ffb6014  A3      : 0x00000000  A4      : 0x3ffb605c  A5      : 0x00000000  
A6      : 0x00000001  A7      : 0x00000001  A8      : 0x80089edc  A9      : 0x3ffb00e0
A10     : 0x00000001  A11     : 0x3ffc6570  A12     : 0x3ffc6570  A13     : 0x00000001
A14     : 0x00060820  A15     : 0x00000000  SAR     : 0x00000010  EXCCAUSE: 0x00000001  
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff

Backtrace: 0x4008cad4:0x3ffb0040 0x40085c2d:0x3ffb0140 0x40160132:0x3ffb0160 0x40155663:0x3ffb0180 0x400d708a:0x3ffb01b0 0x4011f6f5:0x3ffb0230 0x4011dc4b:0x3ffb0260 0x400f6401:0x3ffb0280 0x400f6611:0x3ffb02e0 0x400f666a:0x3ffb0310 0x4011e585:0x3ffb0330 0x4011e72b:0x3ffb0380 0x4011f78f:0x3ffb03a0 0x4011dc4b:0x3ffb03d0 0x400f6401:0x3ffb03f0 0x400f6611:0x3ffb0450 0x400f666a:0x3ffb0480 0x4011e585:0x3ffb04a0 0x4011e72b:0x3ffb04f0 0x4011f78f:0x3ffb0510 0x4011dc4b:0x3ffb0540 0x400f6401:0x3ffb0560 0x400f6611:0x3ffb05c0 0x400f666a:0x3ffb05f0 0x4011e585:0x3ffb0610 0x4011e72b:0x3ffb0660 0x4011f78f:0x3ffb0680 0x4011dc4b:0x3ffb06b0 0x400f6401:0x3ffb06d0 0x400f6611:0x3ffb0730 0x400f666a:0x3ffb0760 0x4011e585:0x3ffb0780 0x4011e72b:0x3ffb07d0 0x4011f78f:0x3ffb07f0 0x4011dc4b:0x3ffb0820 0x400f6401:0x3ffb0840 0x400f6611:0x3ffb08a0 0x400f666a:0x3ffb08d0 0x4011e585:0x3ffb08f0 0x4011e72b:0x3ffb0940 0x4011f78f:0x3ffb0960 0x4011dc4b:0x3ffb0990 0x400f6401:0x3ffb09b0 0x400f6611:0x3ffb0a10 0x400f666a:0x3ffb0a40 0x4011e585:0x3ffb0a60 0x4011e72b:0x3ffb0ab0 0x4011f78f:0x3ffb0ad0 0x4011dc4b:0x3ffb0b00 0x400f6401:0x3ffb0b20 0x400f6611:0x3ffb0b80

Rebooting...
ets Jun  8 2016 00:22:57

@fmuntean
Copy link
Contributor Author

Before was failing after 4 attempts now it fails after two attempts only. So from this point of view is worse than before.
My expectation is to try few times then start in AP mode like ESP8266.

@TD-er
Copy link
Member

TD-er commented Jul 28, 2020

What build is this?
We don't have an ESP32 build with 16 plugins, do we?
Are you sure you're trying with the nightly builds?

@fmuntean
Copy link
Contributor Author

this is a build with only the plugins I use enabled.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 2, 2020

just got the lastest from mega branch and uploaded to my board.
Still getting the same problem.
here are the logs:

Rebooting...
ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U36 : Info :

INIT : Booting version: MFD-mega-2020_07_21 (ESP32 SDK v3.2.3-14-gd3e562907)
37 : Info : INIT : Free RAM:294924
37 : Info : INIT : Cold Boot - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
38 : Info : FS : Mounting...
76 : Info : CRC : SecuritySettings CRC ...OK
142 : Info : INIT : Free RAM:289412
144 : Info : INIT : I2C
145 : Info : INIT : SPI Init (without CS)
159 : Info : MFRC522: Init
160 : Info : MFRC522: Reset on pin: 25
373 : Info : MFRC522: Software Version: = v2.0
430 : Info : INFO : Plugins: 16 [Normal] (ESP32 SDK v3.2.3-14-gd3e562907)
432 : Info : EVENT: System#Wake
560 : Info : WIFI : Set WiFi to STA
748 : Info : WIFI : Start network scan
3058 : Info : WIFI : Connecting Howard attempt #1
3061 : Info : WIFI : WiFi.status() = WL_DISCONNECTED SSID: Howard
3065 : Info : Webserver: start
3079 : Info : EVENT: System#Boot
3087 : Info : ACT : NOTIFY,1
3090 : Info : Command: NOTIFY
3130 : Info : WIFI : Scan finished, found: 60
3132 : Info : WIFI : Selected: Linksys 00:1E:E5:2D:4C:87 Ch:1 (-61dBm) WPA2/PSK
3680 : Info : SYS : 0.00,0.00,100.00,-1.00
4523 : Info : EVENT: SYSTEM#Uptime=0.00
4675 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 221096 WiFiStatus WL_DISCONNECTED
4703 : Info : EVENT: SYSTEM#WiFi=0.00
4775 : Info : EVENT: SYSTEM#Load=100.00
4847 : Info : EVENT: SYSTEM#=-1.00
12606 : Info : WIFI : Disconnected! Reason: '(15) 4way handshake timeout' Connected for 9441 ms
12723 : Info : WIFI : Set WiFi to STA
12836 : Info : WIFI : Start network scan
15546 : Info : WIFI : Connecting Linksys attempt #2
15548 : Info : WIFI : WiFi.status() = WL_DISCONNECTED SSID: Linksys
15560 : Info : WIFI : Scan finished, found: 54
15562 : Info : WIFI : Selected: Linksys 00:1E:E5:2D:4C:87 Ch:1 (-59dBm) WPA2/PSK
15591 : Info : EVENT: WiFi#Disconnected
20188 : Info : WIFI : Set WiFi to AP+STA
20288 : Info : WIFI : Set WiFi to AP+STA
20388 : Info : WIFI : Set WiFi to AP+STA
20488 : Info : WIFI : Set WiFi to AP+STA
20588 : Info : WIFI : Set WiFi to AP+STA
20688 : Info : WIFI : Set WiFi to AP+STA
20788 : Info : WIFI : Set WiFi to AP+STA
20888 : Info : WIFI : Set WiFi to AP+STA
20988 : Info : WIFI : Set WiFi to AP+STA
21088 : Info : WIFI : Set WiFi to AP+STA
21188 : Info : WIFI : Set WiFi to AP+STA
21288 : Info : WIFI : Set WiFi to AP+STA
21388 : Info : WIFI : Set WiFi to AP+STA
21488 : Info : WIFI : Set WiFi to AP+STA
21588 : Info : WIFI : Set WiFi to AP+STA
21688 : Info : WIFI : Set WiFi to AP+STA
21788 : Info : WIFI : Set WiFi to AP+STA
21888 : Info : WIFI : Set WiFi to AP+STA
21988 : Info : WIFI : Set WiFi to AP+STA
22088 : Info : WIFI : Set WiFi to AP+STAGuru Meditation Error: Core 1 panic'ed (Unhandled debug exception)
Debug exception reason: Stack canary watchpoint triggered (loopTask)
Core 1 register dump:
PC : 0x40089d93 PS : 0x00060036 A0 : 0x80089f38 A1 : 0x3ffb0070
A2 : 0x3ffb5c9c A3 : 0x00000000 A4 : 0xffffffff A5 : 0x00000000
A6 : 0x00000000 A7 : 0x00000000 A8 : 0x8008af45 A9 : 0x3ffb0080
A10 : 0x00000003 A11 : 0x00060023 A12 : 0x00060020 A13 : 0x0000ff00
A14 : 0x00ff0000 A15 : 0xff000000 SAR : 0x00000010 EXCCAUSE: 0x00000001
EXCVADDR: 0x00000000 LBEG : 0x4000c28c LEND : 0x4000c296 LCOUNT : 0x00000000

Backtrace: 0x40089d93:0x3ffb0070 0x40089f35:0x3ffb00b0 0x40082c69:0x3ffb00d0 0x40154647:0x3ffb00f0 0x4015464f:0x3ffb0110 0x40154a17:0x3ffb0130 0x400d60b9:0x3ffb0160 0x400d704d:0x3ffb0190 0x4011f551:0x3ffb0210 0x4011daa7:0x3ffb0240 0x400f63f1:0x3ffb0260 0x400f6601:0x3ffb02c0 0x400f665a:0x3ffb02f0 0x4011e3e1:0x3ffb0310 0x4011e587:0x3ffb0360 0x4011f5eb:0x3ffb0380 0x4011daa7:0x3ffb03b0 0x400f63f1:0x3ffb03d0 0x400f6601:0x3ffb0430 0x400f665a:0x3ffb0460 0x4011e3e1:0x3ffb0480 0x4011e587:0x3ffb04d0 0x4011f5eb:0x3ffb04f0 0x4011daa7:0x3ffb0520 0x400f63f1:0x3ffb0540 0x400f6601:0x3ffb05a0 0x400f665a:0x3ffb05d0 0x4011e3e1:0x3ffb05f0 0x4011e587:0x3ffb0640 0x4011f5eb:0x3ffb0660 0x4011daa7:0x3ffb0690 0x400f63f1:0x3ffb06b0 0x400f6601:0x3ffb0710 0x400f665a:0x3ffb0740 0x4011e3e1:0x3ffb0760 0x4011e587:0x3ffb07b0 0x4011f5eb:0x3ffb07d0 0x4011daa7:0x3ffb0800 0x400f63f1:0x3ffb0820 0x400f6601:0x3ffb0880 0x400f665a:0x3ffb08b0 0x4011e3e1:0x3ffb08d0 0x4011e587:0x3ffb0920 0x4011f5eb:0x3ffb0940 0x4011daa7:0x3ffb0970 0x400f63f1:0x3ffb0990 0x400f6601:0x3ffb09f0 0x400f665a:0x3ffb0a20 0x4011e3e1:0x3ffb0a40 0x4011e587:0x3ffb0a90 0x4011f5eb:0x3ffb0ab0
#0 0x40089d93:0x3ffb0070 in xQueueGenericReceive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/queue.c:1996
#1 0x40089f35:0x3ffb00b0 in xQueueTakeMutexRecursive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/queue.c:1996
#2 0x40082c69:0x3ffb00d0 in mutex_lock_wrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/esp_adapter.c:300
#3 0x40154647:0x3ffb00f0 in wifi_api_lock at ??:?
#4 0x4015464f:0x3ffb0110 in wifi_init_completed at ??:?
#5 0x40154a17:0x3ffb0130 in esp_wifi_get_mode at ??:?
#6 0x400d60b9:0x3ffb0160 in WiFiGenericClass::getMode() at c:\users\fmunt.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\5.2.0/functional:2114
#7 0x400d704d:0x3ffb0190 in WiFiSTAClass::RSSI() at C:\Users\fmunt.platformio\packages\framework-arduinoespressif32\libraries\WiFi\src/WiFiSTA.cpp:718
#8 0x4011f551:0x3ffb0210 in WiFiConnected() at src/ESPEasyWifi.cpp:119
#9 0x4011daa7:0x3ffb0240 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#10 0x400f63f1:0x3ffb0260 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#11 0x400f6601:0x3ffb02c0 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#12 0x400f665a:0x3ffb02f0 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#13 0x4011e3e1:0x3ffb0310 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#14 0x4011e587:0x3ffb0360 in setAP(bool) at src/ESPEasyWifi.cpp:676
#15 0x4011f5eb:0x3ffb0380 in WiFiConnected() at src/ESPEasyWifi.cpp:141
#16 0x4011daa7:0x3ffb03b0 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#17 0x400f63f1:0x3ffb03d0 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#18 0x400f6601:0x3ffb0430 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#19 0x400f665a:0x3ffb0460 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#20 0x4011e3e1:0x3ffb0480 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#21 0x4011e587:0x3ffb04d0 in setAP(bool) at src/ESPEasyWifi.cpp:676
#22 0x4011f5eb:0x3ffb04f0 in WiFiConnected() at src/ESPEasyWifi.cpp:141
#23 0x4011daa7:0x3ffb0520 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#24 0x400f63f1:0x3ffb0540 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#25 0x400f6601:0x3ffb05a0 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#26 0x400f665a:0x3ffb05d0 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#27 0x4011e3e1:0x3ffb05f0 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#28 0x4011e587:0x3ffb0640 in setAP(bool) at src/ESPEasyWifi.cpp:676
#29 0x4011f5eb:0x3ffb0660 in WiFiConnected() at src/ESPEasyWifi.cpp:141
#30 0x4011daa7:0x3ffb0690 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#31 0x400f63f1:0x3ffb06b0 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#32 0x400f6601:0x3ffb0710 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#33 0x400f665a:0x3ffb0740 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#34 0x4011e3e1:0x3ffb0760 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#35 0x4011e587:0x3ffb07b0 in setAP(bool) at src/ESPEasyWifi.cpp:676
#36 0x4011f5eb:0x3ffb07d0 in WiFiConnected() at src/ESPEasyWifi.cpp:141
#37 0x4011daa7:0x3ffb0800 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#38 0x400f63f1:0x3ffb0820 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#39 0x400f6601:0x3ffb0880 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#40 0x400f665a:0x3ffb08b0 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#41 0x4011e3e1:0x3ffb08d0 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#42 0x4011e587:0x3ffb0920 in setAP(bool) at src/ESPEasyWifi.cpp:676
#43 0x4011f5eb:0x3ffb0940 in WiFiConnected() at src/ESPEasyWifi.cpp:141
#44 0x4011daa7:0x3ffb0970 in NetworkConnected() at src/ESPEasyNetwork.cpp:38
#45 0x400f63f1:0x3ffb0990 in syslog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#46 0x400f6601:0x3ffb09f0 in addToLog(unsigned char, char const*) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#47 0x400f665a:0x3ffb0a20 in addToLog(unsigned char, String const&) at D:/git/HomeAutomation/ESPEasy/src/Misc.ino:2584
#48 0x4011e3e1:0x3ffb0a40 in setWifiMode(wifi_mode_t) at src/ESPEasyWifi.cpp:676
#49 0x4011e587:0x3ffb0a90 in setAP(bool) at src/ESPEasyWifi.cpp:676
#50 0x4011f5eb:0x3ffb0ab0 in WiFiConnected() at src/ESPEasyWifi.cpp:141

Rebooting...
ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_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:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:9720
ho 0 tail 12 room 4
load:0x40080400,len:6352
entry 0x400806b8
�U36 : Info :

@TD-er
Copy link
Member

TD-er commented Aug 2, 2020

Do you use syslog?

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 2, 2020

yes.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 2, 2020

also the latest build seems to be even more unstable. It does reboot even when I start wifiapmode and connect to the page

@TD-er
Copy link
Member

TD-er commented Aug 2, 2020

Try to disable syslog and see if stability improves.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 2, 2020

just did that and is working.
After two tries it does start the AP and even if I don't connect ot it it keeps the board running.
So it seems to be related to the syslog being enable.

@TD-er
Copy link
Member

TD-er commented Aug 3, 2020

Yep
Problem is somewhat also present in ESP8266 builds.
What happens is that buffers overflow with UDP packets.
This does not happen with TCP packets, even when the network state is interpreted correctly.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

but the code should not send if not connected as there is a call to NetworkConneted()

@TD-er
Copy link
Member

TD-er commented Aug 3, 2020

but the code should not send if not connected as there is a call to NetworkConneted()

Yep, but then you assume the status of the core lib is correct... which isn't always the case :(

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

Is there anything we can do about ?

@TD-er
Copy link
Member

TD-er commented Aug 3, 2020

Is there anything we can do about ?

If there is, please let me know.
I'm hunting down bugs like these for the last 2 years.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

So it looks that sending any syslog/udp message before the wifi connects will trigger this overflow and reboot.
Do you think the issue is in the Arduino Lib or the ESP driver ?

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

The way I see it is that two statuses ( WL_NO_SSID_AVAIL = 1,WL_SCAN_COMPLETED = 2)arriving at the wrong time could result in (WL_CONNECTED = 3):
void WiFiSTAClass::_setStatus(wl_status_t status)
{
.....
xEventGroupClearBits(_sta_status_group, 0x00FFFFFF);
xEventGroupSetBits(_sta_status_group, status);
}

The ClearBits and SetBits are two atomic operations by themselves but in between we can have the following:

Thread1=>ClearBits(..)
Thread2 =>ClearBits(..)
Thread1 => SetBits(b01);
Thread2 => SetBits(b10);

Resulting in the status = b11 aka 3 aka WL_CONNECTED

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

After some more investigation I think the NetworkConnected() inside the syslog(..) method is too heavy.
It generates other logs thus entering circular calls back to the syslog

@TD-er
Copy link
Member

TD-er commented Aug 3, 2020

After some more investigation I think the NetworkConnected() inside the syslog(..) method is too heavy.
It generates other logs thus entering circular calls back to the syslog

Yep and that's where I'm working on.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 3, 2020

I just changed it to WiFi.isconnected() for testing purposes and the board is stable now

@TD-er
Copy link
Member

TD-er commented Aug 3, 2020

Problem is with ESP8226, where the return value of that function is not reliable.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 4, 2020

Problem is with ESP8226, where the return value of that function is not reliable.

do we know if it is reliable for ESP32 ?
also do we know why is not reliable for ESP8266 ?

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 4, 2020

Found your ticket for ESP8266 wifi status issue: esp8266/Arduino#7432 (so it seems that one is in the low level SDK driver)

@TD-er
Copy link
Member

TD-er commented Aug 4, 2020

I know for sure it is not reliable on ESP8266 and I hope it is more reliable now on ESP32 since my recent changes of the past 2 months.

I for sure want to have it in a more generic function, so we have a single function both supporting WiFi and ethernet.

@fmuntean
Copy link
Contributor Author

fmuntean commented Aug 4, 2020

The problem with the NetworkConnected() is that it not only check the connection but tries to set AP mode and reset wifi thus triggering other addToLog() thus calling back the syslog and here we go in circles.
Maybe splitting this method in two parts: one for checking only and one for fixing.
The one for fixing can be called from somewhere else once a flag is set by the first part.

Or we can hope they fix the isConnected() for ESP32.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2021

This has been fixed a while ago, as far as I know.
So will close it now. Please let me know if it isn't fixed.

@TD-er TD-er closed this as completed Aug 12, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Category: Stabiliy Things that work, but not as long as desired Category: Wifi Related to the network connectivity Type: Bug Considered a bug
Projects
None yet
Development

No branches or pull requests

4 participants