Skip to content

Commit 06441a2

Browse files
committed
Stop BLE log streaming from starving the NimBLE notify pool
sendLog() notified once per firmware log line with no backpressure. With debug_log_api_enabled and a subscribed client, a logging burst drains the msys_1 mbuf pool that every GATT notification and ATT response allocates from, so ble_gatts_notify_custom starts returning BLE_HS_ENOMEM (rc=6) -- for the fromNum doorbell too, not just the log line that exhausted it. Each failure then prints an error over serial at ~12ms apiece, which is itself enough to throttle the main loop during a burst. Register a callback on the log characteristic so the host's own ERROR_GATT verdict pauses log notifies for 250ms and lets the pool refill. Keying off the failure rather than a free-block count keeps this correct however the pools are sized. Also restore CONFIG_BT_NIMBLE_MSYS_1_BLOCK_COUNT to the IDF default of 12. Pool selection is by block size and a notify request always resolves to the smallest pool, so msys_1 is the only pool GATT draws from; 8 was thin once anything chains or fragments. msys_2 and the ACL/EVT transport pools are left trimmed -- neither is on the notify path, and restoring the full defaults would re-spend the contiguous allocation that #10741 was fixing on heap-tight boards. sendLog() also lacked the null check onNowHasData() already has, so a log line arriving during BLE teardown dereferenced a freed characteristic. Fixes #11245
1 parent 1e982fa commit 06441a2

2 files changed

Lines changed: 39 additions & 1 deletion

File tree

src/nimble/NimbleBluetooth.cpp

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -637,6 +637,30 @@ class NimbleBluetoothFromRadioCallback : public BLECharacteristicCallbacks
637637
}
638638
};
639639

640+
// Debug-log streaming is best-effort, but it competes for the same resources as the traffic that
641+
// isn't. Every GATT notification allocates from the NimBLE host's msys_1 mbuf pool, and log_to_ble()
642+
// attempts one notification per log line, so a logging burst (a config import, the position replay
643+
// that runs at every connect) drains the pool faster than the link gives it back. Once it is empty
644+
// the fromNum doorbell and ATT responses fail too, and each failed notify costs an error print on
645+
// the serial console -- which produces more log lines, at ~12ms apiece.
646+
//
647+
// So treat a rejected log notify as backpressure: stop offering log lines to the pool for a moment
648+
// and let it refill. This keys off the host's own verdict rather than a free-block count, so it
649+
// stays correct no matter how the pools are sized.
650+
static constexpr uint32_t kLogNotifyBackoffMs = 250;
651+
static std::atomic<uint32_t> lastLogNotifyFailureMs{0};
652+
653+
class NimbleBluetoothLogRadioCallback : public BLECharacteristicCallbacks
654+
{
655+
void onStatus(BLECharacteristic *, Status s, uint32_t) override
656+
{
657+
// Only ERROR_GATT means the host refused the notification (BLE_HS_ENOMEM when the pool is
658+
// dry). The no-client/no-subscriber statuses are normal and return before allocating.
659+
if (s == Status::ERROR_GATT)
660+
lastLogNotifyFailureMs.store(millis());
661+
}
662+
};
663+
640664
class NimbleBluetoothSecurityCallback : public BLESecurityCallbacks
641665
{
642666
void onPassKeyNotify(uint32_t passkey) override
@@ -1005,6 +1029,9 @@ void NimbleBluetooth::setupService()
10051029
static NimbleBluetoothFromRadioCallback fromRadioCallbacks;
10061030
FromRadioCharacteristic->setCallbacks(&fromRadioCallbacks);
10071031

1032+
static NimbleBluetoothLogRadioCallback logRadioCallbacks;
1033+
logRadioCharacteristic->setCallbacks(&logRadioCallbacks);
1034+
10081035
bleService->start();
10091036

10101037
// Setup the battery service
@@ -1056,6 +1083,12 @@ void NimbleBluetooth::sendLog(const uint8_t *logMessage, size_t length)
10561083
if (!isConnected() || length > 512) {
10571084
return;
10581085
}
1086+
if (!logRadioCharacteristic) // BLE may have been torn down; never notify a freed characteristic
1087+
return;
1088+
// The host rejected a log notify recently, so the mbuf pool is under pressure. Drop this line
1089+
// rather than spend a buffer the fromNum doorbell needs; see kLogNotifyBackoffMs.
1090+
if (Throttle::isWithinTimespanMs(lastLogNotifyFailureMs.load(), kLogNotifyBackoffMs))
1091+
return;
10591092
logRadioCharacteristic->setValue(logMessage, length);
10601093
logRadioCharacteristic->notify();
10611094
}

variants/esp32/esp32-common.ini

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -291,7 +291,12 @@ custom_sdkconfig =
291291
CONFIG_BT_CTRL_BLE_MAX_ACT=2
292292
CONFIG_BT_CTRL_SCAN_DUPL_CACHE_SIZE=10
293293
CONFIG_BT_NIMBLE_WHITELIST_SIZE=1
294-
CONFIG_BT_NIMBLE_MSYS_1_BLOCK_COUNT=8
294+
# msys_1 is the only pool GATT uses: every notification and ATT response allocates through
295+
# os_msys_get_pkthdr(0, 0), which always resolves to the smallest pool, and chained buffers stay
296+
# in it. 8 blocks left too little headroom for a notify burst (#11245), so restore the IDF default
297+
# of 12 -- +1KB, and still well under the pre-trim footprint. Raising msys_2 instead would do
298+
# nothing here; nothing on the notify path ever allocates from it.
299+
CONFIG_BT_NIMBLE_MSYS_1_BLOCK_COUNT=12
295300
CONFIG_BT_NIMBLE_MSYS_2_BLOCK_COUNT=8
296301
CONFIG_BT_NIMBLE_TRANSPORT_ACL_FROM_LL_COUNT=8
297302
CONFIG_BT_NIMBLE_TRANSPORT_EVT_COUNT=12

0 commit comments

Comments
 (0)