From ae91ccdd928c4eb2875ea7df9e66f3ec171b2feb Mon Sep 17 00:00:00 2001 From: "torlando-agent[bot]" <281092095+torlando-agent[bot]@users.noreply.github.com> Date: Mon, 3 Aug 2026 20:36:55 +0000 Subject: [PATCH] [verified] fix: restore watchdog panic with bounded polling --- lib/auto_interface/AutoInterface.cpp | 23 ++- lib/ble_interface/BLEInterface.cpp | 36 ++++- src/TCPClientInterface.cpp | 85 ++++++----- src/main.cpp | 102 +++++++------ tests/build_scripts/test_watchdog_contract.py | 140 ++++++++++++++++++ tests/build_scripts/test_watchdog_harness.py | 42 ++++++ tests/hardware/tdeck_harness.py | 71 +++++++-- 7 files changed, 383 insertions(+), 116 deletions(-) create mode 100644 tests/build_scripts/test_watchdog_contract.py create mode 100644 tests/build_scripts/test_watchdog_harness.py diff --git a/lib/auto_interface/AutoInterface.cpp b/lib/auto_interface/AutoInterface.cpp index 4354f2ef..ca9336a1 100644 --- a/lib/auto_interface/AutoInterface.cpp +++ b/lib/auto_interface/AutoInterface.cpp @@ -27,6 +27,11 @@ using namespace RNS; +// Bound each non-blocking socket drain so a continuous multicast/data flood +// cannot keep loopTask inside AutoInterface long enough to miss its watchdog +// deadline. Remaining datagrams stay queued for the next main-loop pass. +static constexpr size_t SOCKET_RX_BUDGET = 16; + // Helper: Convert IPv6 address bytes to compressed string format (RFC 5952) // This matches Python's inet_ntop output static std::string ipv6_to_compressed_string(const uint8_t* addr) { @@ -943,7 +948,9 @@ void AutoInterface::process_discovery() { // Hot path - no logging to avoid heap allocation on every packet - while (len > 0) { + for (size_t packet_count = 0; + packet_count < SOCKET_RX_BUDGET && len > 0; + ++packet_count) { _stat_discovery_rx++; // Convert source address to COMPRESSED string format (match Python) std::string src_str = ipv6_to_compressed_string((const uint8_t*)&src_addr.sin6_addr); @@ -997,7 +1004,9 @@ void AutoInterface::process_data() { ssize_t len = recvfrom(_data_socket, recv_buffer, sizeof(recv_buffer), 0, (struct sockaddr*)&src_addr, &src_len); - while (len > 0) { + for (size_t packet_count = 0; + packet_count < SOCKET_RX_BUDGET && len > 0; + ++packet_count) { _stat_data_rx++; _buffer.clear(); _buffer.append(recv_buffer, len); @@ -1038,7 +1047,9 @@ void AutoInterface::process_unicast_discovery() { ssize_t len = recvfrom(_unicast_discovery_socket, recv_buffer, sizeof(recv_buffer), 0, (struct sockaddr*)&src_addr, &src_len); - while (len > 0) { + for (size_t packet_count = 0; + packet_count < SOCKET_RX_BUDGET && len > 0; + ++packet_count) { // Convert source address to COMPRESSED string format (match Python) std::string src_str = ipv6_to_compressed_string((const uint8_t*)&src_addr.sin6_addr); @@ -1246,7 +1257,7 @@ void AutoInterface::process_discovery() { struct sockaddr_in6 src_addr; socklen_t addr_len = sizeof(src_addr); - while (true) { + for (size_t packet_count = 0; packet_count < SOCKET_RX_BUDGET; ++packet_count) { ssize_t len = recvfrom(_discovery_socket, recv_buffer, sizeof(recv_buffer), 0, (struct sockaddr*)&src_addr, &addr_len); if (len <= 0) break; @@ -1280,7 +1291,7 @@ void AutoInterface::process_data() { struct sockaddr_in6 src_addr; socklen_t addr_len = sizeof(src_addr); - while (true) { + for (size_t packet_count = 0; packet_count < SOCKET_RX_BUDGET; ++packet_count) { _buffer.clear(); ssize_t len = recvfrom(_data_socket, _buffer.writable(Type::Reticulum::MTU), Type::Reticulum::MTU, 0, @@ -1353,7 +1364,7 @@ void AutoInterface::process_unicast_discovery() { struct sockaddr_in6 src_addr; socklen_t addr_len = sizeof(src_addr); - while (true) { + for (size_t packet_count = 0; packet_count < SOCKET_RX_BUDGET; ++packet_count) { ssize_t len = recvfrom(_unicast_discovery_socket, recv_buffer, sizeof(recv_buffer), 0, (struct sockaddr*)&src_addr, &addr_len); if (len <= 0) break; diff --git a/lib/ble_interface/BLEInterface.cpp b/lib/ble_interface/BLEInterface.cpp index b545969c..c7589bd1 100644 --- a/lib/ble_interface/BLEInterface.cpp +++ b/lib/ble_interface/BLEInterface.cpp @@ -10,11 +10,22 @@ #ifdef ARDUINO #include #include +#include #endif using namespace RNS; using namespace RNS::BLE; +static void feed_ble_watchdog_if_owner(const void* owner) { +#ifdef ARDUINO + if (owner != nullptr && owner == static_cast(xTaskGetCurrentTaskHandle())) { + esp_task_wdt_reset(); + } +#else + (void)owner; +#endif +} + BLEInterface::BLEInterface(const char* name) : InterfaceImpl(name) { _IN = true; _OUT = true; @@ -135,6 +146,16 @@ void BLEInterface::stop() { } void BLEInterface::loop() { +#ifdef ARDUINO + // Once the dedicated BLE task exists, it is the sole owner of polling and + // blocking GATT work. Reticulum::loop() also invokes every registered + // interface from loopTask; ignore that duplicate call so BLE cannot run + // concurrently on both cores or block the watchdog-subscribed loopTask. + if (_task_handle != nullptr && xTaskGetCurrentTaskHandle() != _task_handle) { + return; + } +#endif + static double last_loop_log = 0; static bool local_mac_set = false; double now = Utilities::OS::time(); @@ -651,6 +672,7 @@ void BLEInterface::onConnected(const ConnectionHandle& conn) { " mtu=" + std::to_string(conn.mtu) + " (we are central)"); } // _mutex released BEFORE blocking GATT service discovery + feed_ble_watchdog_if_owner(_task_handle); // Discover services — this does blocking GATT reads (3-15s) and must NOT // hold _mutex, otherwise the NimBLE host task and main loop both block. _platform->discoverServices(conn.handle); @@ -707,6 +729,7 @@ void BLEInterface::onMTUChanged(const ConnectionHandle& conn, uint16_t mtu) { } void BLEInterface::onServicesDiscovered(const ConnectionHandle& conn, bool success) { + feed_ble_watchdog_if_owner(_task_handle); if (!success) { WARNING("BLEInterface: Service discovery failed for " + conn.peer_address.toString()); @@ -731,6 +754,7 @@ void BLEInterface::onServicesDiscovered(const ConnectionHandle& conn, bool succe // Enable notifications on TX characteristic _platform->enableNotifications(conn.handle, true); + feed_ble_watchdog_if_owner(_task_handle); // Protocol v2.2: Read peer's identity characteristic before sending ours // This matches the Kotlin implementation's 4-step handshake @@ -740,6 +764,7 @@ void BLEInterface::onServicesDiscovered(const ConnectionHandle& conn, bool succe _platform->read(conn.handle, conn.identity_handle, [this, mac, handle](OperationResult result, const Bytes& identity) { + feed_ble_watchdog_if_owner(_task_handle); if (result == OperationResult::SUCCESS && identity.size() == Limits::IDENTITY_SIZE) { DEBUG("BLEInterface: Read peer identity: " + identity.toHex().substr(0, 8) + "..."); @@ -1153,17 +1178,18 @@ void BLEInterface::ble_task(void* param) { BLEInterface* self = static_cast(param); Serial.printf("BLE task started on core %d\n", xPortGetCoreID()); - // NOTE: BLE task is intentionally NOT subscribed to the FreeRTOS Task WDT. - // Blocking NimBLE GATT operations (service discovery, subscribe, read, write) - // each have ~30s internal timeouts. A full connect chain (connect + discover + - // enable notifications + identity read) can legitimately block 30-60s total, - // which exceeds the 30s WDT. NimBLE's own timeouts provide recovery. + // GATT operations are individually bounded and the handshake feeds at each + // demonstrated forward-progress boundary. A stalled operation must now + // trigger the production 60s TWDT instead of leaving BLE wedged forever. + ESP_ERROR_CHECK(esp_task_wdt_add(nullptr)); while (true) { + esp_task_wdt_reset(); // Run the BLE loop (already has internal mutex protection) self->loop(); // Yield to other tasks + esp_task_wdt_reset(); vTaskDelay(pdMS_TO_TICKS(10)); } } diff --git a/src/TCPClientInterface.cpp b/src/TCPClientInterface.cpp index 792ff887..5e119687 100644 --- a/src/TCPClientInterface.cpp +++ b/src/TCPClientInterface.cpp @@ -23,6 +23,22 @@ using namespace RNS; +// Keep TCP work per main-loop pass bounded. A peer that continuously fills the +// receive socket must not prevent loopTask from returning to its watchdog feed. +static constexpr size_t MAX_TCP_BYTES_PER_LOOP = 4096; +static constexpr size_t MAX_TCP_FRAMES_PER_LOOP = 32; +static constexpr size_t MAX_TCP_FRAME_BUFFER = 16384; + +static bool contains_complete_hdlc_frame(const RNS::Bytes& buffer) { + bool saw_start = false; + for (size_t i = 0; i < buffer.size(); ++i) { + if (buffer.data()[i] != HDLC::FLAG) continue; + if (saw_start) return true; + saw_start = true; + } + return false; +} + TCPClientInterface::TCPClientInterface(const char* name /*= "TCPClientInterface"*/) : RNS::InterfaceImpl(name) { @@ -342,6 +358,19 @@ void TCPClientInterface::task_loop() { } /*virtual*/ void TCPClientInterface::loop() { + // Drain existing complete frames before accepting more bytes. If 32 frames + // remain after one pass, defer socket reads until later passes rather than + // dropping valid backlog. An over-limit buffer with no complete frame is an + // invalid/hostile partial HDLC frame and can be discarded safely. + extract_and_process_frames(); + if (_frame_buffer.size() >= MAX_TCP_FRAME_BUFFER) { + if (!contains_complete_hdlc_frame(_frame_buffer)) { + WARNING("TCPClientInterface: oversized incomplete HDLC frame; discarding"); + _frame_buffer.clear(); + } + return; + } + #ifdef ARDUINO // tcp_task owns _client while (re)connecting; the main loop only touches the // socket once CONNECTED. read/write/frame all happen here (same low-latency @@ -360,9 +389,14 @@ void TCPClientInterface::task_loop() { } if (_client.available() > 0) { _last_data_received = millis(); - while (_client.available() > 0) { - uint8_t byte = _client.read(); - _frame_buffer.append(byte); + size_t room = MAX_TCP_FRAME_BUFFER - _frame_buffer.size(); + size_t read_budget = std::min(MAX_TCP_BYTES_PER_LOOP, room); + size_t bytes_read = 0; + while (bytes_read < read_budget && _client.available() > 0) { + int byte = _client.read(); + if (byte < 0) break; + _frame_buffer.append(static_cast(byte)); + bytes_read++; } } extract_and_process_frames(); @@ -415,47 +449,12 @@ void TCPClientInterface::task_loop() { // Note: ESP32 WiFiClient.connected() has known bugs where it returns false incorrectly // See: https://github.com/espressif/arduino-esp32/issues/1714 // Workaround: only disconnect if connected() is false AND no data available -#ifdef ARDUINO - if (!_client.connected() && _client.available() == 0) { - Serial.printf("[TCP] Connection closed (connected=false, available=0)\n"); - handle_disconnect(); - return; - } - - // Stale connection detection disabled - was causing frequent reconnects - // TODO: investigate why this triggers even when receiving data - // if (_last_data_received > 0 && (now - _last_data_received) > STALE_CONNECTION_MS) { - // WARNING("TCPClientInterface: Connection appears stale, forcing reconnection"); - // handle_disconnect(); - // return; - // } - - // Read available data - int avail = _client.available(); - if (avail > 0) { - bool dbg = RNS::loglevel() >= RNS::LOG_DEBUG; - if (dbg) Serial.printf("[TCP] Reading %d bytes\n", avail); - total_rx += avail; - _last_data_received = now; // Update stale timer on any data receipt - size_t start_pos = _frame_buffer.size(); - while (_client.available() > 0) { - uint8_t byte = _client.read(); - _frame_buffer.append(byte); - } - if (dbg) { - Serial.printf("[TCP] First bytes: "); - size_t dump_len = (_frame_buffer.size() - start_pos); - if (dump_len > 20) dump_len = 20; - for (size_t i = 0; i < dump_len; ++i) { - Serial.printf("%02x ", _frame_buffer.data()[start_pos + i]); - } - Serial.printf("\n"); - } - } -#else +#ifndef ARDUINO // Non-blocking read uint8_t buf[4096]; - ssize_t len = recv(_socket, buf, sizeof(buf), MSG_DONTWAIT); + size_t room = MAX_TCP_FRAME_BUFFER - _frame_buffer.size(); + size_t read_budget = std::min(sizeof(buf), room); + ssize_t len = recv(_socket, buf, read_budget, MSG_DONTWAIT); if (len > 0) { DEBUG("TCPClientInterface: Received " + std::to_string(len) + " bytes"); _frame_buffer.append(buf, len); @@ -484,7 +483,7 @@ void TCPClientInterface::extract_and_process_frames() { // Find and process complete HDLC frames: [FLAG][data][FLAG] static uint32_t frame_count = 0; - while (true) { + for (size_t frame_budget = 0; frame_budget < MAX_TCP_FRAMES_PER_LOOP; ++frame_budget) { if (_frame_buffer.size() == 0) break; // Find first FLAG byte diff --git a/src/main.cpp b/src/main.cpp index 834a1948..4f0f7c1a 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -1057,10 +1057,18 @@ void enter_storage_recovery_mode() { } static void configure_loop_watchdog() { - esp_task_wdt_init(60, false); - esp_task_wdt_add(NULL); + // The 60-second panic policy is installed at the start of setup(), before + // any application worker can subscribe to Arduino's shorter default TWDT. + // Subscribe loopTask here after startup has completed. Recovery mode uses + // this same path before starting its LVGL worker. + esp_err_t loop_wdt_status = esp_task_wdt_status(nullptr); + if (loop_wdt_status == ESP_ERR_NOT_FOUND) { + ESP_ERROR_CHECK(esp_task_wdt_add(nullptr)); + } else { + ESP_ERROR_CHECK(loop_wdt_status); + } RNS::Utilities::OS::set_loop_callback([]() { esp_task_wdt_reset(); }); - INFO("Task Watchdog: loopTask subscribed (60s timeout, log-only)"); + INFO("Task Watchdog: loopTask subscribed (60s timeout, panic enabled)"); } void setup_reticulum() { @@ -1531,6 +1539,15 @@ void setup_ui_manager() { INFO("BLE interface started"); // Register with transport if not already registered Transport::register_interface(*ble_interface); + // Runtime enable must use the same single, watched BLE + // owner as boot-time initialization. If the worker + // already survived a prior disable, start_task is a no-op. + if (ble_interface_impl->start_task(1, 0)) { + INFO("BLE task running on core 0"); + } else { + ERROR("Failed to start BLE task; disabling BLE interface"); + ble_interface_impl->stop(); + } } else { ERROR("Failed to start BLE interface!"); } @@ -1634,6 +1651,12 @@ void setup() { Serial.begin(115200); delay(100); + // Apply the production TWDT policy before any application worker task is + // created. Arduino-ESP32 starts with a baked 5s policy; BLE/LVGL workers + // subscribe later and require the audited 60s window for bounded flash and + // GATT operations. Task subscriptions are added at their creation sites. + ESP_ERROR_CHECK(esp_task_wdt_init(60, true)); + // Create diagnostic recorder synchronization before any audio task starts. g_rec_mutex = xSemaphoreCreateMutex(); if (!g_rec_mutex) { @@ -1895,31 +1918,21 @@ void setup() { INFO("╚══════════════════════════════════════╝"); INFO(""); - // Reconfigure Task Watchdog with 30s timeout (default 10s is too tight - // for SPIFFS flash I/O — identity persistence writes 40-50 entries and - // can take 5-15s with sector erases and garbage collection) - // Task Watchdog config: - // - 60s timeout (was 30s; bumped to tolerate WiFi-stack busy windows - // on CPU0 — `pm_tx_data_done_process` in ESP-IDF's `ppTask` can - // starve CPU0 idle for >30s under heavy multicast/mDNS traffic) - // - panic=false: log warnings, don't reset. The reset behavior was - // blocking pyxis from running long enough to debug anything else - // on the graft. Will revisit panic=true once the WDT culprit is - // tracked down — see pyxis_microReticulum_graft_spike_findings.md + // The Task Watchdog uses a 60s timeout. Identity/path + // persistence can spend 5-15s in flash erase/GC, and ESP-IDF's CPU0 WiFi + // task has previously kept the subscribed CPU0 idle task from running for + // more than 30s under heavy multicast traffic. The production watchdog must + // still panic and reboot on a genuine deadlock instead of logging forever. // - // We tried `esp_task_wdt_delete(xTaskGetIdleTaskHandleForCPU(0))` to - // unsubscribe just CPU0 idle, but Arduino-ESP32's prebuilt framework - // re-adds it on the next loop iteration (CONFIG_ESP_TASK_WDT_CHECK_IDLE_TASK_CPU0=y - // is baked in and sdkconfig.defaults can't override without a framework - // rebuild from source). + // The runtime policy was installed before worker creation. Subscribe + // loopTask only when it is not already present, and fail loudly if the + // production watchdog cannot be configured. configure_loop_watchdog(); - // Feed WDT during long persistence + clean_cache operations (71+ entries - // to SPIFFS can take >30s). Upstream microReticulum @ 0.3.0 moved the - // per-Identity yield hook to a global RNS::Utilities::OS::_on_loop - // callback (set via set_loop_callback), invoked during long operations - // like clean_caches, identity persistence, and the path-table flush. - // Was: Identity::set_persist_yield_callback (fork-only). + // Feed the WDT at microReticulum's explicit OS::run_loop() progress points + // (currently cache cleanup/clear paths). Current path persistence does not + // invoke this callback, so the main loop measures that whole operation below + // instead of using a timer-based feed that could conceal a storage hang. // Show startup message INFO("Press any key to start messaging"); } @@ -2742,7 +2755,8 @@ void loop() { // NOTE: Persistence writes 40-50 entries via microStore (which routes // through the new microStore::FileSystem to SPIFFS or whichever backend // is configured). Sector erases (100ms each) can stretch the call to - // 5-15s; the OS::set_loop_callback above feeds the WDT between entries. + // 5-15s. Current upstream persistence does not expose a per-entry progress + // callback; measure the complete operation and let TWDT recover a true hang. // // Upstream microReticulum @ 0.3.0 unified persistence into a single // Reticulum::should_persist_data() entry point — the fork had a @@ -2753,29 +2767,21 @@ void loop() { // crashes, revisit microStore's flush cadence rather than re-adding // the fork-only Identity API.) LOOP_STEP(5); // persist data + uint32_t persistence_started_ms = millis(); reticulum->should_persist_data(); + uint32_t persistence_elapsed_ms = millis() - persistence_started_ms; + if (persistence_elapsed_ms > 30000) { + WARNINGF("Reticulum persistence took %lu ms (TWDT limit is 60000 ms)", + (unsigned long)persistence_elapsed_ms); + } esp_task_wdt_reset(); - // Process TCP interface - LOOP_STEP(6); // TCP loop - if (tcp_interface) { - tcp_interface->loop(); - } - - // Process LoRa interface - LOOP_STEP(7); // LoRa loop - if (lora_interface) { - lora_interface->loop(); - } - - // Process BLE interface (skip if running on its own task) - LOOP_STEP(8); // BLE loop - if (ble_interface && ble_interface_impl && !ble_interface_impl->is_task_running()) { - ble_interface->loop(); - } + // Reticulum::loop() above polls every registered interface exactly once. + // Do not poll TCP/LoRa/BLE again here; BLE additionally enforces dedicated + // task ownership when its worker is running. // Process LXMF router queues - LOOP_STEP(9); // Router processing + LOOP_STEP(6); // Router processing if (router) { router->process_outbound(); router->process_inbound(); @@ -2783,17 +2789,17 @@ void loop() { } // Update UI manager (processes LXMF messages) - LOOP_STEP(10); // UI manager update + LOOP_STEP(7); // UI manager update if (ui_manager) { ui_manager->update(); } - LOOP_STEP(11); // Memory monitor + LOOP_STEP(8); // Memory monitor // Process deferred memory monitor logging (flag set by timer callback) MEMORY_MONITOR_POLL(); // Periodic announce (using interval from settings) - LOOP_STEP(12); // Periodic tasks + LOOP_STEP(9); // Periodic tasks if (app_settings.announce_interval > 0) { // 0 = disabled uint32_t announce_interval_ms = app_settings.announce_interval * 1000; if (millis() - last_announce > announce_interval_ms) { @@ -2976,7 +2982,7 @@ void loop() { } // Screen timeout handling - LOOP_STEP(13); // Screen timeout + LOOP_STEP(10); // Screen timeout if (app_settings.screen_timeout > 0) { // 0 = never timeout uint32_t inactive_ms; { diff --git a/tests/build_scripts/test_watchdog_contract.py b/tests/build_scripts/test_watchdog_contract.py new file mode 100644 index 00000000..ea8bae31 --- /dev/null +++ b/tests/build_scripts/test_watchdog_contract.py @@ -0,0 +1,140 @@ +"""Source-level regression checks for production watchdog liveness.""" + +from pathlib import Path + + +REPO_ROOT = Path(__file__).resolve().parents[2] +MAIN = REPO_ROOT / "src/main.cpp" +AUTO_INTERFACE = REPO_ROOT / "lib/auto_interface/AutoInterface.cpp" +TCP_INTERFACE = REPO_ROOT / "src/TCPClientInterface.cpp" +LVGL_INIT = REPO_ROOT / "lib/tdeck_ui/UI/LVGL/LVGLInit.cpp" +BLE_INTERFACE = REPO_ROOT / "lib/ble_interface/BLEInterface.cpp" +CAPTURE = REPO_ROOT / "lib/lxst_audio/i2s_capture.cpp" +PLAYBACK = REPO_ROOT / "lib/lxst_audio/i2s_playback.cpp" + + +def function_body(source: str, signature: str, next_signature: str) -> str: + start = source.index(signature) + end = source.index(next_signature, start) + return source[start:end] + + +def test_production_watchdog_panics_and_loop_task_is_subscribed(): + source = MAIN.read_text() + setup = function_body(source, "void setup()", "// Serial command buffer") + configure = function_body( + source, + "static void configure_loop_watchdog()", + "void setup_reticulum()", + ) + + assert "ESP_ERROR_CHECK(esp_task_wdt_init(60, true));" in setup + assert "esp_task_wdt_init(60, false)" not in setup + assert setup.index("ESP_ERROR_CHECK(esp_task_wdt_init(60, true));") < setup.index( + "setup_hardware();" + ) + assert "esp_task_wdt_status(nullptr)" in configure + assert "ESP_ERROR_CHECK(esp_task_wdt_add(nullptr));" in configure + assert "panic enabled" in configure + + +def test_main_and_lvgl_tasks_feed_and_yield(): + main = MAIN.read_text() + loop = main[main.index("void loop()") :] + lvgl = LVGL_INIT.read_text() + lvgl_task = function_body(lvgl, "void LVGLInit::lvgl_task(", "bool LVGLInit::start_task(") + + assert loop.index("esp_task_wdt_reset();") < loop.index("ArduinoOTA.handle();") + assert "RNS::Utilities::OS::set_loop_callback([]() { esp_task_wdt_reset(); });" in main + assert "persistence_elapsed_ms > 30000" in loop + assert "Reticulum persistence took %lu ms" in loop + assert "delay(5);" in loop + assert "esp_task_wdt_add(nullptr);" in lvgl_task + assert "esp_task_wdt_reset();" in lvgl_task + assert "vTaskDelay(pdMS_TO_TICKS(5));" in lvgl_task + + +def test_auto_interface_socket_drains_are_bounded(): + source = AUTO_INTERFACE.read_text() + assert "static constexpr size_t SOCKET_RX_BUDGET = 16;" in source + + for signature, next_signature in ( + ("void AutoInterface::process_discovery()", "void AutoInterface::process_data()"), + ("void AutoInterface::process_data()", "bool AutoInterface::setup_unicast_discovery_socket()"), + ( + "void AutoInterface::process_unicast_discovery()", + "void AutoInterface::reverse_announce(", + ), + ): + body = function_body(source, signature, next_signature) + assert "packet_count < SOCKET_RX_BUDGET" in body + assert "while (true)" not in body + + +def test_tcp_socket_and_frame_processing_are_bounded(): + source = TCP_INTERFACE.read_text() + loop_start = source.index("/*virtual*/ void TCPClientInterface::loop()") + loop_end = source.index("\n#endif", loop_start) + len("\n#endif") + arduino_loop = source[loop_start:loop_end] + frames = function_body( + source, + "void TCPClientInterface::extract_and_process_frames()", + "/*virtual*/ bool TCPClientInterface::send_outgoing(", + ) + + assert "static constexpr size_t MAX_TCP_BYTES_PER_LOOP = 4096;" in source + assert "static constexpr size_t MAX_TCP_FRAMES_PER_LOOP = 32;" in source + assert "static constexpr size_t MAX_TCP_FRAME_BUFFER = 16384;" in source + assert "extract_and_process_frames();" in arduino_loop + assert "_frame_buffer.size() >= MAX_TCP_FRAME_BUFFER" in arduino_loop + assert "std::min(MAX_TCP_BYTES_PER_LOOP, room)" in arduino_loop + assert "bytes_read < read_budget" in arduino_loop + assert arduino_loop.index("extract_and_process_frames();") < arduino_loop.index( + "_client.available()" + ) + assert "frame_budget < MAX_TCP_FRAMES_PER_LOOP" in frames + assert "while (true)" not in frames + + +def test_worker_tasks_are_watched_or_yield_with_bounded_timeouts(): + ble = BLE_INTERFACE.read_text() + capture = CAPTURE.read_text() + playback = PLAYBACK.read_text() + tcp = TCP_INTERFACE.read_text() + + ble_task = function_body(ble, "void BLEInterface::ble_task(", "bool BLEInterface::start_task(") + tcp_task = function_body(tcp, "void TCPClientInterface::task_loop()", "#endif") + + assert "ESP_ERROR_CHECK(esp_task_wdt_add(nullptr));" in ble_task + assert ble_task.count("esp_task_wdt_reset();") >= 2 + assert "feed_ble_watchdog_if_owner(_task_handle);" in ble + assert "vTaskDelay(pdMS_TO_TICKS(10));" in ble_task + assert "vTaskDelay(pdMS_TO_TICKS(100));" in tcp_task + assert "i2s_read(" in capture and "pdMS_TO_TICKS(100)" in capture + assert "i2s_write(" in playback and "pdMS_TO_TICKS(100)" in playback + assert "vTaskDelay(pdMS_TO_TICKS(5));" in playback + + +def test_registered_interfaces_have_one_polling_owner(): + main = MAIN.read_text() + loop = main[main.index("void loop()") :] + ble = BLE_INTERFACE.read_text() + ble_loop = function_body( + ble, + "void BLEInterface::loop()", + "//=============================================================================\n// Data Transfer", + ) + + # Reticulum polls registered TCP/LoRa interfaces. The main loop must not + # invoke them a second time after reticulum->loop(). + assert "reticulum->loop();" in loop + assert "tcp_interface->loop();" not in loop + assert "lora_interface->loop();" not in loop + assert "ble_interface->loop();" not in loop + + # Once started, only the dedicated BLE worker may enter blocking GATT work; + # Reticulum's loopTask-side interface poll must return immediately. + assert "xTaskGetCurrentTaskHandle() != _task_handle" in ble_loop + assert main.count("ble_interface_impl->start_task(1, 0)") >= 2 + assert "feed_ble_watchdog_if_owner(const void* owner)" in ble + assert "return;" in ble_loop diff --git a/tests/build_scripts/test_watchdog_harness.py b/tests/build_scripts/test_watchdog_harness.py new file mode 100644 index 00000000..69f160bc --- /dev/null +++ b/tests/build_scripts/test_watchdog_harness.py @@ -0,0 +1,42 @@ +"""Regression checks for watchdog/reset detection in the hardware soak harness.""" + +import importlib.util +import queue +import threading +from pathlib import Path + + +REPO_ROOT = Path(__file__).resolve().parents[2] +HARNESS_PATH = REPO_ROOT / "tests/hardware/tdeck_harness.py" +SPEC = importlib.util.spec_from_file_location("tdeck_harness", HARNESS_PATH) +assert SPEC is not None +HARNESS = importlib.util.module_from_spec(SPEC) +assert SPEC.loader is not None +SPEC.loader.exec_module(HARNESS) + + +def test_fault_classifier_detects_watchdog_panic_and_reboot_evidence(): + assert HARNESS.is_fault_line("Guru Meditation Error: Core 0 panic'ed") + assert HARNESS.is_fault_line("Reset reason: TASK_WDT (6)") + assert HARNESS.is_fault_line("rst:0xc (SW_CPU_RESET)") + assert not HARNESS.is_fault_line("Task Watchdog: loopTask subscribed") + assert not HARNESS.is_fault_line("normal message traffic") + + +def test_fault_queue_is_armed_atomically_after_intentional_boot(): + tdeck = HARNESS.TDeck.__new__(HARNESS.TDeck) + tdeck._fault_q = queue.Queue() + tdeck._fault_lock = threading.Lock() + tdeck._fault_monitor_armed = threading.Event() + + # Evidence from the intentional harness reset is ignored while unarmed. + tdeck._record_fault_if_armed("Reset reason: SOFTWARE") + assert tdeck.drain_faults() == [] + + # arm_fault_monitor holds the same lock used by the reader-side recorder, so + # no reset line can land in the gap between clearing boot evidence and arming. + tdeck.arm_fault_monitor() + assert tdeck._fault_monitor_armed.is_set() + tdeck._record_fault_if_armed("Reset reason: TASK_WDT") + assert tdeck.drain_faults() == ["Reset reason: TASK_WDT"] + assert tdeck.drain_faults() == [] diff --git a/tests/hardware/tdeck_harness.py b/tests/hardware/tdeck_harness.py index ab4e9ed7..829a9413 100644 --- a/tests/hardware/tdeck_harness.py +++ b/tests/hardware/tdeck_harness.py @@ -33,14 +33,13 @@ What it does: - Send long (~1KB) message and repeat. - Sleep `--cadence` seconds between rounds. -6. Soak: run for at least `--soak-hours` hours (default 1.1). Crash = - fail. Mid-test failures are logged but don't abort. +6. Soak: pass `--soak-hours 1.0` for the watchdog acceptance run. The + default is one pass. Any crash or reset after initialization is a failure. Usage: # Run with a python that has pyserial available. PlatformIO's # bundled python works: - "$(pio system info | awk -F: '/Python Executable/{print $2}' | xargs)" \\ - tests/soak/tdeck_soak_harness.py [--soak-hours 1.1] [--cadence 30] + python3 tests/hardware/tdeck_harness.py --soak-hours 1.0 --cadence 30 Outputs: /tmp/tdeck-harness.log — combined timestamped event log @@ -76,6 +75,18 @@ ECHOBOT_PY = os.path.join(os.path.dirname(os.path.abspath(__file__)), # importable via the bot's repo-path insert). Override with PYXIS_BOT_PY if the # bot needs a different interpreter than the harness. BOT_PY = os.environ.get("PYXIS_BOT_PY") or sys.executable +FAULT_MARKERS = ( + "Guru Meditation", + "PANIC", + "abort", + "assertion", + "rst:0x", + "Reset reason:", +) + + +def is_fault_line(text): + return any(marker in text for marker in FAULT_MARKERS) def ts(): @@ -102,8 +113,11 @@ class TDeck: def __init__(self, port=PORT, baud=BAUD): self.ser = serial.Serial(port, baud, timeout=0.1) self._line_q = queue.Queue() # raw text lines + self._fault_q = queue.Queue() # crash/reset evidence, never consumed by commands + self._fault_lock = threading.Lock() # atomic boot-to-soak monitor handoff self._tdeck_log = open(TDECK_LOG, "wb") self._stop = threading.Event() + self._fault_monitor_armed = threading.Event() self._reader = threading.Thread(target=self._read_loop, daemon=True) self._reader.start() @@ -126,6 +140,7 @@ class TDeck: d = self.ser.read(4096) except Exception as e: log("HARNESS", f"Serial read error: {e}") + self._record_fault_if_armed(f"Serial read error: {e}") return if not d: continue @@ -139,6 +154,34 @@ class TDeck: except Exception: text = repr(line) self._line_q.put(text) + if is_fault_line(text): + self._record_fault_if_armed(text) + + def _record_fault_if_armed(self, text): + """Record fault evidence atomically with the monitor-arm transition.""" + with self._fault_lock: + if self._fault_monitor_armed.is_set(): + self._fault_q.put(text) + + def arm_fault_monitor(self): + """Start treating every subsequent reset/crash line as a soak failure.""" + with self._fault_lock: + while True: + try: + self._fault_q.get_nowait() + except queue.Empty: + break + self._fault_monitor_armed.set() + + def drain_faults(self): + """Return crash/reset evidence without competing with command responses.""" + out = [] + while True: + try: + out.append(self._fault_q.get_nowait()) + except queue.Empty: + break + return out def drain_lines(self): """Pop all currently-buffered lines (non-blocking).""" @@ -492,6 +535,9 @@ def main(): # 5. Round-trip tests. DIRECT + OPPORTUNISTIC always run; PROPAGATED runs # only when PYXIS_PROPAGATION_NODE_HEX is set (deployment-specific hash # kept out of source). Runs one pass minimum, then loops for --soak-hours. + # Initial harness reset/boot evidence is intentionally ignored; every + # crash or reset after this point is a stability failure. + t.arm_fault_monitor() deadline = time.time() + args.soak_hours * 3600 round_n = 0 payloads = [ @@ -632,16 +678,13 @@ def main(): log("HARNESS", f"=== Round {round_n} / {label}: PASS " f"(total: {successes} pass, {fails} fail) ===") - # Stability check: peek for any panic/abort/assert in the T-Deck log - # (drain new lines but don't block on them). - for line in t.drain_lines(): - if any(k in line for k in ( - "Guru Meditation", "PANIC", "abort", "assertion", "rst:0x" - )): - log("HARNESS", f"CRASH detected: {line}") - fails += 1 - deadline = 0 - break + # Fault lines are mirrored by the serial reader before command polling + # can consume them, so a reset cannot hide inside send_command(). + for line in t.drain_faults(): + log("HARNESS", f"CRASH/reset detected: {line}") + fails += 1 + deadline = 0 + break time.sleep(args.cadence)