wifi disconnects randomly

NRollo
Posts: 21
Joined: Fri Jan 22, 2021 1:04 pm

wifi disconnects randomly

Postby NRollo » Tue Jan 04, 2022 11:39 pm

After a successful wifi connection to my AP my ESP32 webserver system disconnects randomly and stops working. I enabled the wifi debug output and got these two wifi messages when the disconnect occur:

Code: Select all

D (1154407) wifi:obss scan is disabled
D (1154407) wifi:start obss scan: obss scan is stopped
The below is the complete log from when the system initializes to the system "crashes". At the end my heap hooks kicks in and halts the system.
The system is based on esp-idf 4.3.1 running on a ESP32-WROOM module.
Has anyone seen the likes?

Code: Select all

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:DIO, clock div:2
load:0x3fff0030,len:7188
load:0x40078000,len:14308
load:0x40080400,len:3716
entry 0x40080680
I (27) boot: ESP-IDF 4.3.1 2nd stage bootloader
I (27) boot: compile time 15:05:32
I (27) boot: chip revision: 1
I (30) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (37) boot.esp32: SPI Speed      : 40MHz
I (41) boot.esp32: SPI Mode       : DIO
I (46) boot.esp32: SPI Flash Size : 8MB
I (50) boot: Enabling RNG early entropy source...
I (56) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (67) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (74) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (82) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (89) boot:  3 app0             OTA app          00 10 00010000 00180000
I (97) boot:  4 app1             OTA app          00 11 00190000 00180000
I (104) boot: End of partition table
I (108) boot_comm: chip revision: 1, min. application chip revision: 0
I (115) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=27f6ch (163692) map
I (183) esp_image: segment 1: paddr=00037f94 vaddr=3ffb0000 size=04518h ( 17688) load
I (190) esp_image: segment 2: paddr=0003c4b4 vaddr=40080000 size=03b64h ( 15204) load
I (197) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a861ch (689692) map
I (447) esp_image: segment 4: paddr=000e8644 vaddr=40083b64 size=14774h ( 83828) load
I (482) esp_image: segment 5: paddr=000fcdc0 vaddr=400c0000 size=00064h (   100) load
I (482) esp_image: segment 6: paddr=000fce2c vaddr=50000000 size=00010h (    16) load
I (499) boot: Loaded app from partition at offset 0x10000
I (499) boot: Disabling RNG early entropy source...
I (512) cpu_start: Pro cpu up.
I (513) cpu_start: Starting app cpu, entry point is 0x40083318
I (0) cpu_start: App cpu up.
I (527) cpu_start: Pro cpu start user code
I (527) cpu_start: cpu freq: 240000000
I (527) cpu_start: Application information:
I (531) cpu_start: Project name:     nanoBrewer
I (537) cpu_start: App version:      0.8-16-g2be9c21-dirty
I (543) cpu_start: Compile time:     Jan  4 2022 20:31:52
I (549) cpu_start: ELF file SHA256:  95b41521c521e582...
I (555) cpu_start: ESP-IDF:          4.3.1
I (560) heap_init: Initializing. RAM available for dynamic allocation:
I (567) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (573) heap_init: At 3FFB8740 len 000278C0 (158 KiB): DRAM
I (579) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (585) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (592) heap_init: At 400982D8 len 00007D28 (31 KiB): IRAM
I (599) spi_flash: detected chip: gd
I (602) spi_flash: flash io: dio
I (608) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (617) Main: Main running on: 0

I (617) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (627) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (637) gpio: GPIO[26]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (647) gpio: GPIO[27]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (677) SDcard: Initializing SD card using SPI peripheral
I (677) gpio: GPIO[5]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (677) sdspi_transaction: cmd=52, R1 response: command not supported
I (727) sdspi_transaction: cmd=5, R1 response: command not supported
Name: SDU1
Type: SDHC/SDXC
Speed: 13 MHz
Size: 61503MB
I (937) wifi:wifi driver task: 3ffce3ac, prio:23, stack:6656, core=0
I (937) system_api: Base MAC address is not set
I (937) system_api: read default base MAC address from EFUSE
I (947) wifi:wifi firmware version: 88c8747
I (947) wifi:wifi certification version: v7.0
I (947) wifi:config NVS flash: enabled
I (957) wifi:config nano formating: disabled
I (957) wifi:Init data frame dynamic rx buffer num: 32
I (957) wifi:Init management frame dynamic rx buffer num: 32
I (967) wifi:Init management short buffer num: 32
I (967) wifi:Init dynamic tx buffer num: 32
I (977) wifi:Init static rx buffer size: 1600
I (977) wifi:Init static rx buffer num: 10
I (987) wifi:Init dynamic rx buffer num: 32
I (987) wifi_init: rx ba win: 6
I (987) wifi_init: tcpip mbox: 32
I (997) wifi_init: udp mbox: 6
I (997) wifi_init: tcp mbox: 6
I (1007) wifi_init: tcp tx win: 5744
I (1007) wifi_init: tcp rx win: 5744
I (1007) wifi_init: tcp mss: 1440
I (1017) wifi_init: WiFi IRAM OP enabled
I (1017) wifi_init: WiFi RX IRAM OP enabled
D (1027) wifi:clear blacklist
I (1027) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
D (1167) wifi:filter: set rx policy=0
I (1177) wifi:mode : sta (84:0d:8e:dc:11:10)
I (1177) wifi:enable tsf
D (1177) wifi:filter: set rx policy=1
D (1177) wifi:connect status 0 -> 0
I (1177) wifi:Set ps type: 0

D (1177) wifi:Start wifi connect
D (1187) wifi:connect status 0 -> 0
D (1187) wifi:connect chan=0
D (1187) wifi:first chan=6
D (1187) wifi:connect status 0 -> 1
D (1197) wifi:filter: set rx policy=3
D (1197) wifi:clear scan ap list
D (1197) wifi:start scan: type=0x50f, priority=2, cb=0x40147148, arg=0x0, ss_state=0x1, time=30099, index=0
D (1207) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
I (1217) wifi station: wifi_init_sta finished.
D (1227) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (1227) wifi:profile match: ss_state=0x7
D (1227) wifi:scan end: arg=0x0, status=0, ss_state=0x7
D (1237) wifi:find first mathched ssid, scan done
D (1237) wifi:filter: set rx policy=4
D (1237) wifi:first chan=1
D (1247) wifi:handoff_cb: status=0
D (1247) wifi:ap found, mac=fc:34:97:48:38:51
D (1247) wifi:new_bss=0x3ffb7698, cur_bss=0x0, new_chan=<6,0>, cur_chan=1
D (1257) wifi:filter: set rx policy=5
I (1257) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
D (1267) wifi:connect_op: status=0, auth=5, cipher=3
D (1277) wifi:auth mode is not none
D (1277) wifi:connect_bss: auth=1, reconnect=0
I (1277) wifi:state: init -> auth (b0)
D (1287) wifi:start 1s AUTH timer
D (1287) wifi:clear scan ap list
D (1297) wifi:recv auth: seq=2, status=0
I (1297) wifi:state: auth -> assoc (0)
D (1297) wifi:restart connect 1s timer for assoc
D (1307) wifi:recv assoc: type=0x10
D (1307) wifi:filter: set rx policy=6
I (1307) wifi:state: assoc -> run (10)
D (1307) wifi:start 10s connect timer for 4 way handshake
I (1327) wifi:connected with Mesh2020, aid = 22, channel 6, BW20, bssid = fc:34:97:48:38:51
I (1327) wifi:security: WPA2-PSK, phy: bgn, rssi: -70
D (1337) wifi:remove all except fc:34:97:48:38:51 from rc list
D (1337) wifi:clear blacklist
D (1347) wifi:filter: set rx policy=7
I (1347) wifi:pm start, type: 0

D (1347) wifi:Send sta connected event
D (1347) wifi:connect status 1 -> 5
D (1357) wifi:obss scan is disabled
D (1357) wifi:start obss scan: obss scan is stopped
I (1367) wifi station: Connected to the AP
I (1367) esp_netif_handlers: sta ip: 10.0.0.231, mask: 255.255.255.0, gw: 10.0.0.1
1970-01-01 00:00:00 2 mongoose.c:3329:mg_listen  I (1377) wifi station: Got ip: 10.0.0.231
1 accepting on 0.0.0.0:80 (port 80)I (1387) wifi station: Got Gateway: 10.0.0.1
I (1397) wifi:
AP's beacon interval = 102400 us, DTIM period = 1I (1397) wifi station: Got Submask: 255.255.255.0

D (1407) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (1407) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (1417) wifi:update trc
I (1397) wifi station: connected to ap SSID:Mesh2020
W (1457) wifi:<ba-add>idx:0 (ifx:0, fc:34:97:48:38:51), tid:0, ssn:0, winSize:64
D (1154407) wifi:obss scan is disabled
D (1154407) wifi:start obss scan: obss scan is stopped

I (2089067) SysSurveillance: WARNING: free Heap size went below 30K bytes (min heap: 17536 bytes) - current free Heap: 85780
I (2090677) SysSurveillance: heap_caps_malloc failed to allocate 1402 bytes of Heap with Caps: 0x0000080c - Current free Heap size: 9424

WiFive
Posts: 3529
Joined: Tue Dec 01, 2015 7:35 am

Re: wifi disconnects randomly

Postby WiFive » Wed Jan 05, 2022 4:13 am

Nothing happens in the 15+ minutes between the timestamps?

NRollo
Posts: 21
Joined: Fri Jan 22, 2021 1:04 pm

Re: wifi disconnects randomly

Postby NRollo » Wed Jan 05, 2022 8:57 am

@WiFive - at least nothing that gives any log output. The webserver was supposed to be running but that is dead silent. But something seems to be happening as the 'SysSurveillance' task seems to be running.

I have always wondered about what this wifi warning meant:

Code: Select all

W (1457) wifi:<ba-add>idx:0 (ifx:0, fc:34:97:48:38:51), tid:0, ssn:0, winSize:64
It also seems to be random but not always ending in a crash. Do you know the meaning of this wifi warning?

NRollo
Posts: 21
Joined: Fri Jan 22, 2021 1:04 pm

Re: wifi disconnects randomly

Postby NRollo » Mon Jan 10, 2022 2:48 pm

After debugging this for days now I turned to my ISP, believe it or not he found some issues with my wireless router :( . Now everything work as expected with no random disconnect on the ESP32. ;)
That just goes to shows you, it's not always a SW issue - HW has issues too. 8-)

Who is online

Users browsing this forum: Bing [Bot] and 56 guests