1.6.5-1106-g8253b82 version has leak memory ? #780

luc-github · 2015-09-14T07:18:03Z

Hi not sure how to debug this:
using my code with http://arduino.esp8266.com/versions/1.6.5-1084-ga39ce29/package_esp8266com_index.json (previous staging)
I always have 27k free memory when displaying web pages- web server was displaying full page as normal - wifi scan was working well, etc...

Today I moved to current staging which is : http://arduino.esp8266.com/versions/1.6.5-1106-g8253b82/package_esp8266com_index.json, without any code change.
My free memory drop to 21K then 17K after displaying 1 or 2 pages and pages are not fully displayed (first part only) or even at all and wifi scan seems randomly not working.

Looks like something is messing up. I must precise I do not use SPIFFS

I know it is normal staging version having issue as it is to be tested so my question is : is it a known issue ?
If not, how to find the change that could cause the problem ? I do not see in Github the tags 1.6.5-1084-ga39ce29 / 1.6.5-1106-g8253b82

Thanks

igrr · 2015-09-14T08:34:52Z

I'm not aware of this issue yet. Would you mind sharing the code which triggers this issue?

Regarding version names, the thing which follows -g is the (short) commit hash. So to see what has changed you could do

[arduino]$ git diff  --name-only  a39ce29..8253b82
build/build_board_manager_package.sh
build/shared/tools/ESP8266FS/make.sh
build/shared/tools/ESP8266FS/src/ESP8266FS.java
hardware/esp8266com/esp8266/boards.txt
hardware/esp8266com/esp8266/cores/esp8266/Esp.cpp
hardware/esp8266com/esp8266/cores/esp8266/HardwareSerial.cpp
hardware/esp8266com/esp8266/cores/esp8266/libc_replacements.c
hardware/esp8266com/esp8266/cores/esp8266/spiffs_api.cpp
hardware/esp8266com/esp8266/cores/esp8266/spiffs_hal.cpp
hardware/esp8266com/esp8266/doc/reference.md
hardware/esp8266com/esp8266/libraries/DNSServer/src/DNSServer.cpp
hardware/esp8266com/esp8266/libraries/ESP8266AVRISP/src/ESP8266AVRISP.cpp
hardware/esp8266com/esp8266/libraries/ESP8266AVRISP/src/ESP8266AVRISP.h
hardware/esp8266com/esp8266/libraries/ESP8266WebServer/examples/AdvancedWebServer/AdvancedWebServer.ino
hardware/esp8266com/esp8266/libraries/ESP8266WebServer/examples/HelloServer/HelloServer.ino
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/ESP8266WiFi.cpp
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClient.h
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecure.h
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/include/ssl.h
hardware/esp8266com/esp8266/platform.txt
hardware/esp8266com/esp8266/tools/sdk/lib/libaxtls.a

ghost · 2015-09-14T08:48:51Z

Sort of same issue here. Already during compile time it shows a large drop in available memory for variables.

Running exactly the same sketch on two staging releases:
Board package 1.6.5-1044-g170995a : leaving 31,896 bytes for local variables.
Board package 1.6.5-1106-g8253b82 : leaving 25,984 bytes for local variables

So suddenly 5912 bytes more taken by sdk or other libraries?

What could have happened here?

igrr · 2015-09-14T08:51:04Z

Doesn't look like the same issue. Original issue is

free memory drop to 21K then 17K after displaying 1 or 2 pages and pages are not fully displayed

luc-github · 2015-09-14T09:30:38Z

@igrr I did not trigger what generate the different behaviour yet , as change behavior was really obvious using my project : https://github.com/luc-github/ESP8266
I will use DEBUG to see if can get more information as it is not known issue

Anyway, I have noticed on this warning when compiling:
C:\Users\luc\AppData\Roaming\Arduino15\packages\esp8266\hardware\esp8266\1.6.5-1106-g8253b82\cores\esp8266\libc_replacements.c:408:22: warning: 'struct tm' declared inside parameter list [enabled by default] time_t mktime(struct tm *timp) { ^ C:\Users\luc\AppData\Roaming\Arduino15\packages\esp8266\hardware\esp8266\1.6.5-1106-g8253b82\cores\esp8266\libc_replacements.c:408:22: warning: its scope is only this definition or declaration, which is probably not what you want [enabled by default]

and here compiling output (sorry it is in french - I need to switch windows to English):

For http://arduino.esp8266.com/versions/1.6.5-1084-ga39ce29/package_esp8266com_index.json:

Le croquis utilise 366 160 octets (84%) de l'espace de stockage de programmes. Le maximum est de 434 160 octets.
Les variables globales utilisent 40 448 octets (49%) de mémoire dynamique, ce qui laisse 41 472 octets pour les variables locales. Le maximum est de 81 920 octets.

For http://arduino.esp8266.com/versions/1.6.5-1106-g8253b82/package_esp8266com_index.json:

Le croquis utilise 402 916 octets (92%) de l'espace de stockage de programmes. Le maximum est de 434 160 octets.
Les variables globales utilisent 46 328 octets (56%) de mémoire dynamique, ce qui laisse 35 592 octets pour les variables locales. Le maximum est de 81 920 octets.

sdrsdr · 2015-09-14T10:02:24Z

@mvdbro This might be the axTLS library linked to your code no matter used or not ..

luc-github · 2015-09-14T10:52:03Z

Seems what ever I do I am in SoftAP+ Client with latest staging, when I am supposed to be Client only as i use

WiFi.disconnect();
WiFi.mode(WIFI_STA);
WiFi.begin(sbuf, pwd);

here the debug of previous staging which start in client as requested, this include my own debug including the dump of EEPROM to verify data are not corrupted

sleep enable,type: 2
M117 192.168.0.122
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/5876318
f 0, 2
dlink
XXXXXXXX
1
192.168.0.1
255.255.255.0
192.168.0.1
9600
2
2
11
2
1
80
8888
3
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 7
pm open phy_2,type:2 0 0

connected with dlink, channel 1
dhcp client start...
cnt 
ip:192.168.0.122,mask:255.255.255.0,gw:192.168.0.1

and this is with current staging:

M117 192.168.0.122
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/5954810
mode : sta(18:fe:34:9b:2d:5b) + softAP(1a:fe:34:9b:2d:5b)
add if1
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
f 0, 2
dlink
XXXXXXXX
1
192.168.0.1
255.255.255.0
192.168.0.1
9600
2
2
11
2
1
80
8888
3
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 5

connected with dlink, channel 1
dhcp client start...
cnt 
ip:192.168.0.122,mask:255.255.255.0,gw:192.168.0.1

is there a way to ensure module is is sta mode only or softAp only ?

luc-github · 2015-09-14T11:53:27Z

Seems starting in SoftAP+Station mode is due to :
7f3987b
reverting this change make WiFi.mode(WIFI_STA); working as expected

I still have memory drop between 2 staging from 27K to 21K but now memory stay around 21K

Edit: wrong statement this change is not the root cause

ghost · 2015-09-14T12:01:57Z

@iggr
Should I create a separate issue for my reduced memory size of about 5 kb? So this is not a leak due to some command. It's just a 'static' loss of 5 kb.

It's not my sketch issue anyway. These are compiler results with the example hello server sketch:
Board package 1.6.5-1044-g170995a : leaving 42,400 bytes for local variables.
Board package 1.6.5-1106-g8253b82 : leaving 36,680 bytes for local variables

igrr · 2015-09-14T12:04:36Z

The 5kb free heap reduction is mostly due to SSL stuff pulled in. I'll look into optimizing that.

luc-github · 2015-09-14T12:29:31Z

That is odd :
I start module :
I get :

sleep disable
state: 5 -> 0 (0)
rm 0
bcn 0
del if1
mode : sta(18:fe:34:9b:e0:62)
f 0, M117 Connecting...
M117 Connecting...
M117 Connecting...
M117 Connecting...
M117 Connecting...
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 5
pm open phy_2,type:0 0 0

connected with dlink, channel 1
dhcp client start...
cnt 
M117 Connecting...
M117 Connecting...
ip:192.168.0.107,mask:255.255.255.0,gw:192.168.0.1
M117 192.168.0.107
2
dlink
XXXXXXXX
1
192.168.0.1
255.255.255.0
192.168.0.1
115200
2
0
11
2
1
80
8888
3

work as expected

I unplug/plug my ESP then I get :

sleep disable
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/5939930
mode : sta(18:fe:34:9b:e0:62) + softAP(1a:fe:34:9b:e0:62)
add if1
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
f 0, M117 Connecting...
M117 Connecting...
M117 Connecting...
M117 Connecting...
M117 Connecting...
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 5

connected with dlink, channel 1
dhcp client start...
cnt 
M117 Connecting...
M117 Connecting...
ip:192.168.0.107,mask:255.255.255.0,gw:192.168.0.1
M117 192.168.4.1
2
dlink
XXXXXXXX
1
192.168.0.1
255.255.255.0
192.168.0.1
115200
2
0
11
2
1
80
8888
3

Unplug/ plug and back to STA mode

I tried several modules and all same

luc-github · 2015-09-14T16:16:26Z

I moved all file listed here from current staging to previous staging :

hardware/esp8266com/esp8266/boards.txt
hardware/esp8266com/esp8266/cores/esp8266/Esp.cpp
hardware/esp8266com/esp8266/cores/esp8266/HardwareSerial.cpp
hardware/esp8266com/esp8266/cores/esp8266/libc_replacements.c
hardware/esp8266com/esp8266/cores/esp8266/spiffs_api.cpp
hardware/esp8266com/esp8266/cores/esp8266/spiffs_hal.cpp
hardware/esp8266com/esp8266/doc/reference.md
hardware/esp8266com/esp8266/libraries/DNSServer/src/DNSServer.cpp
hardware/esp8266com/esp8266/libraries/ESP8266AVRISP/src/ESP8266AVRISP.cpp
hardware/esp8266com/esp8266/libraries/ESP8266AVRISP/src/ESP8266AVRISP.h
hardware/esp8266com/esp8266/libraries/ESP8266WebServer/examples/AdvancedWebServer/AdvancedWebServer.ino
hardware/esp8266com/esp8266/libraries/ESP8266WebServer/examples/HelloServer/HelloServer.ino
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/ESP8266WiFi.cpp
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClient.h
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/WiFiClientSecure.h
hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/include/ssl.h
hardware/esp8266com/esp8266/platform.txt
hardware/esp8266com/esp8266/tools/sdk/lib/libaxtls.a

And cannot reproduce the issue - also I cannot see the
mode : sta(18:fe:34:9b:e0:62) output so it means another file does this output - no ?

Because if I use the current staging - I saw them immediately the error and the output line

@igrr can you point me what file do this? - I suspect it is a library (binary) as I cannot find in cpp/h files and does not show up in meld (my diff tool)

Thanks

luc-github · 2015-09-15T03:04:25Z

I used the sample of wifi client to get a reproductible behavior limiting the scope of root cause:
I set DEBUG mode in core
The sketch set to STA Mode - then launch a connection - do 3 loops showing the mode then restart
Nothing weird normaly
on my ESP01 using latest staging on Win7

here the sketch

#include <ESP8266WiFi.h>
extern "C" {
#include "user_interface.h"
}
const char* ssid     = "dlink";
const char* password = "XXXXXXXX";

void setup() {
   delay(10000);

  Serial.begin(9600);
   Serial.setDebugOutput(true);
  delay(10);

  Serial.println();
  Serial.println();
  Serial.print("Connecting to ");
  Serial.println(ssid);
  WiFi.mode(WIFI_STA);
  WiFi.begin(ssid, password);

  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.print(".");
  }

  Serial.println("");
  Serial.println("WiFi connected");  
  Serial.println("IP address: ");
  Serial.println(WiFi.localIP());
}

int value = 0;

void loop() {
  delay(2000);
   Serial.print("Mode : ");
   Serial.println(wifi_get_opmode());
   value=value+1;
    if (value==3)
    {
        Serial.println("Restart ");
        Serial.flush();
        delay(1000);
        ESP.restart();
        while (1){delay(1);};
    }
}

the module alternate STA mode and SOFT_AP+ STA mode when only STA is set
and randomly crash on when it is SOFT_AP
here the sample of the output:

Connecting to dlink
mode : sta(18:fe:34:9b:2d:5b) + softAP(1a:fe:34:9b:2d:5b)
add if1
pm close 7 0 0/7873298
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
f 0, ....scandone
..reconnect
state: 5 -> 0 (0)
rm 0
wifi evt: 1
f -180, ....scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 2

connected with dlink, channel 1
wifi evt: 0
dhcp client start...
cnt 
chg_B:-120
..wifi evt: 3
ip:192.168.0.122,mask:255.255.255.0,gw:192.168.0.1
chg_B:-60
.
WiFi connected
IP address: 
192.168.0.122
Mode : 3
Mode : 3
Mode : 3
Restart 
state: 5 -> 0 (0)
rm 0
wifi evt: 1
del if0
bcn 0
del if1
usl
sul 0 0
bB���SH���/

Connecting to dlink
bcn 0
del if1
pm open phy_2,type:2 0 0
mode : sta(18:fe:34:9b:2d:5b)
sl
f 0, ....scandone
usl
sul 7 0
..reconnect
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/3289733
wifi evt: 1
f -180, ....scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 2
pm open phy_2,type:2 0 0

connected with dlink, channel 1
wifi evt: 0
dhcp client start...
cnt 
chg_B:-120
..chg_B:-60
wifi evt: 3
ip:192.168.0.122,mask:255.255.255.0,gw:192.168.0.1
.
WiFi connected
IP address: 
192.168.0.122
Mode : 1
Mode : 1
Mode : 1
Restart 
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/8253889
wifi evt: 1
del if0
usl
sul 0 0
bB���SH���/

Connecting to dlink

WiFi connected
IP address: 
192.168.0.122
mode : sta(18:fe:34:9b:2d:5b) + softAP(1a:fe:34:9b:2d:5b)
add if1
Exception (0):
epc1=0x402061cc epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000

ctx: sys 
sp: 3ffffbf0 end: 3fffffb0 offset: 01a0

>>>stack>>>
3ffffd90:  400043f0 00000030 00000019 ffffffff  
3ffffda0:  400044ab 3fffc718 3ffffe90 08000000  
3ffffdb0:  60000200 08000000 00000003 00000000  
3ffffdc0:  0000ffff 00000001 04000002 0007e000  
3ffffdd0:  3fff3b08 0000007e 3fff1b54 00000030  
3ffffde0:  400044ab 3fffc718 3ffffed0 08000000  
3ffffdf0:  60000200 08000000 00000003 00000000  
3ffffe00:  0000ffff 00000001 04000002 0007d000  
3ffffe10:  3fff3b08 0000007d 3fff1b54 00000030  
3ffffe20:  40101b49 00000008 00000008 00000020  
3ffffe30:  8ed91c6b 30fdb9dd c6ce2cd0 3a43a42f  
3ffffe40:  3fff39d8 00000001 402442e1 3fff3970  
3ffffe50:  3fff38d0 00000010 60000600 00000020  
3ffffe60:  4023b908 3fff3a18 3fff3994 40244217  
3ffffe70:  4023b2cc 4023c622 3fff0e40 3fff3800  
3ffffe80:  3ffffec8 00000010 4023c7c5 3fff0380  
3ffffe90:  00000002 4000410f 60000600 3fff34a0  
3ffffea0:  3fffc718 40004a3c 0000007e 3fff3b08  
3ffffeb0:  3fffc718 40101954 00000378 0007f000  
3ffffec0:  0000007e 40212687 00000378 0000007f  
3ffffed0:  00001000 4021271d 3fff1b54 0000007f  
3ffffee0:  0000007d 00000064 0007e000 3fff1b54  
3ffffef0:  ffffff01 55aa55aa 0000007f 0000001c  
3fffff00:  0000001c 00000052 00000050 0000007f  
3fffff10:  40212b29 3ffec4c0 00000001 3ffec38b  
3fffff20:  00000001 3ffec3ab 40212c2f 3ffec4c0  
3fffff30:  00000001 3ffec38b 00000064 3fff1a44  
3fffff40:  3fff1c10 3ffec3ec 00000001 4021169b  
3fffff50:  3ffec380 00000000 3ffec4b0 60000600  
3fffff60:  3ffec3ab 40211689 00000003 ffffffff  
3fffff70:  40211405 3ffec374 3ffec320 009c213d  
3fffff80:  4021144a 3fffdab0 00000000 3fffdcb0  
3fffff90:  3ffec348 3ffecbd0 00000005 40201795  
3fffffa0:  40000f49 40000f49 3fffdab0 40000f49  
<<<stack<<<"!Hb�SH���/

not same behavior with 1.6.5-1084-ga39ce29

sorry do not know what to do to help to debug more

igrr · 2015-09-15T07:26:36Z

I think switching between STA and AP_STA is due to a bug in this line:
https://github.com/esp8266/Arduino/blame/esp8266/hardware/esp8266com/esp8266/libraries/ESP8266WiFi/src/ESP8266WiFi.cpp#L50
It has to be _useApMode = (m & WIFI_AP);

The code in ESP8266WiFi.cpp is getting unnecessary complicated and full of quirks such as this one. I'm going to clean up this part of the library and add some documentation as well.

luc-github · 2015-09-15T08:04:51Z

@igrr your are the best - I did the modification and now it loop as STA and even does not crash
also some output disappear :

mode : sta(18:fe:34:9b:2d:5b) does not appear any more

Here the new output

Connecting to dlink

WiFi connected
IP address: 
192.168.0.102
sl
f 0, Mode : 1
scandone
usl
sul 7 0
reconnect
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/11097906
wifi evt: 1

f -180, Mode : 1
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 4
pm open phy_2,type:2 0 0

connected with dlink, channel 1
wifi evt: 0

dhcp client start...
cnt 
chg_B:-120
Mode : 1
Restart 
chg_B:-60
state: 5 -> 0 (0)
rm 0
pm close 7 0 0/1650680
wifi evt: 1

del if0
usl
sul 0 0
bB���SH���/

Thanks a lot and sorry not being efficient finding root cause - I should saw it

igrr · 2015-09-15T09:41:25Z

Regarding free memory size reduction, so far i was able to track down 2495 bytes in .data/.rodata/.bss which are related to TLS library:

CSWTCH$39 00000028
CSWTCH$83 00000010
CSWTCH$88 00000054
PADDING 00000040
PI_SUBST 00000100
Rcon 0000001e
_ZL11INADDR_NONE 00000008
_ZN10SSLContext15_ssl_ctx_refcntE 00000004
_ZN10SSLContext8_ssl_ctxE 00000004
_ZTV16WiFiClientSecure 00000040
aes_isbox 00000100
aes_sbox 00000100
begins 00000010
cipher_info 00000050
column$2770 00000004
default_certificate$3153 000001db
default_private_key$3151 00000261
ends 00000010
entropy_pool 00000020
g_cert_request 00000008
g_chg_cipher_spec_pkt 00000001
g_hello_done 00000004
g_hello_request 00000004
hex_finish 00000004
hex_index 00000004
last$3694 00000004
map 00000080
sig_oid_prefix 00000008
sig_sha1WithRSAEncrypt 00000005
sig_subject_alt_name 00000003
ssl_prot_prefs 00000004
unsupported_str 00000004

Things like default_certificate, default_private_key and PI_SUBST should be easy to get rid of, and I'll also take a look at enabling -fdata-sections -Wl,-gc-sections (there is another open issue about that).

luc-github · 2015-09-15T10:22:41Z

I guess the issue has some side effect like crashing at some restart and some memory not released and so a decrease of free memory.

since I use the temporary fix, memory is average 21.5K in my project when it was 27k with previous staging, so it is not a memory leak but a static loss like the one you mention due to TLS

Thanks again for your help

igrr added a commit that referenced this issue Sep 15, 2015

Temporary fix for #780

989eeb5

luc-github mentioned this issue Sep 16, 2015

Some time ESP.restart, goes KAPUT, :) #793

Closed

igrr closed this as completed Sep 28, 2015

igrr added a commit that referenced this issue Oct 29, 2015

Temporary fix for #780

c528a44

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

1.6.5-1106-g8253b82 version has leak memory ? #780

1.6.5-1106-g8253b82 version has leak memory ? #780

luc-github commented Sep 14, 2015

igrr commented Sep 14, 2015

ghost commented Sep 14, 2015

igrr commented Sep 14, 2015

luc-github commented Sep 14, 2015

sdrsdr commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 14, 2015

ghost commented Sep 14, 2015

igrr commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 15, 2015

igrr commented Sep 15, 2015

luc-github commented Sep 15, 2015

igrr commented Sep 15, 2015

luc-github commented Sep 15, 2015

1.6.5-1106-g8253b82 version has leak memory ? #780

1.6.5-1106-g8253b82 version has leak memory ? #780

Comments

luc-github commented Sep 14, 2015

igrr commented Sep 14, 2015

ghost commented Sep 14, 2015

igrr commented Sep 14, 2015

luc-github commented Sep 14, 2015

sdrsdr commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 14, 2015

ghost commented Sep 14, 2015

igrr commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 14, 2015

luc-github commented Sep 15, 2015

igrr commented Sep 15, 2015

luc-github commented Sep 15, 2015

igrr commented Sep 15, 2015

luc-github commented Sep 15, 2015