[Bug] WDT reset due to infinite wait in retrieveServices/readValue & potential bug with custom timeout

[yorling]

【Description】

I am experiencing an issue where the ESP32 occasionally encounters a WDT reset (Watchdog Timer reset) when calling client->getService(servName) or pService->getCharacteristic(charName). It appears that the library hangs indefinitely while waiting for a response from the BLE server.

【My Workaround】

To prevent the device from freezing, I modified the source code to add a timeout mechanism. I replaced the infinite wait flag BLE_NPL_TIME_FOREVER with a fixed timeout (e.g., 3000ms) in the following functions:

-- NimBLEClient::retrieveServices
-- NimBLERemoteService::retrieveCharacteristics
-- NimBLERemoteValueAttribute::readValue
Code Change:
// Original
NimBLEUtils::taskWait(taskData, BLE_NPL_TIME_FOREVER);
// Modified
NimBLEUtils::taskWait(taskData, 3000); // 3 second timeout

【The Problem】

While this successfully prevents the WDT reset, when I use NimBLEDevice::deleteClient(client) to release the client after the 3-second timeout, it occasionally triggers a bug. This bug appears to be caused by xTaskNotify(static_cast<TaskHandle_t>(taskData.m_pHandle), TASK_BLOCK_BIT, eSetBits) inside NimBLEUtils::taskRelease:

D NimBLEClient: Service Discovered >> status: 7 handle: -1
NimBLEClient: << Service Discovered; Disconnected
Guru Meditation Error: Core  0 panic'ed (LoadStoreError). Exception was unhandled.
Core  0 register dump:
PC      : 0x40099a22  PS      : 0x00060233  A0      : 0x800d859d  A1      : 0x3ffd4e70  
A2      : 0x3f4069f8  A3      : 0x00000000  A4      : 0x80000000  A5      : 0x00000001  
A6      : 0x00000000  A7      : 0x3f4069f8  A8      : 0x0000008b  A9      : 0x3f406af8  
A10     : 0x00000002  A11     : 0xffffffff  A12     : 0x0000002d  A13     : 0x00060223  
A14     : 0x00000002  A15     : 0x0000cdcd  SAR     : 0x00000010  EXCCAUSE: 0x00000003  
EXCVADDR: 0x3f406b54  LBEG    : 0x400930d5  LEND    : 0x400930e5  LCOUNT  : 0xfffffffd  
Backtrace: 0x40099a1f:0x3ffd4e70 0x400d859a:0x3ffd4e90 0x400d5d0a:0x3ffd4eb0 0x400de46f:0x3ffd4ee0 0x400de4a3:0x3ffd4f00 0x400def29:0x3ffd4f20 0x400dfcb3:0x3ffd4f50 0x400dd7e3:0x3ffd4f70 0x400dd878:0x3ffd4fd0 0x400e2276:0x3ffd5030 0x400e24b5:0x3ffd5050 0x400e10bd:0x3ffd5070 0x400e8d25:0x3ffd5090 0x400d5dff:0x3ffd50b0 0x40097385:0x3ffd50d0
  #0  0x40099a1f in xTaskGenericNotify at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:5921
  #1  0x400d859a in NimBLEUtils::taskRelease(NimBLETaskData const&, int) at lib/NimBLE-Arduino/src/NimBLEUtils.cpp:127
  #2  0x400d5d0a in NimBLEClient::serviceDiscoveredCB(unsigned short, ble_gatt_error const*, ble_gatt_svc const*, void*) at lib/NimBLE-Arduino/src/NimBLEClient.cpp:790

【Questions】

How should I properly handle the timeout to avoid this secondary bug?
Is it possible for the official library to integrate a configurable timeout feature for these blocking calls to make them more robust?

[yorling]

NimBLE-Arduino version 2.4.0

[h2zero]

The reason for those timers to be set forever like that is because the stack is guaranteed to call the callback that releases it.
I suspect the issue that's causing this for you is your code is calling these blocking functions from a callback, which is not supported.

[yorling]

@h2zero I am developing a Bluetooth gateway that needs to frequently connect to different devices and read GATT values. I very often encounter infinite waiting situations. This happens multiple times within an hour and causes the device to restart. Is there any solution to resolve the infinite waiting issue?

[yorling]

@h2zero

my code:

BLEClientGuard::~BLEClientGuard() {
  if (client != nullptr) {
    static EmptyCallbacks emptyCallbacks;
    client->setClientCallbacks(&emptyCallbacks, false);
    // 【After I modified the source code to incorporate a timeout function,
    //  the aforementioned bug(Guru Meditation Error) would occasionally occur after calling deleteClient() when a
    //  timeout occurred. Even after set an EmptyCallbacks, the problem still cannot be solved】
    NimBLEDevice::deleteClient(client);
    client = nullptr;
  }
}

bool readGatt(...) {
  // other code...
  xxx...
  // auto release client
  BLEClientGuard guard;
  if (!guard.client) {
      return false;
  }
  // connect
  NimBLEAddress address(mac, BLE_ADDR_PUBLIC);
  guard.client->setConnectTimeout(5000);
  if (!guard.client->connect(address)) {
    return false;
  }
  // getService【Perhaps waiting forever】
  NimBLERemoteService *pService = guard.client->getService(servName);
  if (pService == nullptr) {
    return false;
  }
  // getCharacteristic【Perhaps waiting forever】
  NimBLERemoteCharacteristic *pChar = pService->getCharacteristic(charName);
  if (pChar == nullptr) {
    return false;
  }
  // readValue【Perhaps waiting forever】
  String readData = pChar->readValue();
  respStr = bytesToHex(readData);
  Serial.printf("respStr(Hex): %s\n", respStr.c_str());
  return true;
}```

[h2zero]

Thanks, but it doesn't really show the context of these calls.

I have opened #1136 that will help discover why your code hangs, if your calls are in the host task context this PR will print an error and return immediately.

We need to find the cause of these calls hanging, the WDT timeout is just the symptom of the problem.

[yorling]

@h2zero

After merging the code from branch "err-on-block" into branch "2.4.0", the following error log was encountered. It seems that the log "xxx cannot be called from host task" was not printed.

12:17:13.121 > D NimBLERemoteService: << Characteristic found
12:17:13.126 > ------ start readValue...
12:17:13.131 > D NimBLERemoteValueAttribute: >> readValue()
12:17:16.131 > D NimBLERemoteValueAttribute: << readValue
12:17:16.131 > ------ readValue = null
12:17:16.136 > ------ NimBLEDevice.delectClient start
12:17:16.136 > D NimBLERemoteService: Characteristic Discovery >> status: 7 handle: -1
12:17:16.147 > E NimBLERemoteService: << Characteristic Discovery; Not connected
12:17:16.153 > E NimBLEUtils: taskRelease() xTaskNotify start
12:17:16.153 > 
12:17:16.153 > E NimBLEUtils: taskRelease() xTaskNotify end
12:17:16.158 > 
12:17:16.158 > E NimBLERemoteService: << taskRelease over
12:17:16.164 > E NimBLERemoteValueAttribute: << Read complete; Not connected
12:17:16.170 > E NimBLEUtils: taskRelease() xTaskNotify start
12:17:16.175 > 
12:17:16.175 > E NimBLGuru Meditation Error: Core  1 panic'ed (Double exception). 
12:17:16.181 > 
12:17:16.181 > Core  1 register dump:
12:17:16.181 > PC      : 0x4009f5be  PS      : 0x00040436  A0      : 0x800f603d  A1      : 0x3ffd0cc0  
12:17:16.186 > A2      : 0x00000002  A3      : 0x3ffbdd1c  A4      : 0x00000000  A5      : 0x00000002  
12:17:16.197 > A6      : 0x3ffe3244  A7      : 0x3ffc44ec  A8      : 0x800f990c  A9      : 0x3ffd0ca0  
12:17:16.203 > A10     : 0x00000002  A11     : 0x00060620  A12     : 0x400977db  A13     : 0x3ffd0c70  
12:17:16.214 > A14     : 0x00000000  A15     : 0x3ffd1228  SAR     : 0x0000001b  EXCCAUSE: 0x00000002  
12:17:16.219 > EXCVADDR: 0xffffffd7  LBEG    : 0x4008393d  LEND    : 0x40083945  LCOUNT  : 0x00000027  
12:17:16.225 > 
12:17:16.230 > 
12:17:16.230 > Backtrace: 0x4009f5bb:0x3ffd0cc0 0x400f603a:0x00000007 |<-CORRUPTED
  #0  0x4009f5bb in _xt_context_save at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/xtensa/xtensa_context.S:202
  #1  0x400f603a in readGatt(char const*, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&) at src/main.cpp:221 (discriminator 1)```

[yorling]

After merging the code from the "err-on-block branch", I didn't see any "xxx cannot be called from host task" logs. This suggests that the root cause of the crash might not be in the area you modified.

However, after some investigation, I managed to resolve the "Guru Meditation Error" by implementing a finite timeout for NimBLEUtils::taskWait.

I've pasted my code below. I hope you find it useful. Could you please review it to make it more robust and consider integrating this finite timeout logic into your main codebase?

-- NimBLEClient::retrieveServices
-- NimBLERemoteService::retrieveCharacteristics
-- NimBLERemoteValueAttribute::readValue
Code Change:
// Original
NimBLEUtils::taskWait(taskData, BLE_NPL_TIME_FOREVER);
// Modified
NimBLEUtils::taskWait(taskData, 3000); // finite timeout

void NimBLEUtils::taskRelease(const NimBLETaskData& taskData, int flags) {
    NIMBLE_LOGE(LOG_TAG, "taskRelease() >> start");
    // Add: Check handler
    if (taskData.m_pHandle == nullptr) {
        NIMBLE_LOGE(LOG_TAG, "taskRelease() >> xTaskNotify cancel, because m_pHandle is nullptr");
        return;
    }
    // Add: Check pointer address. A dangling pointer will cause a "Guru Meditation Error".
    TaskHandle_t taskHandle = static_cast<TaskHandle_t>(taskData.m_pHandle);
    NIMBLE_LOGE(LOG_TAG, "taskRelease() >> 1");
    uint32_t handleAddr = (uint32_t)taskHandle;
    NIMBLE_LOGE(LOG_TAG, "taskRelease() >> handleAddr: 0x%08X", handleAddr);
    if (handleAddr == 0 || handleAddr < 0x3FF00000 || handleAddr > 0x3FFFFFFF) { // ESP32 RAM range
        NIMBLE_LOGE(LOG_TAG, "taskRelease() >> xTaskNotify cancel, because handleAddr not in (0x3FF00000~0x3FFFFFFF)");
        return;
    }
    // Add: Check task state. A "Guru Meditation Error" occurs when the state is 1 (eReady) or 4 (eDeleted).
    eTaskState taskState = eTaskGetState(taskHandle);
    NIMBLE_LOGE(LOG_TAG, "taskRelease() >> taskState: %d", taskState);
    if (taskState == eReady || taskState == eDeleted || taskState == eInvalid) {
        NIMBLE_LOGE(LOG_TAG, "taskRelease() >> xTaskNotify cancel, because taskState in (1:eReady/4:eDeleted/5:eInvalid)");
        return;
    }
    // Original code
    taskData.m_flags = flags;
    # if defined INC_FREERTOS_H
        xTaskNotify(taskHandle, TASK_BLOCK_BIT, eSetBits);
        NIMBLE_LOGE(LOG_TAG, "taskRelease() >> xTaskNotify success");
    # else
        ble_npl_sem_release(static_cast<ble_npl_sem*>(taskData.m_pHandle));
    # endif
    NIMBLE_LOGE(LOG_TAG, "taskRelease() << end");
}