Release blocker: eliminate ESP32-P4 START timing misses

.github/workflows/esp32p4-smv-injector.yml

@@ -55,6 +55,28 @@ jobs:
           grep -qx 'CONFIG_ESP32P4_SELECTS_REV_LESS_V3=y' sdkconfig
           echo 'ESP32-P4 pre-v3 build policy: PASS'
 
+      - name: Verify realtime START and telemetry boundary policy
+        run: |
+          set -euo pipefail
+          python3 - <<'PY'
+          from pathlib import Path
+
+          source = Path('main/app_main.cpp').read_text(encoding='utf-8')
+          start_begin = source.index('if (take_start_request())')
+          start_end = source.index('if (!live_tx_running())', start_begin)
+          start_block = source[start_begin:start_end]
+          clock_start = start_block.rindex(
+              'sample_clock = start_sample_clock(task_handle, active_profile.publisher_rate_hz);'
+          )
+          assert start_block.rindex('ESP_LOGI') < clock_start
+          assert 'ESP_LOG' not in start_block[clock_start:]
+          assert 'static_assert(std::atomic<std::uint32_t>::is_always_lock_free);' in source
+          assert 'g_sample_tick_total.fetch_add(1U, std::memory_order_relaxed);' in source
+          assert 'elapsed_ticks) * 1000000ULL' in source
+          assert 'rate_baseline_valid = true;' in source
+          print('Realtime boundary policy: PASS - timer starts after formatting and telemetry rate is elapsed-time normalized')
+          PY
+
       - name: Build firmware
         run: source /opt/esp/idf/export.sh && idf.py build
 

apps/arstack_studio/release/freeze-manifest.json

@@ -38,5 +38,20 @@
     "autoStartAfterReconnect": false,
     "physicalAcceptanceRequiredBeforeMergeOrTag": true
   },
-  "exceptions": []
+  "exceptions": [
+    {
+      "path": "embedded/esp32p4_smv_injector/main/app_main.cpp",
+      "blockerIssue": "#83 physical RC2 retained-run telemetry failure",
+      "risk": "The 250 us sample clock starts before synchronous profile logging completes, causing deterministic missed slots at every START; asynchronous telemetry buckets are also mislabeled as one-second fps windows.",
+      "rationale": "Physical board evidence showed the first stream counter starting after skipped slots and fail-closed RC2 telemetry outside 3999..4001 despite a stable 3999.94 fps wire segment. The minimum production fix moves timer enable after preparation and reports elapsed-time-normalized fps from a bounded lock-free tick counter.",
+      "verification": "ESP32-P4 build and realtime boundary policy gate; real-board 10x Start/Stop; first transmitted smpCnt begins at 0 with missed=0; retained 4000-fps telemetry has missed=0 and TX fail=0; independent capture proves continuous counters and 3999..4001 fps; full exact-head release gates."
+    },
+    {
+      "path": ".github/workflows/esp32p4-smv-injector.yml",
+      "blockerIssue": "#83 physical RC2 retained-run telemetry failure",
+      "risk": "The timer/log ordering and normalized telemetry invariant could regress without a deterministic source-policy gate.",
+      "rationale": "Add the smallest CI assertion at the existing ESP32-P4 firmware boundary instead of introducing a second test framework or weakening the physical evaluator.",
+      "verification": "The workflow must reject timer enable before START-path formatting, missing lock-free sample tick accounting, or removal of elapsed-time telemetry normalization; the complete ESP32-P4 firmware build must still pass."
+    }
+  ]
 }

embedded/esp32p4_smv_injector/main/app_main.cpp

@@ -22,6 +22,7 @@
 
 #include <algorithm>
 #include <array>
+#include <atomic>
 #include <cstddef>
 #include <cstdint>
 #include <limits>
@@ -77,6 +78,8 @@ struct TimingStats final {
 };
 
 TimingStats g_interval_stats{};
+static_assert(std::atomic<std::uint32_t>::is_always_lock_free);
+std::atomic<std::uint32_t> g_sample_tick_total{0U};
 
 struct PacketTemplate final {
     std::vector<std::uint8_t> bytes;
@@ -296,6 +299,21 @@ void merge_stats(TimingStats& local) noexcept {
     local = TimingStats{};
 }
 
+void accumulate_stats(TimingStats& target, const TimingStats& source) noexcept {
+    if (source.samples == 0U) return;
+    target.samples += source.samples;
+    target.canonical_ok += source.canonical_ok;
+    target.canonical_fail += source.canonical_fail;
+    target.mirror_ok += source.mirror_ok;
+    target.mirror_fail += source.mirror_fail;
+    target.missed_slots += source.missed_slots;
+    target.lateness_sum_us += source.lateness_sum_us;
+    target.lateness_min_us = std::min(target.lateness_min_us, source.lateness_min_us);
+    target.lateness_max_us = std::max(target.lateness_max_us, source.lateness_max_us);
+    target.last_sample_count = source.last_sample_count;
+    target.last_signal_generation = source.last_signal_generation;
+}
+
 void reset_interval_stats() noexcept {
     portENTER_CRITICAL(&g_stats_mux);
     g_interval_stats = TimingStats{};
@@ -450,8 +468,6 @@ void publisher_task(void* argument) {
             schedule_anchored = false;
             expected_schedule.reset(active_profile.publisher_rate_hz);
             static_cast<void>(expected_schedule.next_ticks()); // first alarm interval
-            sample_clock = start_sample_clock(task_handle, active_profile.publisher_rate_hz);
-
             ESP_LOGI(kTag,
                      "PROFILE armed generation=%llu svID=%s APPID=0x%04X rate=%lu wrap=%u confRev=%lu VLAN=%u/%u/%u frameLen=%u",
                      static_cast<unsigned long long>(active_profile.generation),
@@ -464,6 +480,12 @@ void publisher_task(void* argument) {
                      static_cast<unsigned>(active_profile.vlan_id),
                      static_cast<unsigned>(active_profile.vlan_priority),
                      static_cast<unsigned>(canonical.bytes.size()));
+
+            // Starting the 250 us clock is the final operation in this branch.
+            // Formatting the profile log after timer enable previously queued
+            // dozens of ISR notifications before the publisher could consume
+            // its first tick, so every START falsely began with missed slots.
+            sample_clock = start_sample_clock(task_handle, active_profile.publisher_rate_hz);
             continue;
         }
 
@@ -537,6 +559,7 @@ void publisher_task(void* argument) {
 
         update_local_timing(
             local, lateness_us, missed_slots, canonical_sample_count, signal_state.generation);
+        g_sample_tick_total.fetch_add(1U, std::memory_order_relaxed);
         canonical_sample_count = static_cast<std::uint16_t>(
             (canonical_sample_count + 1U) % active_profile.sample_counter_modulus);
         mirror_sample_count = static_cast<std::uint16_t>(mirror_sample_count + 1U);
@@ -550,21 +573,59 @@ void publisher_task(void* argument) {
 }
 
 void telemetry_task(void*) {
+    std::uint32_t previous_tick_total = 0U;
+    std::int64_t previous_tick_time_us = 0;
+    bool rate_baseline_valid = false;
+    TimingStats baseline_stats{};
+
     while (true) {
         vTaskDelay(pdMS_TO_TICKS(1000));
         TimingStats snapshot{};
         portENTER_CRITICAL(&g_stats_mux);
         snapshot = g_interval_stats;
         g_interval_stats = TimingStats{};
         portEXIT_CRITICAL(&g_stats_mux);
-        if (snapshot.samples == 0U) continue;
+
+        const std::int64_t now_us = esp_timer_get_time();
+        const std::uint32_t tick_total = g_sample_tick_total.load(std::memory_order_relaxed);
+        if (!live_tx_running() || snapshot.samples == 0U) {
+            rate_baseline_valid = false;
+            baseline_stats = {};
+            previous_tick_total = tick_total;
+            previous_tick_time_us = now_us;
+            continue;
+        }
+
+        // The telemetry task is independent from START and can first wake in
+        // the middle of a publisher second. Use that partial bucket only as a
+        // baseline, while carrying its failures into the first complete report.
+        if (!rate_baseline_valid) {
+            rate_baseline_valid = true;
+            baseline_stats = snapshot;
+            previous_tick_total = tick_total;
+            previous_tick_time_us = now_us;
+            continue;
+        }
+
+        const std::uint32_t elapsed_ticks = tick_total - previous_tick_total;
+        const std::int64_t elapsed_us = now_us - previous_tick_time_us;
+        previous_tick_total = tick_total;
+        previous_tick_time_us = now_us;
+        if (elapsed_ticks == 0U || elapsed_us <= 0) continue;
+
+        accumulate_stats(snapshot, baseline_stats);
+        baseline_stats = {};
+        const std::uint64_t normalized_fps =
+            (static_cast<std::uint64_t>(elapsed_ticks) * 1000000ULL +
+             static_cast<std::uint64_t>(elapsed_us / 2)) /
+            static_cast<std::uint64_t>(elapsed_us);
 
         const std::int64_t mean_lateness_us =
             snapshot.lateness_sum_us / static_cast<std::int64_t>(snapshot.samples);
         ESP_LOGI(kTag,
                  "timing: samples=%llu (~%llu fps) MC ok=%llu fail=%llu mirror ok=%llu fail=%llu missed=%llu wake_late_us[min/mean/max]=%ld/%lld/%ld smpCnt=%u signal_gen=%llu",
                  static_cast<unsigned long long>(snapshot.samples),
-                 static_cast<unsigned long long>(snapshot.samples),
+                 static_cast<unsigned long long>(normalized_fps),
                  static_cast<unsigned long long>(snapshot.canonical_ok),
                  static_cast<unsigned long long>(snapshot.canonical_fail),
                  static_cast<unsigned long long>(snapshot.mirror_ok),