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

WiFiClientSecure.connect crash after several POST requests #4569

Closed
telliottosceola opened this issue Mar 26, 2018 · 20 comments
Closed

WiFiClientSecure.connect crash after several POST requests #4569

telliottosceola opened this issue Mar 26, 2018 · 20 comments

Comments

@telliottosceola
Copy link

telliottosceola commented Mar 26, 2018

I have an application where post requests are made to an HTTPS server repeatedly. After several requests, generally 100-200 or so my application crashes. I have debugging enabled for SSL so I can see what is going on there. It seems to crash right after Server Hello Done(14) every time. I have also Decoded the exception. Here is my code which I have simplified as much as possible:

#include <WiFiServerSecure.h>
#include <WiFiClientSecure.h>
#include <ESP8266WiFi.h>
#include <ESP8266WiFiMulti.h>
#include <WiFiUdp.h>
#include <ESP8266WiFiType.h>
#include <ESP8266WiFiAP.h>
#include <WiFiClient.h>
#include <WiFiServer.h>
#include <ESP8266WiFiScan.h>
#include <ESP8266WiFiGeneric.h>
#include <ESP8266WiFiSTA.h>

unsigned long wifiConnectTimeout = 5000;
WiFiClientSecure client;

const char* host = "univagohealthcare.com";
int httpsPort = 443;
const char* fingerprint = "D9 B3 32 51 E5 2A 45 A7 1F 1D 93 E8 07 75 DF 7A 04 63 6E E6";

char* httpRequestContent = "POST /api/circuit_reboot_check HTTP/1.0\r\n"
    "User-Agent: MatrixSSL/ 3.7.2-OPEN \r\n"
    "Host: univagohealthcare.com\r\n"
    "Accept: */*\r\n"
    "Content-Type: text/html\r\n"
    "Content-Length: 132\r\n\r\n{\"event_type\":\"INTERVAL\",\"event_reason\":\"Check In\",\"device_id\":\"e5:a1:36:43:4f:e0\",\"ssid\":\"Travis-WiFi\",\"input\":\"open\",\"interval\":5}";

int requests = 0;

void setup() {
  // put your setup code here, to run once:
  WiFi.begin("Travis-WiFi", "*********");
  Serial.begin(115200);
  Serial.print("Connecting");
  
}

void loop() {

  while(WiFi.status() != WL_CONNECTED){
    Serial.print('.');
    delay(500);
  }
  Serial.print("Requests: ");
  Serial.println(requests);
  
  // put your main code here, to run repeatedly:
  if(WiFi.status() == WL_CONNECTED){
    Serial.println("Sending request");
    if(!client.connect(host, httpsPort)){
      Serial.println("server connection failed");
      delay(1000);
      return;
    }
    if(!client.verify(fingerprint, host)){
      Serial.println("Cannot verify Server");
      delay(1000);
      return;
    }
    client.print(httpRequestContent);
    while(client.connected()){
      if(client.available()){
        String line = client.readStringUntil('\n');
        Serial.println(line);
      }
    }
    requests++;
  }
}

Here is the decoded Exception on crash:

Decoding 31 results
0x4021952a: more_comps at crypto/bigint.c line 672
0x40219724: alloc at crypto/bigint.c line 672
0x40100980: realloc at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/umm_malloc/umm_malloc.c line 1720
0x40219a3d: regular_multiply at crypto/bigint.c line 672
0x4021a0b9: bi_square at crypto/bigint.c line 1016
0x4021a577: bi_barrett at crypto/bigint.c line 1289
0x4021a7cc: bi_mod_power at crypto/bigint.c line 1414
0x402195d0: trim at crypto/bigint.c line 672
0x4021b955: RSA_public at crypto/rsa.c line 254
:  (inlined by) RSA_encrypt at crypto/rsa.c line 288
0x40216650: send_client_key_xchg at ssl/tls1_clnt.c line 409
0x40216ae5: do_clnt_handshake at ssl/tls1_clnt.c line 123
0x402144ad: DISPLAY_STATE at ssl/tls1.c line 2007
0x4020f70d: pbuf_free_LWIP2 at /local/users/gauchard/arduino/arduino_esp8266/origin/tools/sdk/lwip2/builder/lwip2-src/src/core/pbuf.c line 1306
0x40246884: sleep_reset_analog_rtcreg_8266 at ?? line ?
0x40204a58: __yield at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/core_esp8266_main.cpp line 57
0x40216458: do_handshake at ssl/tls1.c line 2007
:  (inlined by) basic_read at ssl/tls1.c line 1483
0x40216834: do_client_connect at ssl/tls1_clnt.c line 168
0x401007ac: malloc at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/umm_malloc/umm_malloc.c line 1668
0x402031d0: SSLContext::_delete_shared_SSL(SSL_*) at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x402165c0: ssl_read at ssl/tls1.c line 2007
0x40203bb9: SSLContext::connect(ClientContext*, char const*, unsigned int) at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x402049e0: esp_yield at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/core_esp8266_main.cpp line 57
0x4020136f: delay at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/core_esp8266_wiring.c line 51
0x40203e07: WiFiClientSecure::_connectSSL(char const*) at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x40203ead: WiFiClientSecure::connect(char const*, unsigned short) at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x40107478: sntp_get_current_timestamp at ?? line ?
0x40107478: sntp_get_current_timestamp at ?? line ?
0x402021e9: loop at /Users/traviselliott/Documents/Arduino/Yorktel_post_simpl_test/Yorktel_post_simpl_test.ino line 51
0x402041b0: Print::print(char const*) at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/Print.cpp line 99
0x40204a2c: loop_wrapper at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/core_esp8266_main.cpp line 57
0x40100a2c: cont_norm at /Users/traviselliott/Library/Arduino15/packages/esp8266/hardware/esp8266/2.4.1/cores/esp8266/cont.S line 109

Here is the log on the last successful transmission and the subsequent transmission after that which crashed:

Requests: 210
Sending request
State:	sending Client Hello (1)
State:	receiving Server Hello (2)
State:	receiving Certificate (11)
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		univagohealthcare.com
Organization (O):		<Not Part Of Certificate>
Organizational Unit (OU):	Domain Control Validated
Basic Constraints:		critical, CA:FALSE, pathlen:10000
Key Usage:			critical, Digital Signature, Key Encipherment
Subject Alt Name:		univagohealthcare.com www.univagohealthcare.com 
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		Go Daddy Secure Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Organizational Unit (OU):	http://certs.godaddy.com/repository/
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Not Before:			Tue Mar 28 17:03:00 2017
Not After:			Wed Mar 28 17:03:00 2018
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		Go Daddy Secure Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Organizational Unit (OU):	http://certs.godaddy.com/repository/
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Basic Constraints:		critical, CA:TRUE, pathlen:10000
Key Usage:			critical, Key Cert Sign, CRL Sign
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		Go Daddy Root Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Not Before:			Tue May  3 07:00:00 2011
Not After:			Sat May  3 07:00:00 2031
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		Go Daddy Root Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Basic Constraints:		critical, CA:TRUE, pathlen:10000
Key Usage:			critical, Key Cert Sign, CRL Sign
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Not Before:			Wed Jan  1 07:00:00 2014
Not After:			Fri May 30 07:00:00 2031
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Basic Constraints:		CA:TRUE, pathlen:10000
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Not Before:			Tue Jun 29 17:06:20 2004
Not After:			Thu Jun 29 17:06:20 2034
RSA bitsize:			2048
Sig Type:			SHA1
State:	receiving Server Hello Done (14)
State:	sending Client Key Exchange (16)
State:	sending Finished (16)
State:	receiving Finished (16)
HTTP/1.1 200 OK

Content-Type: application/json; charset=utf-8

Connection: close

Status: 200 OK

Cache-Control: no-cache, no-store

Strict-Transport-Security: max-age=15552000; includeSubDomains

Pragma: no-cache

X-XSS-Protection: 1; mode=block

X-Request-Id: 9db8207d-b8cc-488c-8e63-0e7a76e9463c

X-Runtime: 0.008300

X-Frame-Options: SAMEORIGIN

X-Content-Type-Options: nosniff

Expires: Fri, 01 Jan 1990 00:00:00 GMT

Date: Mon, 26 Mar 2018 16:25:43 GMT

X-Powered-By: Phusion Passenger 5.1.4

Server: nginx/1.10.3 + Phusion Passenger 5.1.4



{"result":"on"}
Requests: 211
Sending request
State:	sending Client Hello (1)
State:	receiving Server Hello (2)
State:	receiving Certificate (11)
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		univagohealthcare.com
Organization (O):		<Not Part Of Certificate>
Organizational Unit (OU):	Domain Control Validated
Basic Constraints:		critical, CA:FALSE, pathlen:10000
Key Usage:			critical, Digital Signature, Key Encipherment
Subject Alt Name:		univagohealthcare.com www.univagohealthcare.com 
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		Go Daddy Secure Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Organizational Unit (OU):	http://certs.godaddy.com/repository/
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Not Before:			Tue Mar 28 17:03:00 2017
Not After:			Wed Mar 28 17:03:00 2018
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		Go Daddy Secure Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Organizational Unit (OU):	http://certs.godaddy.com/repository/
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Basic Constraints:		critical, CA:TRUE, pathlen:10000
Key Usage:			critical, Key Cert Sign, CRL Sign
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		Go Daddy Root Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Not Before:			Tue May  3 07:00:00 2011
Not After:			Sat May  3 07:00:00 2031
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		Go Daddy Root Certificate Authority - G2
Organization (O):		GoDaddy.com, Inc.
Location (L):			Scottsdale
Country (C):			US
State (ST):			Arizona
Basic Constraints:		critical, CA:TRUE, pathlen:10000
Key Usage:			critical, Key Cert Sign, CRL Sign
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Not Before:			Wed Jan  1 07:00:00 2014
Not After:			Fri May 30 07:00:00 2031
RSA bitsize:			2048
Sig Type:			SHA256
=== CERTIFICATE ISSUED TO ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Basic Constraints:		CA:TRUE, pathlen:10000
=== CERTIFICATE ISSUED BY ===
Common Name (CN):		<Not Part Of Certificate>
Organization (O):		The Go Daddy Group, Inc.
Organizational Unit (OU):	Go Daddy Class 2 Certification Authority
Country (C):			US
Not Before:			Tue Jun 29 17:06:20 2004
Not After:			Thu Jun 29 17:06:20 2034
RSA bitsize:			2048
Sig Type:			SHA1
State:	receiving Server Hello Done (14)
Fatal exception 29(StoreProhibitedCause):
epc1=0x4020c4ea, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000004, depc=0x00000000

Exception (29):
epc1=0x4020c4ea epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000004 depc=0x00000000

ctx: cont 
sp: 3fff00d0 end: 3fff05c0 offset: 01a0

>>>stack>>>
3fff0270:  00820000 00000082 3fff8ecc 4021952a  
3fff0280:  00000214 3fff8f64 3fff8ecc 40219724  
3fff0290:  3fff3964 00000214 3fff248c 40100980  
3fff02a0:  00000114 00001900 00000320 00000043  
3fff02b0:  00000040 00000082 3fff6b64 40219a3d  
3fff02c0:  00800000 00000080 00000000 00000041  
3fff02d0:  0002a990 0000003f 3fff80a4 00000041  
3fff02e0:  3fff3544 3fff6b64 3fff80a4 3fff8a2c  
3fff02f0:  3fff3a68 ffffffff 3fff8f64 4021a0b9  
3fff0300:  00000040 3fff8f64 3fff6b64 3fff8f64  
3fff0310:  00000040 3fff8f64 3fff6b64 4021a577  
3fff0320:  3fff71cc 0000003f 6374e630 00000001  
3fff0330:  3fff8f64 3fff6b44 3fff6b64 00000001  
3fff0340:  00000010 3fff8f64 0000000f 4021a7cc  
3fff0350:  3fff80a4 3fff4e84 0000000f 00000001  
3fff0360:  00000001 3fff6d34 3fffa389 402195d0  
3fff0370:  00000100 3fff9f34 3fffa387 00000000  
3fff0380:  00000100 3fff9f34 3fffa387 4021b955  
3fff0390:  3fff03c0 00000000 000000d0 00000030  
3fff03a0:  293ae808 3fff6d40 000012bb 00000004  
3fff03b0:  3fffa381 3fff1c9c 3fffa381 40216650  
3fff03c0:  1fca0303 3dd42a56 d1183edf 48fa3deb  
3fff03d0:  31142dc3 bc264dac c3e9927e e8119120  
3fff03e0:  c36932a3 881d00b1 0b050cc2 e8081f8a  
3fff03f0:  3fffa381 00000004 3fff1c9c 40216ae5  
3fff0400:  3fff0420 3fff0420 00000004 402144ad  
3fff0410:  3ffe91fc 00000017 3fffa224 4020f70d  
3fff0420:  3fff0440 3fff0458 40246884 00000000  
3fff0430:  00000026 00000090 00000064 40204a58  
3fff0440:  76726553 48207265 6f6c6c65 00000004  
3fff0450:  3fffa381 00000004 3fff1c9c 00000004  
3fff0460:  3fffa381 00000004 3fff1c9c 40216458  
3fff0470:  6612ec57 000009df 3ffef548 0000002c  
3fff0480:  00000061 3fffa381 3fff1c9c 40216834  
3fff0490:  00000015 3fffa3b4 00000200 401007ac  
3fff04a0:  3fff04f8 0000000e 00000010 3fff9e5c  
3fff04b0:  402031d0 3fff1c9c 00000020 01000000  
3fff04c0:  3fff04f8 0073cde5 3fff1c9c 402165c0  
3fff04d0:  3fff1c9c 3fff5a8c 3fff9e5c 3fff9e5c  
3fff04e0:  3fff9984 0073cde5 3fff176c 40203bb9  
3fff04f0:  3fff1c9c 3fff5a8c 402049e0 3ffef5a0  
3fff0500:  00003a98 00003a98 00003a98 4020136f  
3fff0510:  3ffef304 00000000 3fff9984 3ffef568  
3fff0520:  000001bb 3ffe8b8e 3ffef304 40203e07  
3fff0530:  000001bb 3ffef304 3ffe8b8e 3ffef568  
3fff0540:  000001bb 3ffef304 3ffe8b8e 40203ead  
3fff0550:  40107478 6200bcc0 40107478 6200bcc0  
3fff0560:  3ffef300 3ffef324 3ffef568 402021e9  
3fff0570:  00000000 00000000 00000000 feefeffe  
3fff0580:  3ffef304 0000001c 3ffef568 402041b0  
3fff0590:  00000000 00000000 00000001 3ffef594  
3fff05a0:  3fffdad0 00000000 3ffef58c 40204a2c  
3fff05b0:  feefeffe feefeffe 3ffef5a0 40100a2c  
<<<stack<<<

 ets Jan  8 2013,rst cause:4, boot mode:(1,6)

wdt reset

 ets Jan  8 2013,rst cause:4, boot mode:(1,6)

wdt reset

Any insight into the possible causes of these crashes would be greatly appreciated. I just cannot imagine what is causing these crashes.

@debsahu
Copy link

debsahu commented Mar 31, 2018

I see something like this as well. A few WiFiClientSecure request go through but 3rd or 4th one I see the same error as you. If I convert the server to not use SSL, WiFiClient sends same data without issues. Usually you will be asked to enable "SSL" debugging in Arduino IDE and post debugging results here as well.

@jo-russ
Copy link

jo-russ commented Apr 1, 2018

Same here.
There's somewhere a memory leak in connection handling routines.
Tested all boards > 2.0.0 It works correctly only in v2.2.0 though, so consider downgrading until this is solved.

@telliottosceola
Copy link
Author

Hi @jo-russ,

Which library are you referring to? WiFiClientSecure? I show my installed version of that library is 1.0.0 in the Arduino IDE.

@debsahu,
I had SSL debugging enabled and have posted the output above at the time of the crash.

Thanks everyone.

@jo-russ
Copy link

jo-russ commented Apr 2, 2018

@telliottosceola
Not the library itself, the esp8266 arduino board / bundle.
With version 2.2.0 my code is running flawlessly for days now (free heap size stabilized) while on 2.3.x and 2.4.x it gets eaten away and in the end crashes.
IIRC with version 2.1.x it managed to make 2 consecutive (and that's probably why it worked) connections then for any other attempt - failure.

@telliottosceola
Copy link
Author

Hi @jo-russ
Just tried running on 2.2. My code posted above instantly fails on client.connect. Any ideas? I'll post the debug logs soon. Do you see anything in the code above that would cause that?

@comino
Copy link
Contributor

comino commented Apr 11, 2018

I can confirm some kind of memory leak, even with latest git version ( as there was a similar issue with WiFiClient fixed versus 2.4 at 95b1348 ). I observe a leakage of around 100B per request, which adds up to @telliottosceola reported crash after 100-200 requests.

I will have a look and report in case Im able to get more information.

@jo-russ
Copy link

jo-russ commented Apr 12, 2018

@telliottosceola Can't see anything out of ordinary. The only difference I see from what I have is "Connection: close" header in request and httpsPort as "const int"
I'd try to remove all unnecessary included libraries and see if this helps. Does the httpsclient example works for you?
Check up on memory available, try disabling ssl debugging etc...

@bhaskar-anil429
Copy link

@earlephilhower tried the new latest git version as well, still its crashing after several requests.
@comino thank you for looking into this. let us now if you find any thing.

@earlephilhower
Copy link
Collaborator

(looks like I posted this in the PR and not the issue before, reposting)

I'm not seeing any leak per connection using a modified version of the script posted at the top here (to point to my public web server, and do GET instead of POST, but nothing materially different). I'm running with debug level "None", not even the larger mem free option of NoAssert+NDEBUG///

#include <WiFiServerSecure.h>
#include <WiFiClientSecure.h>
#include <ESP8266WiFi.h>
#include <ESP8266WiFiMulti.h>
#include <WiFiUdp.h>
#include <ESP8266WiFiType.h>
#include <ESP8266WiFiAP.h>
#include <WiFiClient.h>
#include <WiFiServer.h>
#include <ESP8266WiFiScan.h>
#include <ESP8266WiFiGeneric.h>
#include <ESP8266WiFiSTA.h>

unsigned long wifiConnectTimeout = 5000;
WiFiClientSecure client;

const char* host = "ziplabel.com";
int httpsPort = 443;
const char* fingerprint = "37 00 53 F1 10 64 F2 41 99 E6 84 07 C5 71 3F 3D 53 25 91 1E";

char* httpRequestContent = "GET /index.html HTTP/1.0\r\n"
    "User-Agent: MatrixSSL/ 3.7.2-OPEN \r\n"
    "Host: ziplabel.com\r\n"
    "Accept: */*\r\n"
    "\r\n";

int requests = 0;

void setup() {
  // put your setup code here, to run once:
  WiFi.begin("*", "*");
  Serial.begin(115200);
  Serial.print("Connecting");

}

void loop() {
  Serial.printf("Free: %d\n", ESP.getFreeHeap());
  while(WiFi.status() != WL_CONNECTED){
    Serial.print('.');
    delay(500);
  }
  Serial.print("Requests: ");
  Serial.println(requests);

  // put your main code here, to run repeatedly:
  if(WiFi.status() == WL_CONNECTED){
    Serial.println("Sending request");
    if(!client.connect(host, httpsPort)){
      Serial.println("server connection failed");
      delay(1000);
      return;
    }
    if(!client.verify(fingerprint, host)){
      Serial.println("Cannot verify Server");
      delay(1000);
      return;
    }
    client.print(httpRequestContent);
    while(client.connected()){
      if(client.available()){
        String line = client.readStringUntil('\n');
        Serial.println(line);
      }
    }
    requests++;
  }
}

Mem free stabilized at 31056 bytes after 2 or 3 cycles and is now at ~400 loops without any change.

</BODY>
</HTML>
Free: 31056
Requests: 164
Sending request
HTTP/1.1 200 OK
Date: Thu, 12 Apr 2018 15:25:04 GMT
Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips PHP/5.4.16
Last-Modified: Tue, 01 

@bhaskar-anil429
Copy link

bhaskar-anil429 commented Apr 12, 2018

it just crashed after 288 request.
i am going to run a new instance and will print the memory info.
so far it made 25 requests
started with free -- 21992
memory after 8 requests -- 21600
memory after 25 requests -- 20600

`{"result":"on"}
Free: 21992
Requests: 1
Sending request
HTTP/1.1 200 OK

Content-Type: application/json; charset=utf-8

Connection: close

Status: 200 OK

Cache-Control: no-cache, no-store

Strict-Transport-Security: max-age=15552000; includeSubDomains

Pragma: no-cache

X-XSS-Protection: 1; mode=block

X-Request-Id: f5999b09-d58b-4a9f-b364-1e9de325ceeb

X-Runtime: 0.005893

X-Frame-Options: SAMEORIGIN

X-Content-Type-Options: nosniff

Expires: Fri, 01 Jan 1990 00:00:00 GMT

Date: Thu, 12 Apr 2018 15:52:36 GMT

X-Powered-By: Phusion Passenger 5.1.4

Server: nginx/1.10.3 + Phusion Passenger 5.1.4

`

`{"result":"on"}
Free: 20600
Requests: 25
Sending request
HTTP/1.1 200 OK

Content-Type: application/json; charset=utf-8

Connection: close

Status: 200 OK

Cache-Control: no-cache, no-store

Strict-Transport-Security: max-age=15552000; includeSubDomains

Pragma: no-cache

X-XSS-Protection: 1; mode=block

X-Request-Id: dff3c8ca-0f61-41fc-b384-de8a4c2935d2

X-Runtime: 0.007524

X-Frame-Options: SAMEORIGIN

X-Content-Type-Options: nosniff

Expires: Fri, 01 Jan 1990 00:00:00 GMT

Date: Thu, 12 Apr 2018 15:58:57 GMT

X-Powered-By: Phusion Passenger 5.1.4

Server: nginx/1.10.3 + Phusion Passenger 5.1.4`

@telliottosceola
Copy link
Author

telliottosceola commented Apr 12, 2018

I'm running the same test here as well. I slightly modified the code so the http response does not print to the serial monitor(just commented out Serial.println(line);
I also added the print for getFreeHeap(). I appear to be loosing exactly 56 bytes per request. It is very consistent. Here is the current version of code I am running followed by my serial monitor output thus far.

#include <WiFiClientSecure.h>
#include <ESP8266WiFi.h>

unsigned long wifiConnectTimeout = 5000;
WiFiClientSecure client;

const char* host = "univagohealthcare.com";
int httpsPort = 443;
const char* fingerprint = "CE 01 11 1A A1 2E 18 65 F5 9D 65 3B C3 3B A0 73 7F 79 85 B9";

char* httpRequestContent = "POST /api/circuit_reboot_check HTTP/1.0\r\n"
    "User-Agent: MatrixSSL/ 3.7.2-OPEN \r\n"
    "Host: univagohealthcare.com\r\n"
    "Accept: */*\r\n"
    "Content-Type: text/html\r\n"
    "Content-Length: 132\r\n\r\n{\"event_type\":\"INTERVAL\",\"event_reason\":\"Check In\",\"device_id\":\"e5:a1:36:43:4f:e0\",\"ssid\":\"Travis-WiFi\",\"input\":\"open\",\"interval\":5}";

int requests = 0;

void setup() {
  // put your setup code here, to run once:
  WiFi.begin("*", "*");
  Serial.begin(115200);
  Serial.print("Connecting");
  
}

void loop() {
  Serial.printf("Free: %d\n", ESP.getFreeHeap());

  while(WiFi.status() != WL_CONNECTED){
    Serial.print('.');
    delay(500);
  }
  Serial.print("Requests: ");
  Serial.println(requests);
  
  // put your main code here, to run repeatedly:
  if(WiFi.status() == WL_CONNECTED){
    Serial.println("Sending request");
    if(!client.connect(host, httpsPort)){
      Serial.println("server connection failed");
      delay(1000);
      return;
    }
    if(!client.verify(fingerprint, host)){
      Serial.println("Cannot verify Server");
      delay(1000);
      return;
    }
    client.print(httpRequestContent);
    while(client.connected()){
      if(client.available()){
        String line = client.readStringUntil('\n');
        //Serial.println(line);
      }
    }
    requests++;
  }
}

Serial monitor log thus far

Requests: 0
Sending request
Free: 22040
Requests: 1
Sending request
Free: 21984
Requests: 2
Sending request
Free: 21928
Requests: 3
Sending request
Free: 21872
Requests: 4
Sending request
Free: 21816
Requests: 5
Sending request
Free: 21760
Requests: 6
Sending request
Free: 21704
Requests: 7
Sending request
Free: 21648
Requests: 8
Sending request
Free: 21592
Requests: 9
Sending request
Free: 21536
Requests: 10
Sending request
Free: 21480
Requests: 11
Sending request
Free: 21424
Requests: 12
Sending request
Free: 21368
Requests: 13
Sending request
Free: 21312
Requests: 14
Sending request
Free: 21256
Requests: 15
Sending request
Free: 21200
Requests: 16
Sending request
Free: 21144
Requests: 17
Sending request
Free: 21088
Requests: 18
Sending request
Free: 21032
Requests: 19
Sending request
Free: 20976
Requests: 20
Sending request
Free: 20920
Requests: 21
Sending request
Free: 20864
Requests: 22
Sending request
Free: 20808
Requests: 23
Sending request
Free: 20752
Requests: 24
Sending request

@telliottosceola
Copy link
Author

telliottosceola commented Apr 12, 2018

Also @earlephilhower I want to say thank you very much for your input thus far. You are more than welcome to run a test using the exact code I have posted above so it makes post requests to our server. This way you can run a test identical to ours. Only difference would be your hardware. I would be very curious to see if you see the same small memory leak we are seeing.

@earlephilhower
Copy link
Collaborator

Your first 2 lines say what's happening:

Requests: 0
Sending request
Free: 22040

So the GET is well behaved and closes the connection, so the next loop the memory is free (hence 30KB avail). Seems like the PUT isn't closing the connection (probably no Content-Length in the reply and the server is trying to keep the link open with a Connection: keep-alive (hence 20KB avail).

For a quick fix I suggest moving the WiFiClientSecure object into the loop() context which should ensure it's closed at the end of a loop (or calling client.stop()). The longer fix is to see what happens to HTTPS and HTTP connections when you call connect() on an object that already has a connection open.

@telliottosceola
Copy link
Author

telliottosceola commented Apr 12, 2018

Hi @earlephilhower
Success! I actually already added client.stop to the end of the loop after the server before you posted. I had also added client.flush() as well although never in my experience has flush ever done anything for anyone.
The magic key was declaring the WiFiClientSecure object inside the loop. I honestly have no idea how or why that would make a difference but I took your word for it and it works. Here is my current code:

#include <WiFiClientSecure.h>
#include <ESP8266WiFi.h>

unsigned long wifiConnectTimeout = 5000;


const char* host = "univagohealthcare.com";
int httpsPort = 443;
const char* fingerprint = "CE 01 11 1A A1 2E 18 65 F5 9D 65 3B C3 3B A0 73 7F 79 85 B9";

char* httpRequestContent = "POST /api/circuit_reboot_check HTTP/1.0\r\n"
    "User-Agent: MatrixSSL/ 3.7.2-OPEN \r\n"
    "Host: univagohealthcare.com\r\n"
    "Accept: */*\r\n"
    "Content-Type: text/html\r\n"
    "Content-Length: 132\r\n\r\n{\"event_type\":\"INTERVAL\",\"event_reason\":\"Check In\",\"device_id\":\"e5:a1:36:43:4f:e0\",\"ssid\":\"Travis-WiFi\",\"input\":\"open\",\"interval\":5}";

int requests = 0;

void setup() {
  // put your setup code here, to run once:
  WiFi.begin("*", "*");
  Serial.begin(115200);
  Serial.print("Connecting");
  
}

void loop() {
  WiFiClientSecure client;
  while(WiFi.status() != WL_CONNECTED){
    Serial.print('.');
    delay(500);
  }
  Serial.println();
  int startHeap = ESP.getFreeHeap();
  int heap = startHeap;
  Serial.printf("Free at start of request %i: %d\n", requests, ESP.getFreeHeap());
  
  Serial.printf("Free after WiFi check: %d, lost: %i\n", ESP.getFreeHeap(), heap - ESP.getFreeHeap());
  heap = ESP.getFreeHeap();
  
  // put your main code here, to run repeatedly:
  if(WiFi.status() == WL_CONNECTED){
    if(!client.connect(host, httpsPort)){
      Serial.println("server connection failed");
      delay(1000);
      return;
    }
    Serial.printf("Free after client.connect check: %d, lost: %i\n", ESP.getFreeHeap(), heap - ESP.getFreeHeap());
    heap = ESP.getFreeHeap();
    if(!client.verify(fingerprint, host)){
      Serial.println("Cannot verify Server");
      delay(1000);
      return;
    }
    Serial.printf("Free after client.verify check: %d, lost: %i\n", ESP.getFreeHeap(), heap - ESP.getFreeHeap());
    heap = ESP.getFreeHeap();
    client.print(httpRequestContent);
    Serial.printf("Free after client.print: %d, lost: %i\n", ESP.getFreeHeap(), heap - ESP.getFreeHeap());
    heap = ESP.getFreeHeap();
    int index = 0;
    while(client.connected()){
      if(client.available()){
        String line = client.readStringUntil('\n');
        Serial.printf("Free after read line %i: %d, lost: %i\n", index, ESP.getFreeHeap(), heap - ESP.getFreeHeap());
        heap = ESP.getFreeHeap();
        index++;
        //Serial.println(line);
      }
    }
    requests++;
  }
  Serial.printf("Client.available after disconnect = %i\n", client.available());
  client.flush();
  client.stop();
  
  int finishHeap = ESP.getFreeHeap();
  Serial.printf("Free at end of request %i: %d\n", requests, finishHeap);
  Serial.printf("Heap Memory lost: %i \n", startHeap - finishHeap);
  Serial.println();
  delay(5000);
}

And here's the the serial monitor log:

Connecting...
Free at start of request 0: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21608, lost: -688
Free after read line 1: 21704, lost: -96
Free after read line 2: 21720, lost: -16
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 1: 21784
Heap Memory lost: 20184 


Free at start of request 1: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21608, lost: -688
Free after read line 1: 21704, lost: -96
Free after read line 2: 21720, lost: -16
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 2: 21784
Heap Memory lost: 20184 


Free at start of request 2: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21496, lost: -576
Free after read line 1: 21592, lost: -96
Free after read line 2: 21720, lost: -128
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 3: 21784
Heap Memory lost: 20184 


Free at start of request 3: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21328, lost: -408
Free after read line 1: 21592, lost: -264
Free after read line 2: 21720, lost: -128
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 4: 21784
Heap Memory lost: 20184 


Free at start of request 4: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21552, lost: -632
Free after read line 1: 21592, lost: -40
Free after read line 2: 21720, lost: -128
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21728, lost: -8
Free after read line 12: 21728, lost: 0
Free after read line 13: 21728, lost: 0
Free after read line 14: 21728, lost: 0
Free after read line 15: 21728, lost: 0
Free after read line 16: 21760, lost: -32
Free after read line 17: 21760, lost: 0
Client.available after disconnect = 0
Free at end of request 5: 21784
Heap Memory lost: 20184 


Free at start of request 5: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21328, lost: -408
Free after read line 1: 21448, lost: -120
Free after read line 2: 21576, lost: -128
Free after read line 3: 21592, lost: -16
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21592, lost: -32
Free after read line 17: 21760, lost: -168
Client.available after disconnect = 0
Free at end of request 6: 21784
Heap Memory lost: 20184 


Free at start of request 6: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21608, lost: -688
Free after read line 1: 21704, lost: -96
Free after read line 2: 21720, lost: -16
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 7: 21784
Heap Memory lost: 20184 


Free at start of request 7: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21552, lost: -632
Free after read line 1: 21448, lost: 104
Free after read line 2: 21576, lost: -128
Free after read line 3: 21592, lost: -16
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21592, lost: -32
Free after read line 17: 21760, lost: -168
Client.available after disconnect = 0
Free at end of request 8: 21784
Heap Memory lost: 20184 


Free at start of request 8: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21608, lost: -688
Free after read line 1: 21704, lost: -96
Free after read line 2: 21720, lost: -16
Free after read line 3: 21736, lost: -16
Free after read line 4: 21704, lost: 32
Free after read line 5: 21688, lost: 16
Free after read line 6: 21720, lost: -32
Free after read line 7: 21704, lost: 16
Free after read line 8: 21688, lost: 16
Free after read line 9: 21720, lost: -32
Free after read line 10: 21720, lost: 0
Free after read line 11: 21704, lost: 16
Free after read line 12: 21704, lost: 0
Free after read line 13: 21704, lost: 0
Free after read line 14: 21704, lost: 0
Free after read line 15: 21704, lost: 0
Free after read line 16: 21736, lost: -32
Free after read line 17: 21760, lost: -24
Client.available after disconnect = 0
Free at end of request 9: 21784
Heap Memory lost: 20184 


Free at start of request 9: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21552, lost: -632
Free after read line 1: 21336, lost: 216
Free after read line 2: 21464, lost: -128
Free after read line 3: 21592, lost: -128
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21592, lost: -32
Free after read line 17: 21760, lost: -168
Client.available after disconnect = 0
Free at end of request 10: 21784
Heap Memory lost: 20184 


Free at start of request 10: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21184, lost: -264
Free after read line 1: 21448, lost: -264
Free after read line 2: 21576, lost: -128
Free after read line 3: 21592, lost: -16
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21616, lost: -56
Free after read line 17: 21760, lost: -144
Client.available after disconnect = 0
Free at end of request 11: 21784
Heap Memory lost: 20184 


Free at start of request 11: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21440, lost: -520
Free after read line 1: 21448, lost: -8
Free after read line 2: 21576, lost: -128
Free after read line 3: 21592, lost: -16
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21592, lost: -32
Free after read line 17: 21760, lost: -168
Client.available after disconnect = 0
Free at end of request 12: 21784
Heap Memory lost: 20184 


Free at start of request 12: 41968
Free after WiFi check: 41968, lost: 0
Free after client.connect check: 21592, lost: 20376
Free after client.verify check: 21592, lost: 0
Free after client.print: 20920, lost: 672
Free after read line 0: 21184, lost: -264
Free after read line 1: 21448, lost: -264
Free after read line 2: 21576, lost: -128
Free after read line 3: 21592, lost: -16
Free after read line 4: 21560, lost: 32
Free after read line 5: 21544, lost: 16
Free after read line 6: 21576, lost: -32
Free after read line 7: 21560, lost: 16
Free after read line 8: 21544, lost: 16
Free after read line 9: 21576, lost: -32
Free after read line 10: 21576, lost: 0
Free after read line 11: 21560, lost: 16
Free after read line 12: 21560, lost: 0
Free after read line 13: 21560, lost: 0
Free after read line 14: 21560, lost: 0
Free after read line 15: 21560, lost: 0
Free after read line 16: 21592, lost: -32
Free after read line 17: 21712, lost: -120
Client.available after disconnect = 0
Free at end of request 13: 21736
Heap Memory lost: 20232 


Free at start of request 13: 41920
Free after WiFi check: 41920, lost: 0
Free after client.connect check: 21544, lost: 20376
Free after client.verify check: 21544, lost: 0
Free after client.print: 20872, lost: 672
Free after read line 0: 21280, lost: -408
Free after read line 1: 21400, lost: -120
Free after read line 2: 21528, lost: -128
Free after read line 3: 21544, lost: -16
Free after read line 4: 21512, lost: 32
Free after read line 5: 21496, lost: 16
Free after read line 6: 21528, lost: -32
Free after read line 7: 21512, lost: 16
Free after read line 8: 21496, lost: 16
Free after read line 9: 21528, lost: -32
Free after read line 10: 21528, lost: 0
Free after read line 11: 21512, lost: 16
Free after read line 12: 21512, lost: 0
Free after read line 13: 21512, lost: 0
Free after read line 14: 21512, lost: 0
Free after read line 15: 21512, lost: 0
Free after read line 16: 21544, lost: -32
Free after read line 17: 21712, lost: -168
Client.available after disconnect = 0
Free at end of request 14: 21736
Heap Memory lost: 20184 


Free at start of request 14: 41920
Free after WiFi check: 41920, lost: 0
Free after client.connect check: 21544, lost: 20376
Free after client.verify check: 21544, lost: 0
Free after client.print: 20872, lost: 672
Free after read line 0: 21136, lost: -264
Free after read line 1: 21400, lost: -264
Free after read line 2: 21528, lost: -128
Free after read line 3: 21544, lost: -16
Free after read line 4: 21512, lost: 32
Free after read line 5: 21496, lost: 16
Free after read line 6: 21528, lost: -32
Free after read line 7: 21512, lost: 16
Free after read line 8: 21496, lost: 16
Free after read line 9: 21528, lost: -32
Free after read line 10: 21528, lost: 0
Free after read line 11: 21512, lost: 16
Free after read line 12: 21512, lost: 0
Free after read line 13: 21512, lost: 0
Free after read line 14: 21512, lost: 0
Free after read line 15: 21512, lost: 0
Free after read line 16: 21544, lost: -32
Free after read line 17: 21712, lost: -168
Client.available after disconnect = 0
Free at end of request 15: 21736
Heap Memory lost: 20184 


Free at start of request 15: 41920
Free after WiFi check: 41920, lost: 0
Free after client.connect check: 21544, lost: 20376
Free after client.verify check: 21544, lost: 0
Free after client.print: 20872, lost: 672
Free after read line 0: 21280, lost: -408
Free after read line 1: 21432, lost: -152
Free after read line 2: 21560, lost: -128
Free after read line 3: 21576, lost: -16
Free after read line 4: 21544, lost: 32
Free after read line 5: 21640, lost: -96
Free after read line 6: 21672, lost: -32
Free after read line 7: 21656, lost: 16
Free after read line 8: 21640, lost: 16
Free after read line 9: 21672, lost: -32
Free after read line 10: 21672, lost: 0
Free after read line 11: 21656, lost: 16
Free after read line 12: 21656, lost: 0
Free after read line 13: 21656, lost: 0
Free after read line 14: 21656, lost: 0
Free after read line 15: 21656, lost: 0
Free after read line 16: 21688, lost: -32
Free after read line 17: 21712, lost: -24
Client.available after disconnect = 0
Free at end of request 16: 21736
Heap Memory lost: 20184 


Free at start of request 16: 41920
Free after WiFi check: 41920, lost: 0
Free after client.connect check: 21544, lost: 20376
Free after client.verify check: 21544, lost: 0
Free after client.print: 20872, lost: 672
Free after read line 0: 21304, lost: -432
Free after read line 1: 21400, lost: -96
Free after read line 2: 21528, lost: -128
Free after read line 3: 21544, lost: -16
Free after read line 4: 21512, lost: 32
Free after read line 5: 21496, lost: 16
Free after read line 6: 21528, lost: -32
Free after read line 7: 21512, lost: 16
Free after read line 8: 21496, lost: 16
Free after read line 9: 21528, lost: -32
Free after read line 10: 21528, lost: 0
Free after read line 11: 21512, lost: 16
Free after read line 12: 21512, lost: 0
Free after read line 13: 21512, lost: 0
Free after read line 14: 21512, lost: 0
Free after read line 15: 21512, lost: 0
Free after read line 16: 21544, lost: -32
Free after read line 17: 21712, lost: -168
Client.available after disconnect = 0
Free at end of request 17: 21736
Heap Memory lost: 20184 


Free at start of request 17: 41920
Free after WiFi check: 41920, lost: 0
Free after client.connect check: 21544, lost: 20376
Free after client.verify check: 21544, lost: 0
Free after client.print: 20872, lost: 672
Free after read line 0: 21136, lost: -264
Free after read line 1: 21400, lost: -264
Free after read line 2: 21528, lost: -128
Free after read line 3: 21544, lost: -16
Free after read line 4: 21512, lost: 32
Free after read line 5: 21496, lost: 16
Free after read line 6: 21528, lost: -32
Free after read line 7: 21512, lost: 16
Free after read line 8: 21496, lost: 16
Free after read line 9: 21528, lost: -32
Free after read line 10: 21528, lost: 0
Free after read line 11: 21512, lost: 16
Free after read line 12: 21512, lost: 0
Free after read line 13: 21512, lost: 0
Free after read line 14: 21512, lost: 0
Free after read line 15: 21512, lost: 0
Free after read line 16: 21544, lost: -32

@telliottosceola
Copy link
Author

telliottosceola commented Apr 12, 2018

Just cleaned up the code and removed everything that was not required. Here is the minimal code that works successfully:

#include <WiFiClientSecure.h>
#include <ESP8266WiFi.h>

unsigned long wifiConnectTimeout = 5000;


const char* host = "univagohealthcare.com";
int httpsPort = 443;
const char* fingerprint = "CE 01 11 1A A1 2E 18 65 F5 9D 65 3B C3 3B A0 73 7F 79 85 B9";

char* httpRequestContent = "POST /api/circuit_reboot_check HTTP/1.0\r\n"
    "User-Agent: MatrixSSL/ 3.7.2-OPEN \r\n"
    "Host: univagohealthcare.com\r\n"
    "Accept: */*\r\n"
    "Content-Type: text/html\r\n"
    "Content-Length: 132\r\n\r\n{\"event_type\":\"INTERVAL\",\"event_reason\":\"Check In\",\"device_id\":\"e5:a1:36:43:4f:e0\",\"ssid\":\"Travis-WiFi\",\"input\":\"open\",\"interval\":5}";

int requests = 0;

void setup() {
  // put your setup code here, to run once:
  WiFi.begin("*", "*");
  Serial.begin(115200);
  Serial.print("Connecting");
  
}

void loop() {
  WiFiClientSecure client;
  while(WiFi.status() != WL_CONNECTED){
    Serial.print('.');
    delay(500);
  }
  Serial.println();
  int startHeap = ESP.getFreeHeap();

  Serial.printf("Free at start of request %i: %d\n", requests, startHeap);
  
  // put your main code here, to run repeatedly:
  if(WiFi.status() == WL_CONNECTED){
    if(!client.connect(host, httpsPort)){
      Serial.println("server connection failed");
      delay(1000);
      return;
    }

    if(!client.verify(fingerprint, host)){
      Serial.println("Cannot verify Server");
      delay(1000);
      return;
    }

    client.print(httpRequestContent);

    while(client.connected()){
      if(client.available()){
        String line = client.readStringUntil('\n');
      }
    }
    requests++;
  }
  
  int finishHeap = ESP.getFreeHeap();
  Serial.printf("Free at end of request %i: %d\n", requests, finishHeap);
  Serial.printf("Heap Memory lost: %i \n", startHeap - finishHeap);
  Serial.println();
}

And the serial monitor log:

Connecting..
Free at start of request 0: 42224
Free at end of request 1: 22040
Heap Memory lost: 20184 


Free at start of request 1: 42224
Free at end of request 2: 22040
Heap Memory lost: 20184 


Free at start of request 2: 42224
Free at end of request 3: 22040
Heap Memory lost: 20184 


Free at start of request 3: 42224
Free at end of request 4: 22040
Heap Memory lost: 20184 


Free at start of request 4: 42224
Free at end of request 5: 22040
Heap Memory lost: 20184 


Free at start of request 5: 42224
Free at end of request 6: 22040
Heap Memory lost: 20184 


Free at start of request 6: 42224

@telliottosceola
Copy link
Author

@earlephilhower,

Well... After letting the code run for a bit I found that I am loosing 48 bytes from heap memory "every once in a while". It does not happen after a consistent number of requests it seems to be random at the moment. In this test the first time memory was lost was after the first 32 requests, so the programmer in me quickly scrolled down to the 64th request expecting to find loss in memory there as well but no memory had been lost at that point. The next time 48 bytes were lost from heap was after request 158. Then there was a loss at 210, another at 225, another at 267, etc.

Now this is a vast improvement from before but if the module is loosing heap memory then eventually it WILL crash.

I just added client.stop at the end of the loop and will let that run now for testing. So far it lost 48 bytes of memory after request number 5 so I am still seeing it. Somehow 48 bytes are not being freed. Other than declaring the WiFiClientSecure object in the loop so it leaves scope every cycle to free memory and calling client.stop at the end of the loop for good measure is there anything else you can think I should try?

If you want me to post most recent code update please let me know and I'll be happy to.

@earlephilhower
Copy link
Collaborator

I'm on git head (well, git head as of 2-3 days ago) but I'm unable to make your original test app lose memory now, connecting to your server. Can you verify that it fails consistently for you? I see ~22KB (22136) free on each loop, with the # constant for loops 2-13. All I did was update the fingerprint, which I guess changed since your original posting.

I was also unable to see a memory leak when I took the last code and moved the WiFiClientSecure out to globals and off the stack.

There will be +/- a few bytes, unrelated to the WiFiClient*, simply due to LWIP and it's connection cache/received buffers. If you can leave your app running and capture the free over a longer period (maybe let it try overnight, capture Serial output to a file, but at least 15mins or so) that would help to see if it's really lost or a temporary thing.

I also edited your last code sample to remove your WiFi password.

@sumitkumarjaiswal
Copy link

sumitkumarjaiswal commented Apr 13, 2018

Using 2.4.1 - Can any one help me what should i do, because WiFiClientSecure client
client.connect(host, 443) drops the stack memory and after some time it crashes. see below logs. Kindly reply..

Before connecting to https url

Free heap:- 32304
unmodified stack = 3168
current free stack = 3824

Just After 1st connection with https url

Free heap:- 18088
unmodified stack = 1536
current free stack = 3824

After 2nd connection with https url

Free heap:- 37152
unmodified stack = 1488
current free stack = 3856

After 3rd connection with https url

Free heap:- 37152
unmodified stack = 1348
current free stack = 3808

Code to display head and stack

Serial.print ("Free heap:- ");
Serial.println(ESP.getFreeHeap ());
Serial.printf("unmodified stack = %4d\n", cont_get_free_stack(&g_cont));
register uint32_t *sp asm("a1");
Serial.printf("current free stack = %4d\n", 4 * (sp - g_cont.stack));

Exception Stack Trace Decoder

Exception 29: StoreProhibited: A store referenced a page mapped with an attribute that does not permit stores
Decoding 36 results
0x4021ded3: send_client_hello at ssl/tls1_clnt.c line 202
: (inlined by) do_client_connect at ssl/tls1_clnt.c line 167
0x4021decf: send_client_hello at ssl/tls1_clnt.c line 202
: (inlined by) do_client_connect at ssl/tls1_clnt.c line 167
0x401004d8: malloc at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266\umm_malloc/umm_malloc.c line 1668
0x4021e112: ssl_client_new at ssl/tls1_clnt.c line 89
0x4020ecd6: strdup at /Users/igrokhotkov/e/newlib-xtensa/xtensa-lx106-elf/newlib/libc/string/../../../.././newlib/libc/string/strdup.c line 11
0x4010500c: ets_timer_arm_new at ?? line ?
0x40206f67: shared_ptr at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\libraries\ESP8266WiFi\src/WiFiClientSecure.cpp line 310 (discriminator 1)
: (inlined by) SSLContext::connect(ClientContext*, char const*, unsigned int) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\libraries\ESP8266WiFi\src/WiFiClientSecure.cpp line 138 (discriminator 1)
0x4020b978: esp_yield at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/core_esp8266_main.cpp line 57
0x4020b7a0: operator new(unsigned int) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/abi.cpp line 57
0x40206ff8: std::__shared_ptr ::operator=(std::__shared_ptr &&) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\libraries\ESP8266WiFi\src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x40207207: WiFiClientSecure::_connectSSL(char const*) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\libraries\ESP8266WiFi\src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x402072ad: WiFiClientSecure::connect(char const*, unsigned short) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\libraries\ESP8266WiFi\src/WiFiClientSecure.cpp line 310 (discriminator 1)
0x40107450: sntp_get_current_timestamp at ?? line ?
0x40107450: sntp_get_current_timestamp at ?? line ?
0x4020a4e7: WebSocketsClient::loop() at C:\Users\user1\Documents\Arduino\libraries\arduinoWebSockets-master\src/WebSocketsClient.cpp line 159
0x40202ece: ConnectIoTWebSocketClient::connect(char const*, unsigned short) at C:\Users\310235~1\AppData\Local\Temp\arduino_build_592607\sketch/ConnectIoTWebSocketClient.cpp line 70
0x40201df3: delay at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/core_esp8266_wiring.c line 51
0x40203dd8: IPStack::connect(char*, int) at C:\Users\user1\Documents\Arduino\libraries\MQTTClient/IPStack.h line 35
: (inlined by) mqttConnect() at C:\Users\user1\Documents\Arduino\connectIoT_DHT22_v4/connectIoT_DHT22_v4.ino line 430
0x4020abf3: Print::print(long, int) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/Print.cpp line 99
0x4020c53c: Print::write(unsigned char const*, unsigned int) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/Print.cpp line 99
0x4020a541: Print::write(char const*) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/Print.cpp line 99
0x4020502f: publishMessage() at C:\Users\user1\Documents\Arduino\connectIoT_DHT22_v4/connectIoT_DHT22_v4.ino line 471
0x4020b32c: String::concat(char) at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/WString.cpp line 746
0x4010020c: _umm_free at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266\umm_malloc/umm_malloc.c line 1291
0x40205256: uploadToDataBrokerIoT(float, float) at C:\Users\user1\Documents\Arduino\connectIoT_DHT22_v4/connectIoT_DHT22_v4.ino line 276
0x4020aad4: Print::println() at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/Print.cpp line 99
0x40205459: loop at C:\Users\user1\Documents\Arduino\connectIoT_DHT22_v4/connectIoT_DHT22_v4.ino line 382 (discriminator 2)
0x402086c4: DHT::begin() at C:\Users\user1\Documents\Arduino\libraries\DHT_sensor_library/DHT.cpp line 121
0x402035f1: setup at C:\Users\user1\Documents\Arduino\connectIoT_DHT22_v4/connectIoT_DHT22_v4.ino line 103
0x4020b9c4: loop_wrapper at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/core_esp8266_main.cpp line 57
0x40100710: cont_norm at C:\Users\user1\Documents\ArduinoData\packages\esp8266\hardware\esp8266\2.4.1\cores\esp8266/cont.S line 109

@telliottosceola
Copy link
Author

@sumitkumarjaiswal
Can you post your full code?

@devyte
Copy link
Collaborator

devyte commented May 29, 2018

BearSSL is merged in #4273 , with alternate BearSSL::WiFi* classes. Although axtls-based classes are still available and even the default, they are planned for deprecation and then retirement, hence won't be fixed. Any issues with BearSSL-based classes should be reported in new issues.
Finally, several issues have been fixed recently regarding connection stability.
Closing.

@devyte devyte closed this as completed May 29, 2018
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

8 participants