Panic reset when scanning and several concurrent http requests occur

[pletch]

Working with others on a project which leverages NimBLE as a client only receiving advertisements (ADV_NONCONN_IND) from up to 8 devices. We have recently converted the project over to use ESPAsyncWebserver and have started experiencing sporadic PANIC resets. A reset can be fairly reliably triggered by hard reloading one of the pages with several concurrent jQuery requests repeatedly. We suspect this relates to competition for radio time between WiFi and BLE but are unsure about this aspect. Have done some troubleshooting such as trying to adjust the Scan Interval and Scan Window but have not been able to reliably eliminate the issue and am looking for ideas. The backtrace is always the same and appears to indicate that the PANIC is being triggered in NimBLE related code.

Any guidance on whether this likely points to a problem with our implementation or whether we have uncovered a library issue is much appreciated!

Logging output:
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000c len=2
0x0c 0x20 0x02 0x00 0x00
Command complete: cmd_pkts=5 ogf=0x8 ocf=0xc status=0
GAP procedure initiated: discovery; own_addr_type=0 filter_policy=0 passive=1 limited=0 filter_duplicates=0 duration=3000ms
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000b len=7
0x0b 0x20 0x07 0x00 0x54 0x00 0x3b 0x00 0x00 0x00
Command complete: cmd_pkts=5 ogf=0x8 ocf=0xb status=0
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000c len=2
0x0c 0x20 0x02 0x01 0x00

Backtrace: 0x40091fa4:0x3ffbdc20 0x400921d5:0x3ffbdc40 0x40085a9d:0x3ffbdc60 0x40085bc9:0x3ffbdc90 0x40180377:0x3ffbdcb0 0x4017ad15:0x3ffbdf70 0x40177de9:0x3ffbdfc0 0x400ee0e2:0x3ffbdff0 0x401c75ea:0x3ffbe010 0x401bba2a:0x3ffbe030 0x4001791d:0x3ffbe050 0x401bc029:0x3ffbe070 0x401bc106:0x3ffbe0b0 0x400188f5:0x3ffbe0e0 0x400175ee:0x3ffbe120 0x40017688:0x3ffbe140 0x4008cb36:0x3ffbe170 0x4008cd0b:0x3ffbe190 0x401bb9d7:0x3ffbe1b0 0x4008cd28:0x3ffbe1d0 0x40085025:0x3ffbe1f0 0x4008583e:0x3ffb9d00 0x4008cadd:0x3ffb9d20 0x401c7789:0x3ffb9d40 0x401aa088:0x3ffb9d60 0x400edd8d:0x3ffb9d80 0x40082b53:0x3ffb9da0 0x4008e33d:0x3ffb9dc0
#0 0x40091fa4:0x3ffbdc20 in invoke_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
#1 0x400921d5:0x3ffbdc40 in abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
#2 0x40085a9d:0x3ffbdc60 in lock_acquire_generic at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/locks.c:143
#3 0x40085bc9:0x3ffbdc90 in _lock_acquire_recursive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/locks.c:171
#4 0x40180377:0x3ffbdcb0 in _vfiprintf_r at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdio/../../../.././newlib/libc/stdio/vfprintf.c:860 (discriminator 2)
#5 0x4017ad15:0x3ffbdf70 in fiprintf at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdio/../../../.././newlib/libc/stdio/fiprintf.c:50
#6 0x40177de9:0x3ffbdfc0 in __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:59 (discriminator 8)
#7 0x400ee0e2:0x3ffbdff0 in host_rcv_pkt at .pio\libdeps\lcd_ssd1306\NimBLE-Arduino@src-e248a3b4ca528fb2d5b4751077939ebd\src\esp-hci\src/esp_nimble_hci.c:365
#8 0x401c75ea:0x3ffbe010 in vhci_send at ??:?
#9 0x401bba2a:0x3ffbe030 in r_eif_send at ??:?
#10 0x4001791d:0x3ffbe050 in ?? ??:0
#11 0x401bc029:0x3ffbe070 in hci_tx_start at hci_tl.c:?
#12 0x401bc106:0x3ffbe0b0 in r_hci_tl_send at ??:?
#13 0x400188f5:0x3ffbe0e0 in ?? ??:0
#14 0x400175ee:0x3ffbe120 in ?? ??:0
#15 0x40017688:0x3ffbe140 in ?? ??:0
#16 0x4008cb36:0x3ffbe170 in vhci_recv_end at vhci.c:?
#17 0x4008cd0b:0x3ffbe190 in r_vhci_isr at ??:?
#18 0x401bb9d7:0x3ffbe1b0 in r_eif_isr at ??:?
#19 0x4008cd28:0x3ffbe1d0 in r_eif_isr_wrapper at intc.c:?
#20 0x40085025:0x3ffbe1f0 in _xt_lowint1 at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/xtensa_vectors.S:1154
#21 0x4008583e:0x3ffb9d00 in cause_sw_intr_to_core_wrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/bt/bt.c:1322
#22 0x4008cadd:0x3ffb9d20 in vhci_set_interrupt at vhci.c:?
#23 0x401c7789:0x3ffb9d40 in API_vhci_host_send_packet at ??:?
#24 0x401aa088:0x3ffb9d60 in esp_vhci_host_send_packet at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/bt/bt.c:1322
#25 0x400edd8d:0x3ffb9d80 in ble_hci_trans_hs_cmd_tx_on_core_0 at .pio\libdeps\lcd_ssd1306\NimBLE-Arduino@src-e248a3b4ca528fb2d5b4751077939ebd\src\esp-hci\src/esp_nimble_hci.c:171
#26 0x40082b53:0x3ffb9da0 in ipc_task at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/ipc.c:62
#27 0x4008e33d:0x3ffb9dc0 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

[doudar]

I can only add that I fought the exact same issue for a couple weeks with espasyncwebserver and the old Bluetooth library. I ended up dropping back to the regular webserver and using client side JavaScript to provide the functionality I needed.

[h2zero]

Well I cannot say for sure what is happening here but I found this interesting, in 7 this assert is triggered. This is a message from the controller that it has encountered a hardware error.

Not much to work with here, except perhaps a power issue. If not that, then perhaps a bug in the controller, guessing by the previous area of the backtrace (who knows here, it's black magic).

One other thing it could be that could be tested however, is the commands being sent from core 0. This is a modification made to the esp-nimble files to address delay issues when sending commands from core 1. If you revert this commit and test I'd be very curious of the results.

[justoke]

Hi. I have run into the same issue running an http server using ESPAsyncWebserver and scanning BLE - my understanding is that this is hardware problem in that the WiFi and BLE share the same hardware radio. Meaning that you have a harder software problem to balance scanning BLE for devices and servicing Wifi packets as they share the data pipeline. I've not found a solution yet and may have to make a separate controller for BLE scanning as the ESP32 crashes often or the http server takes as long to respond as the shortest scanning cycle. It seems while BLE scan is in progress you can't service http requests.

I'll share my findings if I manage to come up with a workable approach.

[justoke]

Backtrace: 0x40091fa4:0x3ffbdc20 0x400921d5:0x3ffbdc40 0x40085a9d:0x3ffbdc60 0x40085bc9:0x3ffbdc90 0x40180377:0x3ffbdcb0 0x4017ad15:0x3ffbdf70 0x40177de9:0x3ffbdfc0 0x400ee0e2:0x3ffbdff0 0x401c75ea:0x3ffbe010 0x401bba2a:0x3ffbe030 0x4001791d:0x3ffbe050 0x401bc029:0x3ffbe070 0x401bc106:0x3ffbe0b0 0x400188f5:0x3ffbe0e0 0x400175ee:0x3ffbe120 0x40017688:0x3ffbe140 0x4008cb36:0x3ffbe170 0x4008cd0b:0x3ffbe190 0x401bb9d7:0x3ffbe1b0 0x4008cd28:0x3ffbe1d0 0x40085025:0x3ffbe1f0 0x4008583e:0x3ffb9d00 0x4008cadd:0x3ffb9d20 0x401c7789:0x3ffb9d40 0x401aa088:0x3ffb9d60 0x400edd8d:0x3ffb9d80 0x40082b53:0x3ffb9da0 0x4008e33d:0x3ffb9dc0

I've put that through an Exception Decoder. It looks like its related to the WiFi data, DNS and so on - I get the same sort of issues. If I find a workable approach I'll share it.

[doudar]

Nimble works perfectly fine with me with all of these libraries, even during scan. It's just the espasync . Which sucks because it is a nice webserver. You can however spin off the regular webserver below on its own task and it works reasonably well. Good luck!

#include <WebServer.h>
#include <HTTPClient.h>
#include <HTTPUpdate.h>
#include <SPIFFS.h>
#include <ESPmDNS.h>
#include <WiFiClientSecure.h>
#include <Update.h>
#include <DNSServer.h>

[justoke]

Someone did mention power supply maybe needing a capacitor to deal with extra power needed during scan. Has anyone tried the setActiveScan with false or observed anything related to this setting and stability with Wifi and BLE. I'll try this myself anyway and see if this helps.

[lbussy]

I'm one of the unnamed co-conspirators.

Not much to work with here, except perhaps a power issue.

I can help rule-out the power unless it's a design flaw in the dev board itself (Lolin D32 Pro.) There's three of us working on this with similar results, it seems unlikely all of us have flakey power. I'd also expect to see a reset caused by brownout, not a panic. Unless you see something I do not?

Has anyone tried the setActiveScan with false or observed anything related to this setting and stability with Wifi and BLE.

setActiveScan is set to false. We are just using the iBeacon in this project.

@justoke which exception decoder are you using? I've had horrible results trying to consistently use those, but that would be a nice thing to figure out. I am using the esp32_exception_decoder built in to PIO and I get this which does not show the same information:

Backtrace: 0x40091978:0x3ffbe190 0x40091ba9:0x3ffbe1b0 0x40121f58:0x3ffbe1d0 0x400847ed:0x3ffbe1f0 0x401c4ecf:0x3ffb5cf0 0x401c65c5:0x3ffb5d60 0x401c3adb:0x3ffb5db0 0x401c106e:0x3ffb5e00 0x40019d11:0x3ffb5e40 0x40055b4d:0x3ffb5e60 0x401bb1e7:0x3ffb5e80 0x401bb731:0x3ffb5ea0 0x4008dd45:0x3ffb5ed0
  #0  0x40091978:0x3ffbe190 in invoke_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
  #1  0x40091ba9:0x3ffbe1b0 in abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
  #2  0x40121f58:0x3ffbe1d0 in task_wdt_isr at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/task_wdt.c:252
  #3  0x400847ed:0x3ffbe1f0 in _xt_lowint1 at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/xtensa_vectors.S:1154
  #4  0x401c4ecf:0x3ffb5cf0 in r_llm_le_adv_report_ind at ??:?
  #5  0x401c65c5:0x3ffb5d60 in r_llm_pdu_defer at ??:?
  #6  0x401c3adb:0x3ffb5db0 in r_lld_pdu_check at ??:?
  #7  0x401c106e:0x3ffb5e00 in r_lld_evt_deffered_elt_handler at ??:?
  #8  0x40019d11:0x3ffb5e40 in ?? ??:0
  #9  0x40055b4d:0x3ffb5e60 in ?? ??:0
  #10 0x401bb1e7:0x3ffb5e80 in r_rw_schedule at ??:?
  #11 0x401bb731:0x3ffb5ea0 in btdm_controller_task at ??:?
  #12 0x4008dd45:0x3ffb5ed0 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

I ended up dropping back to the regular webserver

Rolling back to use the synchronous web server is an undesirable outcome. The performance difference between the two is quite pronounced for this application. Unless I inline all of the code (undesirable from a re-use and maintenance standpoint), a single connection would be quite bad.

One other thing it could be that could be tested however, is the commands being sent from core 0. This is a modification made to the esp-nimble files to address delay issues when sending commands from core 1. If you revert this commit and test I'd be very curious of the results.

The web server (async specifically) is pinned to core 1 per this note. Removing that makes things quite a bit worse, I did attempt to pin NimBLE to core 1 as well with no improvement.

Reverting that commit has proved challenging for me, and I'm sure it's something I am forgetting but I don't see it:

git log --oneline  
bc52eac (grafted, HEAD -> master, origin/master, origin/HEAD) Fix attributes not found with 16/32bit UUIDs.

I appreciate the folks here willing to help out. If it's something we need to bring upstream we can obviously do that. It's just quite a bit more challenging to work there.

[justoke]

I think this might resolve your issue on ESP32. Add this define you your code - in main.cpp if you are using Platform IO
#define CONFIG_ASYNC_TCP_RUNNING_CORE 1

This will pin the AsyncWebserver which runs as a FreeRTOS task on CORE 1. I tried this and although the web server can still get blocked by the BLE(apparent because the web server response times are longer when the scan is in progress), it has not crashed since I tried this and often it responds in sub 100ms times which is as good as I could hope for. I implemented some other things specific to my use case - like blocking my loop() task logic while updating data from the BLE onResult() event.

[lbussy]

I think this might resolve your issue on ESP32.

Yes, sir - already doing that. My comment about it was not horribly clear in retrospect. I've edited my post above.

[justoke]

@lbussy I used this decode the exceptions https://github.com/me-no-dev/EspExceptionDecoder. Although I mainly use PIO, this is the only thing I use Arduino IDE for.

[justoke]

I think this might resolve your issue on ESP32.

Yes, sir - already doing that. My comment about it was not horribly clear in retrospect. I've edited my post above.

I had replied before I saw your comment. I'm happy to try help you. I was definitely in a world of pain before I made the core assignment. Of course my use case will differ from yours, but maybe there is an approach to what I have done that might help you.

[lbussy]

Thanks - I really hate going back to the Arduino IDE after PIO.

So here's something interesting. I have a fork of ESPAsynchWebServer I was using elsewhere and I pulled that in instead. The behavior is much improved (but not perfect). Here's the PR I merged in my fork:

https://github.com/me-no-dev/ESPAsyncWebServer/pull/836/files

As you can see the difference is basically cleaning up connections. It's not making perfect sense yet as I've not had my coffee - but you are 5 hours ahead so maybe it strikes a chord with you.

[lbussy]

I was definitely in a world of pain before I made the core assignment. Of course my use case will differ from yours, but maybe there is an approach to what I have done that might help you.

I agree - and we're using that:

    -D CONFIG_ASYNC_TCP_RUNNING_CORE=1  ; per: https://github.com/me-no-dev/ESPAsyncWebServer/issues/731#issuecomment-628163515
    -D CONFIG_ASYNC_TCP_USE_WDT=1

So aside from the PR up there having a net positive impact, if I remove the CONFIG_ASYNC_TCP_USE_WDT=1 define I get no crashes, but eventually the webserver stops responding.

We're poking in the right place for sure.

[h2zero]

I can help rule-out the power unless it's a design flaw in the dev board itself (Lolin D32 Pro.) There's three of us working on this with similar results, it seems unlikely all of us have flakey power. I'd also expect to see a reset caused by brownout, not a panic. Unless you see something I do not?

If the regulator is weak, which it may be on this board, the voltage might dip low enough to cause an error but not low enough to trigger the brownout detection (2.43v default in arduino). So if your regulator dropped to, say, 2.9v, that might be enough to trigger this. Just speculating here though, you would have to measure with a scope or meter to detect min levels.

Hopefully your PR there will lead to a software resolution though.

[doudar]

Thanks - I really hate going back to the Arduino IDE after PIO.

So here's something interesting. I have a fork of ESPAsynchWebServer I was using elsewhere and I pulled that in instead. The behavior is much improved (but not perfect). Here's the PR I merged in my fork:

https://github.com/me-no-dev/ESPAsyncWebServer/pull/836/files

As you can see the difference is basically cleaning up connections. It's not making perfect sense yet as I've not had my coffee - but you are 5 hours ahead so maybe it strikes a chord with you.

FYI, you can still work in PIO and just use the trace debugger
In Arduino IDE separately. When you select it from the menu, it asks for your firmware.elf file (grab it from your .pio folder) and paste the debug message into the window that pops up.