"Connection: close" header from server causes ESP32 to crash #5

ugluguglug · 2022-01-30T14:51:45Z

Describe the bug

ESP32 crashes with either "CORRUPT HEAP" or "Exception was unhandled" after receiving "Connection: close" header from target server following a POST request.

Similar issues did not happen when using the library AsyncHTTPRequest_Generic.

Steps to Reproduce

Start a server that returns "Connection: close" as response header
Make any POST request to the server
ESP32 crashes

Expected behavior

Start a new TCP connection after closing the previous one.

Actual behavior

Crashes with either CORRUPT HEAP or "Exception was unhandled" as error message.

Debug and AT-command log (if applicable)

Logs are generated using esp32_exception_decoder with #define _ASYNC_HTTPS_LOGLEVEL_ 4, domain name of the server is removed

When Connection header of response is "keep-alive"

[AHTTPS] open( POST , url = 
[AHTTPS] _parseURL(): scheme+host HTTPS:// 
[AHTTPS] _parseURL(): port+path+query 443 
[AHTTPS] open: connecting to hostname = 
[AHTTPS] _connect()
[AHTTPS] _onConnect handler
[AHTTPS] _setReadyState : 1

[AHTTPS] send(String) {
  "floor": "L , length = 38
[AHTTPS] _buildRequest()
[AHTTPS] _HTTPmethod = 1
[AHTTPS] POST  /api/library/entrances  HTTP/1.1

[AHTTPS] write _HTTPmethodStringwithSpace :  POST 
[AHTTPS] write path :  /api/library/entrances
[AHTTPS] write query 
[AHTTPS] write HTTP/1.1
[AHTTPS] To write hdr
[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] host : 

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Type : application/json 

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Length : 38 

[AHTTPS] Write hdr done
[AHTTPS] _buildRequest() done
[AHTTPS] Done supply
[AHTTPS] To send()
[AHTTPS] send 192
[AHTTPS] ========= _onData handler =======
[AHTTPS] Vbuf = HTTP/1.1 200 OK
Server: nginx/1.18.0 (Ubuntu)
Date: 
Content-Type: text/html; charset=utf-8
Content-Length: 8
**Connection: keep-alive**
X-Powered-By: Express

[AHTTPS] =================================
[AHTTPS] Vbuf len = 242
[AHTTPS] =================================
[AHTTPS] _collectHeaders()
[AHTTPS] xbuf::readString: Reserved size =  18
[AHTTPS] xbuf::readString: Reserved size =  32
[AHTTPS] xbuf::readString: Reserved size =  38
[AHTTPS] xbuf::readString: Reserved size =  41
[AHTTPS] xbuf::readString: Reserved size =  20
[AHTTPS] xbuf::readString: Reserved size =  25
[AHTTPS] xbuf::readString: Reserved size =  24
[AHTTPS] xbuf::readString: Reserved size =  42
[AHTTPS] xbuf::readString: Reserved size =  3
[AHTTPS] _setReadyState : 2
[AHTTPS] _setReadyState : 3
**[AHTTPS] *all data received - no disconnect**
[AHTTPS] _setReadyState : 4

[AHTTPS] responseText()
[AHTTPS] xbuf::readString: Reserved size =  9
[AHTTPS] ========= responseText(char) =======
[AHTTPS] localString = 
[AHTTPS] =================================
[AHTTPS] avail = 8
[AHTTPS] ====================================

When Connection header of response is "close" (Unhandled exception)

[AHTTPS] open( POST , url = 
[AHTTPS] _parseURL(): scheme+host HTTPS:// 
[AHTTPS] _parseURL(): port+path+query 443 
[AHTTPS] open: connecting to hostname = 
[AHTTPS] _connect()
[AHTTPS] _onConnect handler
[AHTTPS] _setReadyState : 1

[AHTTPS] send(String) {
  "floor": "L , length = 38
[AHTTPS] _buildRequest()
[AHTTPS] _HTTPmethod = 1
[AHTTPS] POST  /api/library/entrances  HTTP/1.1

[AHTTPS] write _HTTPmethodStringwithSpace :  POST 
[AHTTPS] write path :  
[AHTTPS] write query 
[AHTTPS] write HTTP/1.1
[AHTTPS] To write hdr
[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] host : 

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Type : application/json 

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Length : 38 

[AHTTPS] Write hdr done
[AHTTPS] _buildRequest() done
[AHTTPS] Done supply
[AHTTPS] To send()
[AHTTPS] send 192

[AHTTPS] ========= _onData handler =======
[AHTTPS] Vbuf = HTTP/1.1 200 OK
Server: nginx/1.18.0 (Ubuntu)
Date: Sun, 30 Jan 2022 13:48:21 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 8
**Connection: close**
X-Powered-By: Express

[AHTTPS] =================================
[AHTTPS] Vbuf len = 237
[AHTTPS] =================================
[AHTTPS] _collectHeaders()
[AHTTPS] xbuf::readString: Reserved size =  18
[AHTTPS] xbuf::readString: Reserved size =  32
[AHTTPS] xbuf::readString: Reserved size =  38
[AHTTPS] xbuf::readString: Reserved size =  41
[AHTTPS] xbuf::readString: Reserved size =  20
[AHTTPS] xbuf::readString: Reserved size =  20
[AHTTPS] xbuf::readString: Reserved size =  24
[AHTTPS] xbuf::readString: Reserved size =  42
[AHTTPS] xbuf::readString: Reserved size =  3
[AHTTPS] _setReadyState : 2
[AHTTPS] _setReadyState : 3
**[AHTTPS] *all data received - closing TCP**
[AHTTPS] _setReadyState : 4

[AHTTPS] responseText()
[AHTTPS] xbuf::readString: Reserved size =  9
[AHTTPS] ========= responseText(char) =======
[AHTTPS] localString = Received
[AHTTPS] =================================
[AHTTPS] avail = 8
[AHTTPS] ====================================
-----
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4014ac74  PS      : 0x00060130  A0      : 0x80141e2e  A1      : 0x3ffb3e30  
A2      : 0x3ffd0108  A3      : 0x6e6f430a  A4      : 0x0000baaf  A5      : 0x00000000  
A6      : 0x3ffb3328  A7      : 0x00000000  A8      : 0x6bbd06da  A9      : 0xabba134a  
A10     : 0x3ffd0138  A11     : 0x00000116  A12     : 0xabba1234  A13     : 0x00000b38  
A14     : 0x00060720  A15     : 0x00000000  SAR     : 0x00000019  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000004  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

ELF file SHA256: 0000000000000000

Backtrace: 0x4014ac74:0x3ffb3e30 0x40141e2b:0x3ffb3e60 0x400d1212:0x3ffb3e80 0x401414b4:0x3ffb3ea0 0x400897ea:0x3ffb3ed0
  #0  0x4014ac74:0x3ffb3e30 in tcp_output at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp_out.c:1027
  #1  0x40141e2b:0x3ffb3e60 in tcp_recved at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp.c:1765
  #2  0x400d1212:0x3ffb3e80 in _tcp_recved_api(tcpip_api_call_data*) at .pio/libdeps/esp32doit-devkit-v1/AsyncHTTPSRequest_Generic/src/AsyncHTTPSRequest_Impl_Generic.h:970
  #3  0x401414b4:0x3ffb3ea0 in tcpip_thread at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/api/tcpip.c:483
  #4  0x400897ea:0x3ffb3ed0 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

When Connection header of response is "close" (Corrupt heap)

[AHTTPS] open( POST , url = 
[AHTTPS] _parseURL(): scheme+host HTTPS:// 
[AHTTPS] _parseURL(): port+path+query 443 
[AHTTPS] open: connecting to hostname = 
[AHTTPS] _connect()
[AHTTPS] _onConnect handler
[AHTTPS] _setReadyState : 1

[AHTTPS] send(String) {
  "floor": "L , length = 38
[AHTTPS] _buildRequest()
[AHTTPS] _HTTPmethod = 1
[AHTTPS] POST  /api/library/entrances  HTTP/1.1

[AHTTPS] write _HTTPmethodStringwithSpace :  POST 
[AHTTPS] write path :  /api/library/entrances
[AHTTPS] write query 
[AHTTPS] write HTTP/1.1
[AHTTPS] To write hdr
[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] host :

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Type : application/json 

[AHTTPS] hdr->name
[AHTTPS] hdr->value
[AHTTPS] Content-Length : 38 

[AHTTPS] Write hdr done
[AHTTPS] _buildRequest() done
[AHTTPS] Done supply
[AHTTPS] To send()
[AHTTPS] send 192

[AHTTPS] ========= _onData handler =======
[AHTTPS] Vbuf = HTTP/1.1 200 OK
Server: nginx/1.18.0 (Ubuntu)
Date: Sun, 30 Jan 2022 13:46:31 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 8
**Connection: close**
X-Powered-By: Express

[AHTTPS] =================================
[AHTTPS] Vbuf len = 237
[AHTTPS] =================================
[AHTTPS] _collectHeaders()
[AHTTPS] xbuf::readString: Reserved size =  18
[AHTTPS] xbuf::readString: Reserved size =  32
[AHTTPS] xbuf::readString: Reserved size =  38
[AHTTPS] xbuf::readString: Reserved size =  41
[AHTTPS] xbuf::readString: Reserved size =  20
[AHTTPS] xbuf::readString: Reserved size =  20
[AHTTPS] xbuf::readString: Reserved size =  24
[AHTTPS] xbuf::readString: Reserved size =  42
[AHTTPS] xbuf::readString: Reserved size =  3
[AHTTPS] _setReadyState : 2
[AHTTPS] _setReadyState : 3
**[AHTTPS] *all data received - closing TCP**
[AHTTPS] _setReadyState : 4

[AHTTPS] responseText()
[AHTTPS] xbuf::readString: Reserved size =  9
[AHTTPS] ========= responseText(char) =======
[AHTTPS] localString = Received
[AHTTPS] =================================
[AHTTPS] avail = 8
[AHTTPS] ====================================
[AHTTPS] 
_onDisconnect handler
[AHTTPS] open( POST , url =
CORRUPT HEAP: Bad tail at 0x3ffd00d3. Expected 0xbaad5678 got 0x70167078
abort() was called at PC 0x4008696d on core 1

ELF file SHA256: 0000000000000000

Backtrace: 0x4008855c:0x3ffb1900 0x400887d9:0x3ffb1920 0x4008696d:0x3ffb1940 0x40086a99:0x3ffb1970 0x40107c97:0x3ffb1990 0x40103f65:0x3ffb1c50 0x40103efd:0x3ffb1ca0 0x4008ceb5:0x3ffb1cd0 0x40081bba:0x3ffb1cf0 0x40086865:0x3ffb1d10 0x4000bec7:0x3ffb1d30 0x4016c98d:0x3ffb1d50 0x4016c6cd:0x3ffb1d70 0x400d523f:0x3ffb1d90 0x400d77bc:0x3ffb1dd0 0x400d7636:0x3ffb1df0 0x400da880:0x3ffb1fb0 0x400897ea:0x3ffb1fd0

Information

Platform.io version: Core 5.2.4, Home 3.4.0
ESP32 IDF version: v3.3.5-1-g85c43024c
ESP32 module: DEVKITV1
OS: Ubuntu 20.04 LTS
Linux focal 5.13.0-27-generic #29~20.04.1-Ubuntu SMP x86_64 x86_64 x86_64 GNU/Linux

Context:
Trying to make a POST request to a server through HTTPS.

The text was updated successfully, but these errors were encountered:

khoih-prog · 2022-01-30T18:23:53Z

Hi @ugluguglug

Thanks for your interest in the library and the bug report.

To help duplicate, isolate then fix the issue, please post the MRE.

ugluguglug · 2022-01-31T09:26:53Z

Hello @khoih-prog, thank you so much for creating this library!
This is my first time writing a bug report, I will try my best but please kindly let me know if anything is unclear or incorrect 🙇‍♂️

Run a web server (on Ubuntu):

Install nginx with sudo apt install nginx
My version: nginx version: nginx/1.18.0 (Ubuntu), but the version should not matter much
Get a SSL/TLS certificate for HTTPS connections, I used certbot following the instructions on this site (https://certbot.eff.org/instructions) using the domain name provided by my ISP and forwarded the port running nginx.
Configure nginx to close the TCP connection after 3 requests for faster error replication (default is 100).
Modify /etc/nginx/nginx.conf by adding the line keepalive_requests 3; in the http context like the following

http {

        ##
        # Basic Settings
        ##

        sendfile on;
        tcp_nopush on;
        tcp_nodelay on;
        keepalive_timeout 65;
        keepalive_requests 3;
        types_hash_max_size 2048;
        ...

Test if configurations file are correct by running sudo nginx -t, which should return

nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful

Restart the nginx service using sudo systemctl restart nginx

Code for ESP32 (Modified from AsyncHTTPSRequest_ESP.ino)

Upload the following code to ESP32

A few things to change:

const char* ssid = {SSID}
const char* password = {password}
requestOpenResult = request.open("POST", {nginx server IP});

Main.cpp

#if !( defined(ESP8266) ||  defined(ESP32) )
#error This code is intended to run on the ESP8266 or ESP32 platform! Please check your Tools->Board setting.
#endif

#define ASYNC_HTTPS_REQUEST_GENERIC_VERSION_MIN_TARGET      "AsyncHTTPSRequest_Generic v1.3.0"
#define ASYNC_HTTPS_REQUEST_GENERIC_VERSION_MIN             1003000

// Level from 0-4
#define ASYNC_HTTPS_DEBUG_PORT      Serial

#define _ASYNC_TCP_SSL_LOGLEVEL_    0
#define _ASYNC_HTTPS_LOGLEVEL_      4

// 300s = 5 minutes to not flooding
#define HTTPS_REQUEST_INTERVAL      10  //300

int status;     // the Wifi radio's status

const char* ssid = "SSID";
const char* password = "password";

#if (ESP8266)
#include <ESP8266WiFi.h>
#elif (ESP32)
#include <WiFi.h>
#endif

// To be included only in main(), .ino with setup() to avoid `Multiple Definitions` Linker Error
#include <AsyncHTTPSRequest_Generic.h>            // https://github.com/khoih-prog/AsyncHTTPSRequest_Generic

#include <Ticker.h>

AsyncHTTPSRequest request;
Ticker ticker;

void sendRequest()
{
    static bool requestOpenResult;

    if (request.readyState() == readyStateUnsent || request.readyState() == readyStateDone)
    {
        requestOpenResult = request.open("POST", "nginx server IP");

        if (requestOpenResult)
        {
            // Only send() if open() returns true, or crash
            request.send("12345");
        }
        else
        {
            Serial.println("Can't send bad request");
        }
    }
    else
    {
        Serial.println("Can't send request");
    }
}

void requestCB(void* optParm, AsyncHTTPSRequest* request, int readyState)
{
    (void)optParm;

    if (readyState == readyStateDone)
    {
        Serial.println("\n**************************************");
        Serial.println(request->responseText());
        Serial.println("**************************************");

        request->setDebug(false);
    }
}

void setup()
{
    // put your setup code here, to run once:
    Serial.begin(115200);
    while (!Serial);

    Serial.println("\nStarting AsyncHTTPSRequest_ESP using " + String(ARDUINO_BOARD));

#if defined(ESP32)
    Serial.println(ASYNC_TCP_SSL_VERSION);
#else
    //Serial.println(ESPASYNC_TCP_SSL_VERSION);
#endif

    Serial.println(ASYNC_HTTPS_REQUEST_GENERIC_VERSION);

#if defined(ASYNC_HTTPS_REQUEST_GENERIC_VERSION_MIN)
    if (ASYNC_HTTPS_REQUEST_GENERIC_VERSION_INT < ASYNC_HTTPS_REQUEST_GENERIC_VERSION_MIN)
    {
        Serial.print("Warning. Must use this example on Version equal or later than : ");
        Serial.println(ASYNC_HTTPS_REQUEST_GENERIC_VERSION_MIN_TARGET);
    }
#endif

    WiFi.mode(WIFI_STA);

    WiFi.begin(ssid, password);

    Serial.println("Connecting to WiFi SSID: " + String(ssid));

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

    Serial.print(F("\nAsyncHTTPSRequest @ IP : "));
    Serial.println(WiFi.localIP());

    request.setDebug(false);

    request.onReadyStateChange(requestCB);

    ticker.attach(HTTPS_REQUEST_INTERVAL, sendRequest);

    // Send first request now
    sendRequest();
}

void loop()
{
    //delay(1);
}

Open serial monitor and inspect the headers

Connection: keep-alive

[AHTTPS] ========= _onData handler =======
[AHTTPS] Vbuf = HTTP/1.1 200 OK
Server: nginx/1.18.0 (Ubuntu)
Date: Mon, 31 Jan 2022 08:59:09 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 4
Connection: keep-alive
X-Powered-By: Express
ETag: W/"4-Yf+Bwwqjx254r+pisuO9HfpJ6FQ"

Connection: close

[AHTTPS] ========= _onData handler =======
[AHTTPS] Vbuf = HTTP/1.1 200 OK
Server: nginx/1.18.0 (Ubuntu)
Date: Mon, 31 Jan 2022 08:59:03 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 4
Connection: close
X-Powered-By: Express
ETag: W/"4-Yf+Bwwqjx254r+pisuO9HfpJ6FQ"

If Nginx does not return "Connection: close" header after doing the above

Install node by sudo apt install nodejs
Create directory

mkdir myapp
cd myapp

Create package.json file using npm init --yes
Install Express.js with npm install express
Create app.js with the code below

const express = require('express')
const app = express()
const port = 3000

app.post('/', (req, res) => {
  res.send('Hello World!')
})

app.listen(port, () => {
  console.log(`Example app listening on port ${port}`)
})

Start node app using node app.js
Modify location block in /etc/nginx/sites-available/default file for proxy to point to node app

server {

	# SSL configuration
	#
	# listen 443 ssl default_server;
	# listen [::]:443 ssl default_server;
	#
	# Note: You should disable gzip for SSL traffic.
	# See: https://bugs.debian.org/773332
	#
	# Read up on ssl_ciphers to ensure a secure configuration.
	# See: https://bugs.debian.org/765782
	#
	# Self signed certs generated by the ssl-cert package
	# Don't use them in a production server!
	#
	# include snippets/snakeoil.conf;

	root /var/www/html;

	# Add index.php to the list if you are using PHP
	index index.html index.htm index.nginx-debian.html;

	server_name 061239230208.ctinets.com 061239230208.ctinets.com;

	location / {
		# First attempt to serve request as file, then
		# as directory, then fall back to displaying a 404.
		proxy_pass http://127.0.0.1:3000; # Address of the node app
                proxy_http_version 1.1;
                proxy_set_header Upgrade $http_upgrade;
                proxy_set_header Connection 'upgrade';
                proxy_set_header Host $host;
                proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
                proxy_set_header X-Real-IP $remote_addr;
                proxy_cache_bypass $http_upgrade;
	}

Restart nginx with sudo systemctl restart nginx
Inspect the serial monitor again

khoih-prog · 2022-01-31T18:41:57Z

Hi @ugluguglug

That's the perfect MRE anyone can expect. I hope I'll have time to spend on duplicating the issue soon, and if any bug found, will fix.

Certainly with your experience and knowledge, you can help isolate the issue and spot the possible bug by turning on the debug option and looking in the library code.

#define _ASYNC_TCP_SSL_LOGLEVEL_    4
#define _ASYNC_HTTPS_LOGLEVEL_      4

Thanks a lot,

khoih-prog · 2022-02-03T02:07:16Z

HI @ugluguglug

I'm currently have no time to spend on this issue yet.

Can you try by

Using Arduino IDE, not Platform IO, which can introduce unnecessary problem to the current issue, especially not updated ESP32 core
Using ESP32 core v2.0.1 (not v2.0.2). Some HTTPS was reportedly causing issue in Connection problem via https ESP32S2 #6117

then post your test result here.

khoih-prog · 2022-02-03T02:38:23Z

More to try and digest

WiFiClientSecure handshake fails after client.stop(). Regression in 2.0.2 #60770

As a workaround for the issue, one can add client.setHandshakeTimeout(30); before every connection attempt.

ESP32 core 2.0.2 does not work (2.0.1 does) #270

A temporary fix that worked for me was to change line 266 in the ssl_client.cpp (in the WiFiClientSecure library) file from:
if((millis()-handshake_start_time)>ssl_client->handshake_timeout)
to:
if((millis()-handshake_start_time)>(ssl_client->handshake_timeout != 0?ssl_client->handshake_timeout:120000))
(So I manually set a timeout if the handshake_timeout is zero.)

khoih-prog · 2022-02-26T04:34:50Z

I'm sorry I don't have time to install the nginx SSL server to test. I have the non-SSL test server running but don't have time to convert and test the SSL, especially with my private domain name.

It's better that you set-up the SSL server, then email me / post here the test server host name + port if you'd like me to spend some time on this issue.

I'm closing the issue now, won't reopen until you can help with the SSL test server.

khoih-prog closed this as completed Feb 26, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

"Connection: close" header from server causes ESP32 to crash #5

"Connection: close" header from server causes ESP32 to crash #5

ugluguglug commented Jan 30, 2022 •

edited

Loading

khoih-prog commented Jan 30, 2022

Uh oh!

ugluguglug commented Jan 31, 2022

Uh oh!

khoih-prog commented Jan 31, 2022

Uh oh!

khoih-prog commented Feb 3, 2022

Uh oh!

khoih-prog commented Feb 3, 2022

Uh oh!

khoih-prog commented Feb 26, 2022

Uh oh!

"Connection: close" header from server causes ESP32 to crash #5

"Connection: close" header from server causes ESP32 to crash #5

Comments

ugluguglug commented Jan 30, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Describe the bug

Steps to Reproduce

Expected behavior

Actual behavior

Debug and AT-command log (if applicable)

Information

khoih-prog commented Jan 30, 2022

Uh oh!

ugluguglug commented Jan 31, 2022

Run a web server (on Ubuntu):

Code for ESP32 (Modified from AsyncHTTPSRequest_ESP.ino)

If Nginx does not return "Connection: close" header after doing the above

Uh oh!

khoih-prog commented Jan 31, 2022

Uh oh!

khoih-prog commented Feb 3, 2022

Uh oh!

khoih-prog commented Feb 3, 2022

Uh oh!

khoih-prog commented Feb 26, 2022

Uh oh!

ugluguglug commented Jan 30, 2022 •

edited

Loading