Keep USB watchdog snapshots coherent and fail-safe

docs/usb_logging_watchdog.md

@@ -161,6 +161,14 @@ Python and browser decoders retain released MGR1 support; older decoder copies
 must be updated to read MGR2. Events appear on the normal management schedule, not
 as immediate alerts. Reading status does not renew the logging-client lease.
 
+Concurrent readers receive one coherent status publication, including its tier,
+counters, and latest event. Reads never wait for a writer. If three bounded
+attempts cannot obtain a snapshot, status conservatively reports deferred
+recovery and no verified persistence, ages, counters, or event. It preserves
+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.
+
 ## Verification
 
 The two qualification stages below precede the subsequent upstream USB/GPS

src/helpers/UsbLoggingWatchdog.cpp

@@ -108,22 +108,24 @@ void publish(const UsbLoggingObservation& observation) {
       | (policy.deferred() || backend_deferred ? 128U : 0U)
       | (persistence_ready ? 256U : 0U) | (config.mode == 2 ? 512U : 0U)
       | (reader_seen ? 1024U : 0U) | (logger_active ? 2048U : 0U);
+  // Bracket the entire status, not just its event. A counter/tier read from
+  // one publication must never be paired with another event's journal.
+  status_event_guard.fetch_add(1);
   status_stage_step.store(uint32_t(policy.stage()) | (uint32_t(config.step) << 8));
   status_retry.store(Policy::intervalMs(config.step) / 1000);
   status_inactive.store(policy.inactiveSeconds());
   status_recoveries.store(config.recoveries);
   status_reboots.store(config.reboots);
   status_auto_seconds.store(auto_arm.connectedSeconds());
-  // A bounded sequence guard prevents mixing fields from different events.
-  // All words are atomic, and seq_cst keeps the guard around their publication.
-  status_event_guard.fetch_add(1);
+  // Every shared word remains atomic: the sequence guard alone would not make
+  // concurrent non-atomic reads/writes legal in the C++ memory model.
   status_event_code.store(config.last_event.reasons | (uint32_t(config.last_event.action) << 4)
       | (config.last_event.persisted ? 128U : 0U));
   status_event_epoch.store(config.last_event.epoch);
   status_event_uptime.store(config.last_event.uptime_seconds);
   status_event_sequence.store(config.last_event.sequence);
-  status_event_guard.fetch_add(1);
   status_flags.store(flags, std::memory_order_release);
+  status_event_guard.fetch_add(1);
 }
 
 ReadResult readImage(const char* path, uint8_t* image, size_t* read_size = nullptr) {
@@ -206,31 +208,31 @@ bool keyMatches(const char* command, const char* key) {
 }  // namespace
 
 UsbLoggingStatus usbLoggingStatus() {
-  UsbLoggingStatus status;
-  const uint32_t flags = status_flags.load(std::memory_order_acquire);
-  const uint32_t stage_step = status_stage_step.load();
-  status.supported = flags & 1U;
-  status.logging_enabled = flags & 2U;
-  status.watchdog_enabled = flags & 4U;
-  status.host_connected = flags & 8U;
-  status.reader_connected = flags & 16U;
-  status.stalled = flags & 32U;
-  status.recovering = flags & 64U;
-  status.recovery_deferred = flags & 128U;
-  status.persistence_ready = flags & 256U;
-  status.watchdog_auto = flags & 512U;
-  status.logger_active = flags & 2048U;
-  status.stage = stage_step & 0xff;
-  status.backoff_step = (stage_step >> 8) & 0xff;
-  status.retry_seconds = status_retry.load();
-  status.inactive_seconds = status_inactive.load();
-  status.recovery_count = status_recoveries.load();
-  status.reboot_count = status_reboots.load();
-  status.auto_connected_seconds = status_auto_seconds.load();
   for (uint8_t attempt = 0; attempt < 3; ++attempt) {
     const uint32_t before = status_event_guard.load();
     if (before & 1U) continue;
-    Event event;
+    UsbLoggingStatus status;
+    const uint32_t flags = status_flags.load(std::memory_order_acquire);
+    const uint32_t stage_step = status_stage_step.load();
+    status.supported = flags & 1U;
+    status.logging_enabled = flags & 2U;
+    status.watchdog_enabled = flags & 4U;
+    status.host_connected = flags & 8U;
+    status.reader_connected = flags & 16U;
+    status.stalled = flags & 32U;
+    status.recovering = flags & 64U;
+    status.recovery_deferred = flags & 128U;
+    status.persistence_ready = flags & 256U;
+    status.watchdog_auto = flags & 512U;
+    status.logger_active = flags & 2048U;
+    status.stage = stage_step & 0xff;
+    status.backoff_step = (stage_step >> 8) & 0xff;
+    status.retry_seconds = status_retry.load();
+    status.inactive_seconds = status_inactive.load();
+    status.recovery_count = status_recoveries.load();
+    status.reboot_count = status_reboots.load();
+    status.auto_connected_seconds = status_auto_seconds.load();
+    auto& event = status.last_event;
     const uint32_t code = status_event_code.load();
     event.reasons = code & 15U;
     event.action = (code >> 4) & 7U;
@@ -238,21 +240,38 @@ UsbLoggingStatus usbLoggingStatus() {
     event.epoch = status_event_epoch.load();
     event.uptime_seconds = status_event_uptime.load();
     event.sequence = status_event_sequence.load();
-    if (before == status_event_guard.load()) {
-      status.last_event = event;
-      break;
-    }
+    if (before == status_event_guard.load()) return status;
   }
+  // A writer may be preempted, so retries must stay bounded. This is an
+  // unavailable/conservative snapshot, not fresh physical measurements.
+  // Keep published hardware/logging/mode intent; never pretend unsupported.
+  // A possibly live reader must still protect functional CLI work. No durable
+  // authorization or event is claimed until a coherent snapshot is available.
+  UsbLoggingStatus status;
+  const uint32_t flags = status_flags.load(std::memory_order_acquire);
+  status.supported = flags & 1U;
+  status.logging_enabled = flags & 2U;
+  status.watchdog_enabled = flags & 4U;
+  status.watchdog_auto = flags & 512U;
+  status.reader_connected = true;
+  status.recovery_deferred = true;
+  status.backoff_step = Policy::MAX_STEP;
+  status.retry_seconds = Policy::MAX_MS / 1000;
   return status;
 }
 
 bool isUsbLoggingWatchdogArmed() {
   if (isUsbLoggingTransportRecoveryPending()) return true;
-  const auto status = usbLoggingStatus();
-  const bool seen = status_flags.load(std::memory_order_acquire) & 1024U;
-  return status.supported && status.logging_enabled
-      && (status.watchdog_enabled || (status.watchdog_auto && seen && status.stage < 2))
-      && status.persistence_ready;
+  // 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.
+  const uint32_t before = status_event_guard.load();
+  const uint32_t flags = status_flags.load(std::memory_order_acquire);
+  const uint32_t stage = status_stage_step.load() & 0xffU;
+  const bool busy = (before & 1U) || before != status_event_guard.load();
+  const bool ready = (flags & (1U | 2U | 256U)) == (1U | 2U | 256U);
+  return ready && ((flags & 4U)
+      || ((flags & 512U) && (flags & 1024U) && (busy || stage < 2)));
 }
 
 void loadUsbLoggingWatchdog(FILESYSTEM* fs, bool durable, uint32_t (*epoch_seconds)()) {

test/fixtures/usb_logging_watchdog/test_usb_logging_watchdog_runtime.cpp

@@ -1011,10 +1011,20 @@ static void check_event_snapshot_is_coherent_with_concurrent_readers() {
   std::atomic<unsigned> snapshots{0};
   std::thread reader([&] {
     while (running.load()) {
-      const auto event = mesh::usbLoggingStatus().last_event;
+      const auto status = mesh::usbLoggingStatus();
+      const auto event = status.last_event;
       if (event.sequence) {
+        assert(status.persistence_ready && status.watchdog_enabled);
+        assert(status.recovery_count == event.sequence);
+        assert(status.backoff_step == 0 && status.retry_seconds == 3600);
         assert(event.epoch == 2000000000U + event.sequence);
         assert(event.action == Event::SOFT_RECOVERY && event.reasons == 3 && event.persisted);
+      } else if (!status.persistence_ready) {
+        // A bounded busy-reader fallback has no mixed partial journal/tier.
+        assert(status.supported && status.logging_enabled && status.watchdog_enabled);
+        assert(status.reader_connected && !status.stalled && status.recovery_deferred);
+        assert(status.backoff_step == 8 && status.retry_seconds == 604800);
+        assert(!status.recovery_count && !status.reboot_count && !status.auto_connected_seconds);
       }
       ++snapshots;
     }

test/test_usb_logging_watchdog_runtime.py

@@ -6,12 +6,127 @@ import subprocess
 import tempfile
 import unittest
 
+from test_radio_receive_contract import method
+
 
 ROOT = Path(__file__).resolve().parents[1]
 FIXTURE = ROOT / 'test' / 'fixtures' / 'usb_logging_watchdog'
 
 
 class UsbLoggingWatchdogRuntimeTest(unittest.TestCase):
+    def test_busy_snapshot_protects_commands_and_keeps_durable_policy_awake(self):
+        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')
+        callback = method((ROOT / 'examples/simple_sensor/main.cpp').read_text(),
+                          'static bool usbLoggingRecoverySafe(void*)')
+        harness = r'''
+#include <Arduino.h>
+#include <FS.h>
+#include <helpers/UsbLogging.h>
+#include <helpers/UsbLoggingWatchdog.cpp>
+#include <cassert>
+#include <cstring>
+
+static mesh::UsbLoggingObservation observation{true, false, false, false, 0};
+static bool pending_attach = false;
+static bool logger_active = false;
+namespace mesh {
+bool isUsbLoggingEnabled() { return true; }
+bool isUsbLoggingClientActive() { return logger_active; }
+void clearUsbLoggingClientActivity() {}
+bool isUsbLoggingTransportRecoveryPending() { return pending_attach; }
+UsbLoggingObservation observeUsbLoggingTransport() { return observation; }
+UsbLoggingRecoveryResult recoverUsbLoggingTransport(uint8_t) {
+  return UsbLoggingRecoveryResult::Attempted;
+}
+void probeUsbLoggingTransport() {}
+}
+struct Board {
+  bool isOTAUpdateRunning() const { return false; }
+  bool isRadioTestActive() const { return false; }
+} board;
+struct Radio {
+  bool isWatchdogObserving() const { return false; }
+  bool isCalibratingNoiseFloor() const { return false; }
+} radio_driver;
+struct Mesh { bool canRecoverUsbLogging() const { return true; } } the_mesh;
+static char command[32] = {};
+@CALLBACK@
+
+int main() {
+  fs::FS fs;
+  fs::stat_filesystem = &fs;
+  mesh::loadUsbLoggingWatchdog(&fs);
+  char reply[160];
+  assert(mesh::handleUsbLoggingWatchdogCommand("set usb.watchdog on", reply, sizeof(reply)));
+  assert(!std::strcmp(reply, "OK - USB watchdog on (saved)"));
+  for (uint32_t now : {0U, 300000U, 360000U}) {
+    mock_watchdog_millis = now;
+    assert(!mesh::serviceUsbLoggingWatchdog(usbLoggingRecoverySafe));
+  }
+  assert(mesh::usbLoggingStatus().stage == 2);
+  const auto writes = fs.write_opens;
+  // Simulate a publisher preempted while the real status getter is called.
+  // No test hook or substituted getter is used; all atomic words are real.
+  mesh::status_event_guard.fetch_add(1);
+  const auto busy = mesh::usbLoggingStatus();
+  assert(busy.supported && busy.logging_enabled && busy.watchdog_enabled && !busy.watchdog_auto);
+  assert(busy.reader_connected && !busy.stalled && busy.recovery_deferred && !busy.persistence_ready);
+  assert(busy.backoff_step == 8 && busy.retry_seconds == 604800);
+  assert(!busy.recovery_count && !busy.reboot_count && !busy.inactive_seconds);
+  assert(!busy.auto_connected_seconds && !busy.last_event.sequence);
+  assert(mesh::isUsbLoggingWatchdogArmed()); // Awake hint is not reset authority.
+  std::strcpy(command, "stats-core");
+  assert(!usbLoggingRecoverySafe(nullptr)); // Execute the actual sensor veto.
+  mock_watchdog_millis = 3600000;
+  assert(!mesh::serviceUsbLoggingWatchdog(usbLoggingRecoverySafe));
+  assert(fs.write_opens == writes); // No new tier/journal/reset authorization.
+  mesh::status_event_guard.fetch_add(1);
+  assert(mesh::usbLoggingStatus().persistence_ready);
+  assert(mesh::handleUsbLoggingWatchdogCommand("set usb.watchdog off", reply, sizeof(reply)));
+  mesh::status_event_guard.fetch_add(1);
+  assert(!mesh::isUsbLoggingWatchdogArmed());
+  pending_attach = true;
+  assert(mesh::isUsbLoggingWatchdogArmed()); // Finish USB reattach even in Off.
+  mesh::status_event_guard.fetch_add(1);
+  pending_attach = false;
+  command[0] = 0;
+  assert(mesh::handleUsbLoggingWatchdogCommand("set usb.watchdog auto", reply, sizeof(reply)));
+  observation = {true, true, true, false, 1};
+  logger_active = true;
+  assert(!mesh::serviceUsbLoggingWatchdog(usbLoggingRecoverySafe));
+  assert(mesh::isUsbLoggingWatchdogArmed()); // Auto has observed a logging client.
+  observation = {true, false, false, false, 1};
+  logger_active = false;
+  for (uint32_t now : {3600001U, 3900001U, 3960001U}) {
+    mock_watchdog_millis = now;
+    assert(!mesh::serviceUsbLoggingWatchdog(usbLoggingRecoverySafe));
+  }
+  assert(mesh::usbLoggingStatus().stage == 2);
+  assert(!mesh::isUsbLoggingWatchdogArmed()); // Auto completed USB-only attempts.
+  mesh::status_event_guard.fetch_add(1);
+  assert(mesh::usbLoggingStatus().watchdog_auto);
+  assert(mesh::isUsbLoggingWatchdogArmed()); // Busy Auto publication stays awake.
+  mesh::status_event_guard.fetch_add(1);
+}
+'''.replace('@CALLBACK@', callback)
+        sanitizer_flags = [] if os.name == 'nt' else [
+            '-fsanitize=address,undefined', '-fno-sanitize-recover=all', '-fno-pie', '-no-pie']
+        with tempfile.TemporaryDirectory(prefix='usb-watchdog-snapshot-') as directory:
+            source = Path(directory) / 'snapshot.cpp'
+            source.write_text(harness, encoding='ascii')
+            binary = Path(directory) / 'snapshot.exe'
+            built = subprocess.run([
+                compiler, '-std=c++17', '-Wall', '-Wextra', '-Werror', '-pthread',
+                *sanitizer_flags, '-DARDUINO', '-DESP32', '-DESP32_PLATFORM',
+                '-DARDUINO_USB_MODE=0', '-DARDUINO_USB_CDC_ON_BOOT=1',
+                '-I' + str(FIXTURE / 'mocks'), '-I' + str(ROOT / 'src'),
+                str(source), '-o', str(binary)], capture_output=True, text=True, timeout=60)
+            self.assertEqual(built.returncode, 0, built.stderr)
+            tested = subprocess.run([str(binary)], capture_output=True, text=True, timeout=10)
+            self.assertEqual(tested.returncode, 0, tested.stderr)
+
     def test_production_runtime_and_persistence(self):
         compiler = os.environ.get('CXX') or shutil.which('g++') or shutil.which('clang++')
         if compiler is None: