From c33bbaf8f20e03494bd650db0b7d88314b0ab61a Mon Sep 17 00:00:00 2001 From: mikecarper Date: Wed, 21 Oct 2026 22:12:03 -0700 Subject: [PATCH] Fix NimBLE queued timer crash when stopping Bluetooth --- .github/workflows/run-unit-tests.yml | 1 + docs/power_saving_diagnostics.md | 7 + .../esp32_ble_radio2_sleep_2026-10-21.md | 12 + platformio.ini | 1 + scripts/esp32_nimble_timer_fix.py | 79 +++++ test/test_esp32_nimble_timer_fix.py | 317 ++++++++++++++++++ 6 files changed, 417 insertions(+) create mode 100644 scripts/esp32_nimble_timer_fix.py create mode 100644 test/test_esp32_nimble_timer_fix.py diff --git a/.github/workflows/run-unit-tests.yml b/.github/workflows/run-unit-tests.yml index aee3ab1d4..a50f18593 100644 --- a/.github/workflows/run-unit-tests.yml +++ b/.github/workflows/run-unit-tests.yml @@ -1008,6 +1008,7 @@ jobs: python3 -B test/test_esp32_ble_power.py -v python3 -B test/test_esp32_native_ble_stop.py -v python3 -B test/test_esp32_ble_lifecycle_fix.py -v + python3 -B test/test_esp32_nimble_timer_fix.py -v python3 -B test/test_bluetooth_pairing_ui.py python3 -B test/test_companion_pairing_display.py python3 -B test/test_companion_identity_startup.py diff --git a/docs/power_saving_diagnostics.md b/docs/power_saving_diagnostics.md index 6a9f321bc..5c3dd580e 100644 --- a/docs/power_saving_diagnostics.md +++ b/docs/power_saving_diagnostics.md @@ -82,6 +82,13 @@ failed teardown keeps the CPU awake rather than treating stopped advertising as a stopped controller. `get bluetooth` reports a pending change until that transition finishes. +NimBLE-Arduino 2.5.1 builds include the upstream host-timer shutdown fix +([NimBLE-Arduino #1185](https://github.com/h2zero/NimBLE-Arduino/pull/1185)). +Stopping Bluetooth preserves an already queued timer event's callback until +final host cleanup. Without this fix, switching Bluetooth off can reset an +ESP32 through a null callback. The version/hash-checked repair is applied to a +build-local source copy; the shared library installation is unchanged. + USB host sessions, logging, active WiFi/ESP-NOW, OTA and serial work keep their existing sleep guards. This change does not sleep an ESP32 through a live Bluetooth or WiFi connection. Such connections require SDK-managed modem and diff --git a/docs/test-results/esp32_ble_radio2_sleep_2026-10-21.md b/docs/test-results/esp32_ble_radio2_sleep_2026-10-21.md index 016176dc1..8c9a63f70 100644 --- a/docs/test-results/esp32_ble_radio2_sleep_2026-10-21.md +++ b/docs/test-results/esp32_ble_radio2_sleep_2026-10-21.md @@ -13,6 +13,18 @@ Bluetooth and SDK wait checks pass. Three strict sleeping RF trials with matched preambles received five of six packets, including the trial after the IRQ fix. They remain failures; radio2 is not fully qualified. +The subsequent V3 CPU-clock sweep stopped during setup, before any of its +20-packet-per-frequency cases transmitted. Switching Bluetooth off exposed a +NimBLE-Arduino 2.5.1 shutdown crash: PC zero in the host task, with the event +address resolving to `ble_hs_timer + 8`. This matches upstream +[issue #1184](https://github.com/h2zero/NimBLE-Arduino/issues/1184) and its +[merged fix #1185](https://github.com/h2zero/NimBLE-Arduino/pull/1185). +The backport removes premature timer deinitialization while leaving final +cleanup intact. The earlier V4 Bluedroid checks do not qualify V3 NimBLE. +The regression reproduces the original null callback, then passes 1,000 +shutdown/cleanup cycles under ASan/UBSan for each timer backend. Library +version, source hash and build-local middleware checks also pass. + ## Behavior and safeguards Bluetooth off disconnects clients and completes host/controller teardown in diff --git a/platformio.ini b/platformio.ini index f8a111195..daed06d25 100644 --- a/platformio.ini +++ b/platformio.ini @@ -97,6 +97,7 @@ extra_scripts = pre:scripts/esp32_usb_session_fix.py pre:scripts/esp32_file_buffer_fix.py pre:scripts/esp32_ble_lifecycle_fix.py + pre:scripts/esp32_nimble_timer_fix.py pre:scripts/esp32_wifi_scan_fix.py pre:scripts/esp32_async_web_fix.py merge-bin.py diff --git a/scripts/esp32_nimble_timer_fix.py b/scripts/esp32_nimble_timer_fix.py new file mode 100644 index 000000000..dc604781f --- /dev/null +++ b/scripts/esp32_nimble_timer_fix.py @@ -0,0 +1,79 @@ +"""Backport NimBLE-Arduino PR1185 without changing the shared dependency. + +The 2.5.1 host clears its timer event callback while that event may still be +queued during shutdown. Keep the callout alive until ble_hs_deinit(), which +already releases it after host shutdown. Upstream fix: +https://github.com/h2zero/NimBLE-Arduino/pull/1185 +""" +from pathlib import Path +import hashlib +import re + + +PINNED_VERSION = "2.5.1" +PINNED_SHA256 = "c5677503b264738b692d0e688672011206a308d20c5ca1aa5e32a649443bd48a" +PATCHED_SHA256 = "8232c5a8721f8a75dc08dd93a7b7a1690c16a57f0c8f4660029c45e5a27be324" +SOURCE_SUFFIX = ("src", "nimble", "nimble", "host", "src", "ble_hs.c") +ORIGINAL = """ if (!ble_hs_is_enabled()) { + ble_npl_callout_stop(&ble_hs_timer); + ble_npl_callout_deinit(&ble_hs_timer); + } else { +""" +REPAIRED = """ if (!ble_hs_is_enabled()) { + ble_npl_callout_stop(&ble_hs_timer); + } else { +""" + + +def patched_nimble_source(source, version): + if version != PINNED_VERSION: + raise RuntimeError("ESP32 NimBLE timer fix: unreviewed library version") + source = source.replace("\r\n", "\n") + digest = hashlib.sha256(source.encode("utf-8")).hexdigest() + if digest == PATCHED_SHA256: + return source + if digest != PINNED_SHA256 or source.count(ORIGINAL) != 1: + raise RuntimeError("ESP32 NimBLE timer fix: changed pinned source; review library update") + patched = source.replace(ORIGINAL, REPAIRED, 1) + if hashlib.sha256(patched.encode("utf-8")).hexdigest() != PATCHED_SHA256: + raise RuntimeError("ESP32 NimBLE timer fix: unexpected transform result") + return patched + + +def library_version(source): + metadata = source.parents[5] / "library.properties" + try: + text = metadata.read_text(encoding="utf-8") + except OSError as error: + raise RuntimeError("ESP32 NimBLE timer fix: missing library metadata") from error + names = re.findall(r"^name=(.*)$", text, re.MULTILINE) + versions = re.findall(r"^version=(.*)$", text, re.MULTILINE) + if names != ["NimBLE-Arduino"] or len(versions) != 1: + raise RuntimeError("ESP32 NimBLE timer fix: malformed library metadata") + return versions[0] + + +def replace_nimble_source(build_env, node): + source = Path(node.srcnode().get_abspath()) + if source.parts[-6:] != SOURCE_SUFFIX or source.parents[5].name != "NimBLE-Arduino": + return node + original = source.read_text(encoding="utf-8") + patched = patched_nimble_source(original, library_version(source)) + if patched == original: + return node + destination = Path(build_env.subst("$BUILD_DIR")) / "patched-esp32-nimble" / source.name + destination.parent.mkdir(parents=True, exist_ok=True) + if not destination.exists() or destination.read_text(encoding="utf-8") != patched: + destination.write_text(patched, encoding="utf-8") + # ble_hs_priv.h is a quoted sibling include in the original C source. + build_env.AppendUnique(CPPPATH=[str(source.parent)]) + return build_env.File(str(destination)) + + +def install(build_env): + build_env.AddBuildMiddleware(replace_nimble_source, "*NimBLE-Arduino*ble_hs.c") + + +if "Import" in globals(): + Import("env") + install(env) diff --git a/test/test_esp32_nimble_timer_fix.py b/test/test_esp32_nimble_timer_fix.py new file mode 100644 index 000000000..2fddce268 --- /dev/null +++ b/test/test_esp32_nimble_timer_fix.py @@ -0,0 +1,317 @@ +#!/usr/bin/env python3 +"""Reproduce the queued timer callback crash and verify the pinned backport.""" +from pathlib import Path +import hashlib +import importlib.util +import os +import resource +import signal +import subprocess +import tempfile +import unittest +from unittest.mock import patch + + +ROOT = Path(__file__).resolve().parents[1] +SPEC = importlib.util.spec_from_file_location("esp32_nimble_timer_fix", ROOT / "scripts/esp32_nimble_timer_fix.py") +FIX = importlib.util.module_from_spec(SPEC) +SPEC.loader.exec_module(FIX) + +# These are the actual relevant 2.5.1 function bodies, with the original +# preprocessor branches retained. Compile the transformed functions below. +TIMER_RESET = """static void +ble_hs_timer_reset(uint32_t ticks) +{ + int rc; + + if (!ble_hs_is_enabled()) { + ble_npl_callout_stop(&ble_hs_timer); + ble_npl_callout_deinit(&ble_hs_timer); + } else { + rc = ble_npl_callout_reset(&ble_hs_timer, ticks); + BLE_HS_DBG_ASSERT_EVAL(rc == 0); + } +} +""" +HOST_DEINIT = """void +ble_hs_deinit(void) +{ + ble_hs_flow_deinit(); + +#if BLE_MONITOR + ble_monitor_deinit(); +#endif + + ble_npl_mutex_deinit(&ble_hs_mutex); + + ble_mqueue_deinit(&ble_hs_rx_q); + + ble_hs_stop_deinit(); + + ble_gap_deinit(); + + ble_hs_hci_deinit(); + + ble_npl_event_deinit(&ble_hs_ev_start_stage2); + + ble_npl_event_deinit(&ble_hs_ev_start_stage1); + + ble_npl_event_deinit(&ble_hs_ev_reset); + +#if NIMBLE_BLE_CONNECT + ble_npl_event_deinit(&ble_hs_ev_tx_notifications); + + ble_gatts_stop(); +#endif + + ble_npl_callout_deinit(&ble_hs_timer); + +#if (MYNEWT_VAL(BLE_HOST_BASED_PRIVACY)) + ble_hs_resolv_deinit(); +#endif +} +""" +CALLOUT_DEINIT = """void +npl_freertos_callout_deinit(struct ble_npl_callout *co) +{ + if (!co->handle) { + return; + } + +#if CONFIG_BT_NIMBLE_USE_ESP_TIMER + if(esp_timer_stop(co->handle)) + ESP_LOGW(LOG_TAG, "Timer not stopped"); + + if(esp_timer_delete(co->handle)) + ESP_LOGW(LOG_TAG, "Timer not deleted"); +#else + xTimerDelete(co->handle, portMAX_DELAY); + ble_npl_event_deinit(&co->ev); +#endif + memset(co, 0, sizeof(struct ble_npl_callout)); +} +""" +SOURCE = "// NimBLE-Arduino 2.5.1 host function fixture.\n" + TIMER_RESET + HOST_DEINIT + +HARNESS = r""" +#include +#include +#include +#include +#define BLE_MONITOR 0 +#define NIMBLE_BLE_CONNECT 1 +#define MYNEWT_VAL(x) 0 +#define BLE_HS_DBG_ASSERT_EVAL(x) assert(x) +#define ESP_LOGW(...) ((void)0) +static constexpr unsigned portMAX_DELAY = 0xffffffff; +struct ble_npl_event { void (*fn)(ble_npl_event*); }; +struct ble_npl_callout { void* handle; ble_npl_event ev; }; +static ble_npl_callout ble_hs_timer{}; +static ble_npl_event ble_hs_ev_start_stage2{}, ble_hs_ev_start_stage1{}, ble_hs_ev_reset{}, ble_hs_ev_tx_notifications{}; +static int ble_hs_mutex = 0, ble_hs_rx_q = 0; +static bool enabled = true, host_running = true; +static unsigned stops = 0, deletes = 0, resets = 0, callbacks = 0, final_cleanups = 0; +static uint32_t last_ticks = 0; +static bool ble_hs_is_enabled() { return enabled; } +static void ble_npl_callout_stop(ble_npl_callout*) { ++stops; } +static int ble_npl_callout_reset(ble_npl_callout* co, uint32_t ticks) { + assert(co->handle && co->ev.fn); ++resets; last_ticks = ticks; return 0; +} +static void ble_npl_event_deinit(ble_npl_event*) {} +static void xTimerDelete(void* handle, unsigned) { assert(handle); ++deletes; } +static int esp_timer_stop(void* handle) { assert(handle); return 0; } +static int esp_timer_delete(void* handle) { assert(handle); ++deletes; return 0; } +@CALLOUT_DEINIT@ +static void ble_npl_callout_deinit(ble_npl_callout* co) { npl_freertos_callout_deinit(co); } +static void ble_hs_flow_deinit() { assert(!host_running); ++final_cleanups; } +static void ble_npl_mutex_deinit(int*) {} +static void ble_mqueue_deinit(int*) {} +static void ble_hs_stop_deinit() {} +static void ble_gap_deinit() {} +static void ble_hs_hci_deinit() {} +static void ble_gatts_stop() {} +@SOURCE@ +static void timer_callback(ble_npl_event* ev) { assert(ev == &ble_hs_timer.ev); ++callbacks; } +static void ble_npl_event_run(ble_npl_event* ev) { ev->fn(ev); } +int main(int argc, char**) { + for (unsigned cycle = 0; cycle < 1000; ++cycle) { + host_running = true; + enabled = true; + ble_hs_timer.handle = reinterpret_cast(1); + ble_hs_timer.ev.fn = timer_callback; + ble_hs_timer_reset(125); + assert(last_ticks == 125 && resets == cycle + 1); + // An expired timer queues a pointer to this same embedded event. + ble_npl_event* queued = &ble_hs_timer.ev; + // ble_hs_stop_begin transitions ON -> STOPPING before rescheduling. + enabled = false; + ble_hs_timer_reset(0); + // The old body memsets the queued callback here. Exercise the exact + // indirect event call to reproduce PC zero, rather than masking it. + if (argc > 1) { + assert(queued->fn == nullptr); + ble_npl_event_run(queued); + return 99; + } + assert(queued->fn != nullptr && ble_hs_timer.handle); + assert(deletes == cycle); // Stop alone must preserve the live callout. + ble_npl_event_run(queued); + assert(callbacks == cycle + 1 && stops == cycle + 1); + host_running = false; + ble_hs_deinit(); // Retained final cleanup releases the timer once. + assert(deletes == cycle + 1 && final_cleanups == cycle + 1); + assert(ble_hs_timer.handle == nullptr && ble_hs_timer.ev.fn == nullptr); + } + puts("queued timer shutdown and final cleanup passed"); +} +""" + + +def fixture_pins(source=SOURCE): + repaired = source.replace(FIX.ORIGINAL, FIX.REPAIRED, 1) + return patch.multiple(FIX, PINNED_SHA256=hashlib.sha256(source.encode()).hexdigest(), + PATCHED_SHA256=hashlib.sha256(repaired.encode()).hexdigest()) + + +def disable_core_dumps(): + resource.setrlimit(resource.RLIMIT_CORE, (0, 0)) + + +class FakeNode: + def __init__(self, path): + self.path = path + + def srcnode(self): + return self + + def get_abspath(self): + return str(self.path) + + +class FakeEnvironment: + def __init__(self, build): + self.build = build + self.paths = [] + self.middleware = [] + + def subst(self, expression): + assert expression == "$BUILD_DIR" + return str(self.build) + + def AppendUnique(self, **kwargs): + for path in kwargs["CPPPATH"]: + if path not in self.paths: + self.paths.append(path) + + def File(self, path): + return Path(path) + + def AddBuildMiddleware(self, callback, pattern): + self.middleware.append((callback, pattern)) + + +class NimbleTimerFixTests(unittest.TestCase): + def test_queued_event_reproduces_null_call_and_fixed_cycles_release_timer(self): + with fixture_pins(): + repaired = FIX.patched_nimble_source(SOURCE, FIX.PINNED_VERSION) + self.assertIn(HOST_DEINIT, repaired) + for esp_timer in (0, 1): + with self.subTest(esp_timer=esp_timer), tempfile.TemporaryDirectory(prefix="nimble-timer-race-") as directory: + root = Path(directory) + cpp, executable = root / "test.cpp", root / "test" + for legacy in (True, False): + text = HARNESS.replace("@SOURCE@", SOURCE if legacy else repaired).replace("@CALLOUT_DEINIT@", CALLOUT_DEINIT) + cpp.write_text(text) + command = [os.environ.get("CXX", "c++"), "-std=c++17", "-Wall", "-Wextra", "-Werror", + "-Wno-unused-function", "-fno-pie", "-no-pie", f"-DCONFIG_BT_NIMBLE_USE_ESP_TIMER={esp_timer}"] + if not legacy: + command += ["-fsanitize=address,undefined"] + built = subprocess.run(command + [str(cpp), "-o", str(executable)], text=True, capture_output=True, timeout=30) + self.assertEqual(built.returncode, 0, built.stderr) + run = subprocess.run([str(executable)] + (["expect-null"] if legacy else []), text=True, + capture_output=True, timeout=10, preexec_fn=disable_core_dumps) + if legacy: + self.assertEqual(run.returncode, -signal.SIGSEGV, run.stderr) + else: + self.assertEqual(run.returncode, 0, run.stderr) + self.assertIn("final cleanup passed", run.stdout) + + def test_version_hash_idempotence_and_final_cleanup_guards(self): + with fixture_pins(): + expected = SOURCE.replace(FIX.ORIGINAL, FIX.REPAIRED, 1) + self.assertEqual(FIX.patched_nimble_source(SOURCE, "2.5.1"), expected) + self.assertEqual(FIX.patched_nimble_source(expected, "2.5.1"), expected) + self.assertEqual(FIX.patched_nimble_source(SOURCE.replace("\n", "\r\n"), "2.5.1"), expected) + self.assertEqual(SOURCE.splitlines().count(" ble_npl_callout_deinit(&ble_hs_timer);"), 1) + self.assertIn(HOST_DEINIT, expected) + self.assertEqual(len(SOURCE.splitlines()) - len(expected.splitlines()), 1) + for version in ("2.5.0", "2.5.2", "3.0.0"): + with self.subTest(version=version), self.assertRaisesRegex(RuntimeError, "unreviewed library version"): + FIX.patched_nimble_source(SOURCE, version) + for source in (SOURCE + "// changed\n", SOURCE.replace(HOST_DEINIT, ""), SOURCE + FIX.ORIGINAL): + with self.assertRaisesRegex(RuntimeError, "changed pinned source"): + FIX.patched_nimble_source(source, "2.5.1") + with patch.object(FIX, "REPAIRED", FIX.REPAIRED + "// unintended edit\n"): + with self.assertRaisesRegex(RuntimeError, "unexpected transform"): + FIX.patched_nimble_source(SOURCE, "2.5.1") + + def test_middleware_only_copies_pinned_library_source(self): + with tempfile.TemporaryDirectory(prefix="nimble-timer-middleware-") as directory, fixture_pins(): + root = Path(directory) + library = root / "libdeps/test/NimBLE-Arduino" + source = library.joinpath(*FIX.SOURCE_SUFFIX) + source.parent.mkdir(parents=True) + metadata = library / "library.properties" + metadata.write_text("name=NimBLE-Arduino\nversion=2.5.1\n") + source.write_text(SOURCE) + source_timestamp = source.stat().st_mtime_ns + node, env = FakeNode(source), FakeEnvironment(root / "build") + FIX.install(env) + self.assertEqual(env.middleware, [(FIX.replace_nimble_source, "*NimBLE-Arduino*ble_hs.c")]) + destination = FIX.replace_nimble_source(env, node) + self.assertEqual(source.read_text(), SOURCE) + self.assertEqual(source.stat().st_mtime_ns, source_timestamp) + self.assertEqual(destination, root / "build/patched-esp32-nimble/ble_hs.c") + self.assertEqual(destination.read_text(), SOURCE.replace(FIX.ORIGINAL, FIX.REPAIRED, 1)) + self.assertEqual(env.paths, [str(source.parent)]) + timestamp = destination.stat().st_mtime_ns + self.assertEqual(FIX.replace_nimble_source(env, node), destination) + self.assertEqual(destination.stat().st_mtime_ns, timestamp) + # Arduino's native NimBLE and unrelated source files bypass this. + other = FakeNode(root / "framework" / Path(*FIX.SOURCE_SUFFIX)) + self.assertIs(FIX.replace_nimble_source(env, other), other) + other = FakeNode(source.with_name("ble_gap.c")) + self.assertIs(FIX.replace_nimble_source(env, other), other) + for content, reason in (("name=NimBLE-Arduino\nversion=2.5.2\n", "unreviewed library"), + ("name=NimBLE-Arduino\nversion=2.5.1\nversion=2.5.1\n", "malformed"), + ("name=Other\nversion=2.5.1\n", "malformed")): + metadata.write_text(content) + with self.assertRaisesRegex(RuntimeError, reason): + FIX.replace_nimble_source(env, node) + metadata.unlink() + with self.assertRaisesRegex(RuntimeError, "missing library"): + FIX.replace_nimble_source(env, node) + + def test_installed_pinned_source_when_available(self): + candidates = list((ROOT / ".pio/libdeps").glob("*/NimBLE-Arduino/src/nimble/nimble/host/src/ble_hs.c")) + if not candidates: + self.skipTest("NimBLE-Arduino 2.5.1 dependency is not installed") + reviewed = 0 + for source in candidates: + if FIX.library_version(source) != "2.5.1": + continue + with self.subTest(source=str(source)): + original = source.read_text() + self.assertIn(TIMER_RESET, original) + self.assertIn(HOST_DEINIT, original) + repaired = FIX.patched_nimble_source(original, "2.5.1") + self.assertNotEqual(original, repaired) + self.assertEqual(FIX.patched_nimble_source(repaired, "2.5.1"), repaired) + self.assertEqual(len(original.splitlines()) - len(repaired.splitlines()), 1) + self.assertIn(" ble_npl_callout_deinit(&ble_hs_timer);", repaired) + reviewed += 1 + self.assertGreater(reviewed, 0, "No reviewed 2.5.1 dependency found") + + +if __name__ == "__main__": + unittest.main()