Destroyed AsyncClient object is still used and causes a crash

[BlueAndi]

The shown log is in combination with ESPAsyncWebServer, which destroys the AsyncClient always after getting a disconnect indication via callback: https://github.com/me-no-dev/ESPAsyncWebServer/blob/f71e3d427b5be9791a8a2c93cf8079792c3a9a26/src/WebRequest.cpp#L74

The log shows that after _close() the destructor is called. Anyway later the _error() is called, which causes the crash.

[ 37260][E][AsyncTCP.cpp:807] _flushWriteQueue(): socket 51 lwip_write() failed errno=104
AsyncClient(0x3FFE1F38)::_sockIsWriteable: _socket = 51, _conn_state = 4
AsyncClient(0x3FFE1F38)::_close: _socket = 51
AsyncClient(0x3FFE1F38)::~AsyncClient(): _socket = -1
AsyncClient(0x3FFE1F38)::_error: _socket = -1

assert failed: xQueueSemaphoreTake queue.c:1545 (( pxQueue ))


Backtrace:0x40083e39:0x3ffe88600x4008e8d9:0x3ffe8880 0x400941b9:0x3ffe88a0 0x4008f899:0x3ffe89d0 0x401003a4:0x3ffe8a10 0x40100609:0x3ffe8a30 0x401007b7:0x3ffe8a60 0x40100c21:0x3ffe8a90 0x400ffd0b:0x3ffe8b10 

  #0  0x40083e39:0x3ffe8860 in panic_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/panic.c:402
  #1  0x4008e8d9:0x3ffe8880 in esp_system_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/esp_system.c:128
  #2  0x400941b9:0x3ffe88a0 in __assert_func at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/assert.c:85
  #3  0x4008f899:0x3ffe89d0 in xQueueSemaphoreTake at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/queue.c:1549 (discriminator 1)
  #4  0x401003a4:0x3ffe8a10 in AsyncClient::_clearWriteQueue() at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:1087
  #5  0x40100609:0x3ffe8a30 in AsyncClient::_error(signed char) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:1008
  #6  0x401007b7:0x3ffe8a60 in AsyncClient::_notifyWrittenBuffers(std::deque<AsyncClient::notify_writebuf, std::allocator<AsyncClient::notify_writebuf> >&, int) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:855 (discriminator 1)
  #7  0x40100c21:0x3ffe8a90 in AsyncClient::_sockIsWriteable() at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:742
  #8  0x400ffd0b:0x3ffe8b10 in _asynctcpsock_task(void*) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:141

[BlueAndi]

I got the problem, see following trace with additional detail:

AsyncClient(0x3FFE391C)::_sockIsWriteable: _socket = 51, _conn_state = 4
[ 44763][E][AsyncTCP.cpp:809] _flushWriteQueue(): socket 51 lwip_write() failed errno=104
AsyncWebServerRequest::_onAck: client = 0x3FFE391C - response finished
AsyncClient(0x3FFE391C)::_close: _socket = 51
AsyncClient(0x3FFE391C)::~AsyncClient(): _socket = -1
AsyncClient(0x3FFE391C)::_error: _socket = -1

assert failed: xQueueSemaphoreTake queue.c:1545 (( pxQueue ))


Backtrace:0x40083e39:0x3ffe88600x4008e8d9:0x3ffe8880 0x400941b9:0x3ffe88a0 0x4008f899:0x3ffe89d0 0x401003b4:0x3ffe8a10 0x40100619:0x3ffe8a30 0x401007f5:0x3ffe8a60 0x40100c79:0x3ffe8a90 0x400ffd1b:0x3ffe8b10 

  #0  0x40083e39:0x3ffe8860 in panic_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/panic.c:402
  #1  0x4008e8d9:0x3ffe8880 in esp_system_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/esp_system.c:128
  #2  0x400941b9:0x3ffe88a0 in __assert_func at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/assert.c:85
  #3  0x4008f899:0x3ffe89d0 in xQueueSemaphoreTake at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/queue.c:1549 (discriminator 1)
  #4  0x401003b4:0x3ffe8a10 in AsyncClient::_clearWriteQueue() at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:1091
  #5  0x40100619:0x3ffe8a30 in AsyncClient::_errorXX(signed char) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:1012
  #6  0x401007f5:0x3ffe8a60 in AsyncClient::_notifyWrittenBuffers(std::deque<AsyncClient::notify_writebuf, std::allocator<AsyncClient::notify_writebuf> >&, int) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:857
      (inlined by) AsyncClient::_notifyWrittenBuffers(std::deque<AsyncClient::notify_writebuf, std::allocator<AsyncClient::notify_writebuf> >&, int) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:848
  #7  0x40100c79:0x3ffe8a90 in AsyncClient::_sockIsWriteable() at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:744
  #8  0x400ffd1b:0x3ffe8b10 in _asynctcpsock_task(void*) at .pio/libdeps/esp32doit-devkit-v1-usb/AsyncTCPSock/src/AsyncTCP.cpp:143

void AsyncClient::_notifyWrittenBuffers(std::deque<notify_writebuf> & notifyqueue, int write_errno)
{
    while (notifyqueue.size() > 0) {
        if (notifyqueue.front().length > 0 && _sent_cb) {
            _sent_cb(_sent_cb_arg, this, notifyqueue.front().length, notifyqueue.front().delay);
        }
        notifyqueue.pop_front();
    }

    if (write_errno != 0) _error(write_errno);
}

1. The _sent_cb() is called, which triggers the AsyncWebServerRequest::_onAck().
2. Because of your PR https://github.com/me-no-dev/ESPAsyncWebServer/pull/836/files which I merged into my ESPAsyncWebServer fork _client->close(); is called because repsonse is finished.
3. close() will trigger the disconnect indication, which destroys the AsyncClient.
4. Unfortunately now code continues in _notifyWrittenBuffers() with the destroyed AsyncClient object.

What is your suggestion how to solve it?

[avillacis]

Do you have a particular connection sequence that reliably triggers this crash?

For my own projects, I use branch yuboxfixes-0xFEEDC0DE64-cleanup from the fork at https://github.com/yubox-node-org/ESPAsyncWebServer . It is not clear which particular fork and branch you are using to reproduce this crash. Could you please try switching to yuboxfixes-0xFEEDC0DE64-cleanup and attempt to reproduce?

[BlueAndi]

Yes, I can reproduce it with 90% probability.
Sequence:

1. Setup wifi access point with captive portal.
2. Connect with a Android mobile phone.
3. After the mobile phone requests further actions to access the net. Click on it.
4. Captive portal is loaded and it crashes.

I will try it with your variant of the webserver and come back.

[BlueAndi]

I can not reproduce it with your variant of the webserver. I think I will jump on yours for my project. :-)

What I figured out so far is in my problem use case, the WebResponse is closed too fast (state = RESPONSE_END).

https://github.com/yubox-node-org/ESPAsyncWebServer/blob/1dde9cf0219de662ed0882c0b6208057f70f105d/src/WebResponses.cpp#L359-L363

size_t AsyncAbstractResponse::_ack(AsyncWebServerRequest *request, size_t len, uint32_t time)

...

    if(!_sendContentLength || _ackedLength >= _writtenLength){
      _state = RESPONSE_END;
      if(!_chunked && !_sendContentLength)
        request->client()->close(true);
    }

...

Too fast means, the response is written back with two write() operations, because of less space.
With the _ack of the first part, the state is set to RESPONSE_END, which causes closing in the middle of AsyncClient::_notifyWrittenBuffers(), because _sendContentLength is false.

What I am not sure whether its a bug, but it solves the problem as well, is removing the !_sendContentLength condition in the upper check. Also without sending the content length header, we get the acknowledged length from the AsyncTcp, isn't it?

What's your opinion? I am not so deep familiar here.

[zekageri]

I'm using https://github.com/yubox-node-org/ESPAsyncWebServer as well and the exact same crash happening to me too.

[zekageri]

I can reproduce even if i comment out !_sendContentLength in https://github.com/yubox-node-org/ESPAsyncWebServer/blob/1dde9cf0219de662ed0882c0b6208057f70f105d/src/WebResponses.cpp#LL359C62-L359C62

[avillacis]

I'm using https://github.com/yubox-node-org/ESPAsyncWebServer as well and the exact same crash happening to me too.

Could you please build a minimal sketch that will reproduce the issue and post it here. I have been using the libraries for months on my own projects without issue.

I can reproduce even if i comment out !_sendContentLength in https://github.com/yubox-node-org/ESPAsyncWebServer/blob/1dde9cf0219de662ed0882c0b6208057f70f105d/src/WebResponses.cpp#LL359C62-L359C62

This explanation is suspect anyway. The real question is why would the code enter the RESPONSE_WAIT_ACK state when not all of the chunks have been written. Again, a minimal demonstration sketch would be nice.

[zekageri]

I will definitely make one because iam struggling with this async server for months now. I even got a said perfect fork of both of the libs from github somewhere else and I still got crashes.

Unfortunately Iam not able to make my own fork since I don't understand that so deeply.

My tests will include several front end files and it's gonna crash

[zekageri]

Here is the test repo: https://github.com/zekageri/AsyncServerTest/tree/main
For now it seems to me that it crashes when the clients wants to reconnect after something.

I connected 3 clients. Two from a desktop and one from a mobile.
Restarted the esp32. While it restarted the clients losed the connection, so they wanted to reconnect.
When the esp booted up all the client wanted to connect at once and the crash happened.

I'm testing large payloads as well as frequent messages for now.

[avillacis]

Here is the test repo: https://github.com/zekageri/AsyncServerTest/tree/main For now it seems to me that it crashes when the clients wants to reconnect after something.

I connected 3 clients. Two from a desktop and one from a mobile. Restarted the esp32. While it restarted the clients losed the connection, so they wanted to reconnect. When the esp booted up all the client wanted to connect at once and the crash happened.

I'm testing large payloads as well as frequent messages for now.

I am currently unable to reproduce the crash in my setup with your code.

• My test board is an ESP32 WROOM, no PSRAM, 4Mb flash.
• I am using Arduino IDE 1.8.19, not PlatformIO. My currently installed ESP32 platform is Arduino-ESP32 2.0.7, which embeds ESP-IDF 4.4.4.
• I checked the embedded libraries against my source trees used in my normal Arduino-ESP32 projects. Apart from DOS vs Unix line endings, the libraries are identical.
• Since the Arduino project layout is incompatible with PlatformIO, I created a new Arduino project folder, in which I copied the file AsyncServerTest/src/main.cpp and renamed it to AsyncServerTest-arduino.ino. Additionally, I extracted the files AsyncServerTest/src/socketHandler/socketHandler.* and placed them at the same level as the .ino file. Finally, I copied the AsyncServerTest-arduino/data/ to the Arduino project as is. Also, fixed the headers referencing socketHelper/... to be case sensitive and reference the same filesystem level.
• I installed the @lorol fork of the ESP32FS Arduino plugin in order to have the LittleFS filesystem available instead of the default SPIFFS, as required by your code.
• I opened two Firefox browser tabs and pointed them at the IP in my local WiFi, and one Google Chrome tab in my Android cellphone, to the same IP. I checked that all three sessions ping and pong as normal.
• I then restarted the board with its reset button. Device kept the same IP via DHCP, immediately received three connections. No crash. Waited a minute, then tried resetting it again. Again, no crash.

Is there something I should be doing differently?

[avillacis]

@zekageri I noticed you appear to be using ESP32-S2, so I tried replicating the test there. However, my ESP32-S2 keeps getting a different IP every time I reboot.

[avillacis]

I forced a static IP with WiFi.config(), then repeated the test on the ESP32-S2 with the same methodology. Again no crash after repeated reboots.

[zekageri]

Iam using wrom in my tests and not s2. In my real project iam using wrover with psram. So far I can not reproduce the same crash with the wrom. Will try with psram. Iam really confused as in my real project every clue is pointing to the Async lib. Will test further. Thank you for your tests. I really appreciate your help

[zekageri]

I can't belive this. Meanwhile in my big project it just happened again in front of my eyes.

assert failed: xQueueSemaphoreTake queue.c:1545 (( pxQueue ))


Backtrace: 0x40083d69:0x3ffd9820 0x4008eeb1:0x3ffd9840 0x400948b5:0x3ffd9860 0x4008fec1:0x3ffd9990 0x401a7b0b:0x3ffd99d0 0x401a7c6c:0x3ffd99f0 0x401a7db3:0x3ffd9a20 0x401a80c5:0x3ffd9a50 0x401a766b:0x3ffd9ab0

  #0  0x40083d69:0x3ffd9820 in panic_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/panic.c:402
  #1  0x4008eeb1:0x3ffd9840 in esp_system_abort at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_system/esp_system.c:128    
  #2  0x400948b5:0x3ffd9860 in __assert_func at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/assert.c:85
  #3  0x4008fec1:0x3ffd9990 in xQueueSemaphoreTake at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/queue.c:1549 (discriminator 1)
  #4  0x401a7b0b:0x3ffd99d0 in AsyncClient::_clearWriteQueue() at lib/AsyncTCPSock/src/AsyncTCP.cpp:1077
  #5  0x401a7c6c:0x3ffd99f0 in AsyncClient::_error(signed char) at lib/AsyncTCPSock/src/AsyncTCP.cpp:998
  #6  0x401a7db3:0x3ffd9a20 in AsyncClient::_notifyWrittenBuffers(std::deque<AsyncClient::notify_writebuf, std::allocator<AsyncClient::notify_writebuf> >&, int) at lib/AsyncTCPSock/src/AsyncTCP.cpp:846 (discriminator 1)
  #7  0x401a80c5:0x3ffd9a50 in AsyncClient::_sockIsWriteable() at lib/AsyncTCPSock/src/AsyncTCP.cpp:733
  #8  0x401a766b:0x3ffd9ab0 in _asynctcpsock_task(void*) at lib/AsyncTCPSock/src/AsyncTCP.cpp:141 (discriminator 1)




ELF file SHA256: 83667e7d6bcd3ad4

Rebooting...

[zekageri]

Three client refresh at the same time.