NimBLE-Arduino: Broken characteristic state in `onReadCB`

Hi, first of all, big thanks for maintaining the project! I’m running into a problem with my project after upgrading some dependencies, including moving NimBLE version from 1.2 to 1.3. It seems to me that the RemoteService is in a wrong state (client being null) here: uint16_t conn_id = characteristic->getRemoteService()->getClient()->getConnId();

I’m not sure how to investigate what is the reason of the error - the logic in my project hasn’t changed, just the dependencies. It happens when I’m subscribing to a characteristic right after reading its value.

Could you give me some pointers on what to try next?

Here are the logs right before the crash and the stacktrace:

HTTP server started
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0035 len=5
0x35 0x0c 0x05 0x01 0x00 0x00 0x01 0x00 
D NimBLERemoteCharacteristic: ">> readValue(): uuid: 99fa0021-338a-1024-8a49-009c0215f78a, handle: 26 0x1a"
GATT procedure initiated: read long; att_handle=26
host tx hci data; handle=0 length=7
ble_hs_hci_acl_tx(): 0x00 0x00 0x07 0x00 0x03 0x00 0x04 0x00 0x0a 0x1a 0x00 
D NimBLERemoteCharacteristic: "<< readValue length: 0 rc=0"
D NimBLERemoteCharacteristic: ">> setNotify(): Characteristic: uuid: 99fa0021-338a-1024-8a49-009c0215f78a, handle: 26 0x001a, props:  0x12, 01"
D NimBLERemoteCharacteristic: ">> getDescriptor: uuid: 0x2902"
D NimBLERemoteCharacteristic: ">> retrieveDescriptors() for characteristic: 99fa0021-338a-1024-8a49-009c0215f78a"
GATT procedure initiated: discover all characteristics; start_handle=26 end_handle=31
host tx hci data; handle=0 length=11
ble_hs_hci_acl_tx(): 0x00 0x00 0x0b 0x00 0x07 0x00 0x04 0x00 0x08 0x1a 0x00 0x1f 0x00 0x03 0x28 
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=9 data=0x05 0x00 0x04 0x00 0x0b 0x51 0x04 0x00 0x00 
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x401b60db  PS      : 0x00060e30  A0      : 0x80186fb8  A1      : 0x3ffdbd00  
A2      : 0x00000000  A3      : 0x00000009  A4      : 0x00000009  A5      : 0x00060023  
A6      : 0x007daf30  A7      : 0x003fffff  A8      : 0x8018fa51  A9      : 0x3ffdbd00  
A10     : 0x00000002  A11     : 0x00000000  A12     : 0x00060e20  A13     : 0x3ffc80e4  
A14     : 0x00000000  A15     : 0x00000001  SAR     : 0x00000010  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000010  LBEG    : 0x40189264  LEND    : 0x40189270  LCOUNT  : 0x00000010  


Backtrace:0x401b60d8:0x3ffdbd000x40186fb5:0x3ffdbd20 0x4018cf8b:0x3ffdbd60 0x4018db6d:0x3ffdbd80 0x4018e73c:0x3ffdbdb0 0x40189778:0x3ffdbde0 0x40189294:0x3ffdbe00 0x401910d6:0x3ffdbe30 0x4018fa64:0x3ffdbe60 0x4018fa6f:0x3ffdbe80 0x40197372:0x3ffdbea0 0x40185f51:0x3ffdbec0 
  #0  0x401b60d8:0x3ffdbd00 in NimBLERemoteService::getClient() at .pio/libdeps/esp32dev/NimBLE-Arduino/src/NimBLERemoteService.cpp:254
  #1  0x40186fb5:0x3ffdbd20 in NimBLERemoteCharacteristic::onReadCB(unsigned short, ble_gatt_error const*, ble_gatt_attr*, void*) at .pio/libdeps/esp32dev/NimBLE-Arduino/src/NimBLERemoteCharacteristic.cpp:541
  #2  0x4018cf8b:0x3ffdbd60 in ble_gattc_read_long_cb at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_gattc.c:3086
  #3  0x4018db6d:0x3ffdbd80 in ble_gattc_read_long_rx_read_rsp at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_gattc.c:3180
  #4  0x4018e73c:0x3ffdbdb0 in ble_gattc_rx_read_rsp at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_gattc.c:4612
  #5  0x40189778:0x3ffdbde0 in ble_att_clt_rx_read at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_att_clt.c:478
  #6  0x40189294:0x3ffdbe00 in ble_att_rx at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_att.c:503
  #7  0x401910d6:0x3ffdbe30 in ble_hs_hci_evt_acl_process at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_hs_hci_evt.c:929
  #8  0x4018fa64:0x3ffdbe60 in ble_hs_process_rx_data_queue at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_hs.c:238
  #9  0x4018fa6f:0x3ffdbe80 in ble_hs_event_rx_data at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/host/src/ble_hs.c:532
  #10 0x40197372:0x3ffdbea0 in ble_npl_event_run at .pio/libdeps/esp32dev/NimBLE-Arduino/src/nimble/nimble_npl_os.h:121
      (inlined by) nimble_port_run at .pio/libdeps/esp32dev/NimBLE-Arduino/src/porting/nimble/src/nimble_port.c:81
  #11 0x40185f51:0x3ffdbec0 in NimBLEDevice::host_task(void*) at .pio/libdeps/esp32dev/NimBLE-Arduino/src/NimBLEDevice.cpp:728




ELF file SHA256: 0000000000000000

Rebooting...

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 29 (16 by maintainers)

Commits related to this issue

Most upvoted comments

Amazingly I was able to reproduce this in IDF, which allowed for some debugging. A few quick asserts lead me to this line: https://github.com/espressif/esp-idf/blob/5c33570524118873f7bd32490c7a0442fede4bf8/components/esp_timer/src/esp_timer.c#L413

Seems the new esp_timer library doesn’t play nice with task notifications or there is something going on with the task pointer. I will merge the PR for now as it also resolves #324 but I may need to look at reworking this in the future.

Hey, a small update: as I know very little about freertos tasks running underneath Arduino core on ESP32, I’ve decided to learn more about it. In the implementation of ulTaskNotifyTake I’ve found this comment: https://github.com/espressif/esp-idf/blob/5624dffc52271389376352974ba5911963ee207b/components/freertos/FreeRTOS-Kernel/tasks.c#L5360 Which lead me to the following experiment: I’ve added

ulTaskNotifyValueClear(xTaskGetCurrentTaskHandle(), UINT_MAX);

right before https://github.com/h2zero/NimBLE-Arduino/blob/4a6111d9639053caddc398f67b3dd455b26eb3aa/src/NimBLERemoteCharacteristic.cpp#L488

and it didn’t crash! here are the logs including the ones from debug branch:

connected
D NimBLERemoteCharacteristic: ">> readValue(): uuid: 99fa0021-338a-1024-8a49-009c0215f78a, handle: 26 0x1a"
D NimBLERemoteCharacteristic: "readValue WAIT"
I NimBLERemoteCharacteristic: "Read complete; status=0 conn_handle=0"
D NimBLERemoteCharacteristic: "Got 4 bytes"
I NimBLERemoteCharacteristic: "Read complete; status=14 conn_handle=0"
D NimBLERemoteCharacteristic: "onReadCB GIVE 14"
D NimBLERemoteCharacteristic: "readValue CONTINUE"
D NimBLERemoteCharacteristic: "<< readValue length: 4 rc=0"
Current height: 1101 mm
Getting height and printing it took: 216ms
After waiting 0.00 secs , WiFi connection result is 3
Local IP: 192.168.0.122
HTTP server started
D NimBLERemoteCharacteristic: ">> readValue(): uuid: 99fa0021-338a-1024-8a49-009c0215f78a, handle: 26 0x1a"
D NimBLERemoteCharacteristic: "readValue WAIT"
I NimBLERemoteCharacteristic: "Read complete; status=0 conn_handle=0"
D NimBLERemoteCharacteristic: "Got 4 bytes"
I NimBLERemoteCharacteristic: "Read complete; status=14 conn_handle=0"
D NimBLERemoteCharacteristic: "onReadCB GIVE 14"
D NimBLERemoteCharacteristic: "readValue CONTINUE"
D NimBLERemoteCharacteristic: "<< readValue length: 4 rc=0"
D NimBLERemoteCharacteristic: ">> setNotify(): Characteristic: uuid: 99fa0021-338a-1024-8a49-009c0215f78a, handle: 26 0x001a, props:  0x12, 01"
D NimBLERemoteCharacteristic: ">> getDescriptor: uuid: 0x2902"
D NimBLERemoteCharacteristic: ">> retrieveDescriptors() for characteristic: 99fa0021-338a-1024-8a49-009c0215f78a"
D NimBLERemoteCharacteristic: "getEndHandle WAIT"
D NimBLERemoteCharacteristic: "Next Characteristic >> status: 0 handle: 29"
D NimBLERemoteCharacteristic: "nextCharCB GIVE 14"
D NimBLERemoteCharacteristic: "getEndHandle CONTINUE"
D NimBLERemoteCharacteristic: "retrieveDescriptors WAIT"
D NimBLERemoteCharacteristic: "Descriptor Discovered >> status: 0 handle: 27"
D NimBLERemoteDescriptor: ">> NimBLERemoteDescriptor()"
[...]

It seems that the previous read somehow didn’t clean the state.