Stop BLE log streaming from starving the NimBLE notify pool - #11253
Merged
Conversation
Contributor
⚡ Try this PR in the Web Flasher
Warning This is an automated, unreviewed CI test build. Back up your device configuration Supported boards built by this PR (31)
Build artifacts expire on 2026-08-26. Updated for |
Contributor
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
🚧 Files skipped from review as they are similar to previous changes (2)
📝 WalkthroughWalkthroughBLE log notifications now detect GATT allocation failures, suppress retries during a cooldown, avoid notifying torn-down characteristics, and use a larger ESP32 NimBLE allocation pool. ChangesBLE notification backpressure
Estimated code review effort: 3 (Moderate) | ~20 minutes Suggested labels: 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
thebentern
added
bugfix
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
Contributor
There was a problem hiding this comment.
🧹 Nitpick comments (2)
src/nimble/NimbleBluetooth.cpp (2)
640-649: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winShorten the explanatory comment block.
This is a multi-paragraph explanation; retain only the concise rationale needed to explain the backoff.
As per coding guidelines, C++ comments should be one or two lines maximum and should explain only non-obvious reasoning.
Proposed simplification
-// Debug-log streaming is best-effort, but it competes for the same resources as the traffic that -// isn't. Every GATT notification allocates from the NimBLE host's msys_1 mbuf pool, and log_to_ble() -// attempts one notification per log line, so a logging burst (a config import, the position replay -// that runs at every connect) drains the pool faster than the link gives it back. Once it is empty -// the fromNum doorbell and ATT responses fail too, and each failed notify costs an error print on -// the serial console -- which produces more log lines, at ~12ms apiece. -// -// So treat a rejected log notify as backpressure: stop offering log lines to the pool for a moment -// and let it refill. This keys off the host's own verdict rather than a free-block count, so it -// stays correct no matter how the pools are sized. +// Failed log notifications can exhaust NimBLE's msys_1 pool; back off after rejection +// to preserve FromRadio and ATT traffic.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@src/nimble/NimbleBluetooth.cpp` around lines 640 - 649, Shorten the comment immediately above the debug-log backpressure logic to one or two lines, retaining only that rejected BLE log notifications trigger a temporary pause to allow NimBLE resources to recover. Remove the detailed pool, timing, and connection-flow explanation while preserving the implementation unchanged.Source: Coding guidelines
650-650: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winUse the prescribed constant naming.
kLogNotifyBackoffMsis a constant but does not followUPPER_SNAKE_CASE; rename it and its references.As per coding guidelines, constants and defines must use UPPER_SNAKE_CASE.
-static constexpr uint32_t kLogNotifyBackoffMs = 250; +static constexpr uint32_t LOG_NOTIFY_BACKOFF_MS = 250;🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@src/nimble/NimbleBluetooth.cpp` at line 650, Rename the constant kLogNotifyBackoffMs to the prescribed UPPER_SNAKE_CASE form and update every reference to it throughout NimbleBluetooth.cpp, preserving its value and behavior.Source: Coding guidelines
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Nitpick comments:
In `@src/nimble/NimbleBluetooth.cpp`:
- Around line 640-649: Shorten the comment immediately above the debug-log
backpressure logic to one or two lines, retaining only that rejected BLE log
notifications trigger a temporary pause to allow NimBLE resources to recover.
Remove the detailed pool, timing, and connection-flow explanation while
preserving the implementation unchanged.
- Line 650: Rename the constant kLogNotifyBackoffMs to the prescribed
UPPER_SNAKE_CASE form and update every reference to it throughout
NimbleBluetooth.cpp, preserving its value and behavior.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro Plus
Run ID: 1f98e676-21f1-4157-9f74-32831ac2f8e4
📒 Files selected for processing (2)
src/nimble/NimbleBluetooth.cppvariants/esp32/esp32-common.ini
Contributor
Author
|
@bruschill can you test? |
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
thebentern
force-pushed
the
fix/ble-log-notify-mbuf-starvation
branch
from
July 27, 2026 12:15
06441a2 to
bfac789
Compare
Contributor
Author
|
Addressed both CodeRabbit nitpicks: trimmed the block comment to two lines and renamed the constant to Same treatment applied to #11254, which had the same two problems. |
Definitely, will just have to be this evening 👍🏻 |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #11245.
On 2.8 / ESP32-S3, a connected phone produces a continuous stream of
rc=6isBLE_HS_ENOMEM: the NimBLE host had no mbuf left to build the notification, so it was dropped. @bruschill measured 694 of these in 479s on a Heltec V4, and none at all on the same workload on nRF52 — so it's the ESP32/NimBLE path specifically.What's actually failing
It's the log characteristic, not the packet path.
log_to_ble()callssendLog()once per firmware log line, andsendLog()notified unconditionally. Withdebug_log_api_enabledset and a client subscribed (the iOS app subscribes to both notify characteristics on every connect), every single log line becomes a GATT notification. In the reporter's captures the errors alternate 1:1 with ordinary log lines — disk-save messages, dedup chatter, module dispatch — and outnumber thefromNumdoorbell attempts by 5-15x. They arrive in bursts at ~12ms intervals aligned with logging storms (a config import, the position replay that runs at connect), not at the steady 1.4/s the averages suggest.Then it feeds itself: each failed notify prints an error line over serial at roughly 12ms apiece, which is enough to visibly throttle the main loop during a burst.
Every GATT notification and ATT response allocates through
ble_hs_mbuf_att_pkt()→os_msys_get_pkthdr(0, 0), so once that pool is dry thefromNumdoorbell and ATT responses fail too. The phone stops being told there is data waiting.What this changes
Treat a rejected log notify as backpressure. The Arduino BLE wrapper's
notify()returnsvoid, but it does invokeonStatus(..., ERROR_GATT, rc)on failure. Registering a callback on the log characteristic gives the host's own verdict, sosendLog()can stand down for 250ms and let the pool refill instead of hammering it once per line. Debug logs are best-effort; the doorbell isn't, and this stops the former from starving the latter. Keying off the failure rather than a free-block count means it stays correct however the pools are sized.Restore
CONFIG_BT_NIMBLE_MSYS_1_BLOCK_COUNTto the IDF default of 12 (from the 8 set in #10741)._os_msys_find_pool()selects by block size, and a notify request always resolves to the smallest pool, so msys_1 is the only pool GATT ever draws from — 8 blocks is thin once anything chains or fragments. This costs 1KB.I deliberately did not touch
MSYS_2,TRANSPORT_ACL_FROM_LL_COUNTorTRANSPORT_EVT_COUNT. Raising msys_2 would do nothing for this bug (nothing on the notify path allocates from it), and the ACL/EVT pools are separate controller→host transport pools, also not involved. Restoring the full IDF defaults would re-spend ~6KB, most of it as one large contiguous allocation at NimBLE init — which is the exact allocation profile #10741 was fixing on heap-tight boards like heltec-v3, so I'd rather not.Null-check
logRadioCharacteristicinsendLog().deinit()nulls it, andonNowHasData()already guards its characteristic the same way —sendLog()was the one path that didn't, so a log line arriving during BLE teardown would dereference a freed pointer. Latent, unrelated to the ENOMEM, but it's two lines away.A note on the 2.7 → 2.8 comparison
The issue reports zero occurrences on 2.7.27. Worth being precise about that: 2.7 used NimBLE-Arduino 1.4.3, whose pool was 12 blocks of 292B — actually smaller in bytes than 2.8's trimmed 8+8 — and its
notify()discarded the return code without logging. So "zero errors on 2.7.27" is partly that the old stack couldn't report the failure. The reporter's own 2.7.27 data point supports this: they saw an ATT error 17 (insufficient resources) on a 104-byte write, which is the same pool exhaustion surfacing on the write path, at default sizing.What genuinely changed in 2.8 is demand — noticeably more log lines, plus the position replay burst at every connect — and a BLE wrapper that now reports each drop. That's why the primary fix here is backpressure rather than just buying more buffers.
Testing
Builds clean for
heltec-v4(the reporter's board). The config change forces a framework rebuild, so expect a slow first build.I don't have a device that reproduces this in front of me, so this is not hardware-verified yet — if anyone with an S3 and a phone can run with
debug_log_api_enabledon, connect, and do a config import, therc=6count during that window is the number to watch.Summary by CodeRabbit
ERROR_GATTfailures to reduce repeated delivery failures.