fhessel / esp32_https_server

Alternative ESP32 Webserver implementation for the ESP32 Arduino Core, supporting HTTPS and HTTP.
MIT License
334 stars 125 forks source link

HTTPS | ESP32 | Core 0 panic'ed #85

Open r-zlotorzynski opened 4 years ago

r-zlotorzynski commented 4 years ago

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 :

image

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?

image

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 commented 4 years ago

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 commented 4 years ago

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 commented 3 years ago

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 commented 2 years ago

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:

With the added check, there is no reset anymore.

levvayner commented 5 months ago

@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