From 585393e36cd14323ee9d94b6704f30b7cab35196 Mon Sep 17 00:00:00 2001 From: mikecarper Date: Wed, 21 Oct 2026 00:56:23 -0700 Subject: [PATCH] Allow nRF52 CPU idle while USB watchdog timers run --- ...ware_validation_ota_1_18_0_1_2026-10-20.md | 84 +++++++++- docs/usb_logging_watchdog.md | 7 + src/helpers/UsbLoggingWatchdog.cpp | 8 + src/helpers/UsbLoggingWatchdog.h | 2 + test/test_nrf52_usb_watchdog_sleep.py | 158 ++++++++++++++++++ 5 files changed, 254 insertions(+), 5 deletions(-) create mode 100644 test/test_nrf52_usb_watchdog_sleep.py diff --git a/docs/test-results/hardware_validation_ota_1_18_0_1_2026-10-20.md b/docs/test-results/hardware_validation_ota_1_18_0_1_2026-10-20.md index f9ed5a009..04b8057f6 100644 --- a/docs/test-results/hardware_validation_ota_1_18_0_1_2026-10-20.md +++ b/docs/test-results/hardware_validation_ota_1_18_0_1_2026-10-20.md @@ -60,6 +60,38 @@ verification and restored the original gateway service. Exact serial-port ownership and unchanged original service configuration were verified. The first failed guard remains a failed workflow record, not a gateway pass. +The later application-only LoRa delta to commit `2bd4cb4d1` completed all +55/55 blocks in 103 seconds. An on-air install acknowledgement verified the +unsigned internal-flash delta, and on-air postboot reads proved exact body +`1A3C9EB603C581C3` after 80 seconds plus the full `dev-2bd4cb4d` version. +The receiving RAK used LoRa for setup, progress, installation and postboot +proof. No receiver USB command drove this update. Normal radio restoration +passed. Lost postboot status/version replies required bounded getter retries; +their failed attempts remain in the private log. A subsequent independent +USB diagnostic snapshot verified the same latest image, original saved +preferences and zero core errors before the CPU sleep measurement. + +That first latest-image CPU measurement FAILED. Over 90.013 seconds, the +nonhalting MEM-AP capture recorded 8013 CPU states, with one sleeping state +(about 0.01% weighted sampled time). There was no halt, lockup or reset in +the capture. Firmware diagnostics reported zero sleep-wait calls and zero +eligible time; the surrounding diagnostic window was blocked primarily by +`usb.recovery`. The saved settings were CPU power saving on, USB logging on, +USB debug off, the system watchdog on and the USB logging watchdog in Auto. +The gateway service and UART were closed during the capture. + +The watchdog's Auto policy still retained a previously confirmed reader and +an initial recovery stage after the serial client closed. The shared awake +hint treated that waiting policy as work requiring the CPU to remain awake. +A focused nRF52 fix and a new physical measurement are in progress. Logging, +watchdog settings and the failed result have not been disabled or cleared to +obtain a sleep pass. CPU debug enable was already set and stayed unchanged; +the explicit firmware sleep veto is recorded independently of that limit. +Subsequent authenticated LoRa reads returned the exact same latest body and +boot uptime, with zero core errors and both receive/transmit counters +advancing by three. Radio communication remained functional after the failed +idle measurement; this is not a CPU-sleep pass. + ## RAK4631 and XIAO nRF52 full QSPI LoRa updates The RAK4631 downloaded all 325/325 blocks in 375 seconds. Its install response @@ -137,8 +169,15 @@ Commit [720b9728c](https://github.com/mikecarper/MeshCore/commit/720b9728c) adds cold-idle RAK host-preflight preparation. The preparation may initialize optional staging media, but does not itself download firmware, install an image or change saved preferences. The host updater suite passed 379 tests -with zero skips. Its targeted live cold-idle check remains pending; these -host results alone do not qualify that hardware case. +with zero skips. The targeted live cold-idle RAK4631 check subsequently +passed: one USB restart established the unchanged, idle application with +unprobed storage, then authenticated LoRa reads observed that state and the +host performed exactly one explicit storage-preparation query. The result +was external QSPI with ABI 3 and codec subset `0x5`, with unchanged body +`B0886153CE824448` and no firmware download or bootloader write. The first +host attempt lost a version reply before preparing storage; a fresh read-only +snapshot and bounded getter retries completed the check without another +restart. Both attempt records are retained. Commit [093fd98a3](https://github.com/mikecarper/MeshCore/commit/093fd98a3) retries lost remote clock reads within the existing bounded operation budget. @@ -154,6 +193,25 @@ W25Q16 QSPI device and completed its full QSPI LoRa update as recorded above. RAK3401 live diagnostics report no external NOR and 252 KiB internal staging capacity, matching the completed internal delta case. +Commit [2bd4cb4d1](https://github.com/mikecarper/MeshCore/commit/2bd4cb4d1) +automatically restarts the existing four-beacon discovery burst when a +complete, changed update catalog becomes available through the source's +ordinary file-data session. It requires no separate announcement command or +control channel. USB or WiFi can feed files into the source radio; receiving +radios still discover and download them over LoRa. All 136 affected native +test methods passed, including cold catalog discovery and a negative control +that removes the production readiness trigger. Canonical V4 Full and RAK3401 +and RAK4631 Full/Reduced builds passed. This fixes source discovery, and does +not establish a fix for the separate Tower manifest timeout. + +The V4 source subsequently accepted one application-only WiFi upload of this +commit. Authenticated GET and POST both returned HTTP 200, followed by exact +USB version/body proof (`B6E8C347E1C5FA69`) and unchanged saved preferences +and receive-power-saving configuration. This deploys the source firmware; +it is not a receiver LoRa qualification result. The initial preparation +rejected a valid start acknowledgement with a WebConfig-status suffix before +any upload; the corrected continuation did not replay the start command. + During RAK4631 discovery, source receive power saving was on and discovery timed out. After disabling that setting under a restoration intent, a fresh advert was received. This sequence records an observation; it does not @@ -211,12 +269,28 @@ did not support the proposed clock or access-control explanation for the rehearsal failure. The relevant handlers were the same; no clock or ACL cause is claimed from this review. +A later local-control diagnostic made the signed full catalog visible, but +both matching pull attempts remained at manifest timeout, 0/0 blocks. No +install was requested. This local-control attempt is not a wireless-only +qualification pass. Its temporary radio and saved receive-power-saving +settings were restored and its USB port closed. One restoration command was +explicitly rejected with a misleading "unsupported" response; source review +shows that this response also covers a busy or failed reconfiguration. A +fresh identity/settings check followed by one new, acknowledged restoration +attempt proved the original configuration. No particular runtime guard is +identified as the cause of that rejection. + ## Limits and completion -The MeshTower signed full-image LoRa case, the targeted live cold-idle RAK -preflight check and final source cleanup remain pending. Newly requested +The MeshTower signed full-image LoRa case and final source cleanup remain +pending. The live cold-idle RAK preflight check is complete. Newly requested two-frequency ESP-NOW bridged one-hop OTA testing and latest RAK3401 CPU -testing also remain pending. The first-command USB bootstrap observation, +testing also remain pending. Receiver update setup, progress, installation +and post-install verification in the new radio campaign must use LoRa; +receiver USB commands cannot substitute for failed radio communication. +The RAK3401's current-image pause snapshot recorded historical channel-busy +bitmask `0x02`; it was retained without clearing statistics or claiming a +CPU-sleep result. The first-command USB bootstrap observation, Tower SF5 preflight failure, later full-image self-proof failures and separate USB open failure remain unresolved. The Tower signed delta, RAK4631 and XIAO nRF52 full QSPI LoRa updates and their later postchecks are complete; the diff --git a/docs/usb_logging_watchdog.md b/docs/usb_logging_watchdog.md index 969109bf0..0d5ddf124 100644 --- a/docs/usb_logging_watchdog.md +++ b/docs/usb_logging_watchdog.md @@ -189,6 +189,13 @@ published hardware/logging/mode intent and protects a possibly active reader. This temporary fallback cannot authorize a reset. The separate awake hint keeps an already durable watchdog policy serviced while publication is busy. +On nRF52, the CPU can wait for interrupts between watchdog checks in both +`on` and `auto` modes. Its clock and wake interrupts continue running, so this +does not restart recovery deadlines or disable the watchdog. Active USB work +and unfinished transport detach/reattach still prevent that idle wait. Other +platforms retain their existing sleep guard, including protection against +sleep modes that restart the application clock. + ## Verification The two qualification stages below precede the subsequent upstream USB/GPS diff --git a/src/helpers/UsbLoggingWatchdog.cpp b/src/helpers/UsbLoggingWatchdog.cpp index c631363cc..371d78548 100644 --- a/src/helpers/UsbLoggingWatchdog.cpp +++ b/src/helpers/UsbLoggingWatchdog.cpp @@ -262,6 +262,13 @@ UsbLoggingStatus usbLoggingStatus() { bool isUsbLoggingWatchdogArmed() { if (isUsbLoggingTransportRecoveryPending()) return true; +#if defined(NRF52_PLATFORM) + // nRF52 only waits for the next interrupt; its RTC/USB/radio wake sources + // keep the loop and elapsed-millis watchdog deadlines running. A saved On + // policy or confirmed Auto reader is not continuous CPU work. Keep actual + // detach/reattach work awake above without spinning between policy ticks. + return false; +#else // This is only an awake/service hint, never reset authorization. Keep a // previously durable policy awake if publication is busy; falling back to // an unavailable snapshot here could allow sleep to restart its deadline. @@ -272,6 +279,7 @@ bool isUsbLoggingWatchdogArmed() { const bool ready = (flags & (1U | 2U | 256U)) == (1U | 2U | 256U); return ready && ((flags & 4U) || ((flags & 512U) && (flags & 1024U) && (busy || stage < 2))); +#endif } void loadUsbLoggingWatchdog(FILESYSTEM* fs, bool durable, uint32_t (*epoch_seconds)()) { diff --git a/src/helpers/UsbLoggingWatchdog.h b/src/helpers/UsbLoggingWatchdog.h index 2e801e68f..6ad718bd8 100644 --- a/src/helpers/UsbLoggingWatchdog.h +++ b/src/helpers/UsbLoggingWatchdog.h @@ -18,6 +18,8 @@ bool handleUsbLoggingWatchdogCommand(const char* command, char* reply, // and dirty-contact ownership and is rechecked after the durable tier commit. // True authorizes the caller's board.reboot(); this helper never reboots. bool serviceUsbLoggingWatchdog(bool (*safe)(void*), void* context = nullptr); +// Awake/service hint, not reset authorization. nRF52's interrupt wait keeps +// policy time running, so only unfinished USB transport recovery inhibits it. bool isUsbLoggingWatchdogArmed(); bool isUsbLoggingWatchdogUpdateActive(); diff --git a/test/test_nrf52_usb_watchdog_sleep.py b/test/test_nrf52_usb_watchdog_sleep.py new file mode 100644 index 000000000..a181719bc --- /dev/null +++ b/test/test_nrf52_usb_watchdog_sleep.py @@ -0,0 +1,158 @@ +"""Run the nRF52 idle hint with the real watchdog and role sleep guards.""" + +from pathlib import Path +import os +import shutil +import subprocess +import tempfile +import unittest + +from test_replay_reset_integration import extract_braced + + +ROOT = Path(__file__).resolve().parents[1] +FIXTURE = ROOT / "test/fixtures/usb_logging_watchdog" + + +class Nrf52UsbWatchdogSleepTest(unittest.TestCase): + def test_idle_roles_keep_watchdog_deadlines_and_pending_usb_quarantine(self): + source = (ROOT / "src/helpers/UsbLoggingWatchdog.cpp").read_text(encoding="ascii") + # The persistence boundary uses the existing ESP host fake. Compile + # the exact nRF52 hint separately in the same TU, with the real policy, + # publication, staged recovery and persistent state beneath it. + hint = extract_braced(source, "bool isUsbLoggingWatchdogArmed()") + hint = hint.replace("isUsbLoggingWatchdogArmed()", "nrf52UsbNeedsService()", 1) + guards = [] + for role in ("simple_repeater", "simple_room_server", "simple_sensor"): + main = (ROOT / f"examples/{role}/main.cpp").read_text(encoding="ascii") + start = main.index(" const auto sleep_guard =") + guard = main[start:main.index(" if (can_power_save)", start)] + guards.append("static bool " + role + "() {\n" + guard + + "\nreturn can_power_save;\n}\n") + main = (ROOT / "examples/companion_radio/main.cpp").read_text(encoding="ascii") + start = main.index(" using mesh::powerdiag::Reason;", main.index("void loop()")) + guard = main[start:main.index(" uint32_t noise_floor_delay_ms = 0;", start)] + guards.append("static bool companion() {\n" + guard + "\nreturn sleep_reason == 0;\n}\n") + guards = "\n".join(guards).replace("mesh::isUsbLoggingWatchdogArmed()", "mesh::nrf52UsbNeedsService()") + harness = r''' +#include +#include +#include +#include +#include +#include +#include +static mesh::UsbLoggingObservation observation{true, false, false, false, 0}; +static bool logging = true, pending = false, client = false, safe = true; +static std::vector recoveries; +namespace mesh { +bool isUsbLoggingEnabled() { return logging; } +bool isUsbLoggingClientActive() { return client; } +void clearUsbLoggingClientActivity() { client = false; } +bool isUsbLoggingTransportRecoveryPending() { return pending; } +UsbLoggingObservation observeUsbLoggingTransport() { return observation; } +UsbLoggingRecoveryResult recoverUsbLoggingTransport(uint8_t stage) { + recoveries.push_back(stage); return UsbLoggingRecoveryResult::Attempted; +} +void probeUsbLoggingTransport() {} +} +#define NRF52_PLATFORM 1 +#undef ESP32_PLATFORM +namespace mesh { +@HINT@ +namespace wireless { +struct Control { bool busy = false; bool pending() const { return busy; } }; +Control& control() { static Control value; return value; } +} +} +static bool morse_timing = false; +struct Prefs { bool powersaving_enabled = true; }; +struct Mesh { + Prefs prefs; bool work = false; + Prefs* getNodePrefs() { return &prefs; } + bool isTrackerModeEnabled() const { return false; } + mesh::powerdiag::Mask pendingWorkReason() const { + return work ? mesh::powerdiag::mask(mesh::powerdiag::Reason::Ota) : 0; + } +} the_mesh; +struct Board { + bool connected = false; + bool isUsbDataConnected() const { return connected; } + bool isUsbHostConnected() const { return connected; } +} board; +@GUARDS@ +static bool recovery_safe(void*) { return safe; } +static bool service(uint32_t now) { + mock_watchdog_millis = now; + return mesh::serviceUsbLoggingWatchdog(recovery_safe); +} +static void mode(const char* command) { + char reply[160]; + assert(mesh::handleUsbLoggingWatchdogCommand(command, reply, sizeof(reply))); + assert(std::strstr(reply, "(saved)")); + recoveries.clear(); +} +static void all_idle() { + assert(!mesh::nrf52UsbNeedsService() && "armed watchdog must not spin idle nRF52"); + assert(simple_repeater() && simple_room_server() && simple_sensor() && companion()); +} +static void all_busy() { + assert(!simple_repeater() && !simple_room_server() && !simple_sensor() && !companion()); +} +int main() { + fs::FS fs; fs::stat_filesystem = &fs; + mesh::loadUsbLoggingWatchdog(&fs); + mode("set usb.watchdog on"); + assert(!service(0)); all_idle(); + // CPU waits can leave long gaps between loop calls. They must not restart + // or pause the five-minute repair and original one-hour reset deadlines. + assert(!service(299999)); all_idle(); assert(recoveries.empty()); + assert(!service(300000)); all_idle(); assert((recoveries == std::vector{1})); + assert(!service(360000)); all_idle(); assert((recoveries == std::vector{1, 2})); + assert(!service(3599999)); all_idle(); + assert(service(3600000)); + assert(mesh::usbLoggingStatus().reboot_count == 1); + // Mounted USB with its handle closed has the same idle behavior. A real + // open session, OTA owner, or pending detach still keeps its existing veto. + mode("set usb.watchdog on"); + observation = {true, true, false, false, 1}; + assert(!service(3600001)); all_idle(); + board.connected = true; all_busy(); board.connected = false; + the_mesh.work = true; assert(!companion()); the_mesh.work = false; + // Auto has confirmed this boot's stats client, matching the field failure. + mode("set usb.watchdog auto"); + observation = {true, true, true, false, 2}; client = true; + assert(!service(3600002)); + assert(mesh::usbLoggingStatus().watchdog_auto && mesh::usbLoggingStatus().logger_active); + observation.reader_connected = false; + assert(!service(3600003)); all_idle(); + assert(!service(3900003)); all_idle(); assert((recoveries == std::vector{1})); + assert(!service(3960003)); all_idle(); assert((recoveries == std::vector{1, 2})); + assert(!service(7200003)); all_idle(); + assert(mesh::usbLoggingStatus().reboot_count == 1); // Auto never adds a reboot. + // A real in-flight USB cleanup must finish even with the logger/watchdog off. + mode("set usb.watchdog off"); logging = false; pending = true; + assert(mesh::nrf52UsbNeedsService()); all_busy(); + pending = false; all_idle(); +} +'''.replace("@HINT@", hint).replace("@GUARDS@", guards) + compiler = os.environ.get("CXX") or shutil.which("g++") or shutil.which("clang++") + if compiler is None: + self.skipTest("a host C++17 compiler is required") + with tempfile.TemporaryDirectory(prefix="nrf52-watchdog-sleep-") as directory: + cpp, binary = Path(directory) / "sleep.cpp", Path(directory) / "sleep" + cpp.write_text(harness, encoding="ascii") + built = subprocess.run([ + compiler, "-std=c++17", "-Wall", "-Wextra", "-Werror", "-pthread", + "-fsanitize=address,undefined", "-fno-sanitize-recover=all", "-fno-pie", "-no-pie", + "-DARDUINO", "-DESP32", "-DESP32_PLATFORM", "-DARDUINO_USB_MODE=0", + "-DARDUINO_USB_CDC_ON_BOOT=1", "-I" + str(FIXTURE / "mocks"), + "-I" + str(ROOT / "src"), str(cpp), "-o", str(binary), + ], capture_output=True, text=True, timeout=60) + self.assertEqual(built.returncode, 0, built.stdout + built.stderr) + result = subprocess.run([str(binary)], capture_output=True, text=True, timeout=20) + self.assertEqual(result.returncode, 0, result.stdout + result.stderr) + + +if __name__ == "__main__": + unittest.main()