HTTPS | ESP32 | Core 0 panic'ed

[r-zlotorzynski]

Hello
I have a problem with the library on the ESP32 platform. The situation is as follows:

1. I start the HTTPS server
2. I connect to the server using a browser
   - the browser makes a connection on 2-3 sockets (this is its nature and we will not change it :))
3. TLS negotiation is carried out correctly
4. GET requests are received
5. Reply is carried out by me
6. Sockets are closed (some with error)
7. Error closing (Core 0 panic'ed)

I present the exact outline of the situation in the logs.

First of all - I added a few logs (CLOSING n) in the HTTPSConnection.cpp file in the closeConnection () method to better explain the situation :

The result is this debug:

[HTTPS:I: 25987] New connection. Socket FID=56
[HTTPS:D: 35182] Data on Socket FID=56
[HTTPS:I: 35184] Request: GET / (FID=56)
[HTTPS:I: 35185] New connection. Socket FID=57
[HTTPS:E: 35187] SSL_new failed. Aborting handshake. FID=57
[HTTPS:W: 35189] CLOSING 1
[HTTPS:W: 35191] CLOSING 5
[HTTPS:I: 35194] Connection closed. Socket FID=57
[HTTPS:D: 35200] Free headers
[HTTPS:W: 35202] CLOSING 1
[HTTPS:W: 35205] CLOSING 5
[HTTPS:D: 35211] Data on Socket FID=56
[HTTPS:D: 35212] Header: Host = rz-gdansk.example.pl (FID=56)
[HTTPS:D: 35217] Header: Connection = keep-alive (FID=56)
[HTTPS:D: 35223] Header: Cache-Control = max-age=0 (FID=56)
[HTTPS:D: 35228] Header: DNT = 1 (FID=56)
[HTTPS:D: 35233] Header: Upgrade-Insecure-Requests = 1 (FID=56)
[HTTPS:D: 35239] Header: User-Agent = Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.163 Safari/537.36 (FID=56)
[HTTPS:D: 35253] Header: Sec-Fetch-Dest = document (FID=56)
[HTTPS:D: 35259] Header: Accept = text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9 (FID=56)
[HTTPS:D: 35274] Header: Sec-Fetch-Site = cross-site (FID=56)
[HTTPS:D: 35280] Header: Sec-Fetch-Mode = navigate (FID=56)
[HTTPS:D: 35285] Header: Sec-Fetch-User = ?1 (FID=56)
[HTTPS:D: 35292] Data on Socket FID=56
[HTTPS:D: 35294] Header: Accept-Encoding = gzip, deflate, br (FID=56)
[HTTPS:D: 35301] Header: Accept-Language = pl-PL,pl;q=0.9,en-US;q=0.8,en;q=0.7 (FID=56)
[HTTPS:D: 35309] Header: Cookie = io=Bxxbiyg_RSYlvrEWAAAA (FID=56)
[HTTPS:D: 35315] Headers finished, FID=56
[HTTPS:D: 35320] Resolving resource...
[HTTPS:D: 35323] Keep-Alive activated. FID=56
[HTTPS:D: 35327] Creating buffered response, size: 1400
		
		
		IN THIS PLACE I AM SENDING A RESPONSE 
		
		
[HTTPS:D: 35965] Printing headers
[HTTPS:D: 35971] Draining response buffer


		THIS PLACE IS COMPLETING SENDING A RESPONSE 


[HTTPS:D: 37630] Data on Socket FID=56
[HTTPS:E: 37631] An receive error occured, FID=56
[HTTPS:W: 37631] CLOSING 1
[HTTPS:W: 37631] CLOSING 2
[HTTPS:W: 37633] CLOSING 3
[HTTPS:W: 37636] CLOSING 5
[HTTPS:I: 37639] Connection closed. Socket FID=56
[HTTPS:D: 37644] Free headers

Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x401a91e5 PS : 0x00060a30 A0 : 0x800e6d10 A1 : 0x3ffdd440
A2 : 0x00000000 A3 : 0x3ffc2774 A4 : 0x3f40655f A5 : 0x00000000
A6 : 0x3ffdd3fc A7 : 0x3ffdd3fc A8 : 0x800e6e44 A9 : 0x3ffdd420
A10 : 0x00000000 A11 : 0x00000000 A12 : 0x4dc1ce84 A13 : 0x3ffc2b9c
A14 : 0x3ffdd3dc A15 : 0x3ffdd3dc SAR : 0x00000004 EXCCAUSE: 0x0000001c 
EXCVADDR: 0x00000018 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace: 0x401a91e5:0x3ffdd440 0x400e6d0d:0x3ffdd460 0x400e4c93:0x3ffdd480 0x401a6c3e:0x3ffdd4a0 0x400e6011:0x3ffdd4c0 0x400e362e:0x3ffdd6a0 0x400d7709:0x3ffdd6d0 0x4008bffd:0x3ffdd760 

Rebooting...

So my question is, did anyone else have such a problem?

To avoid this error, I have temporarily removed the line shown in the screenshot below. Will this solution not affect the library's operation?

File
HTTPConnection.cpp -> int HTTPConnection::updateBuffer()

After commenting on this line, the problem does not occur.

Thank you in advance for your help.
Greetings

[fhessel]

I cannot reproduce your error by myself, but there seems to be an issue with the state machine of the connection handler. Just removing that line might solve the issue but it leads to resources not being freed correctly, which might catch you at some later point in time.

I'll have a look at it. What would really help me is if you could feed the backtrace ...

Backtrace: 0x401a91e5:0x3ffdd440 0x400e6d0d:0x3ffdd460 0x400e4c93:0x3ffdd480 0x401a6c3e:0x3ffdd4a0 0x400e6011:0x3ffdd4c0 0x400e362e:0x3ffdd6a0 0x400d7709:0x3ffdd6d0 0x4008bffd:0x3ffdd760

... into the ESP stacktrace decoder. If you're not using the Arduino IDE (but have it at least installed), you can call the stacktrace decoder for CLI:

java -jar EspStackTraceDecoder.jar /your/arduino/folder/hardware/espressif/esp32/tools/xtensa-esp32-elf/bin/xtensa-esp32-elf-addr2line /path/to/application.elf /file/with/backtrace.txt

For Platform IO, you'd find the .elf file in the .pio subdirectory in your project.

[bligeti]

Hi,
I believe I was struggling with the same error.
You can see below the debug lines just before the exception and the decoded backtrace.

[HTTPS:E] An receive error occured, FID=56
[HTTPS:I] Connection closed. Socket FID=56
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x4018f361 PS : 0x00060f30 A0 : 0x800da3b0 A1 : 0x3ffdaa70
A2 : 0x00000000 A3 : 0x00000000 A4 : 0xe237ebc6 A5 : 0x3ffcc82c
A6 : 0x3ffdaa2c A7 : 0x3ffdaa2c A8 : 0x800da482 A9 : 0x3ffdaa50
A10 : 0x00000000 A11 : 0x00000000 A12 : 0x00000020 A13 : 0x3ffdaa70
A14 : 0x3ffda9f0 A15 : 0x00000008 SAR : 0x00000004 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000018 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0xffffffff

Backtrace: 0x4018f361:0x3ffdaa70 0x400da3ad:0x3ffdaa90 0x400d855b:0x3ffdaab0 0x400d99bb:0x3ffdaad0 0x400d6db6:0x3ffdaca0 0x400d2ba9:0x3ffdacd0 0x4008b141:0x3ffdad60
 #0 0x4018f361:0x3ffdaa70 in SSL_pending at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/openssl/library/ssl_lib.c:1402
 #1 0x400da3ad:0x3ffdaa90 in httpsserver::HTTPSConnection::pendingByteCount() at C:\Users\eblilig\.platformio\lib\esp32_https_server_ID5887\src/HTTPSConnection.cpp:116
 #2 0x400d855b:0x3ffdaab0 in httpsserver::HTTPConnection::pendingBufferSize() at C:\Users\eblilig\.platformio\lib\esp32_https_server_ID5887\src/HTTPConnection.cpp:258
 #3 0x400d99bb:0x3ffdaad0 in httpsserver::HTTPConnection::loop() at C:\Users\eblilig\.platformio\lib\esp32_https_server_ID5887\src/HTTPConnection.cpp:579
 #4 0x400d6db6:0x3ffdaca0 in httpsserver::HTTPServer::loop() at C:\Users\eblilig\.platformio\lib\esp32_https_server_ID5887\src/HTTPServer.cpp:122
 #5 0x400d2ba9:0x3ffdacd0 in serverTask(void*) at src/main.cpp:297 (discriminator 1)
 #6 0x4008b141:0x3ffdad60 in vPortTaskWrapper at C:/Privat/ESP3.2/components/freertos/port.c:355 (discriminator 1)

This error is well reproducabe with unstable Wifi connection as it is connected to session disconnections or other similar problems coming from SSL.
In HTTPConnection::updateBuffer() closeConnection() is called when error is detected from SSL to clean up but the possibility of already cleaned up session is not handled in HTTPConnection::pendingBufferSize() and in HTTPConnection::loop().

I created a pull request with the modification I'm using: #89

[rljonesau]

I have been having the same problem with exceptions, especially related to poor signal quality.

I'm only using HTTP, but what I have tried instead of commenting out the closeConnection() call is to set a flag and do the closeConnection in the loop() code instead, based on that flag being set.

My test has been connecting to the ESP's AP, then back to home WiFi from a mobile.
This was a sure fire way to trip up the exception, but not always.
I have now tried this vector many more times than I would usually manage and have yet to see a core panic since just moving the closeConnection() action to the loop().

I note that updateBuffer() is called from numerous places, and this may well be the underlying problem given the async nature of some calls.....

In updateBuffer():

 } else {
 // An error occured
 _connectionState = STATE_ERROR;
 HTTPS_LOGE("An receive error occured, FID=%d", _socket);
 _bShouldClose = true;
// closeConnection();
 return -1;
 }

in loop():

 if(_bShouldClose) {
 closeConnection();
 _bShouldClose = false;
 }

[BlueAndi]

Because of closeConnection() the SSL context is released.

Flow:

1. httpsserver::HTTPConnection::pendingBufferSize()
   1. updateBuffer()
      1. HTTPSConnection::closeConnection()
      2. SSL_free();
      3. Now the SSL context is released.
   2. pendingByteCount()
      1. SSL_pending() with released context
      2. Reset

The following methods should check for a valid SSL context, before calling a SSL function:

• HTTPSConnection::writeBuffer()
• HTTPSConnection::readBytesToBuffer()
• HTTPSConnection::pendingByteCount()

With the added check, there is no reset anymore.

[levvayner]

@fhessel just came across that too.
Here's the stack trace
0x4019eea8: SSL_pending at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/openssl/library/ssl_lib.c line 569
0x400e0fdd: httpsserver::HTTPSConnection::pendingByteCount() at lib/esp32_https_server/src/HTTPSConnection.cpp line 116
0x400df2e3: httpsserver::HTTPConnection::pendingBufferSize() at lib/esp32_https_server/src/HTTPConnection.cpp line 258
0x4019da86: httpsserver::HTTPRequest::requestComplete() at lib/esp32_https_server/src/HTTPRequest.cpp line 109
0x400e053f: httpsserver::HTTPConnection::loop() at lib/esp32_https_server/src/HTTPConnection.cpp line 515
0x400ddc1b: httpsserver::HTTPServer::loop() at lib/esp32_https_server/src/HTTPServer.cpp line 122
0x400d75a9: esp32_server::step() at src/System/CORE/esp32_server.cpp line 81
0x400dc1eb: serverTask(void*) at src/main.cpp line 72