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

High memory consumption on 2.0.0rc1 core #5474

Closed
ale-trevizoli opened this issue Jul 28, 2021 · 23 comments · Fixed by #5791
Closed

High memory consumption on 2.0.0rc1 core #5474

ale-trevizoli opened this issue Jul 28, 2021 · 23 comments · Fixed by #5791
Assignees
Labels
Area: ESP-IDF related ESP-IDF related issues

Comments

@ale-trevizoli
Copy link
Contributor

Hi.
I'm using esp32-dev board 4Mb Flash.
I have a system developed with Arduino IDE 1.8.5 and ESP32 core 1.0.6.
This system print on loop() - ESP.getFreeHeap() each 5 seconds, and show me ~302K free.
I exchange 1.0.6 to 2.0.0rc1 and I only compiled again and got ~265K free, difference of 37Kbytes.
What's can happening?

Thanks!

@SuGlider
Copy link
Collaborator

SuGlider commented Aug 11, 2021

I tested the sketch below and got about 343K free.

void setup() {
  Serial.begin(115200);
}

void loop() {
  Serial.println((unsigned long)ESP.getFreeHeap());
  delay(5000);
}

@avillacis
Copy link

This issue of additional memory use persists in recently-released 2.0.0 stable versus 1.0.6. In my case, the difference is enough to have 1.0.6 stashed alongside 2.0.0 in case one of our projects fails due to memory starvation.

For example, consider the following sketch:

WiFiScan-ESP32S2.txt

This sketch compiles properly under 1.0.6 and 2.0.0. However, note the difference in memory use, especially after WiFi is set up:

Under 1.0.6:

ets Jun  8 2016 00:22:57

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:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:10944
load:0x40080400,len:6388
entry 0x400806b4
MEMORY USE AT setup() before WiFi setup: 360808 total, 334340 free, 113792 max.alloc
Setup done
MEMORY USE AT setup() after WiFi setup: 359568 total, 283652 free, 113792 max.alloc
scan start
scan done
12 networks found
(redacted)

MEMORY USE AT after WiFi scan: 359484 total, 282476 free, 113792 max.alloc
scan start
scan done
17 networks found
(redacted)

MEMORY USE AT after WiFi scan: 359484 total, 282076 free, 113792 max.alloc

Under 2.0.0:

ets Jun  8 2016 00:22:57

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:1
load:0x3fff0030,len:1240
load:0x40078000,len:13012
load:0x40080400,len:3648
entry 0x400805f8
MEMORY USE AT setup() before WiFi setup: 366171 total, 308455 free, 65524 max.alloc
Setup done
MEMORY USE AT setup() after WiFi setup: 364203 total, 228051 free, 65524 max.alloc
scan start
scan done
14 networks found
(redacted)

MEMORY USE AT after WiFi scan: 364179 total, 226875 free, 65524 max.alloc
scan start
scan done
13 networks found
(redacted)

MEMORY USE AT after WiFi scan: 364179 total, 226955 free, 65524 max.alloc

By switching SDK releases and doing nothing else, the free memory has decreased from 282076 to 226955 (an unexplained additional 55121 bytes), and the maximum allocatable block has decreased from 113792 to 65524 bytes.

Why????

@SuGlider
Copy link
Collaborator

SuGlider commented Sep 3, 2021

1.0.6 uses IDF 3.3
2.0.0 uses a RC for IDF 4.4
WiFi is completely based on IDF.

I guess this is the reason for a higher RAM consumption.

@SuGlider
Copy link
Collaborator

SuGlider commented Sep 3, 2021

Maybe, in the near future, on the final release of IDF 4.4 and respective rebase of Arduino Core to this IDF, it may improve.

No promises....

@me-no-dev
Copy link
Member

there are many reasons why there is a different memory usage in recent IDF. This is in NO WAY connected to Arduino. Arduino's is mostly disabling some IRAM optimizations, because users have sketches with WiFi, BT and all kinds of other things that make compilation impossible. That change though actually gives you memory. Do you actually have memory issues?

@VojtechBartoska VojtechBartoska added the Area: ESP-IDF related ESP-IDF related issues label Sep 7, 2021
@avillacis
Copy link

there are many reasons why there is a different memory usage in recent IDF. This is in NO WAY connected to Arduino. Arduino's is mostly disabling some IRAM optimizations, because users have sketches with WiFi, BT and all kinds of other things that make compilation impossible.

Maybe some additional IRAM optimization was overlooked?

That change though actually gives you memory. Do you actually have memory issues?

Yes, I do have memory issues with some of my projects that were absent when compiled under 1.0.6. At least one of our projects (the firmware for the OpenVenti artificial respirator project) is unable to complete its OTA firmware update procedure due to insufficient RAM under 2.0.0, where the same source code worked successfully with 1.0.6. This has forced me to look for and remove RAM inefficiencies in the process, but the fact remains that 55Kb extra RAM use is currently a showstopper for updating to 2.0.0, at least for this project.

@igrr
Copy link
Member

igrr commented Sep 7, 2021

Here is some additional data based on IDF example, examples/wifi/getting-started/station:

IDF release sdkconfig Heap [1] after app_main Heap [1] after esp_wifi_start Heap used
IDF master (v4.4-dev-2890-ge93cee4605) from arduino-esp32 2.0.0 [2] 326435 251415 75kB
IDF master (v4.4-dev-2890-ge93cee4605) default 323884 284048 40kB
IDF release/v3.3 (v3.3.4-404-g7e63061fae) from arduino-esp32 1.0.6 [3] 337720 291300 46kB
IDF release/v3.3 (v3.3.4-404-g7e63061fae) default 327232 290864 36kB

First, note that with the default sdkconfig, IDF 4.4-dev has about 7kB less heap at app_main than IDF release/3.3. See the note [1] below, though. These numbers include "IRAM" heap; if we compare only DRAM heap (MALLOC_CAP_DEFAULT), then v4.4-dev has 2kB more heap than 3.3 (277032 bytes free in v4.4-dev, 275824 free in release/v3.3) when this example starts up — see the table below.

We can see that some RAM can be reclaimed by changing the configuration (sdkconfig) that arduino-esp32 is built with. The sdkconfig used in 2.0.0 results in 35kB higher RAM usage than the default sdkconfig (for the same IDF version). In 1.0.6 this was only 10kB higher.

For the rest of the difference between 1.0.6 and 2.0.0 heap usage we should look at the startup heap size: 334340 vs 308455 (26kB difference). This might be due to higher static memory usage (.data, .bss) and/or higher heap usage. The issue might be on IDF side or Arduino-esp32 side, it is hard to say without investigating it in detail. For the static memory usage, idf.py size-components (or idf_size.py) can provide per-library breakdown of static data — including libarduino.a. For the dynamic memory usage, we can enable heap tracing to find the allocations performed at startup (before setup is called). I haven't had time to look into this part yet, but I suspect that there is room for improvement.


Note 1: note that arduino-esp32 ESP.getFreeHeap() function returns the amount of internal DRAM and IRAM; the latter is not available via malloc, so the number is somewhat higher than the useful amount of heap memory. See #5346. To make comparisons easier, i used the same way of measuring the heap size in IDF examples, even though that's not an entirely accurate approach.

Here is the version of the table above, but this time showing only the DRAM heap (MALLOC_CAP_DEFAULT). Note that "Heap used" (difference) is the same as above, just the initial number in each row is less by the amount of free IRAM in the particular configuration:

IDF release sdkconfig Heap after app_main Heap after esp_wifi_start Heap used
IDF master (v4.4-dev-2890-ge93cee4605) from arduino-esp32 2.0.0 [2] 239484 164040 75kB
IDF master (v4.4-dev-2890-ge93cee4605) default 277032 237432 40kB
IDF release/v3.3 (v3.3.4-404-g7e63061fae) from arduino-esp32 1.0.6 [3] 272068 225116 47kB
IDF release/v3.3 (v3.3.4-404-g7e63061fae) default 275824 239288 36kB

Note 2: https://raw.githubusercontent.com/espressif/arduino-esp32/2.0.0/tools/sdk/esp32/sdkconfig
Note 3: https://raw.githubusercontent.com/espressif/arduino-esp32/1.0.6/tools/sdk/sdkconfig

@SuGlider
Copy link
Collaborator

@ale-trevizoli
I'm working on this issue and I was able to get the following results using the same sketch you have posted here as an example, with a customized version of Arduino Core 2.0.0:

a) bin size of 632405 bytes
b) Heap:

SDK: v4.4-dev-3401-gb86fe0c66c
MEMORY USE AT setup() before WiFi setup: 332796 total, 308416 free, 65524 max.alloc - max.alloc internal 65524 
Setup done
MEMORY USE AT setup() after WiFi setup: 331164 total, 275492 free, 65524 max.alloc - max.alloc internal 65524
scan start
scan done
21 networks found

MEMORY USE AT after WiFi scan: 331140 total, 273756 free, 65524 max.alloc - max.alloc internal 65524

I created a repository with a new Arduino Core 2.0.0 that can be tested.
https:/espressif/arduino-esp32/tree/mem-optimized

In order to install it as a separated board for testing, please follow the instructions from
https://docs.espressif.com/projects/arduino-esp32/en/latest/installing.html
The only difference here would be to clone mem-optimized branch instead.

git clone -b mem-optimized https:/espressif/arduino-esp32 esp32

In case it works fine for a number of users, we will commit it for the next ESP32 Arduino release.
Please test it with your project and let me know.

@olicooper
Copy link

olicooper commented Oct 15, 2021

Memory consumption is GREAT! ... but I have wifi issues using the mem-optimized branch. I am using the new esp-idf mqtt functionality (see this) which may be a contributing factor?
The logs don't seem like they will help much, but I can see the line beginning [ 8716][V] has a BSSID of 00:00:00:00:00:00 - I guess this is because it is no longer connected to an AP?

My code worked fine on Arduino v1.0.6 and Arduino v2.0.0 master branch

I have my own logging facility which is why there is additional log output below.

environment

  • Heltec Wireless Stick
  • Network is using WPA2-PSK (CCMP-128)
  • WiFi library is configured with mostly default settings (dynamic IP) and it is close to the AP

additional config

// I use onEvent
WiFi.onEvent([&](arduino_event_id_t event, arduino_event_info_t info) { /* ... */ });
// I only use STA
WiFi.mode(WIFI_MODE_STA);
// I save wifi details elsewhere
WiFi.persistent(false);
// I manually reconnect in my loop
WiFi.setAutoReconnect(false);
// I make the initial connection later on by calling esp_wifi_connect();
WiFi.begin(ssid, password, 0 NULL, false);

logs

[   401][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 0 - WIFI_READY
[   499][V][WiFiGeneric.cpp:272] _arduino_event_cb(): STA Started
[   499][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 2 - STA_START
2021-10-15T18:18:44 [V][mqtt]: WiFi ssid=[MySsid]
2021-10-15T18:18:44 [D][mqtt]: WiFi connecting
[   527][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
2021-10-15T18:18:44 [W][mqtt]: WiFi failed to connect
2021-10-15T18:18:44 [I][mqtt]: Service enabled
2021-10-15T18:18:44 [D][core]: Free memory: 162784 bytes
2021-10-15T18:18:44 [A][core]: System started
2021-10-15T18:18:45 [V][store]: Closed
[  6627][V][WiFiGeneric.cpp:289] _arduino_event_cb(): STA Disconnected: SSID: MySsid, BSSID: ab:cd:ef:01:02:ea, Reason: 2
[  6628][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  6635][W][WiFiGeneric.cpp:841] _eventCallback(): Reason: 2 - AUTH_EXPIRE
2021-10-15T18:18:50 [V][mqtt]: Connect timer expired
2021-10-15T18:18:50 [V][mqtt]: WiFi reconnecting
2021-10-15T18:18:50 [D][mqtt]: notifyEventSubscribers: disconnected
[  8716][V][WiFiGeneric.cpp:289] _arduino_event_cb(): STA Disconnected: SSID: MySsid, BSSID: 00:00:00:00:00:00, Reason: 205
[  8716][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  8724][W][WiFiGeneric.cpp:841] _eventCallback(): Reason: 205 - CONNECTION_FAIL
2021-10-15T18:18:52 [V][mqtt]: Connect timer expired
2021-10-15T18:18:52 [V][mqtt]: WiFi reconnecting
2021-10-15T18:18:52 [D][mqtt]: notifyEventSubscribers: disconnected
[ 14857][V][WiFiGeneric.cpp:289] _arduino_event_cb(): STA Disconnected: SSID: MySsid, BSSID: ab:cd:ef:01:02:ea, Reason: 4
[ 14858][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[ 14865][W][WiFiGeneric.cpp:841] _eventCallback(): Reason: 4 - ASSOC_EXPIRE
[ 14900][V][WiFiGeneric.cpp:275] _arduino_event_cb(): STA Stopped
2021-10-15T18:18:58 [D][mqtt]: notifyEventSubscribers: disconnected
2021-10-15T18:18:58 [D][mqtt]: WiFi disconnected: r=4, WiFi disabled
[ 14933][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 3 - STA_STOP

@chegewara
Copy link
Contributor

Reason: 2 - AUTH_EXPIRE
This is normal when you are using smartphone as AP (maybe with routers too) during development.
When esp32 is connected and you re-flash it then smartphone keeps this connection active, even if esp32 disconnected. Then after reset esp32 is trying to connect again, but smartphone still wants to update old connection.
I dont know how it is handled in low level wifi packets exchange, just saying from experience.
There is 2 options that work for me:

  1. during re-flash disable and re-enable AP,
  2. or after re-flash esp32 and that error occured just restart esp32 with pwr button

@olicooper
Copy link

olicooper commented Oct 16, 2021

Thanks for your reply,
The router I am using is actually an AC series Linksys which is only a few years old. I modified the settings to disable WPA3 just in-case that was causing the issue, but I will also try restarting the router because I haven't tried this yet. I erased the flash and then flashed Arduino 1.0.6 and it worked perfectly again, then I went back to the mem-optimized branch and observed the same connection issues. I will do more testing based on your comments and to confirm if it is working for the main branch.

Update 1

I've created a reproducible example which can be found here https:/olicooper/arduino-v2-esp32-platformio/tree/wifi-test. The repo readme has more detail.
I have tried it with two ESP32 devices now - one is a Heltec Wireless Stick (used in my original tests), and the other is a Lolin 32 Lite. I lifted most of the code from my original project, but the example doesn't have the reconnect code included. It produced the same problem seen in my original code.

Update 2

I have recompiled the code with the v2.0.0 main branch and the Lolin 32 Lite connects immediately, so it is the mem-optimized branch which is the problem. I have also tried disabling all the customisations (persistence and auto-reconnect) in my example code but this didn't fix the issue for the mem-optimized branch.

I've updated the log output with logs from the working v2.0.0 main branch.

@SuGlider
Copy link
Collaborator

SuGlider commented Oct 16, 2021

@olicooper,
Upon your GitHub, it says you are using IDF 4.3. Is it right?
The branch I sent uses 4.4 latest master.

Could you please confirm it by executing:

Serial.println(ESP.getSdkVersion());

Update:

Nevermind, it is in the logs.
Thanks for the information.
I'll look into this issue.

@olicooper
Copy link

olicooper commented Oct 17, 2021

I have now configured an old BT Home Hub 3 router with WPA2, ssid TestNet and password test1234. I used the WiFiClientBasic.ino example and this is the log output (with bssid's changed):

[��mum����2-hal-cpu.c:211] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[    47][I][WiFiMulti.cpp:84] addAP(): [WIFI][APlistAdd] add SSID: TestNet

Waiting for WiFi... [    70][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 0 - WIFI_READY
[   169][V][WiFiGeneric.cpp:272] _arduino_event_cb(): STA Started
[   171][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 2 - STA_START
[  4882][V][WiFiGeneric.cpp:306] _arduino_event_cb(): SCAN Done: ID: 128, Status: 0, Results: 3
[  4883][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 1 - SCAN_DONE
[  4887][I][WiFiMulti.cpp:114] run(): [WIFI] scan done
[  4892][I][WiFiMulti.cpp:119] run(): [WIFI] 3 networks found
[  4897][D][WiFiMulti.cpp:151] run():        0: [4][FF:FF:FF:FF:FF:F1] ssid1 (-41) *
[  4905][D][WiFiMulti.cpp:149] run():  --->   1: [11][FF:FF:FF:FF:FF:F2] TestNet (-46) *
[  4913][D][WiFiMulti.cpp:151] run():        2: [6][FF:FF:FF:FF:FF:F3] ssid3 (-81)
[  4930][I][WiFiMulti.cpp:160] run(): [WIFI] Connecting BSSID: FF:FF:FF:FF:FF:F2 SSID: TestNet Channel: 11 (-46)
[  5017][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
[ 10036][E][WiFiMulti.cpp:187] run(): [WIFI] Connecting Failed (6).
.[ 10537][D][WiFiMulti.cpp:195] run(): [WIFI] delete old wifi config...
[ 10539][D][WiFiMulti.cpp:198] run(): [WIFI] start scan
.[ 10541][V][WiFiGeneric.cpp:289] _arduino_event_cb(): STA Disconnected: SSID: TestNet, BSSID: FF:FF:FF:FF:FF:F2, Reason: 8
[ 10548][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[ 10556][W][WiFiGeneric.cpp:841] _eventCallback(): Reason: 8 - ASSOC_LEAVE
...[ 12460][V][WiFiGeneric.cpp:306] _arduino_event_cb(): SCAN Done: ID: 130, Status: 0, Results: 3
[ 12460][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 1 - SCAN_DONE
[ 17453][V][WiFiGeneric.cpp:306] _arduino_event_cb(): SCAN Done: ID: 131, Status: 0, Results: 4
[ 17454][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 1 - SCAN_DONE
[ 17458][I][WiFiMulti.cpp:114] run(): [WIFI] scan done
[ 17463][I][WiFiMulti.cpp:119] run(): [WIFI] 4 networks found
[ 17468][D][WiFiMulti.cpp:151] run():        0: [4][FF:FF:FF:FF:FF:F1] ssid1 (-43) *
[ 17476][D][WiFiMulti.cpp:149] run():  --->   1: [11][FF:FF:FF:FF:FF:F2] TestNet (-47) *
[ 17492][D][WiFiMulti.cpp:151] run():        2: [6][FF:FF:FF:FF:FF:F3] ssid3 (-80)  
[ 17492][D][WiFiMulti.cpp:151] run():        3: [6][FF:FF:FF:FF:FF:F4] ssid4 (-85)  
[ 17517][I][WiFiMulti.cpp:160] run(): [WIFI] Connecting BSSID: FF:FF:FF:FF:FF:F2 SSID: TestNet Channel: 11 (-47)
[ 17529][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
[ 22556][E][WiFiMulti.cpp:187] run(): [WIFI] Connecting Failed (6).
.[ 23056][D][WiFiMulti.cpp:195] run(): [WIFI] delete old wifi config...
[ 23058][D][WiFiMulti.cpp:198] run(): [WIFI] start scan

Is there a WiFi configuration you are using that I can try to see if I can get it to connect?

@chegewara
Copy link
Contributor

chegewara commented Oct 17, 2021

The logs are not consistent with code from repository. Here you have
[ 5017][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
which tells us you are using static IP, but to do that you have to call WiFi.config() which is missing in your code and in example.
Another thing is last parameter, which is connect, set to false:
https:/olicooper/arduino-v2-esp32-platformio/blob/wifi-test/src/main.cpp#L75
and that means esp32 will not try to connect wifi, you have to do it in code, which you dont do.

@olicooper
Copy link

olicooper commented Oct 17, 2021

Yeah I kept noticing that static IP too, but I am not calling config in my code anywhere. As I said above, I have also tried the example WiFiClientBasic.ino code and only changing the ssid and password: https:/espressif/arduino-esp32/blob/mem-optimized/libraries/WiFi/examples/WiFiClientBasic/WiFiClientBasic.ino
You can see from the logs it says about a static IP there too.

You'll notice that WiFiGeneric::set_esp_interface_ip is called from WiFiSTA::begin if _useStaticIp is false

esp_err_t set_esp_interface_ip(esp_interface_t interface, IPAddress local_ip=IPAddress(), IPAddress gateway=IPAddress(), IPAddress subnet=IPAddress()){

if(!_useStaticIp){
if(set_esp_interface_ip(ESP_IF_WIFI_STA) != ESP_OK) {
return WL_CONNECT_FAILED;
}
}

Also, In my code I call esp_wifi_connect() a few lines down from begin (ignore the inaccurate comment above the code):
https:/olicooper/arduino-v2-esp32-platformio/blob/332caebd3ef3e8d4aa94241265bb1be710b1c4c1/src/main.cpp#L84
... Just as you see in the WiFiSTA.cpp source code:

if(connect){
if(esp_wifi_connect() != ESP_OK) {
log_e("connect failed!");
return WL_CONNECT_FAILED;
}
}

I am happy to provide you with any information to help you figure it out, but please don't suggest that I am providing you with false/inaccurate information or that I am making simple configuration errors rather than this being a genuine bug report. I have a decent amount of experience with networking and I've spent a number of years coding embedded devices. I understand that there may be a lot of people using Arduino that configure their home projects incorrectly but that isn't everyone. I appreciate what you are doing for the community. Thank you for your support and understanding.

Update 1

After you mentioned using WiFi:config I decided to try configuring a static IP before calling WiFi::begin and simplified the begin method. However, the issue is still present.

WiFi.config(IPAddress(192,168,1,8), IPAddress(192,168,1,1), IPAddress(255,255,255,0), IPAddress(192,168,1,1));
WiFi.begin(ssidStr.c_str(), passStr.c_str());
[   270][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 192.168.1.8, MASK: 255.255.255.0, GW: 192.168.1.1
[   270][V][WiFiGeneric.cpp:272] _arduino_event_cb(): STA Started
[   277][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 2 - STA_START
WiFi onEvent: 2
...
[  6579][V][WiFiGeneric.cpp:289] _arduino_event_cb(): STA Disconnected: SSID: TestNet, BSSID: FF:FF:FF:FF:FF:F2, Reason: 15
[  6580][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  6587][W][WiFiGeneric.cpp:841] _eventCallback(): Reason: 15 - 4WAY_HANDSHAKE_TIMEOUT

It seems to be a variation of 4WAY_HANDSHAKE_TIMEOUT ASSOC_LEAVE and HANDSHAKE_TIMEOUT.. I need a known good router configuration so I can rule out router issues (obviously I have tried 2 different routers now to mitigate that possibility). I will try without WPA security next. I don't have any other ESP32 board types to try though.

Update 2

I've isolated the problem... It seems that I am able to connect when security is not configured on the router or esp e.g. WiFi.begin(ssidStr.c_str()). I have tried with and without a static IP but this doesn't effect the outcome.

[  2388][V][WiFiGeneric.cpp:284] _arduino_event_cb(): STA Connected: SSID: TestNet, BSSID: FF:FF:FF:FF:FF:F2, Channel: 11, Auth: OPEN
[  2389][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
[  2391][V][WiFiGeneric.cpp:294] _arduino_event_cb(): STA Got New IP:192.168.1.8
WiFi onEvent: 4
onWifiConnected

Also, the output from WiFi.printDiag(Serial); when a WiFi passphrase and static IP is used:

Mode: STA
Channel: 11
SSID (7): TestNet
Passphrase (8): test1234
BSSID set: 0

@SuGlider The mem-optimized branch is using a newer IDF release (v4.4-dev-3401-gb86fe0c66c) than the main branch (v4.4-dev-2313-gc69f0ec32). I've reviewed the begin code and I am beginning to suspect that there is a bug in the upstream IDF code rather than this branch.

@chegewara
Copy link
Contributor

@olicooper That is good diagnostic
Next i would try is to test all security options you have on router, except WPA3.

@olicooper
Copy link

Good idea. I've tested with WPA2,WPA,WEP as these are the only options on the old router. I can't modify the new router as it is in active use.

WPA and WPA2 are not working (4WAY_HANDSHAKE_TIMEOUT).. But WEP is working fine, so its probable that the WPA encryption/decryption algo is broken on IDF then.

Mode: STA
Channel: 4
SSID (7): TestNet
Passphrase (10): abcdef1234
BSSID set: 0
WiFi start 6
[  2371][V][WiFiGeneric.cpp:284] _arduino_event_cb(): STA Connected: SSID: TestNet, BSSID: FF:FF:FF:FF:FF:F2, Channel: 11, Auth: WEP
[  2372][D][WiFiGeneric.cpp:820] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
WiFi onEvent: 4
onWifiConnected

@SuGlider
Copy link
Collaborator

SuGlider commented Oct 18, 2021

@olicooper
Does this same test with 2.0.0 and 1.0.6 work fine - using WPA/WPA2?
It could also be an issue with sdkconfing settings used within the mem-optimized branch.
Please let me know. Thanks!

@olicooper
Copy link

Arduino v2.0.1 (v4.4-dev-3401-gb86fe0c66c / sha.77f1ebd)

  • Working: WEP
  • Broken: WPA(PSK),WPA2(PSK)

Arduino v2.0.0 (v4.4-dev-2313-gc69f0ec32 / sha.44c1198)

  • Working: WEP,WPA(PSK),WPA2(PSK)

Arduino v1.0.6 (v3.3.5-1-g85c43024c / sha.46d5afb)

platform = https:/platformio/platform-espressif32.git#v3.3.2
platform_packages = framework-arduinoespressif32 @ https:/espressif/arduino-esp32.git#1.0.6
  • Working: WEP,WPA(PSK),WPA2(PSK)

SuGlider added a commit that referenced this issue Oct 19, 2021
WPA/WPA2 demands at least 1 TX Cache Buffer.
issue described in #5474 (comment)
@SuGlider
Copy link
Collaborator

SuGlider commented Oct 19, 2021

@olicooper
I have found the issue with WPA and WPA2.
It's now fixed on mem-optimized branch.
Related commit: f459b10

@SuGlider
Copy link
Collaborator

SuGlider commented Oct 19, 2021

I added Serial.printf("Free memory: %d bytes\n", esp_get_free_heap_size()); to loop() in order to display final heap.

Arduino v1.0.6 (v3.3.5-1-g85c43024c) ==> Free memory: 213,900 bytes || Binary Size 692,190 bytes
Arduino v2.0.0 (v4.4-dev-2313-gc69f0ec32 / sha.44c1198) ==> Free memory: 142,228 bytes || Binary Size 734,576 bytes
Arduino v2.0.1 (v4.4-dev-3401-gb86fe0c66c / sha.f459b10) ==>Free memory: 216,140 bytes || Binary Size 645,381 bytes

Comparing V2.0.0 with V2.0.1, this sketch has about 74K extra heap and takes about 90K less flash with the compiled binary.
The numbers are now likely better than it was before with 1.0.6.

@olicooper
Copy link

Really great work! It's working fine for me now 👍

@Jason2866
Copy link
Collaborator

@SuGlider Really great! It is working now. Just tested with Project Tasmota

me-no-dev pushed a commit to espressif/esp32-arduino-lib-builder that referenced this issue Oct 21, 2021
on commit deacf43

sdkconfig modifications to build libraries with compile optimization to size (-Os)
keep all the bootloaders with -Os and no boot messages
changes max number of sockets from 10 to 16
disables LWIP "Experimental PPP and SLIP" because it adds about 60K to the binary size and it's not used in Arduino
on commit a133257

sets WIFI LWIP to try first to allocate from SPIRAM on esp32 (this is esp32s2 default configuration)
defines SPIRAM_MALLOC_ALWAYSINTERNAL to 4096 bytes on esp32 (same as default for esp32s2)
disables SPIRAM_MALLOC_RESERVE_INTERNAL on both esp32 and esp32s2 to release more RAM to heap
Related PRs in Arduino-ESP32:
espressif/arduino-esp32#5789
espressif/arduino-esp32#5791

Related issue:
espressif/arduino-esp32#5699
espressif/arduino-esp32#5474
espressif/arduino-esp32#5630
espressif/arduino-esp32#5751
me-no-dev pushed a commit that referenced this issue Oct 21, 2021
)

Summary

Modifies WiFi lib to allow dynamic buffer allocation along with SPIRAM MALLOC enabled
This gives more heap space to the users

Related PR in Arduino Lib Builder: espressif/esp32-arduino-lib-builder#47

Impact

WiFi will work the same as it was in version 1.0.6, restoring free heap.

close #5630
close #5474
close #5699
close #5697
ewpa pushed a commit to ewpa/arduino-esp32 that referenced this issue Nov 15, 2021
…pressif#5791)

Summary

Modifies WiFi lib to allow dynamic buffer allocation along with SPIRAM MALLOC enabled
This gives more heap space to the users

Related PR in Arduino Lib Builder: espressif/esp32-arduino-lib-builder#47

Impact

WiFi will work the same as it was in version 1.0.6, restoring free heap.

close espressif#5630
close espressif#5474
close espressif#5699
close espressif#5697
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area: ESP-IDF related ESP-IDF related issues
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants