P0 Flight Recorder Hardening: coherent event snapshots, exact MAC causes, negligible idle overhead

apps/arstack_studio/qml/PtpExpertPanel.qml

@@ -365,7 +365,7 @@ SurfacePanel {
                     }
                     Label {
                         Layout.fillWidth: true
-                        text: "Board-internal reasons, not an independently certified PTP/IED lock."
+                        text: "Last 16 board LOCK transitions are retained in RAM; no per-frame logging. Internal evidence only—not an independently verified PTP/IED lock."
                         color: panel.theme.muted
                         font.family: panel.uiFont
                         font.pixelSize: 9

embedded/esp32p4_smv_injector/main/app_main.cpp

@@ -1143,8 +1143,25 @@ void publisher_task(void* argument) {
                 const auto phase_ns = g_tx_egress_evidence.summary().last_phase_ns;
                 g_local_sync_evidence.observe(egress, result, phase_ns);
                 portEXIT_CRITICAL(&g_tx_egress_mux);
-                if (result != ar::iec61850::time_sync::SvTxEvidenceResult::measured)
-                    revoke_sv_auto_claims(SvSyncLossReason::mac_egress);
+                // Keep the EXACT real descriptor rejection class. This runs
+                // once every two seconds, never per-frame or in an ISR.
+                using Evidence = ar::iec61850::time_sync::SvTxEvidenceResult;
+                if (result != Evidence::measured) {
+                    const auto cause = result == Evidence::transmit_failed
+                        ? SvSyncLossReason::canonical_tx
+                        : result == Evidence::missing_hw_timestamp
+                            ? SvSyncLossReason::mac_missing_timestamp
+                        : result == Evidence::not_a_qualified_epoch
+                            ? SvSyncLossReason::mac_bad_epoch
+                        : result == Evidence::publisher_discontinuity
+                            ? SvSyncLossReason::mac_publisher_discontinuity
+                        : result == Evidence::ptp_clock_discontinuity
+                            ? SvSyncLossReason::mac_ptp_clock_step
+                        : result == Evidence::baseline_established
+                            ? SvSyncLossReason::mac_baseline_reset
+                        : SvSyncLossReason::mac_egress;
+                    revoke_sv_auto_claims(cause);
+                }
             }
 #else
             const esp_err_t canonical_result =
@@ -1445,6 +1462,15 @@ void sv_ptp_phase_observer_task(void* argument) {
                 // An external GM may yield LOCAL or GLOBAL only after both
                 // PTP discipline and this actual SV phase/MAC gate pass.
                 // SOURCE never promotes to GLOBAL through this path.
+                // Publish measured phase/MAC context BEFORE a lock edge,
+                // so each ring event snapshots the causally relevant
+                // observation rather than last second's cached values.
+                smp_synch_diag_observe(
+                    decision.phase_error_us, decision.observation_uncertainty_us,
+                    mac_pairs, local_acquisition.clean_epochs(),
+                    observation.last_sv_epoch_generation,
+                    decision.accepted && decision.epoch_second_continuous,
+                    decision.software_tracking);
                 const auto stamp_ms = static_cast<std::uint32_t>(
                     esp_timer_get_time() / 1000LL);
                 smp_synch_set_source_local_qualified(
@@ -1453,12 +1479,6 @@ void sv_ptp_phase_observer_task(void* argument) {
                 smp_synch_set_receiver_timeline_qualified(
                     stable_local && lease.role == PtpAuthorityRole::receiver,
                     SvSyncLossReason::phase_or_mac, stamp_ms);
-                smp_synch_diag_observe(
-                    decision.phase_error_us, decision.observation_uncertainty_us,
-                    mac_pairs, local_acquisition.clean_epochs(),
-                    observation.last_sv_epoch_generation,
-                    decision.accepted && decision.epoch_second_continuous,
-                    decision.software_tracking);
             } else {
                 local_acquisition.reset();
                 revoke_sv_auto_claims(SvSyncLossReason::publisher_stop);
@@ -1539,20 +1559,28 @@ void telemetry_task(void*) {
         // Auto-surface each change in the flight recorder once per second,
         // even if the operator forgets to request Inspect SV lock. The full
         // event ring remains available on demand through Studio.
-        const auto flight = ar::esp32p4::smv::smp_synch_diag_snapshot();
-        if (flight.events != last_flight_events_reported) {
-            const auto changes = flight.events - last_flight_events_reported;
-            last_flight_events_reported = flight.events;
-            if (flight.recent_count > 0U) {
+        // Do one atomic counter read per second during steady-state LOCK.
+        // Constructing a 16-event snapshot is only needed after a transition.
+        if (ar::esp32p4::smv::smp_synch_diag_event_count() !=
+                last_flight_events_reported) {
+            const auto flight = ar::esp32p4::smv::smp_synch_diag_snapshot();
+            if (flight.events != last_flight_events_reported &&
+                flight.recent_count > 0U &&
+                flight.recent[flight.recent_count - 1U].sequence == flight.events) {
+                const auto changes = flight.events - last_flight_events_reported;
+                last_flight_events_reported = flight.events;
                 const auto& latest = flight.recent[flight.recent_count - 1U];
                 ESP_LOGW(kTag,
                     "SVSYNC FLIGHT transitions=%lu latest_seq=%lu state=%s reason=%s "
-                    "uptime_ms=%lu phase_us=%ld uncertainty_us=%lu MACpairs=%lu clean=%lu",
+                    "uptime_ms=%lu event_phase_us=%ld event_MACpairs=%lu "
+                    "phase_us=%ld uncertainty_us=%lu MACpairs=%lu clean=%lu",
                     static_cast<unsigned long>(changes),
                     static_cast<unsigned long>(latest.sequence),
                     latest.acquired ? "ACQUIRED" : "REVOKED",
                     ar::esp32p4::smv::smp_synch_diag_reason_name(latest.reason),
                     static_cast<unsigned long>(latest.monotonic_ms),
+                    static_cast<long>(latest.phase_error_us),
+                    static_cast<unsigned long>(latest.mac_pairs),
                     static_cast<long>(flight.phase_error_us),
                     static_cast<unsigned long>(flight.uncertainty_us),
                     static_cast<unsigned long>(flight.mac_pairs),

embedded/esp32p4_smv_injector/main/live_control.cpp

@@ -342,11 +342,15 @@ void print_sv_sync_diagnostics() noexcept {
     }
     for (std::size_t i = 0U; i < s.recent_count; ++i) {
         const auto& e = s.recent[i];
-        ESP_LOGI(kTag, "SVSYNC EVENT seq=%lu uptime_ms=%lu state=%s reason=%s",
+        ESP_LOGI(kTag,
+                 "SVSYNC EVENT seq=%lu uptime_ms=%lu state=%s reason=%s "
+                 "event_phase_us=%ld event_MACpairs=%lu",
                  static_cast<unsigned long>(e.sequence),
                  static_cast<unsigned long>(e.monotonic_ms),
                  e.acquired ? "ACQUIRED" : "REVOKED",
-                 smp_synch_diag_reason_name(e.reason));
+                 smp_synch_diag_reason_name(e.reason),
+                 static_cast<long>(e.phase_error_us),
+                 static_cast<unsigned long>(e.mac_pairs));
     }
     ESP_LOGI(kTag, "SVSYNC END events=%lu", static_cast<unsigned long>(s.events));
 }

embedded/esp32p4_smv_injector/main/smp_synch_lab.cpp

@@ -9,6 +9,10 @@
 #include <cstdint>
 #include <optional>
 
+#if defined(ESP_PLATFORM)
+#include "esp_timer.h"
+#endif
+
 namespace ar::esp32p4::smv {
 namespace {
 
@@ -31,6 +35,8 @@ constexpr std::size_t kReasonCount =
 std::array<std::atomic<std::uint32_t>, kReasonCount> g_cause_counts{};
 std::array<std::atomic<std::uint32_t>, kSvSyncFlightEventCapacity> g_event_codes{};
 std::array<std::atomic<std::uint32_t>, kSvSyncFlightEventCapacity> g_event_times{};
+std::array<std::atomic<std::int32_t>, kSvSyncFlightEventCapacity> g_event_phases{};
+std::array<std::atomic<std::uint32_t>, kSvSyncFlightEventCapacity> g_event_mac_pairs{};
 std::atomic<std::uint32_t> g_event_sequence{0U};
 std::atomic<std::uint32_t> g_acquisition_count{0U};
 std::atomic<std::uint32_t> g_loss_count{0U};
@@ -60,7 +66,22 @@ void record_transition(const SvSyncLossReason reason,
     const auto code = ((seq & 0xFFFFU) << 16U) |
         (static_cast<std::uint32_t>(reason) << 1U) |
         (qualified ? 1U : 0U);
-    g_event_times[slot].store(uptime_ms, std::memory_order_relaxed);
+    // Invalidate BEFORE replacing timestamp/context. Otherwise a reader
+    // could observe the previous published code with the next event's time.
+    g_event_codes[slot].store(0U, std::memory_order_release);
+    std::uint32_t event_ms = uptime_ms;
+#if defined(ESP_PLATFORM)
+    // Control-plane STOP/mode/GM events need valid uptime even when their
+    // portable caller did not provide a monotonic timestamp.
+    if (event_ms == 0U)
+        event_ms = static_cast<std::uint32_t>(esp_timer_get_time() / 1000LL);
+#endif
+    g_event_times[slot].store(event_ms, std::memory_order_relaxed);
+    g_event_phases[slot].store(
+        g_diag_phase_us.load(std::memory_order_relaxed), std::memory_order_relaxed);
+    g_event_mac_pairs[slot].store(
+        g_diag_mac_pairs.load(std::memory_order_relaxed), std::memory_order_relaxed);
+    // A code is a publication marker and carries a 16-bit sequence tag.
     g_event_codes[slot].store(code, std::memory_order_release);
 }
 
@@ -195,18 +216,24 @@ SvSyncFlightSnapshot smp_synch_diag_snapshot() noexcept {
         const auto slot = static_cast<std::size_t>(
             (seq - 1U) % kSvSyncFlightEventCapacity);
         const auto before = g_event_codes[slot].load(std::memory_order_acquire);
-        if (((before >> 16U) & 0xFFFFU) != (seq & 0xFFFFU)) continue;
+        if (before == 0U ||
+            ((before >> 16U) & 0xFFFFU) != (seq & 0xFFFFU)) continue;
         const auto time = g_event_times[slot].load(std::memory_order_relaxed);
+        const auto phase = g_event_phases[slot].load(std::memory_order_relaxed);
+        const auto pairs = g_event_mac_pairs[slot].load(std::memory_order_relaxed);
         const auto after = g_event_codes[slot].load(std::memory_order_acquire);
-        if (before != after) continue; // overwritten during read
+        if (before != after) continue; // concurrent overwrite: skip, never invent
         s.recent[s.recent_count++] = SvSyncFlightEvent{
-            seq, time,
+            seq, time, phase, pairs,
             static_cast<SvSyncLossReason>((before >> 1U) & 0xFFU),
             (before & 1U) != 0U
         };
     }
     return s;
 }
+std::uint32_t smp_synch_diag_event_count() noexcept {
+    return g_event_sequence.load(std::memory_order_acquire);
+}
 const char* smp_synch_diag_reason_name(const SvSyncLossReason reason) noexcept {
     switch (reason) {
     case SvSyncLossReason::none: return "ACQUIRED";
@@ -223,6 +250,11 @@ const char* smp_synch_diag_reason_name(const SvSyncLossReason reason) noexcept {
     case SvSyncLossReason::ptp_stop: return "PTP_STOP";
     case SvSyncLossReason::operator_mode: return "OPERATOR_MODE_CHANGE";
     case SvSyncLossReason::other: return "UNCLASSIFIED_REVOCATION";
+    case SvSyncLossReason::mac_missing_timestamp: return "MAC_HW_TIMESTAMP_MISSING";
+    case SvSyncLossReason::mac_bad_epoch: return "MAC_EPOCH_NOT_QUALIFIED";
+    case SvSyncLossReason::mac_publisher_discontinuity: return "MAC_PUBLISHER_DISCONTINUITY";
+    case SvSyncLossReason::mac_ptp_clock_step: return "MAC_PTP_CLOCK_STEP";
+    case SvSyncLossReason::mac_baseline_reset: return "MAC_EVIDENCE_REBASELINE";
     case SvSyncLossReason::count: break;
     }
     return "UNKNOWN";

embedded/esp32p4_smv_injector/main/smp_synch_lab.hpp

@@ -40,12 +40,16 @@ enum class SvSyncLossReason : std::uint8_t {
     none, missed_slot, ethernet_link, observer_stale, mac_egress,
     canonical_tx, ptp_lease, observer_epoch, phase_or_mac,
     phase_handoff, publisher_stop, ptp_stop, operator_mode, other,
+    mac_missing_timestamp, mac_bad_epoch, mac_publisher_discontinuity,
+    mac_ptp_clock_step, mac_baseline_reset,
     count
 };
 constexpr std::size_t kSvSyncFlightEventCapacity = 16;
 struct SvSyncFlightEvent final {
     std::uint32_t sequence{};
     std::uint32_t monotonic_ms{};
+    std::int32_t phase_error_us{};
+    std::uint32_t mac_pairs{};
     SvSyncLossReason reason{SvSyncLossReason::none};
     bool acquired{};
 };
@@ -70,6 +74,7 @@ void smp_synch_diag_observe(std::int32_t phase_us, std::uint32_t uncertainty_us,
                            std::uint32_t mac_pairs, std::uint32_t clean_epochs,
                            std::uint32_t epoch, bool accepted, bool tracking) noexcept;
 [[nodiscard]] SvSyncFlightSnapshot smp_synch_diag_snapshot() noexcept;
+[[nodiscard]] std::uint32_t smp_synch_diag_event_count() noexcept;
 [[nodiscard]] const char* smp_synch_diag_reason_name(SvSyncLossReason reason) noexcept;
 void smp_synch_set_source_local_qualified(
     bool qualified, SvSyncLossReason reason = SvSyncLossReason::other,

tests/test_smp_synch_policy.cpp

@@ -115,6 +115,15 @@ void test_internal_sync_recorder_captures_cause_and_bounded_history() {
     require(after.recent[after.recent_count-1].reason == SvSyncLossReason::mac_egress &&
             !after.recent[after.recent_count-1].acquired,
             "newest loss must retain exact cause");
+    require(after.recent[after.recent_count-1].phase_error_us == -3 &&
+            after.recent[after.recent_count-1].mac_pairs == 4U &&
+            after.recent[after.recent_count-1].monotonic_ms == 1041U,
+            "each lock edge must preserve event-local phase, MAC and uptime");
+    require(smp_synch_diag_event_count() == after.events,
+            "fast event count must match full snapshot");
+    require(smp_synch_diag_reason_name(SvSyncLossReason::mac_missing_timestamp) !=
+            smp_synch_diag_reason_name(SvSyncLossReason::mac_ptp_clock_step),
+            "missing TX timestamp and clock step must have distinct labels");
     require(after.phase_error_us == -3 && after.uncertainty_us == 2U &&
             after.mac_pairs == 4U && after.clean_epochs == 10U &&
             after.sample_epoch == 101U && after.phase_accepted &&