From 7d0709bf03aa53f3a31467f1ed1496e24824a7c8 Mon Sep 17 00:00:00 2001 From: mikecarper Date: Wed, 21 Oct 2026 23:24:07 -0700 Subject: [PATCH] Park paused UART sessions and timestamp ESP32 sleep calls --- .github/workflows/run-unit-tests.yml | 2 + docs/cli_commands.md | 7 + docs/power_saving_diagnostics.md | 18 +- .../esp32_ble_radio2_sleep_2026-10-21.md | 64 +++- examples/companion_radio/main.cpp | 58 ++- src/helpers/ESP32Board.h | 13 +- src/helpers/PowerSavingDiagnostics.h | 83 ++++- src/helpers/esp32/PowerTestControls.h | 22 ++ test/test_esp32_power_test_controls.py | 62 +++- test/test_esp32_uart_quiet_session.py | 350 ++++++++++++++++++ test/test_power_saving_diagnostics_buckets.py | 180 +++++++++ 11 files changed, 843 insertions(+), 16 deletions(-) create mode 100644 test/test_esp32_uart_quiet_session.py create mode 100644 test/test_power_saving_diagnostics_buckets.py diff --git a/.github/workflows/run-unit-tests.yml b/.github/workflows/run-unit-tests.yml index a50f18593..efcccc0b7 100644 --- a/.github/workflows/run-unit-tests.yml +++ b/.github/workflows/run-unit-tests.yml @@ -445,11 +445,13 @@ jobs: python3 -B test/test_regulator_recovery.py -v python3 -B test/test_regulator_settings.py -v python3 -B test/test_power_saving_diagnostics.py -v + python3 -B test/test_power_saving_diagnostics_buckets.py -v python3 -B test/test_power_saving_role_diagnostics.py -v python3 -B test/test_companion_power_diagnostics.py -v python3 -B test/test_esp32_cpu_clock.py -v python3 -B test/test_esp32_cpu_clock_board.py -v python3 -B test/test_esp32_power_test_controls.py -v + python3 -B test/test_esp32_uart_quiet_session.py -v python3 -B test/test_companion_rxps_getters.py -v python3 -B test/test_nrf52_sleep_cycle.py -v python3 -B test/test_nrf52_sleep_events.py -v diff --git a/docs/cli_commands.md b/docs/cli_commands.md index 883e61c0a..fb583f810 100644 --- a/docs/cli_commands.md +++ b/docs/cli_commands.md @@ -2854,6 +2854,13 @@ due wake are distinguished where those guards apply. USB power from a charger is not a host session. Logging enabled alone is not an nRF52 MCU sleep veto; on ESP32, the existing logging and raw-console guards can veto light sleep. +ESP32 pages `9` and `10` count SDK call entries in sixteen 16-second buckets +starting at `start_ms`. They also report entries outside the first 256 seconds +and flags for outside entries (1), saturation (2) or missing timestamps (4). +Use a whole bucket contained within an independently timed interval to prove +SDK calls occurred during that interval; whole-window totals are insufficient. +See [power-saving diagnostics](power_saving_diagnostics.md) for the timing limits. + The `calls` page counts actual instrumented wait calls, returns, short returns, board vetoes and SDK errors. `time` reports time spent inside those wait calls in microseconds, including SDK and interrupt work, **not CPU sleep residency diff --git a/docs/power_saving_diagnostics.md b/docs/power_saving_diagnostics.md index 7e7c041d2..e7a86daf2 100644 --- a/docs/power_saving_diagnostics.md +++ b/docs/power_saving_diagnostics.md @@ -20,6 +20,17 @@ not override any sleep guard. The production USB/DTR policy is unchanged. `get powersaving.diag time` and pages `3` through `8`. 6. If necessary, clear and repeat with only one feature changed. +On ESP32, pages `9` and `10` also show SDK call-entry counts in sixteen +16-second buckets starting at `start_ms`. These cover the first 256 seconds; +`outside` counts later entries. Flag 1 marks entries outside that horizon, +flag 2 marks saturation and flag 4 marks a call without a millisecond timestamp. +A bucket with calls can establish activity within an independently timed test +interval only when its whole time range fits inside that interval. Whole-window +calls alone can all precede packet traffic. Buckets count SDK entries, not +successful returns, physical residency or a particular packet's wake event. +Check the existing call/return/error counters too. Other platforms keep pages +`0` through `8`. + Reconnecting/reading creates real USB or serial work and can affect the final decision and counters. Prefer accumulated time over that final `why` value; check its age. Off freezes recorded values, not the node itself. Re-enabling @@ -136,8 +147,11 @@ allowed, leaving radio calibration timing unchanged. UART quiet is available only for an ordinary hardware UART console, such as the V3's external USB bridge. After draining its acknowledgement, it stops the -UART driver and automatically restores the console at 115200 baud after the -chosen interval. USB logging and OTA must be off. Native USB boards reject +UART driver and parks its Companion session, preventing new push notifications +to the stopped UART from holding the CPU awake. Received messages remain in +the offline inbox; other transports keep their own sessions. It automatically +restores the console at 115200 baud with a fresh, silent protocol session after +the chosen interval. USB logging and OTA must be off. Native USB boards reject this command. A reboot also restores the console. To separate clock speed from CPU sleep, hold the clock at 80 or 160 MHz 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 8c9a63f70..13b622f20 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 @@ -9,11 +9,12 @@ reversibly stopping the Bluetooth host/controller, and allowing bounded MCU light-sleep during a settled secondary-radio receive visit. This report separates host/build coverage, SDK wait measurements and physical packet tests. -Bluetooth and SDK wait checks pass. Three strict sleeping RF trials with +Bluetooth transitions and quiet-window SDK wait checks pass. Three strict RF trials with +power saving on and 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 +The first 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 @@ -25,6 +26,29 @@ 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. +Full Companion source +[`6236eec3`](https://github.com/mikecarper/MeshCore/commit/6236eec386b5450b739a206923a442692eb74f90) +includes that repair and a preferences-reader fix for a truncated timezone +record colliding with the new CPU footer length. Both timezone and CPU suites +pass; damaged CPU overrides still fall back to Auto. V3 and V4.3 OLED FEM-off +builds pass all 24 capability markers and their memory gates, at 2,118,680 and +2,556,504 application bytes respectively. + +The V3 received one application-only update after its old application hash +was verified. Complete new-image readback passed, with its partition table +and OTA metadata unchanged. Starting with Bluetooth saved off, it restored +Bluetooth on and completed three off/on cycles without a reboot or core +error. Uptime advanced from 32 to 58 seconds across 20 health samples. Every +Binary handoff revalidated board identity and source version. The final +checked configuration and credential hashes matched the baseline, and the +active PIN stayed unchanged. This physical check covers Bluetooth power +transitions, USB control and checked preference preservation. + +The recovery also exposed an already-ROM ESP32-S3 UART finish gap. The flasher +now explicitly releases the boot strap before its final reset; its regression +passes with both esptool command spellings. That separate fix is published in +[meshfirmware `f9d03d1`](https://github.com/mikecarper/meshfirmware/commit/f9d03d1). + ## Behavior and safeguards Bluetooth off disconnects clients and completes host/controller teardown in @@ -260,9 +284,40 @@ channel names and every key byte matched across two reads, both temporary slots were empty with zero keys, and every V4 name field had zero padding. The peer's firmware was not changed. +## V3 fixed-clock comparison with 20 packets per frequency + +After the NimBLE repair, the V3 completed all four predeclared cases on +`6236eec3`. Every case sent 20 unique packets per frequency once, with the same +32-symbol preambles, 2 dBm peer TX power and default 10/4/2 ms sleep dials. +Power saving stayed on; CPU speed and the temporary manual sleep switch were +controlled independently. RX power saving was saved off for these comparisons; +the profile scanner itself uses continuous RX during each visit. + +| CPU | Manual CPU sleep | Primary received | Secondary received | SDK calls/returns over the whole diagnostic window | +| --- | --- | --- | --- | --- | +| 80 MHz | Off | 18/20 | 17/20 | 0/0 | +| 80 MHz | On | 20/20 | 19/20 | 270/270 | +| 160 MHz | On | 18/20 | 14/20 | 18/18 | +| 160 MHz | Off | 19/20 | 16/20 | 0/0 | + +All 160 transmissions reached TX_DONE, with no packet retries or duplicates. +All four strict delivery checks failed. Settings, channels and credential +hashes were restored; both radios finished with zero core error flags. +Losses with manual sleep off show that sleep is not required for the observed +failure. Ambient traffic differed between cases, and these samples do not +establish a CPU-speed relationship or a packet-loss cause. + +The On rows do not yet prove sleep during packet traffic. The UART quiet +control stopped the driver but left its Companion session logically connected. +Incoming messages then queued push notifications to that stopped transport; +the existing pending-output guard correctly prevented sleep. Whole-window SDK +calls could have occurred before traffic began. The delivery counts remain +valid, but sleep comparison qualification requires retiring that UART session +and timing evidence inside the RF sequence. No pending-work guard is bypassed. + ## Final handback and limits -The V4 remains on `1ba4e2830`. Its original radio, RX power-saving, Bluetooth, +Both V3 and V4 now run `6236eec3`. Its original radio, RX power-saving, Bluetooth, WiFi, MQTT, logging, diagnostics and USB-watchdog settings were restored and checked against the frozen baseline, including credential digests. Radio2 is `off (automatic allowed)`, preserving its original automatic permission. @@ -278,6 +333,7 @@ electrical power savings. Unchanged Bluetooth and quiet-wait checks were not repeated for padding, version, documentation or fixture-only changes. Private artifacts, receipts and traces are retained under -`/home/mesh/hwtest/esp32-ble-radio2-sleep-cd4ea053-20261021/`. +`/home/mesh/hwtest/esp32-ble-radio2-sleep-cd4ea053-20261021/` and +`/home/mesh/hwtest/esp32-radio2-pson-v3-v4-20261021/`. See [power-saving diagnostics](../power_saving_diagnostics.md) for the controls and the limits of interpreting wait counters as energy savings. diff --git a/examples/companion_radio/main.cpp b/examples/companion_radio/main.cpp index 987bd4c9b..a8cdc0841 100644 --- a/examples/companion_radio/main.cpp +++ b/examples/companion_radio/main.cpp @@ -1167,6 +1167,56 @@ static void beginUsbDefaultSession() { serviceUsbAsciiSessionDefault(); } +#if defined(ESP32_PLATFORM) \ + && (!defined(ARDUINO_USB_CDC_ON_BOOT) || !ARDUINO_USB_CDC_ON_BOOT) \ + && !defined(SERIAL_RX) && !defined(SERIAL_TX) +static bool usb_uart_quiet_parked = false; +static bool usb_uart_quiet_restore_enabled = false; + +static bool transitionCompanionUartQuietSession( + void*, mesh::esp32::UartQuietSessionAction action) { + if (action == mesh::esp32::UartQuietSessionAction::Park) { + if (usb_uart_quiet_parked) return true; + if (!usb_protocol_initialized || usb_serial_interface.hasPendingIO() + || mesh::hasPendingUsbTerminalOutput()) return false; +#if COMPANION_FEATURE_USB_MOTA_SOURCE + if (usb_mota_mode + || mesh::ota::OtaContext::serialFolderSource().hasPendingResponse()) return false; +#endif + usb_uart_quiet_restore_enabled = usb_serial_interface.isEnabled(); + // End only this host's ownership. The inbox and BLE/WiFi transactions + // remain live while the physical UART is unavailable. + cancelUsbSerialOperations(); +#if COMPANION_FEATURE_READER + mesh::cancelReaderCommand(&mesh::usbTerminalPort()); +#endif + the_mesh.resetUsbHostSessionInput(); + if (the_mesh.isTerminalMode()) leaveUsbTerminalMode(false); + usb_binary_startup_probe.cancel(); + usb_ascii_session_default.cancel(); + mesh::discardUsbTerminalOutput(); + clearUsbTerminalLine(); + usb_terminal_discard_line = false; + usb_logging_terminal_mode = false; + usb_serial_interface.disable(); + usb_uart_quiet_parked = true; + return true; + } + + if (!usb_uart_quiet_parked) return true; + if (!Serial) return false; // The board must restore the driver first. + if (usb_uart_quiet_restore_enabled && interface_manager.isEnabled()) { + usb_serial_interface.enable(); + // A new session must not inherit old parser bytes or reply destinations. + // Default ASCII is silent until input, so a framed client gets no banner. + beginUsbDefaultSession(); + } + usb_uart_quiet_parked = false; + usb_uart_quiet_restore_enabled = false; + return true; +} +#endif + static void serviceUsbLoggingOwnership(bool logging_enabled); static void serviceUsbTerminal() { @@ -4038,6 +4088,12 @@ void setup() { #endif interface_manager.addInterface(InterfaceType::USB, &usb_serial_interface); usb_protocol_initialized = true; +#if defined(ESP32_PLATFORM) \ + && (!defined(ARDUINO_USB_CDC_ON_BOOT) || !ARDUINO_USB_CDC_ON_BOOT) \ + && !defined(SERIAL_RX) && !defined(SERIAL_TX) + mesh::esp32::registerUartQuietSessionControl( + nullptr, transitionCompanionUartQuietSession); +#endif // Select ASCII before any framed dispatch, including non-Full USB builds. // BLE/WiFi/Ethernet keep their existing Binary Companion transports. beginUsbDefaultSession(); @@ -4342,7 +4398,7 @@ void loop() { } else { esp_err_t error = esp_sleep_enable_timer_wakeup(static_cast(idle_slice_ms) * 1000ULL); if (error == ESP_OK) { - if (mesh::powerdiag::enabled()) mesh::powerdiag::sleepBegin(micros()); + if (mesh::powerdiag::enabled()) mesh::powerdiag::sleepBegin(micros(), millis()); error = esp_light_sleep_start(); if (mesh::powerdiag::enabled()) mesh::powerdiag::sleepEnd(micros()); } diff --git a/src/helpers/ESP32Board.h b/src/helpers/ESP32Board.h index fc16299dc..5a74309c1 100644 --- a/src/helpers/ESP32Board.h +++ b/src/helpers/ESP32Board.h @@ -198,6 +198,13 @@ public: snprintf(reply, capacity, "Error: UART restore failed; retrying automatically"); return false; } + if (!mesh::esp32::transitionUartQuietSession( + mesh::esp32::UartQuietSessionAction::Resume)) { + uart_quiet_restore_at = millis() + 1000; + if (!uart_quiet_restore_at) uart_quiet_restore_at = 1; + snprintf(reply, capacity, "Error: UART session restore failed; retrying automatically"); + return false; + } uart_quiet_restore_at = 0; } uart_quiet_seconds = 0; @@ -242,6 +249,8 @@ public: } if (!replies_drained || mesh::hasPendingUsbTerminalOutput()) return; Serial.flush(); // drain the hardware FIFO containing the acknowledgement + if (!mesh::esp32::transitionUartQuietSession( + mesh::esp32::UartQuietSessionAction::Park)) return; Serial.end(); uart_quiet_restore_at = millis() + uint32_t(uart_quiet_seconds) * 1000; if (!uart_quiet_restore_at) uart_quiet_restore_at = 1; @@ -386,7 +395,7 @@ public: #endif if (!radio_wakeup && button_gpio < 0) { if (wake_us > 0) { - if (diagnostics) mesh::powerdiag::sleepBegin(micros()); + if (diagnostics) mesh::powerdiag::sleepBegin(micros(), millis()); const esp_err_t error = esp_light_sleep_start(); if (diagnostics) { mesh::powerdiag::sleepEnd(micros()); @@ -448,7 +457,7 @@ public: } esp_err_t sleep_error = ESP_OK; if (gpio_error == ESP_OK && !pending_after_setup && !deadline_expired) { - if (diagnostics) mesh::powerdiag::sleepBegin(micros()); + if (diagnostics) mesh::powerdiag::sleepBegin(micros(), millis()); sleep_error = esp_light_sleep_start(); if (diagnostics) mesh::powerdiag::sleepEnd(micros()); } diff --git a/src/helpers/PowerSavingDiagnostics.h b/src/helpers/PowerSavingDiagnostics.h index 4d40983b6..adcc864dd 100644 --- a/src/helpers/PowerSavingDiagnostics.h +++ b/src/helpers/PowerSavingDiagnostics.h @@ -26,6 +26,13 @@ constexpr Mask mask(Reason reason) { constexpr Mask ValidMask = (Mask(1) << ReasonCount) - 1; // This identifies a short wait call, not proof that the CPU did not sleep. constexpr uint32_t ShortReturnMicros = 100; +#if defined(ESP32_PLATFORM) +constexpr size_t SdkBucketCount = 16; +constexpr uint32_t SdkBucketMillis = 16000; +enum SdkBucketFlags : uint8_t { + SdkBucketOutside = 1, SdkBucketSaturated = 2, SdkBucketMissingClock = 4 +}; +#endif inline const char* reasonName(Reason reason) { static const char* const names[] = { @@ -58,6 +65,14 @@ struct Snapshot { uint32_t last_call_us = 0; uint32_t call_begin_us = 0; int32_t detail = 0; +#if defined(ESP32_PLATFORM) + // SDK entry counts over time, not physical sleep residency. Keep timestamps + // in the millis domain so micros wrap cannot move an entry into another bin. + uint32_t bucket_start_ms = 0; + uint32_t bucket_outside_calls = 0; + uint16_t sdk_call_bins[SdkBucketCount] = {}; + uint8_t bucket_flags = 0; +#endif bool enabled = false; bool observed = false; bool pending = false; @@ -100,6 +115,9 @@ inline void setEnabled(bool on, uint32_t now_ms) { value = Snapshot(); value.enabled = true; value.last_ms = now_ms; +#if defined(ESP32_PLATFORM) + value.bucket_start_ms = now_ms; +#endif } else { account(value, now_ms); value.enabled = false; @@ -112,6 +130,9 @@ inline void reset(uint32_t now_ms) { value = Snapshot(); value.enabled = was_enabled; value.last_ms = now_ms; +#if defined(ESP32_PLATFORM) + value.bucket_start_ms = now_ms; +#endif } inline void decision(Mask reasons, uint32_t now_ms) { @@ -133,13 +154,44 @@ inline void decision(Mask reasons, uint32_t now_ms) { // Instrument the actual SDK/event wait, not an outer board.sleep() which can // decline the request or yield instead. Durations include ISR/SDK work and are // explicitly not physical sleep residency or a current measurement. -inline void sleepBegin(uint32_t now_us) { - Snapshot& value = state(); - if (!value.enabled) return; +inline void sleepBeginCounters(Snapshot& value, uint32_t now_us) { increment(value.calls); value.call_begin_us = now_us; value.pending = true; } +inline void sleepBegin(uint32_t now_us) { + Snapshot& value = state(); + if (!value.enabled) return; + sleepBeginCounters(value, now_us); +#if defined(ESP32_PLATFORM) + // Preserve old callers' counters while making an omitted millis clock + // explicit. Unknown timestamps must never become invented overlap proof. + value.bucket_flags |= SdkBucketMissingClock; +#endif +} +inline void sleepBegin(uint32_t now_us, uint32_t now_ms) { +#if defined(ESP32_PLATFORM) + Snapshot& value = state(); + if (!value.enabled) return; + if (value.calls == UINT32_MAX) value.bucket_flags |= SdkBucketSaturated; + sleepBeginCounters(value, now_us); + const uint32_t elapsed = now_ms - value.bucket_start_ms; + const uint32_t index = elapsed / SdkBucketMillis; + if (index >= SdkBucketCount) { + value.bucket_flags |= SdkBucketOutside; + if (value.bucket_outside_calls == UINT32_MAX) + value.bucket_flags |= SdkBucketSaturated; + increment(value.bucket_outside_calls); + } else if (value.sdk_call_bins[index] == UINT16_MAX) { + value.bucket_flags |= SdkBucketSaturated; + } else { + ++value.sdk_call_bins[index]; + } +#else + (void)now_ms; + sleepBegin(now_us); +#endif +} inline void sleepEnd(uint32_t now_us) { Snapshot& value = state(); if (!value.enabled || !value.pending) return; @@ -223,6 +275,23 @@ inline void formatPage(unsigned page, char* reply, size_t capacity, (unsigned long)value.call_us, (unsigned long)value.max_call_us, (unsigned long)value.last_call_us, (long)value.detail, (unsigned long)ShortReturnMicros); +#if defined(ESP32_PLATFORM) + } else if (page == 9 || page == 10) { + const size_t first = page == 9 ? 0 : 8; + const int initial = snprintf(reply, capacity, + "> bucket_ms=%lu start_ms=%lu now_ms=%lu outside=%lu flags=%u bins%u=", + (unsigned long)SdkBucketMillis, (unsigned long)value.bucket_start_ms, + (unsigned long)now_ms, (unsigned long)value.bucket_outside_calls, + (unsigned)value.bucket_flags, (unsigned)first); + if (initial < 0 || static_cast(initial) >= capacity) return; + size_t used = static_cast(initial); + for (size_t i = first; i < first + 8; ++i) { + const int count = snprintf(reply + used, capacity - used, "%s%u", + i == first ? "" : ",", (unsigned)value.sdk_call_bins[i]); + if (count < 0 || static_cast(count) >= capacity - used) return; + used += static_cast(count); + } +#endif } else { size_t used = 0; const int initial = snprintf(reply, capacity, "> transitions/blocked_ms:"); @@ -266,6 +335,10 @@ inline bool handleCommand(const char* command, char* reply, size_t capacity, else if (argument(tail, "calls")) page = 1; else if (argument(tail, "time")) page = 2; else if (*tail >= '0' && *tail <= '8' && argument(tail + 1, "")) page = *tail - '0'; +#if defined(ESP32_PLATFORM) + else if (argument(tail, "9")) page = 9; + else if (argument(tail, "10")) page = 10; +#endif else { for (size_t i = 0; i < ReasonCount; ++i) { const Reason reason = static_cast(i); @@ -280,7 +353,11 @@ inline bool handleCommand(const char* command, char* reply, size_t capacity, return true; } } +#if defined(ESP32_PLATFORM) + snprintf(reply, capacity, "Error: get powersaving.diag [0-10|state|calls|time|reason]; reason pages 3-8; SDK buckets 9-10"); +#else snprintf(reply, capacity, "Error: get powersaving.diag [0-8|state|calls|time|reason]; reason pages 3-8"); +#endif return true; } formatPage(page, reply, capacity, now_ms); diff --git a/src/helpers/esp32/PowerTestControls.h b/src/helpers/esp32/PowerTestControls.h index a127448b3..60b163d0c 100644 --- a/src/helpers/esp32/PowerTestControls.h +++ b/src/helpers/esp32/PowerTestControls.h @@ -38,6 +38,28 @@ inline void registerUartQuietControl(void* owner, UartQuietHandler handle) { uartQuietControl().handle = handle; } +// The physical UART and its role's protocol session must stop together. A +// failed Park callback must leave that session intact so the console remains +// usable. Infrastructure roles without a framed session need no callback. +enum class UartQuietSessionAction : uint8_t { Park, Resume }; +using UartQuietSessionHandler = bool (*)(void*, UartQuietSessionAction); +struct UartQuietSessionControl { + void* owner = nullptr; + UartQuietSessionHandler handle = nullptr; +}; +inline UartQuietSessionControl& uartQuietSessionControl() { + static UartQuietSessionControl value; + return value; +} +inline void registerUartQuietSessionControl(void* owner, UartQuietSessionHandler handle) { + uartQuietSessionControl().owner = owner; + uartQuietSessionControl().handle = handle; +} +inline bool transitionUartQuietSession(UartQuietSessionAction action) { + const auto& control = uartQuietSessionControl(); + return !control.handle || control.handle(control.owner, action); +} + inline bool manualCpuSleepEnabled() { return powerTestControls().sleep_enabled; } inline uint32_t profileSleepSliceMillis() { return powerTestControls().slice_ms; } inline uint32_t profileSleepGuardMicros() { return uint32_t(powerTestControls().guard_ms) * 1000; } diff --git a/test/test_esp32_power_test_controls.py b/test/test_esp32_power_test_controls.py index 800d1e418..31520911f 100644 --- a/test/test_esp32_power_test_controls.py +++ b/test/test_esp32_power_test_controls.py @@ -113,8 +113,8 @@ int main(){ "bool handleUartQuiet(","void servicePowerTestControls(")) code=HARNESS.split("int main()",1)[0] code=code.replace(" void end() { driver_initialized = false; }",r''' - unsigned begins=0,ends=0,flushes=0; - void begin(unsigned baud){assert(baud==115200);++begins;driver_initialized=true;} + unsigned begins=0,ends=0,flushes=0,fail_begins=0; + void begin(unsigned baud){assert(baud==115200);++begins;driver_initialized=fail_begins==0;if(fail_begins)--fail_begins;} void flush(){++flushes;} void end(){++ends;driver_initialized=false;} ''') @@ -164,10 +164,59 @@ int main(){ } '''],["-DESP32_PLATFORM=1","-DARDUINO_USB_CDC_ON_BOOT=0","-DMESH_USB_LOGGING_AVAILABLE=1"]) - def test_native_usb_quiet_is_unsupported_and_never_ends_driver(self): + def test_role_hook_failures_keep_session_and_bounded_recovery(self): compile_run([self.quiet_harness()+r''' +struct Session { + bool parked=false,refuse_park=true,refuse_resume=false; + unsigned parks=0,resumes=0; +}; +int main(){ + ESP32Board board;Session session;char reply[160]={}; + using mesh::esp32::UartQuietAction;using mesh::esp32::UartQuietSessionAction; + mesh::esp32::registerUartQuietSessionControl(&session, + [](void* owner,UartQuietSessionAction action){ + auto& state=*static_cast(owner); + assert(Serial); // Park precedes end; Resume follows a ready begin. + if(action==UartQuietSessionAction::Park){ + ++state.parks;assert(Serial.flushes>0); + if(state.refuse_park)return false; + state.parked=true; + }else{ + ++state.resumes; + if(state.refuse_resume)return false; + state.parked=false; + } + return true; + }); + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + assert(board.handleUartQuiet(UartQuietAction::Cancel,0,reply,sizeof(reply))); + assert(session.parks==0&&session.resumes==0&&Serial.ends==0); + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + mock_millis+=100;board.servicePowerTestControls(); + assert(session.parks==1&&!session.parked&&Serial&&Serial.ends==0); + mock_millis+=1900;board.servicePowerTestControls(); + assert(!board.uart_quiet_start_at&&session.parks==1&&Serial.ends==0); + session.refuse_park=false; + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + mock_millis+=100;board.servicePowerTestControls(false);assert(session.parks==1); + board.servicePowerTestControls();assert(session.parked&&!Serial&&Serial.ends==1); + Serial.fail_begins=1; + assert(!board.handleUartQuiet(UartQuietAction::Cancel,0,reply,sizeof(reply))); + assert(session.parked&&session.resumes==0&&!Serial&&board.uart_quiet_restore_at); + session.refuse_resume=true;mock_millis+=1000;board.servicePowerTestControls(); + assert(session.parked&&Serial&&session.resumes==1&&board.uart_quiet_restore_at); + session.refuse_resume=false;mock_millis+=1000;board.servicePowerTestControls(); + assert(!session.parked&&Serial&&session.resumes==2&&!board.uart_quiet_restore_at); +} +'''],["-DESP32_PLATFORM=1","-DARDUINO_USB_CDC_ON_BOOT=0","-DMESH_USB_LOGGING_AVAILABLE=1"]) + + def test_native_usb_and_extra_uart_quiet_never_park_the_session(self): + source = self.quiet_harness()+r''' +static unsigned session_actions=0; int main(){ ESP32Board board;char reply[160]={}; + mesh::esp32::registerUartQuietSessionControl(nullptr, + [](void*,mesh::esp32::UartQuietSessionAction){++session_actions;return true;}); assert(!board.handleUartQuiet(mesh::esp32::UartQuietAction::Schedule,5,reply,sizeof(reply))); assert(strstr(reply,"Error:")&&Serial.ends==0); board.servicePowerTestControls();assert(Serial.ends==0); @@ -178,8 +227,13 @@ int main(){ mesh::esp32::powerTestControls().guard_ms=15; assert(mesh::esp32::handlePowerTestCommand("set powersaving.test reset",reply,sizeof(reply),true)); assert(mesh::esp32::profileSleepGuardMicros()==4000&&strstr(reply,"uart=unsupported")); + assert(session_actions==0); } -'''],["-DESP32_PLATFORM=1","-DARDUINO_USB_CDC_ON_BOOT=1","-DMESH_USB_LOGGING_AVAILABLE=1"]) +''' + for defines in (("ARDUINO_USB_CDC_ON_BOOT=1",), ("SERIAL_RX=1",), ("SERIAL_TX=1",)): + with self.subTest(defines=defines): + compile_run([source],["-DESP32_PLATFORM=1","-DMESH_USB_LOGGING_AVAILABLE=1", + *["-D"+value for value in defines]]) if __name__ == "__main__": unittest.main(verbosity=2) diff --git a/test/test_esp32_uart_quiet_session.py b/test/test_esp32_uart_quiet_session.py new file mode 100644 index 000000000..00c82f3a4 --- /dev/null +++ b/test/test_esp32_uart_quiet_session.py @@ -0,0 +1,350 @@ +"""Exercise real UART session parking, inbox delivery and serial sleep vetoes.""" +from pathlib import Path +import os +import re +import subprocess +import tempfile +import unittest + +from test_replay_reset_integration import extract_braced +from test_esp32_usb_sleep import board_method + + +ROOT = Path(__file__).resolve().parents[1] +PRELUDE = r''' +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#define COMPANION_FEATURE_USB_MOTA_SOURCE 1 +#define COMPANION_FEATURE_NETWORK_TERMINAL 1 +#define COMPANION_FEATURE_READER 1 +#define MESH_USB_LOGGING_AVAILABLE 0 +#define MESH_DEBUG_PRINTLN(...) ((void)0) +#define OFFLINE_QUEUE_SIZE 64 +@CONSTANTS@ +@BUFFER@ +struct Uart : BufferStream { + bool driver=true; + unsigned begins=0,ends=0,flushes=0,fail_begins=0; + explicit operator bool() const { return driver; } + int availableForWrite() override { return driver ? BufferStream::availableForWrite() : 0; } + void begin(unsigned baud) { + assert(baud==115200);++begins; + driver=fail_begins==0;if(fail_begins)--fail_begins; + } + void end() { assert(driver);++ends;driver=false;input.clear(); } + void flush() override { assert(driver);++flushes; } +} Serial; +static uint32_t micros() { return millis()*1000; } +static bool terminal_output_pending=false; +namespace mesh { +bool hasPendingUsbTerminalOutput() { return terminal_output_pending; } +bool isUsbLoggingEnabled() { return false; } +bool hasDedicatedUsbLoggingPort() { return false; } +void discardUsbTerminalOutput() { terminal_output_pending=false; } +Stream& usbTerminalPort() { return Serial; } +static struct { const Stream* output=nullptr; } print_job; +static const Stream*& reader_owner=print_job.output; +@READER_CANCEL@ +struct GroupChannel {}; +struct Packet { + uint8_t path_len=0; + float getSNR() const { return 4; } + bool isRouteFlood() const { return false; } +}; +namespace ota { +struct Source { bool pending=false;bool hasPendingResponse() const { return pending; } }; +struct OtaContext { static Source& serialFolderSource() { static Source source;return source; } }; +} +} +ArduinoSerialInterface usb_serial_interface,other_interface; +MultiSerialInterface interface_manager; +BufferStream other_stream; +struct MyMesh { + @FRAME@ + Frame offline_queue[OFFLINE_QUEUE_SIZE]{}; + int offline_queue_len=0,offline_queue_head=0; + uint8_t out_frame[MAX_FRAME_SIZE]{}; + BaseSerialInterface* _serial=&interface_manager; + bool terminal=false,network=false,stale_input=true; + unsigned ascii_starts=0; + bool last_banner=true; + BaseSerialInterface* stream_route=nullptr; + BaseSerialInterface* pending_route=nullptr; + unsigned cancelled_usb=0,cancelled_other=0; + bool isTerminalMode() const { return terminal; } + void enterTerminalMode(bool banner) { assert(!network);terminal=true;++ascii_starts;last_banner=banner; } + void exitTerminalMode() { terminal=false; } + void resetUsbHostSessionInput() { stale_input=false; } + void cancelSerialResponseStream(BaseSerialInterface* route) { + if(stream_route==route)stream_route=nullptr; + } + void cancelSerialOperationsForRoute(BaseSerialInterface* route) { + if(route==&usb_serial_interface)++cancelled_usb;else++cancelled_other; + if(pending_route==route)pending_route=nullptr; + } + int findChannelIdxForPacket(const mesh::GroupChannel&,mesh::Packet*) const { return 0; } + int getOfflineQueueCapacity() const; + Frame& offlineQueueFrameAt(int); + bool addToOfflineQueue(const uint8_t*,int); + int peekOfflineQueue(uint8_t*); + void popOfflineQueue(); + void syncNextOfflineMessage(); + void onChannelDataRecv(const mesh::GroupChannel&,mesh::Packet*,uint16_t,const uint8_t*,size_t); + mesh::powerdiag::Mask serialVeto() const { + using mesh::powerdiag::Reason;using mesh::powerdiag::mask; + @SERIAL_GUARD@ + return 0; + } +} the_mesh; +@INBOX@ +static bool usb_protocol_initialized=true,usb_mota_mode=false; +static bool usb_logging_terminal_mode=false,usb_terminal_discard_line=false; +static bool usb_terminal_host_reset_completion_pending=false; +static char usb_terminal_line[64]{}; +static unsigned usb_terminal_line_len=0; +static mesh::UsbBinaryStartupProbe usb_binary_startup_probe; +static mesh::UsbAsciiSessionDefault usb_ascii_session_default; +static bool usb_uart_quiet_parked=false,usb_uart_quiet_restore_enabled=false; +static bool isNetworkTerminalActive() { return the_mesh.network; } +static void queueUsbTerminalControlReply(const char*) { assert(false); } +static void drainUsbTerminalOutputBeforeProtocolSwitch() { assert(false); } +static void clearUsbTerminalLine() { memset(usb_terminal_line,0,sizeof(usb_terminal_line));usb_terminal_line_len=0; } +@SESSION@ +struct Board { + bool inhibit_sleep=false,ota=false,radio_test=false; + uint32_t uart_quiet_start_at=0,uart_quiet_restore_at=0; + uint16_t uart_quiet_seconds=0; + bool isOTAUpdateRunning() const { return ota; } + bool isRadioTestActive() const { return radio_test; } + @BOARD@ +}; +using Bytes=std::vector; +static void select(ArduinoSerialInterface& route,BufferStream& stream) { + const uint8_t input[]={'<',1,0,10};uint8_t command[MAX_FRAME_SIZE]{}; + stream.push(input,sizeof(input));assert(interface_manager.checkRecvFrame(command)==1); + assert(interface_manager.captureReplyRoute()==&route); +} +static void receive(unsigned sequence) { + mesh::GroupChannel channel;mesh::Packet packet; + const uint8_t data[]={uint8_t(sequence),0xa5,0x5a,0xff}; + the_mesh.onChannelDataRecv(channel,&packet,0xff00,data,sizeof(data)); +} +static void setup() { + resetArduinoMock();g_mock_millis=1000; + usb_serial_interface.begin(Serial,"START");usb_serial_interface.enableFlowControl(true); + other_interface.begin(other_stream);other_interface.enableFlowControl(true); + assert(interface_manager.addInterface(InterfaceType::USB,&usb_serial_interface)); + assert(interface_manager.addInterface(InterfaceType::WiFi,&other_interface)); + interface_manager.enable();other_interface.disable(); + mesh::esp32::registerUartQuietSessionControl(nullptr,transitionCompanionUartQuietSession); +} +''' + +SCENARIOS = r''' +int main(int argc,char**) { + setup();Board board;char reply[160]{}; + using mesh::esp32::UartQuietAction; + using mesh::esp32::UartQuietSessionAction; + select(usb_serial_interface,Serial); + const uint32_t original_count=usb_serial_interface.getCompletedFrameCount(); + the_mesh.stream_route=the_mesh.pending_route=&usb_serial_interface; + interface_manager.lockReplyRoute(); + mesh::reader_owner=&Serial; + // Refused readiness cannot partly retire the live host or its producers. + usb_protocol_initialized=false; + assert(!transitionCompanionUartQuietSession(nullptr,UartQuietSessionAction::Park)); + usb_protocol_initialized=true;usb_mota_mode=true; + assert(!transitionCompanionUartQuietSession(nullptr,UartQuietSessionAction::Park)); + usb_mota_mode=false;mesh::ota::OtaContext::serialFolderSource().pending=true; + assert(!transitionCompanionUartQuietSession(nullptr,UartQuietSessionAction::Park)); + mesh::ota::OtaContext::serialFolderSource().pending=false; + terminal_output_pending=true; + assert(!transitionCompanionUartQuietSession(nullptr,UartQuietSessionAction::Park)); + terminal_output_pending=false; + assert(the_mesh.cancelled_usb==0&&mesh::reader_owner==&Serial&&usb_serial_interface.isEnabled()); + // Cancelling an armed request is not a host-session disconnect. + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + assert(board.handleUartQuiet(UartQuietAction::Cancel,0,reply,sizeof(reply))); + assert(the_mesh.cancelled_usb==0&&usb_serial_interface.isEnabled()&&Serial.ends==0); + // A queued ACK must drain before either the session or UART is parked. + Serial.write_capacity=0;const uint8_t ack=0; + assert(interface_manager.writeFrameToRoute(&usb_serial_interface,&ack,1)==1); + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + g_mock_millis+=100;board.servicePowerTestControls(!interface_manager.hasPendingIO()); + assert(Serial.ends==0&&the_mesh.cancelled_usb==0&&interface_manager.hasPendingIO()); + Serial.write_capacity=4096;interface_manager.loop(); + assert(!interface_manager.hasPendingIO()&&Serial.output==Bytes({'>',1,0,0})); + board.servicePowerTestControls(!interface_manager.hasPendingIO()); + assert(!Serial&&Serial.ends==1&&Serial.flushes==1); + if(argc>1) { + // Negative control: the old board ended the driver without parking its + // still-assumed-connected interface. A real RX queues MSG_WAITING forever. + assert(usb_serial_interface.isEnabled());receive(0); + assert(the_mesh.offline_queue_len==1&&interface_manager.hasPendingIO()); + assert(the_mesh.serialVeto()==mesh::powerdiag::mask(mesh::powerdiag::Reason::Serial)); + puts("old UART quiet retained MSG_WAITING serial veto");return 42; + } + assert(!usb_serial_interface.isEnabled()&&!interface_manager.isConnected()); + assert(the_mesh.cancelled_usb==1&&the_mesh.cancelled_other==0); + assert(mesh::reader_owner==nullptr); + assert(!the_mesh.stream_route&&!the_mesh.pending_route&&!interface_manager.captureReplyRoute()); + assert(!the_mesh.stale_input&&!usb_binary_startup_probe.isActive()); + assert(!interface_manager.isReplyRouteAvailable(&usb_serial_interface)); + // The application's actual RX/inbox method retains every packet while no + // transport is listening, with no unserviceable MSG_WAITING frame queued. + for(unsigned i=0;i<40;++i) { + receive(i);interface_manager.loop(); + assert(the_mesh.offline_queue_len==int(i+1)); + assert(!interface_manager.hasPendingIO()&&the_mesh.serialVeto()==0); + } + const Bytes quiet_output=Serial.output; + the_mesh.syncNextOfflineMessage();assert(the_mesh.offline_queue_len==40); + // Another transport's real queued work keeps the original serial veto. + // Nothing about quiet mode grants it an exception or clears its session. + other_interface.enable();other_stream.write_capacity=0; + the_mesh.pending_route=the_mesh.stream_route=&other_interface; + assert(interface_manager.writeFrameToRoute(&other_interface,&ack,1)==1); + assert(interface_manager.hasPendingIO()); + assert(the_mesh.serialVeto()==mesh::powerdiag::mask(mesh::powerdiag::Reason::Serial)); + assert(!transitionCompanionUartQuietSession(nullptr,UartQuietSessionAction::Resume)); + assert(!usb_serial_interface.isEnabled()&&the_mesh.pending_route==&other_interface); + other_stream.write_capacity=4096;interface_manager.loop(); + assert(!interface_manager.hasPendingIO()&&the_mesh.serialVeto()==0); + other_interface.disable(); + // A failed driver restart retains the parked session and all inbox data; + // the timer retries even when manual CPU sleep has been turned off. + mesh::esp32::powerTestControls().sleep_enabled=false;Serial.fail_begins=1; + g_mock_millis+=5000;board.servicePowerTestControls(); + assert(!Serial&&!usb_serial_interface.isEnabled()&&board.uart_quiet_restore_at); + assert(the_mesh.offline_queue_len==40&&the_mesh.ascii_starts==0); + g_mock_millis+=999;board.servicePowerTestControls();assert(!Serial); + ++g_mock_millis;board.servicePowerTestControls(); + assert(Serial&&usb_serial_interface.isEnabled()&&!board.uart_quiet_restore_at); + assert(the_mesh.ascii_starts==1&&!the_mesh.last_banner&&the_mesh.terminal); + assert(usb_serial_interface.getCompletedFrameCount()==original_count); + assert(Serial.output==quiet_output&&the_mesh.offline_queue_len==40); + assert(the_mesh.pending_route==&other_interface&&the_mesh.stream_route==&other_interface); + assert(!other_interface.isEnabled()&&the_mesh.cancelled_other==0); + // Fresh Binary ownership can download the original inbox once, in order. + leaveUsbTerminalMode(false);select(usb_serial_interface,Serial); + for(unsigned i=0;i<40;++i)the_mesh.syncNextOfflineMessage(); + assert(the_mesh.offline_queue_len==0); + size_t at=quiet_output.size(); + for(unsigned i=0;i<40;++i) { + assert(Serial.output.at(at)=='>');size_t length=Serial.output.at(at+1)|(size_t(Serial.output.at(at+2))<<8); + at+=3;assert(length==13&&Serial.output.at(at)==27&&Serial.output.at(at+9)==i);at+=length; + } + assert(at==Serial.output.size()); + // A pre-disabled interface must stay disabled after the timed recovery. + usb_serial_interface.disable();const unsigned starts=the_mesh.ascii_starts; + mesh::reader_owner=&other_stream; + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + g_mock_millis+=100;board.servicePowerTestControls();assert(!Serial); + g_mock_millis+=5000;board.servicePowerTestControls(); + assert(Serial&&!usb_serial_interface.isEnabled()&&the_mesh.ascii_starts==starts); + assert(mesh::reader_owner==&other_stream); + // A live network terminal/Reader retains its owner when USB comes back. + usb_serial_interface.enable();the_mesh.network=true; + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + g_mock_millis+=100;board.servicePowerTestControls();assert(!Serial); + g_mock_millis+=5000;board.servicePowerTestControls(); + assert(Serial&&usb_serial_interface.isEnabled()&&the_mesh.ascii_starts==starts); + assert(mesh::reader_owner==&other_stream&&the_mesh.network); + // Active USB ASCII ownership is retired too. A subsequent global manager + // shutdown must not be reversed merely because the UART recovery is due. + the_mesh.network=false;serviceUsbAsciiSessionDefault(); + assert(the_mesh.terminal);mesh::reader_owner=&Serial; + assert(board.handleUartQuiet(UartQuietAction::Schedule,5,reply,sizeof(reply))); + g_mock_millis+=100;board.servicePowerTestControls(); + assert(!Serial&&!the_mesh.terminal&&!usb_serial_interface.isEnabled()&&mesh::reader_owner==nullptr); + interface_manager.disable();g_mock_millis+=5000;board.servicePowerTestControls(); + assert(Serial&&!interface_manager.isEnabled()&&!usb_serial_interface.isEnabled()); + puts("parked UART retained forty real RX inbox frames without bypassing serial guards"); +} +''' + + +def harness(legacy=False): + source = (ROOT / "examples/companion_radio/MyMesh.cpp").read_text() + main = (ROOT / "examples/companion_radio/main.cpp").read_text() + header = (ROOT / "examples/companion_radio/MyMesh.h").read_text() + native = (ROOT / "test/test_serial_mode_switch/test_serial_mode_switch.cpp").read_text() + reader = (ROOT / "src/helpers/CompanionReader.cpp").read_text() + constants = "\n".join(re.findall( + r"^#define (?:RESP_CODE_(?:CHANNEL_MSG_RECV|CHANNEL_MSG_RECV_V3|CHANNEL_DATA_RECV|NO_MORE_MESSAGES)|PUSH_CODE_MSG_WAITING|MAX_CHANNEL_DATA_LENGTH)\s+.+$", + source, re.MULTILINE)) + inbox = "\n".join(extract_braced(source, signature) for signature in ( + "bool MyMesh::Frame::isChannelMsg() const", "int MyMesh::getOfflineQueueCapacity() const", + "MyMesh::Frame& MyMesh::offlineQueueFrameAt(", "bool MyMesh::addToOfflineQueue(", + "int MyMesh::peekOfflineQueue(", "void MyMesh::popOfflineQueue(", + "void MyMesh::syncNextOfflineMessage(", "void MyMesh::onChannelDataRecv(")) + session = "\n".join(extract_braced(main, signature) for signature in ( + "static void cancelUsbSerialOperations()", "static void enterUsbTerminalMode(", + "static void leaveUsbTerminalMode(", "static void serviceUsbAsciiSessionDefault()", + "static void beginUsbDefaultSession()", "static bool transitionCompanionUartQuietSession(")) + board = "\n".join(board_method(signature) for signature in ( + "bool handleUartQuiet(", "void servicePowerTestControls(")) + if legacy: + park = " if (!mesh::esp32::transitionUartQuietSession(\n mesh::esp32::UartQuietSessionAction::Park)) return;\n" + assert board.count(park) == 1 + board = board.replace(park, "", 1) + guard = re.search(r" if \(_serial != NULL && _serial->hasPendingIO\(\)\) return mask\(Reason::Serial\);", source) + assert guard is not None + result = PRELUDE + for marker, value in {"@CONSTANTS@": constants, "@BUFFER@": extract_braced(native, "class BufferStream") + ";", + "@FRAME@": extract_braced(header, "struct Frame {") + ";", "@INBOX@": inbox, + "@SERIAL_GUARD@": guard.group(), "@SESSION@": session, "@BOARD@": board, + "@READER_CANCEL@": extract_braced(reader, "void cancelReaderCommand(")}.items(): + result = result.replace(marker, value) + return result + SCENARIOS + + +class UartQuietSessionTests(unittest.TestCase): + def test_actual_rx_queue_and_transport_lifecycle_with_old_negative_control(self): + with tempfile.TemporaryDirectory(prefix="mesh-uart-quiet-session-") as directory: + folder = Path(directory) + for legacy in (True, False): + with self.subTest(legacy=legacy): + cpp, binary = folder / "test.cpp", folder / "test" + cpp.write_text(harness(legacy), encoding="ascii") + built = subprocess.run([os.environ.get("CXX", "c++"), "-std=c++17", "-Wall", "-Wextra", + "-Werror", "-Wno-unused-parameter", "-Wno-unused-function", "-Wno-sign-compare", + "-fsanitize=address,undefined", "-fno-sanitize-recover=all", "-fno-pie", "-no-pie", + "-DESP32_PLATFORM=1", "-DARDUINO_USB_CDC_ON_BOOT=0", + "-I", str(ROOT / "test/mocks"), "-I", str(ROOT / "src"), str(cpp), + str(ROOT / "src/helpers/ArduinoSerialInterface.cpp"), "-o", str(binary)], + text=True, capture_output=True, timeout=60) + self.assertEqual(built.returncode, 0, built.stderr) + ran = subprocess.run([str(binary)] + (["legacy"] if legacy else []), + text=True, capture_output=True, timeout=20) + self.assertEqual(ran.returncode, 42 if legacy else 0, ran.stdout + ran.stderr) + self.assertIn("MSG_WAITING serial veto" if legacy else "forty real RX inbox frames", ran.stdout) + + def test_hook_is_registered_only_for_default_esp32_uart(self): + source = (ROOT / "examples/companion_radio/main.cpp").read_text() + pattern = r"#if defined\(ESP32_PLATFORM\) \\\n && \(!defined\(ARDUINO_USB_CDC_ON_BOOT\) \|\| !ARDUINO_USB_CDC_ON_BOOT\) \\\n && !defined\(SERIAL_RX\) && !defined\(SERIAL_TX\)\n" + self.assertEqual(len(re.findall(pattern, source)), 2) + start = source.index(" mesh::esp32::registerUartQuietSessionControl(") + prefix = source[:start] + block = prefix[prefix.rfind("#if defined(ESP32_PLATFORM)"):] + source[start:source.index("#endif", start) + 6] + for defines, expected in ((["ESP32_PLATFORM=1"], True), (["NRF52_PLATFORM=1"], False), + (["ESP32_PLATFORM=1", "ARDUINO_USB_CDC_ON_BOOT=1"], False), + (["ESP32_PLATFORM=1", "SERIAL_RX=1"], False), (["ESP32_PLATFORM=1", "SERIAL_TX=1"], False)): + with self.subTest(defines=defines): + result = subprocess.run([os.environ.get("CXX", "c++"), "-E", "-P", "-x", "c++", + *["-D" + value for value in defines], "-"], input=block, text=True, capture_output=True, timeout=20) + self.assertEqual(result.returncode, 0, result.stderr) + self.assertEqual("registerUartQuietSessionControl" in result.stdout, expected) + + +if __name__ == "__main__": + unittest.main(verbosity=2) diff --git a/test/test_power_saving_diagnostics_buckets.py b/test/test_power_saving_diagnostics_buckets.py new file mode 100644 index 000000000..273ff4eeb --- /dev/null +++ b/test/test_power_saving_diagnostics_buckets.py @@ -0,0 +1,180 @@ +#!/usr/bin/env python3 +"""Exercise real SDK-entry time buckets, protocol bounds and legacy layout.""" +from pathlib import Path +import os +import shlex +import subprocess +import tempfile +import unittest + +ROOT = Path(__file__).resolve().parents[1] +SOURCE = r''' +#include +#include +#include +#include +using namespace mesh::powerdiag; + +struct LegacySnapshot { + uint32_t blocked_ms[ReasonCount] = {}; + uint16_t transitions[ReasonCount] = {}; + Mask current = 0, seen = 0; + uint32_t union_blocked_ms = 0, eligible_ms = 0, last_ms = 0, decision_at_ms = 0; + uint32_t calls = 0, returns = 0, short_returns = 0, board_vetoes = 0, errors = 0; + uint32_t call_us = 0, max_call_us = 0, last_call_us = 0, call_begin_us = 0; + int32_t detail = 0; + bool enabled = false, observed = false, pending = false; +}; + +#if defined(ESP32_PLATFORM) +static void call(uint32_t elapsed_ms) { + sleepBegin(123, state().bucket_start_ms + elapsed_ms); + sleepEnd(1123); +} +static uint32_t sum() { + uint32_t total = state().bucket_outside_calls; + for (size_t i = 0; i < SdkBucketCount; ++i) total += state().sdk_call_bins[i]; + return total; +} +#endif + +int main(int argc, char** argv) { + assert(argc == 2); + const char* test = argv[1]; +#if defined(ESP32_PLATFORM) + static_assert(sizeof(Snapshot) <= 256, "ESP32 diagnostics RAM budget"); + static_assert(sizeof(Snapshot) - sizeof(LegacySnapshot) <= 40, "Bucket storage grew"); + if (!strcmp(test, "boundaries")) { + setEnabled(true, 1000); + call(0); call(15999); call(16000); call(255999); call(256000); + assert(state().sdk_call_bins[0] == 2 && state().sdk_call_bins[1] == 1); + assert(state().sdk_call_bins[15] == 1 && state().bucket_outside_calls == 1); + assert(state().bucket_flags == SdkBucketOutside && state().calls == 5); + assert(sum() == state().calls && state().returns == state().calls); + // An earlier timestamp becomes explicitly outside; it is never clamped. + sleepBegin(200, 999); sleepEnd(1200); + assert(state().bucket_outside_calls == 2 && state().sdk_call_bins[0] == 2); + } else if (!strcmp(test, "reset_freeze")) { + sleepBegin(12, 12); assert(state().calls == 0 && state().bucket_flags == 0); + setEnabled(true, 1000); call(1); + setEnabled(true, 3000); assert(state().bucket_start_ms == 1000); + setEnabled(false, 4000); + sleepBegin(5000, 9000); sleepEnd(6000); + assert(state().calls == 1 && state().sdk_call_bins[0] == 1); + char text[160]; formatPage(9, text, sizeof(text), 1000000); + assert(state().calls == 1 && state().bucket_start_ms == 1000); + setEnabled(true, 10000); + assert(state().calls == 0 && sum() == 0 && state().bucket_start_ms == 10000); + call(17000); reset(40000); + assert(enabled() && state().calls == 0 && sum() == 0 && state().bucket_start_ms == 40000); + setEnabled(false, 41000); reset(50000); + assert(!enabled() && state().bucket_start_ms == 50000 && sum() == 0); + } else if (!strcmp(test, "clock_wrap")) { + const uint32_t start = UINT32_MAX - 1000; + setEnabled(true, start); + sleepBegin(UINT32_MAX - 31, uint32_t(start + 16000)); + sleepEnd(50); + assert(state().sdk_call_bins[1] == 1 && state().last_call_us == 82); + sleepBegin(0, 500); sleepEnd(1000); + assert(state().sdk_call_bins[0] == 1 && state().bucket_flags == 0); + assert(state().bucket_start_ms == start && sum() == state().calls); + } else if (!strcmp(test, "saturation_missing")) { + setEnabled(true, 0); + state().calls = UINT16_MAX - 1; state().sdk_call_bins[0] = UINT16_MAX - 1; + call(1); assert(state().sdk_call_bins[0] == UINT16_MAX && state().bucket_flags == 0); + call(2); assert(state().sdk_call_bins[0] == UINT16_MAX && state().calls == 65536); + assert(state().bucket_flags == SdkBucketSaturated); + reset(1000); state().calls = UINT32_MAX; state().bucket_outside_calls = UINT32_MAX; + call(256000); + assert(state().bucket_outside_calls == UINT32_MAX && state().calls == UINT32_MAX); + assert(state().bucket_flags == (SdkBucketOutside | SdkBucketSaturated)); + reset(2000); sleepBegin(30); sleepEnd(1030); + assert(state().calls == 1 && sum() == 0 && state().bucket_flags == SdkBucketMissingClock); + } else if (!strcmp(test, "format_capacity")) { + setEnabled(true, UINT32_MAX); + state().bucket_outside_calls = UINT32_MAX; state().bucket_flags = 255; + for (size_t i = 0; i < SdkBucketCount; ++i) state().sdk_call_bins[i] = UINT16_MAX; + for (unsigned page = 9; page <= 10; ++page) { + char full[160]; memset(full, 'x', sizeof(full)); + formatPage(page, full, 157, UINT32_MAX); + assert(strlen(full) < 157 && strstr(full, page == 9 ? "bins0=" : "bins8=")); + assert(strstr(full, "outside=4294967295 flags=255")); + for (size_t capacity = 0; capacity <= 157; ++capacity) { + char guarded[162]; memset(guarded, 'q', sizeof(guarded)); + formatPage(page, guarded + 1, capacity, UINT32_MAX); + assert(guarded[0] == 'q' && guarded[capacity + 1] == 'q'); + if (capacity) assert(memchr(guarded + 1, 0, capacity)); + } + char command[40]; snprintf(command, sizeof(command), "get powersaving.diag %u", page); + char reply[160]; assert(handleCommand(command, reply, 157, UINT32_MAX)); + assert(!strncmp(reply, "> bucket_ms=16000 start_ms=4294967295", 34)); + } + char reply[160]; + assert(handleCommand("get powersaving.diag 09", reply, sizeof(reply), 0)); + assert(!strncmp(reply, "Error:", 6)); + assert(handleCommand("get powersaving.diag 10junk", reply, sizeof(reply), 0)); + assert(!strncmp(reply, "Error:", 6)); + } else return 2; +#else + static_assert(sizeof(Snapshot) == sizeof(LegacySnapshot), "Legacy diagnostics layout changed"); + static_assert(offsetof(Snapshot, enabled) == offsetof(LegacySnapshot, enabled), "Legacy field offset changed"); + static_assert(offsetof(Snapshot, pending) == offsetof(LegacySnapshot, pending), "Legacy field offset changed"); + if (strcmp(test, "legacy")) return 2; + setEnabled(true, UINT32_MAX - 10); decision(0, UINT32_MAX - 5); + sleepBegin(UINT32_MAX - 31); sleepEnd(50); + assert(state().calls == 1 && state().returns == 1 && state().last_call_us == 82); + char reply[160]; + for (unsigned page = 9; page <= 10; ++page) { + char command[40]; snprintf(command, sizeof(command), "get powersaving.diag %u", page); + assert(handleCommand(command, reply, sizeof(reply), 1)); + assert(!strcmp(reply, "Error: get powersaving.diag [0-8|state|calls|time|reason]; reason pages 3-8")); + } +#endif + return 0; +} +''' + + +class SdkBucketTests(unittest.TestCase): + @classmethod + def setUpClass(cls): + cls.temp = tempfile.TemporaryDirectory(prefix='meshcore-sdk-buckets-') + cls.addClassCleanup(cls.temp.cleanup) + source = Path(cls.temp.name) / 'buckets.cpp' + source.write_text(SOURCE, encoding='ascii') + cls.binaries = {} + for platform in ('ESP32_PLATFORM', 'NRF52_PLATFORM'): + binary = Path(cls.temp.name) / platform + result = subprocess.run(shlex.split(os.environ.get('CXX', 'g++')) + + ['-std=c++11', '-Wall', '-Wextra', '-Werror', '-pedantic', '-D' + platform, + '-I', str(ROOT / 'src'), str(source), '-o', str(binary)], + capture_output=True, text=True) + if result.returncode: + raise RuntimeError(result.stderr) + cls.binaries[platform] = binary + + def run_case(self, name, platform='ESP32_PLATFORM'): + result = subprocess.run([str(self.binaries[platform]), name], capture_output=True, text=True) + self.assertEqual(result.returncode, 0, result.stdout + result.stderr) + + def test_bin_boundaries_and_outside_calls_are_not_clamped(self): + self.run_case('boundaries') + + def test_on_reset_disabled_and_off_freeze(self): + self.run_case('reset_freeze') + + def test_millis_wrap_is_independent_of_micros_wrap(self): + self.run_case('clock_wrap') + + def test_saturation_and_missing_clock_are_explicit(self): + self.run_case('saturation_missing') + + def test_real_pages_fit_protocol_and_every_small_buffer(self): + self.run_case('format_capacity') + + def test_nrf52_retains_legacy_layout_counters_and_cli(self): + self.run_case('legacy', 'NRF52_PLATFORM') + + +if __name__ == '__main__': + unittest.main()