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

wifi: bcn_timout,ap_probe_send_start (IDFGH-83) #1021

Closed
jasslo opened this issue Sep 20, 2017 · 33 comments
Closed

wifi: bcn_timout,ap_probe_send_start (IDFGH-83) #1021

jasslo opened this issue Sep 20, 2017 · 33 comments

Comments

@jasslo
Copy link

jasslo commented Sep 20, 2017

Hi,
I have on my ESP32 simple web server, which get data from esp8266 thru get requests and display it on web page. In future ESP32 will send this data to thingspeak or something like that. Everything works fine, but after few minutes it crash and display on monitor:

I (1009053) wifi: bcn_timout,ap_probe_send_start
I (1009553) wifi: bcn_timout,ap_probe_send_start
I (1010053) wifi: bcn_timout,ap_probe_send_start
I (1010553) wifi: bcn_timout,ap_probe_send_start
I (1011053) wifi: bcn_timout,ap_probe_send_start
I (1011553) wifi: bcn_timout,ap_probe_send_start
I (1012053) wifi: bcn_timout,ap_probe_send_start
I (1012553) wifi: bcn_timout,ap_probe_send_start
I (1013053) wifi: bcn_timout,ap_probe_send_start
I (1013553) wifi: bcn_timout,ap_probe_send_start
I (1014053) wifi: bcn_timout,ap_probe_send_start
I (1014563) wifi: bcn_timout,ap_probe_send_start
I (1015063) wifi: bcn_timout,ap_probe_send_start
I (1015563) wifi: bcn_timout,ap_probe_send_start
I (1016063) wifi: bcn_timout,ap_probe_send_start
I (1016563) wifi: bcn_timout,ap_probe_send_start
I (1017063) wifi: bcn_timout,ap_probe_send_start
I (1017563) wifi: bcn_timout,ap_probe_send_start
I (1018063) wifi: bcn_timout,ap_probe_send_start
I (1018563) wifi: bcn_timout,ap_probe_send_start
I (1019063) wifi: bcn_timout,ap_probe_send_start
I (1019563) wifi: bcn_timout,ap_probe_send_start
I (1020063) wifi: bcn_timout,ap_probe_send_start
I (1020563) wifi: bcn_timout,ap_probe_send_start
I (1021063) wifi: bcn_timout,ap_probe_send_start
I (1021573) wifi: bcn_timout,ap_probe_send_start
I (1022073) wifi: bcn_timout,ap_probe_send_start
I (1022573) wifi: bcn_timout,ap_probe_send_start
I (1023073) wifi: bcn_timout,ap_probe_send_start
I (1023573) wifi: bcn_timout,ap_probe_send_start
I (1024073) wifi: bcn_timout,ap_probe_send_start
W (1024333) wifi: inactive timer: now=f70b786 last_rx_time=ad73eb97 diff=50457
I (1024333) wifi: station: 00:c2:c6:0e:5f:79 leave, AID = 1
I (1024333) wifi: n:11 0, o:11 0, ap:11 2, sta:11 0, prof:11
I (1024333) app_main: station:00:c2:c6:0e:5f:79leave,AID=1

I (1024573) wifi: bcn_timout,ap_probe_send_start
I (1025073) wifi: bcn_timout,ap_probe_send_start
I (1025573) wifi: bcn_timout,ap_probe_send_start
I (1026073) wifi: bcn_timout,ap_probe_send_start
I (1026573) wifi: bcn_timout,ap_probe_send_start
I (1027073) wifi: bcn_timout,ap_probe_send_start
I (1027573) wifi: bcn_timout,ap_probe_send_start
I (1028073) wifi: bcn_timout,ap_probe_send_start
I (1028573) wifi: bcn_timout,ap_probe_send_start
I (1029073) wifi: bcn_timout,ap_probe_send_start
I (1029583) wifi: bcn_timout,ap_probe_send_start
I (1030083) wifi: bcn_timout,ap_probe_send_start
I (1030583) wifi: bcn_timout,ap_probe_send_start
I (1031083) wifi: bcn_timout,ap_probe_send_start
I (1031583) wifi: bcn_timout,ap_probe_send_start
I (1032083) wifi: bcn_timout,ap_probe_send_start
I (1032583) wifi: bcn_timout,ap_probe_send_start
I (1033083) wifi: bcn_timout,ap_probe_send_start
I (1033583) wifi: bcn_timout,ap_probe_send_start
I (1034083) wifi: bcn_timout,ap_probe_send_start
I (1034583) wifi: bcn_timout,ap_probe_send_start
I (1035083) wifi: bcn_timout,ap_probe_send_start
I (1035583) wifi: bcn_timout,ap_probe_send_start
I (1036083) wifi: bcn_timout,ap_probe_send_start
I (1036583) wifi: bcn_timout,ap_probe_send_start
I (1037093) wifi: bcn_timout,ap_probe_send_start
I (1037593) wifi: bcn_timout,ap_probe_send_start
I (1038093) wifi: bcn_timout,ap_probe_send_start
I (1038593) wifi: bcn_timout,ap_probe_send_start
I (1039093) wifi: bcn_timout,ap_probe_send_start
I (1039593) wifi: bcn_timout,ap_probe_send_start
I (1040093) wifi: bcn_timout,ap_probe_send_start
I (1040593) wifi: bcn_timout,ap_probe_send_start
I (1041093) wifi: bcn_timout,ap_probe_send_start
I (1041593) wifi: bcn_timout,ap_probe_send_start
I (1042093) wifi: bcn_timout,ap_probe_send_start
I (1042593) wifi: bcn_timout,ap_probe_send_start
I (1043093) wifi: bcn_timout,ap_probe_send_start
I (1043593) wifi: bcn_timout,ap_probe_send_start
I (1044093) wifi: bcn_timout,ap_probe_send_start
I (1044603) wifi: bcn_timout,ap_probe_send_start

This information will be displaying over and over.
I must mention that in the beginning wifi is in AP mode and we can configure sta ssid and password and then wifi is switched to ap+sta mode.
Someone maybe have idea what is wrong ?
Thanks in advance.

@jakkra
Copy link

jakkra commented Sep 21, 2017

Possibly related to #974

@FayeY FayeY changed the title wifi: bcn_timout,ap_probe_send_start [TW#15680] wifi: bcn_timout,ap_probe_send_start Oct 3, 2017
@DigKleppe
Copy link

Any news yet?
I am facing the same issue. Also see my post https://esp32.com/viewtopic.php?f=2&t=3522
After 2615 messages:
2613
2614
2615
I (59562) wifi: bcn_timout,ap_probe_send_start
I (62062) wifi: ap_probe_send over, resett wifi status to disassoc
I (62062) wifi: state: run -> init (1)
I (62062) wifi: pm stop, total sleep time: 0/57061570

I (62062) wifi: n:6 0, o:6 0, ap:255 255, sta:6 0, prof:1
D (62072) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:Klepnet, ssid_len:7, bssid:fc:c8:97:8b:bc:ba, reason:200
V (62082) event: enter default callback
D (62092) tcpip_adapter: check: local, if=0 fn=0x40116520

D (62092) tcpip_adapter: if0 start ip lost tmr: enter
D (62092) tcpip_adapter: if0 start ip lost tmr: interval=120
D (62102) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (62112) tcpip_adapter: check: remote, if=0 fn=0x40116520

V (62112) event: exit default callback
D (64522) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:Klepnet, ssid_len:7, bssid:00:00:00:00:00:00, reason:201
V (64522) event: enter default callback
D (64522) tcpip_adapter: check: local, if=0 fn=0x40116520

And so on.

Also reconnect does not work

@ricksondpenha
Copy link

Yes i get this error too!, I use aws iot mqtt pub sub and a tcp server, when too many messages are sent, wifi timeout and refuses to connect again, tried many things like disconnecting and connecting again, but only way is to restart the esp module. Any workaround for this?

@0BackDoor1
Copy link

Hi,
I'm facing same issue, any news about it?

I (10030333) wifi: bcn_timout,ap_probe_send_start
I (10032837) wifi: ap_probe_send over, resett wifi status to disassoc
I (10032838) wifi: state: run -> init (1)
I (10032840) wifi: pm stop, total sleep time: 0/1437653599
I (10032840) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1
D (10032849) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:abcdefg Guest, ssid_len:13, bssid:e0:b7:e5:b6:b7:bf, reason:200
D (10032863) tcpip_adapter: check: local, if=0 fn=0x4011df00
D (10032874) tcpip_adapter: if0 start ip lost tmr: enter
D (10032879) tcpip_adapter: if0 start ip lost tmr: interval=120
D (10032884) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (10032890) tcpip_adapter: check: remote, if=0 fn=0x4011df00

D (10035311) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:abcdefg Guest, ssid_len:13, bssid:00:00:00:00:00:00, reason:201
D (10035312) tcpip_adapter: check: local, if=0 fn=0x4011df00
D (10035317) tcpip_adapter: if0 start ip lost tmr: enter
D (10035322) tcpip_adapter: if0 start ip lost tmr: already started
D (10035328) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (10035334) tcpip_adapter: check: remote, if=0 fn=0x4011df00

D (10037749) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:abcdefg Guest, ssid_len:13, bssid:00:00:00:00:00:00, reason:201
D (10037750) tcpip_adapter: check: local, if=0 fn=0x4011df00
D (10037755) tcpip_adapter: if0 start ip lost tmr: enter
D (10037760) tcpip_adapter: if0 start ip lost tmr: already started
D (10037766) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (10037772) tcpip_adapter: check: remote, if=0 fn=0x4011df00

ESP-IDF branch: release/v3.0 updated at commit 0ebae99 (17 dec 2017)

@DigKleppe
Copy link

DigKleppe commented Dec 19, 2017

Solved , see post:
www.esp32.com/viewtopic.php?f=13&t=3451&p=17503&hilit=Dig+Kleppe#p16072
Memory leak in netconn

@jack0c
Copy link
Collaborator

jack0c commented Jan 3, 2018

@jasslo @ricksondpenha things you can do to check what's the problem:
1.check the version, give the commit ID here.
2.dump your NVS data to a file, give the file here.
3.erase the flash and flash again.
4.use latest idf3.0 or master and check menuconfig about Components config->PHY->Do phy calibration ..., you can do phy calibration every time.

@0BackDoor1
Copy link

Hi,
any news about this issue?
I tried erasing the flash and with PHY calibration active, but still getting it

@jack0c
Copy link
Collaborator

jack0c commented Jan 24, 2018

@0BackDoor1 Can you capture the packets in the air?

@0BackDoor1
Copy link

@jack0c my issue doesn't occur anymore with IDF updated to latest commit available, good!

@jack0c
Copy link
Collaborator

jack0c commented Mar 22, 2018

@0BackDoor1 Can you give commit you use. Maybe can help us and other developers. Thanks!

@mzimmers
Copy link

mzimmers commented Apr 3, 2018

I'm experiencing this as well. From reading this thread, and the one referenced above, it's still not clear to me whether this has been fixed, and whether it requires a change to user code. Can someone elucidate? Thanks...

@0BackDoor1
Copy link

0BackDoor1 commented May 14, 2018

@jack0c sorry for delay, I missed email notification about this, my repo was at commit cf2600a (branch release/V3.0)

@NOA-Vernon
Copy link

Is there any update? I also experience this issue

  1. wifi: bcn_timout,ap_probe_send_start
    I (121479) wifi: ap_probe_send over, resett wifi status to disassoc
    I (121479) wifi: state: run -> init (1)
    I (121479) wifi: pm stop, total sleep time: 0 us / 111197816 us

I (121489) wifi: n:7 0, o:7 0, ap:255 255, sta:7 0, prof:1

@0BackDoor1
Copy link

@NOA-Vernon first of all ensure to have IDF updated, the same issue occurs if the free heap size (esp_get_free_heap_size) is too low, don't know if this could help on your case

@NOA-Vernon
Copy link

@0BackDoor1 thank you very much for the response, the IDF I used is ESP-IDF v3.1-dev-961-ga255622-dirty, the free heap size is around 50000, this issue still happened again and not have a solution yet. hoping there is anyone who can elucidate or point out the problems.

@bill1davis
Copy link

bill1davis commented Aug 2, 2018

This is reproducible easily using the power_save example source with the current esp-idf. I have seen it on two different mainstream routers using 100ms beacon interval and DTIM settings of 1 or 3. I feel like it happens much more often with DTIM=1. With DTIM=3 I have seen it run for 1/2 hour to 1 hour before getting bcn_timout and disconnecting. I am still testing trying to work around the disconnect. It seems like wifi gets messed up after and can't reconnect. I am using low power mode light sleep.

Log:
I (328) boot: Loaded app from partition at offset 0x10000
I (328) boot: Disabling RNG early entropy source...
I (330) cpu_start: Pro cpu up.
I (333) cpu_start: Single core mode
I (338) heap_init: Initializing. RAM available for dynamic allocation:
I (345) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (351) heap_init: At 3FFB8A30 len 000275D0 (157 KiB): DRAM
I (357) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (363) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (370) heap_init: At 40090A78 len 0000F588 (61 KiB): IRAM
I (376) cpu_start: Pro cpu start user code
I (394) cpu_start: Starting scheduler on PRO CPU.
I (404) pm_esp32: Frequency switching config: CPU_MAX: 80, APB_MAX: 80, APB_MIN:
XTAL, Light sleep: ENABLED
I (414) wifi: wifi driver task: 3ffbf008, prio:23, stack:3584, core=0
I (414) wifi: wifi firmware version: 4c398ce
I (414) wifi: config NVS flash: enabled
I (424) wifi: config nano formating: disabled
I (424) system_api: Base MAC address is not set, read default base MAC address f
rom BLK0 of EFUSE
I (434) system_api: Base MAC address is not set, read default base MAC address f
rom BLK0 of EFUSE
I (454) wifi: Init dynamic tx buffer num: 32
I (454) wifi: Init data frame dynamic rx buffer num: 32
I (454) wifi: Init management frame dynamic rx buffer num: 32
I (464) wifi: Init static rx buffer size: 1600
I (464) wifi: Init static rx buffer num: 10
I (474) wifi: Init dynamic rx buffer num: 32
I (774) phy: phy_version: 3910, c0c45a3, May 21 2018, 18:07:06, 0, 2
I (774) wifi: mode : sta (30:ae:a4:4b:4b:18)
I (774) power_save: SYSTEM_EVENT_STA_START
I (774) power_save: esp_wifi_set_ps().
I (784) wifi: Set ps type: 1

I (894) wifi: n:11 0, o:1 0, ap:255 255, sta:11 0, prof:1
I (2864) wifi: state: init -> auth (b0)
I (2864) wifi: state: auth -> assoc (0)
I (2874) wifi: state: assoc -> run (10)
I (2904) wifi: connected with CareTaker, channel 11
I (2904) wifi: pm start, type: 1

I (2904) power_save: Unknown system event 4
I (3474) event: sta ip: 10.1.10.216, mask: 255.255.255.0, gw: 10.1.10.1
I (3474) power_save: SYSTEM_EVENT_STA_GOT_IP
I (3474) power_save: got ip:10.1.10.216

I (209594) wifi: bcn_timout,ap_probe_send_start
I (212104) wifi: ap_probe_send over, resett wifi status to disassoc
I (212104) wifi: state: run -> init (1)
I (212104) wifi: pm stop, total sleep time: 191543209 us / 207545926 us

I (212104) wifi: n:11 0, o:11 0, ap:255 255, sta:11 0, prof:1
I (212114) power_save: SYSTEM_EVENT_STA_DISCONNECTED

@snahmad
Copy link

snahmad commented Sep 5, 2018

Have anyone resolve this issue. I am facing same. I think it is due to interval ram less available. but with external RAM. I get wifi alloc error.

@bill1davis
Copy link

I was able to work around it by running both cores at 266 mHz. I suspect it is wake timing related. Not my plan for the long term. I hope it gets looked at.

@snahmad
Copy link

snahmad commented Sep 5, 2018

Yes I am only using one core. I think two cores with external RAM is not stable and safe on Esp32.

I am using Http Web server with SD card.

I am getting similar error
wifi: alloc eb len=192 type=2 fail

I am using WIFI with external RAM.

Internal Heap free: 41120
Heap free: 4195984:4233744

Plenty of external ram and some internal RAM.

Does in default settings WIFI only uses internal ram.

@vonnieda
Copy link
Contributor

vonnieda commented Sep 5, 2018

@snahmad If you are using TLS and have 41k internal free, you will likely run out of memory due to TLS connections. Read through the comments on #2184 to see how you can switch to using external RAM for TLS, or see if you can free up more internal RAM. In my tests it seems like each TLS connection takes > 20kB of internal RAM.

@snahmad
Copy link

snahmad commented Sep 5, 2018

I am not using TSL yet. in future may be.
Only unsecure HTTP Mongoose Web server and few TCP and UDP sockets connections.
I will configure to wifi use only static buffer only internal RAM.
My sector size for SD card is 32k. I can try reducing it.

@snahmad
Copy link

snahmad commented Sep 5, 2018

Why WIFI is using external RAM.

I need to specify for both Tx and RX static buffer on internal RAM only for Wifi.

W (6548) wifi: m f probe req l=0

W (6699) wifi: alloc eb len=76 type=2 fail, heap:4192980

W (6700) wifi: m f probe req l=0

Stack free: 6396
Internal Heap free: 39416
Heap free: 4195048:4232808

@dalerks
Copy link

dalerks commented Feb 28, 2019

Any progress I am having this issue too

@snahmad
Copy link

snahmad commented Feb 28, 2019

You mean run-out internal ram. you can specify to use only static ram for Wifi in menuonfig.

@liuzfesp
Copy link
Contributor

liuzfesp commented Mar 4, 2019

@dalerks, what's your issue? beacon timeout or the log "m f probe req l=0" is displayed? Could you paste your error log here?

@dalerks
Copy link

dalerks commented Mar 4, 2019

W (351669) wifi: alloc eb len=24 type=3 fail, heap:88

W (351669) wifi: m f null

I (357609) wifi: bcn_timout,ap_probe_send_start
W (357609) wifi: alloc eb len=76 type=2 fail, heap:88

W (357609) wifi: m f probe req l=0

W (358109) wifi: alloc eb len=76 type=2 fail, heap:88

W (358109) wifi: m f probe req l=0

W (358609) wifi: alloc eb len=76 type=2 fail, heap:88

W (358609) wifi: m f probe req l=0

W (359109) wifi: alloc eb len=76 type=2 fail, heap:88

W (359109) wifi: m f probe req l=0

W (359609) wifi: alloc eb len=76 type=2 fail, heap:88

W (359609) wifi: m f probe req l=0

I (360109) wifi: ap_probe_send over, resett wifi status to disassoc
I (360109) wifi: state: run -> init (c800)
W (360109) wifi: alloc eb len=28 type=3 fail, heap:88

W (360119) wifi: m f disassoc

I (360119) wifi: pm stop, total sleep time: 290332841 us / 355180847 us

I (360129) wifi: new:<10,0>, old:<10,0>, ap:<255,255>, sta:<10,0>, prof:1
I (360129) AirCylcer: Event called
I (360259) wifi: new:<10,0>, old:<10,0>, ap:<255,255>, sta:<10,0>, prof:1
I (360259) wifi: state: init -> auth (b0)
I (360259) wifi: state: auth -> init (8a0)
I (360259) wifi: new:<10,0>, old:<10,0>, ap:<255,255>, sta:<10,0>, prof:1
I (360269) AirCylcer: Event called
Fan on for 0
Runtime 6
Saved time 20
Rem time 20
I (362319) AirCylcer: Event called
I (362449) wifi: new:<10,0>, old:<10,0>, ap:<255,255>, sta:<10,0>, prof:1
I (362449) wifi: state: init -> auth (b0)
I (362449) wifi: state: auth -> assoc (0)
I (362459) wifi: state: assoc -> run (10)
I (362489) wifi: connected with AirLinksys24G, channel 10, bssid = 60:38:e0:99:9d:35
I (362489) wifi: pm start, type: 1

I (362489) AirCylcer: Event called
I (363299) event: sta ip: 192.168.1.149, mask: 255.255.255.0, gw: 192.168.1.1
I (363299) AirCylcer: Event called
E (370139) aws_iot: failed! mbedtls_ssl_write returned -0x4e

@liuzfesp
Copy link
Contributor

liuzfesp commented Mar 5, 2019

HI @dalerks , for "alloc eb fail" issue, please refer to: #3044

In WiFi driver, the TX management frames, such as beacon, probe request, probe response etc, are categorized to following type:

  • If the frame len < 64, it's short management buffer. The maximum allowed short management buffer number is 8. All short management buffer are dynamic buffer.
  • Otherwise, it's long management buffer. The long management buffer share the same buffer as TX data buffer which is configured via menuconfig: "menuconfig => Components => WiFi => Max number of WiFi dynamic TX buffers" if the TX buffer is dynamic or "menuconfig => Components => WiFi => Max number of WiFi static TX buffers" if the TX buffer is static.

Generally, the "alloc eb fail" error has following reasons:

  • Out of memory. The reason of "alloc eb failed" in your log is out of memory because the heap only has 88 Bytes. Generally it's because the application allocates too much memory, or there is memory leak in the system, or the menuconfig is not reasonable etc.
  • The second reason is because the TX malloc speed is faster than WiFi sending speed and the 8 short management buffer already allocated. Generally this may happen in AP + STA mode, especially when the channel is very busy and there are too many WiFi station is probing the AP, it's not a problem if the system can recovery soon. In order to mitigate this case, we already make the short management buffer configurable via menuconfig, refer to TAG V3.1 - esp_wifi_scan_start() in STA mode (IDFGH-619) #3044
  • The 3rd reason is similar as the 2nd one, the different is it impacts the normal function, such as WiFi connection etc, and can't be recoverable. It is a bug, we need to debug it.

@projectgus projectgus changed the title [TW#15680] wifi: bcn_timout,ap_probe_send_start wifi: bcn_timout,ap_probe_send_start (IDFGH-83) Mar 12, 2019
@Alvin1Zhang
Copy link
Collaborator

@jasslo Thanks for reporting the issue, feel free to reopen the issue if it still exists. Thanks.

@hojatm61
Copy link

hojatm61 commented Feb 2, 2020

I also had this problem. I solved it with the following method.
I fixed a Ten millisecond delay inside the main loop of the program.
void loop () {
...
   delay (10);
}

@ZweiEuro
Copy link

I am getting this issue occasionally, as i am reading this it seems it only happens when flashing a lot and then only occasionally.
for me power cycling does the trick but i am not 100% sure

@liuzfesp
Copy link
Contributor

Hi @ZweiEuro, could you provide following info:

  • whole log (better provide with attachment)
  • IDF commit ID

@ZweiEuro
Copy link

ZweiEuro commented Aug 2, 2020

@liuzfesp I opened a new issue. Mainly because the version is completely different.
#5674

@duanshuai007
Copy link

我将idf版本从4.2升级到4.3后解决了这个问题。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests