From 1b6eb46cabe48aa414ebfa1144cc3e8f50792511 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:07:48 +0700 Subject: [PATCH 01/11] feat(sync): qualify warm LOCAL only after preflight phase and real MAC TX epochs --- .../time_sync/sv_tx_egress_evidence.hpp | 126 +++++++++++++++--- 1 file changed, 108 insertions(+), 18 deletions(-) diff --git a/include/ariec61850/time_sync/sv_tx_egress_evidence.hpp b/include/ariec61850/time_sync/sv_tx_egress_evidence.hpp index e39462a44..a76a77dc6 100644 --- a/include/ariec61850/time_sync/sv_tx_egress_evidence.hpp +++ b/include/ariec61850/time_sync/sv_tx_egress_evidence.hpp @@ -277,45 +277,135 @@ class SvLocalSyncEvidenceGate final { std::uint32_t last_epoch_{}; }; -// Fail-closed entry filter: requires consecutive, independently qualified -// real SV epochs before asserting LOCAL, but never delays loss of LOCAL. -// Physical 120 s capture 2026-10-19 showed 0->1 at +22.096 s and 1->0 -// at +23.096 s before stable reacquisition at +32.096 s. Three epochs -// permitted a one-second premature LOCAL advertisement. Demand a 10-second -// stable window of independent MAC/phase evidence before the FIRST claim. -// This is an *entry* stabilizer, not a loss-of-evidence hysteresis: any -// invalid epoch/source/fault still revokes LOCAL immediately. +// Fail-closed LOCAL entry filter. A COLD start demands ten consecutive +// genuinely transmitted, phase+canonical-MAC-qualified SV epochs. A WARM +// preflight may earn phase-only history while SV TX is disabled; it cannot +// advertise synchronization. After START, WARM promotion still requires three +// consecutive live phase+MAC-qualified epochs, from this very publisher +// session, with no lost epoch, lease mutation, or publisher fault. +// +// Earlier field evidence showed a premature one-second LOCAL claim when +// *only* three live epochs were used. Warm promotion is categorically +// different: it requires ten *additional* measured, consecutive preflight +// phase epochs before the three live epochs. No preflight packet is invented, +// and any known invalid clock, discontinuity, or loss of established MAC +// evidence revokes LOCAL immediately. class SvLocalRefAcquisition final { public: static constexpr std::uint32_t kRequiredCleanEpochs = 10U; + static constexpr std::uint32_t kWarmRequiredLiveEpochs = 3U; + // Enough time for the sparse (every-two-epoch) MAC descriptor pair + // baseline, but stale preflight is never useful indefinitely. + static constexpr std::uint32_t kMaxWarmMacAcquisitionEpochs = 8U; + constexpr void reset() noexcept { - count_ = 0U; session_ = 0U; faults_ = 0U; - source_ = 0U; epoch_ = 0U; + count_ = 0U; + preflight_epochs_ = 0U; + live_age_ = 0U; + session_ = 0U; + faults_ = 0U; + source_ = 0U; + epoch_ = 0U; + had_mac_evidence_ = false; } - [[nodiscard]] constexpr bool observe( - const bool qualified, const std::uint32_t session, + + // Called ONLY with real 1Hz GPTimer/PTP phase observations while the + // publisher is OFF and its preflight timer remains armed. No MAC evidence + // or smpSynch claim is implied. + constexpr void observe_preflight( + const bool phase_qualified, const std::uint32_t session, const std::uint32_t faults, const std::uint32_t source, const std::uint32_t epoch) noexcept { - if (!qualified || session == 0U || source == 0U || epoch == 0U) { + if (!phase_qualified || session == 0U || source == 0U || epoch == 0U) { + reset(); + return; + } + if (count_ != 0U || + (preflight_epochs_ != 0U && !same_epoch_identity( + session, faults, source, epoch))) { + reset(); + } + save_epoch_identity(session, faults, source, epoch); + if (preflight_epochs_ < kRequiredCleanEpochs) ++preflight_epochs_; + } + + // Phase continuity and canonical MAC evidence are independent. During + // the first few live epochs a healthy MAC observer must establish its + // descriptor baseline; missing *initial* evidence cannot be mistaken + // for established evidence being revoked. A previously valid MAC gate + // becoming invalid is immediately fail-closed. + [[nodiscard]] constexpr bool observe_live( + const bool phase_qualified, const bool canonical_mac_qualified, + const std::uint32_t session, const std::uint32_t faults, + const std::uint32_t source, const std::uint32_t epoch) noexcept { + if (!phase_qualified || session == 0U || source == 0U || epoch == 0U) { + reset(); + return false; + } + if ((count_ != 0U || preflight_epochs_ != 0U || live_age_ != 0U) && + !same_epoch_identity(session, faults, source, epoch)) { reset(); + } + save_epoch_identity(session, faults, source, epoch); + if (live_age_ < kMaxWarmMacAcquisitionEpochs + 1U) ++live_age_; + if (live_age_ > kMaxWarmMacAcquisitionEpochs) + preflight_epochs_ = 0U; + + if (!canonical_mac_qualified) { + if (had_mac_evidence_) reset(); return false; } - if (count_ != 0U && - (session_ != session || faults_ != faults || source_ != source || - epoch - epoch_ != 1U)) reset(); - session_ = session; faults_ = faults; source_ = source; epoch_ = epoch; + had_mac_evidence_ = true; if (count_ < kRequiredCleanEpochs) ++count_; - return count_ == kRequiredCleanEpochs; + return count_ == kRequiredCleanEpochs || + (preflight_epochs_ == kRequiredCleanEpochs && + live_age_ <= kMaxWarmMacAcquisitionEpochs && + count_ >= kWarmRequiredLiveEpochs); + } + + // Compatibility contract for callers with an already-combined canonical + // phase+MAC boolean: unchanged ten-live-epoch fail-closed behavior. + [[nodiscard]] constexpr bool observe( + const bool qualified, const std::uint32_t session, + const std::uint32_t faults, const std::uint32_t source, + const std::uint32_t epoch) noexcept { + return observe_live(qualified, qualified, session, faults, source, epoch); } + [[nodiscard]] constexpr std::uint32_t clean_epochs() const noexcept { return count_; } + [[nodiscard]] constexpr std::uint32_t preflight_epochs() const noexcept { + return preflight_epochs_; + } + [[nodiscard]] constexpr std::uint32_t live_age_epochs() const noexcept { + return live_age_; + } + private: + [[nodiscard]] constexpr bool same_epoch_identity( + const std::uint32_t session, const std::uint32_t faults, + const std::uint32_t source, const std::uint32_t epoch) const noexcept { + return session_ == session && faults_ == faults && + source_ == source && epoch - epoch_ == 1U; + } + constexpr void save_epoch_identity( + const std::uint32_t session, const std::uint32_t faults, + const std::uint32_t source, const std::uint32_t epoch) noexcept { + session_ = session; + faults_ = faults; + source_ = source; + epoch_ = epoch; + } + std::uint32_t count_{}; + std::uint32_t preflight_epochs_{}; + std::uint32_t live_age_{}; std::uint32_t session_{}; std::uint32_t faults_{}; std::uint32_t source_{}; std::uint32_t epoch_{}; + bool had_mac_evidence_{}; }; } // namespace ar::iec61850::time_sync From f84819b462268c6b191bc2547493a81060e5208d Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:08:35 +0700 Subject: [PATCH 02/11] feat(esp32p4): carry phase-only warm preflight into bounded live MAC qualification --- .../esp32p4_smv_injector/main/app_main.cpp | 39 ++++++++++++++----- 1 file changed, 29 insertions(+), 10 deletions(-) diff --git a/embedded/esp32p4_smv_injector/main/app_main.cpp b/embedded/esp32p4_smv_injector/main/app_main.cpp index 65311773f..2999de093 100644 --- a/embedded/esp32p4_smv_injector/main/app_main.cpp +++ b/embedded/esp32p4_smv_injector/main/app_main.cpp @@ -1369,6 +1369,7 @@ void sv_ptp_phase_observer_task(void* argument) { // the GPTimer mutex. Source identity and fault/session generations // must match the exact phase observation before any AUTO promotion. bool source_local_qualified = false; + bool measured_phase_qualified = false; std::uint32_t mac_pairs = 0U; #if AR_SV_TX_EGRESS_SUPPORTED if ((lease.role == PtpAuthorityRole::source || @@ -1380,6 +1381,9 @@ void sv_ptp_phase_observer_task(void* argument) { const std::uint64_t worst_case_phase_us = static_cast(abs_phase_us) + decision.observation_uncertainty_us; + measured_phase_qualified = decision.software_tracking && + worst_case_phase_us <= + SvLocalSyncEvidenceGate::kMaxSoftwarePhaseBoundUs; portENTER_CRITICAL(&g_tx_egress_mux); source_local_qualified = g_local_sync_evidence.qualified( notified_session, current_faults, lease.generation, @@ -1430,15 +1434,16 @@ void sv_ptp_phase_observer_task(void* argument) { ? decision.slew_ticks_next_epoch : 0, std::memory_order_release); if (injecting) { - // A warm GPTimer is NEVER canonical MAC TX evidence. - // Require the actual descriptor pairs and three clean live - // epochs before advertising LOCAL REF to an IED. - const bool stable_local = local_acquisition.observe( - (lease.role == PtpAuthorityRole::source || - lease.role == PtpAuthorityRole::receiver) && - SvAutoPreflightPolicy::can_advertise_local( - injecting, source_local_qualified) && + // WARM may reuse ten actual pre-START phase observations + // only if this is the same GPTimer/PTP session. The sparse + // canonical MAC descriptor evidence is measured AFTER START, + // and three consecutive live epochs are still mandatory. + // COLD retains the full ten live phase+MAC epochs. + const bool stable_local = local_acquisition.observe_live( + measured_phase_qualified && decision.epoch_second_continuous, + SvAutoPreflightPolicy::can_advertise_local( + injecting, source_local_qualified), notified_session, current_faults, lease.generation, observation.last_sv_epoch_generation); if (!stable_local && @@ -1480,7 +1485,17 @@ void sv_ptp_phase_observer_task(void* argument) { stable_local && lease.role == PtpAuthorityRole::receiver, SvSyncLossReason::phase_or_mac, stamp_ms); } else { - local_acquisition.reset(); + if (preflight_active) { + // No SV packet is transmitted in preflight: this records + // PHASE evidence only and can never advertise smpSynch. + local_acquisition.observe_preflight( + measured_phase_qualified && + decision.epoch_second_continuous, + notified_session, current_faults, lease.generation, + observation.last_sv_epoch_generation); + } else { + local_acquisition.reset(); + } revoke_sv_auto_claims(SvSyncLossReason::publisher_stop); } committed = true; @@ -1527,7 +1542,8 @@ void sv_ptp_phase_observer_task(void* argument) { (accepted_epochs % 60U) == 0U)) { ESP_LOGI(kTag, "SV/PTP AUTO phase=%ldus uncertainty=%luus " - "slew=%ldus/s tracking=%u MACpairs=%lu clean=%lu/%lu epoch=%llu LOCAL=%u", + "slew=%ldus/s tracking=%u MACpairs=%lu " + "live_clean=%lu/%lu warm_phase=%lu/%lu live_age=%lu epoch=%llu LOCAL=%u", static_cast(decision.phase_error_us), static_cast(decision.observation_uncertainty_us), static_cast(decision.slew_ticks_next_epoch), @@ -1535,6 +1551,9 @@ void sv_ptp_phase_observer_task(void* argument) { static_cast(mac_pairs), static_cast(local_acquisition.clean_epochs()), static_cast(SvLocalRefAcquisition::kRequiredCleanEpochs), + static_cast(local_acquisition.preflight_epochs()), + static_cast(SvLocalRefAcquisition::kRequiredCleanEpochs), + static_cast(local_acquisition.live_age_epochs()), static_cast(decision.sv_epoch_ptp_second), auto_local ? 1U : 0U); } From 65fbe451b8323e36747c93c6530e2d31b55d7312 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:09:26 +0700 Subject: [PATCH 03/11] test(sync): guard warm preflight promotion against fake MAC, role change and epoch gaps --- tests/test_sv_tx_egress_evidence.cpp | 98 ++++++++++++++++++++++++++++ 1 file changed, 98 insertions(+) diff --git a/tests/test_sv_tx_egress_evidence.cpp b/tests/test_sv_tx_egress_evidence.cpp index d3aa6a4f4..a1526c801 100644 --- a/tests/test_sv_tx_egress_evidence.cpp +++ b/tests/test_sv_tx_egress_evidence.cpp @@ -147,6 +147,102 @@ void check_external_gm_receiver_requires_real_sv_egress_and_phase() { REQUIRE(!entry.observe(true, 8U, 1U, 4U, 23U)); } +void check_warm_phase_preflight_cannot_fake_canonical_mac() { + SvLocalRefAcquisition gate; + static_assert(SvLocalRefAcquisition::kWarmRequiredLiveEpochs == 3U); + // SOURCE/RECEIVER may accumulate phase-only evidence with SV TX OFF. + // No number of such observations may ever assert smpSynch. + for (std::uint32_t e = 1U; e <= 10U; ++e) { + gate.observe_preflight(true, 7U, 0U, 3U, e); + REQUIRE(gate.clean_epochs() == 0U); + } + REQUIRE(gate.preflight_epochs() == 10U); + // Descriptor baseline does not exist during the first live epochs: + // preserve stable phase history but NEVER claim LOCAL without real MAC. + REQUIRE(!gate.observe_live(true, false, 7U, 0U, 3U, 11U)); + REQUIRE(!gate.observe_live(true, false, 7U, 0U, 3U, 12U)); + REQUIRE(gate.preflight_epochs() == 10U); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 3U, 13U)); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 3U, 14U)); + REQUIRE(gate.observe_live(true, true, 7U, 0U, 3U, 15U)); + REQUIRE(gate.clean_epochs() == 3U); + // An established MAC evidence loss must revoke immediately. + REQUIRE(!gate.observe_live(true, false, 7U, 0U, 3U, 16U)); + REQUIRE(gate.clean_epochs() == 0U); + REQUIRE(gate.preflight_epochs() == 0U); + // Cold recovery still demands ten complete live phase+MAC epochs. + for (std::uint32_t e = 17U; e <= 26U; ++e) { + REQUIRE(gate.observe_live(true, true, 7U, 0U, 3U, e) + == (e == 26U)); + } + REQUIRE(!gate.observe_live(false, true, 7U, 0U, 3U, 27U)); +} + +void check_warm_preflight_negative_session_and_clock_faults() { + auto warm = [](SvLocalRefAcquisition& gate) { + for (std::uint32_t e = 1U; e <= 10U; ++e) + gate.observe_preflight(true, 7U, 0U, 3U, e); + REQUIRE(gate.preflight_epochs() == 10U); + }; + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 4U, 11U)); // GM/source change + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 4U, 12U)); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 4U, 13U)); + } + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(true, true, 7U, 1U, 3U, 11U)); // publisher fault + REQUIRE(gate.preflight_epochs() == 0U); + } + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(true, true, 8U, 0U, 3U, 11U)); // new timer session + REQUIRE(gate.preflight_epochs() == 0U); + } + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 3U, 12U)); // skipped epoch + REQUIRE(gate.preflight_epochs() == 0U); + } + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(false, true, 7U, 0U, 3U, 11U)); // phase/lease loss + REQUIRE(gate.preflight_epochs() == 0U); + } + { + SvLocalRefAcquisition gate; + warm(gate); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 3U, 11U)); + REQUIRE(!gate.observe_live(true, true, 7U, 0U, 3U, 11U)); // duplicate + REQUIRE(gate.preflight_epochs() == 0U); + } + { + SvLocalRefAcquisition gate; + warm(gate); + // No MAC descriptor evidence for eight live seconds: the warm + // privilege expires and COLD retains the strict ten-live gate. + for (std::uint32_t e = 11U; e <= 19U; ++e) + REQUIRE(!gate.observe_live(true, false, 7U, 0U, 3U, e)); + REQUIRE(gate.preflight_epochs() == 0U); + for (std::uint32_t e = 20U; e <= 29U; ++e) + REQUIRE(gate.observe_live(true, true, 7U, 0U, 3U, e) == (e == 29U)); + } + { + SvLocalRefAcquisition gate; + for (std::uint32_t e = 1U; e <= 9U; ++e) + gate.observe_preflight(true, 7U, 0U, 3U, e); + // Nine warm phase epochs are not enough for the 3-live shortcut. + for (std::uint32_t e = 10U; e <= 19U; ++e) + REQUIRE(gate.observe_live(true, true, 7U, 0U, 3U, e) == (e == 19U)); + } +} + void check_no_intermitttent_local_at_start() { SvLocalRefAcquisition gate; static_assert(SvLocalRefAcquisition::kRequiredCleanEpochs == 10U); @@ -309,6 +405,8 @@ int main() { check_auto_local_sync_gate_requires_both_clocks_and_fresh_mac(); check_fast_source_auto_qualification_with_fresh_evidence(); check_external_gm_receiver_requires_real_sv_egress_and_phase(); + check_warm_phase_preflight_cannot_fake_canonical_mac(); + check_warm_preflight_negative_session_and_clock_faults(); check_no_intermitttent_local_at_start(); check_local_only_after_ten_clean_seconds(); check_baseline_and_contiguous_ptp(); From 76b1468c197bbe268dfdee9303ecfbdd69b174ca Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:11:14 +0700 Subject: [PATCH 04/11] feat(studio): trace exact SV START/STOP transaction causality in bounded device log --- apps/arstack_studio/src/DeviceController.cpp | 41 +++++++++++++++++++- 1 file changed, 39 insertions(+), 2 deletions(-) diff --git a/apps/arstack_studio/src/DeviceController.cpp b/apps/arstack_studio/src/DeviceController.cpp index ee6a1ed76..b40d0f3f8 100644 --- a/apps/arstack_studio/src/DeviceController.cpp +++ b/apps/arstack_studio/src/DeviceController.cpp @@ -814,11 +814,19 @@ bool DeviceController::startWithScenario(const QVariantMap& scenario) { scenarioProfileGeneration_ = profileGeneration_; if (!sendCommandBatch(commands, false, true)) { resetScenarioStart(); return false; } scenarioTimer_.start(); + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "TXN_BEGIN session=%1 boot=%2 token=%3 profile=%4 state=CFG_COMMIT") + .arg(sessionGeneration_).arg(scenarioBoot_).arg(scenarioToken_) + .arg(scenarioProfileGeneration_)); emit scenarioStateChanged(); signalFrequencyHz_ = hz; return true; } bool DeviceController::stop() { + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "OPERATOR_STOP_REQUEST session=%1 boot=%2 running=%3 cfg_pending=%4") + .arg(sessionGeneration_).arg(identity_.bootId) + .arg(running_ ? 1 : 0).arg(scenarioStage_ != ScenarioStage::idle ? 1 : 0)); resetScenarioStart(); return sendCommand(QStringLiteral("STOP")); } @@ -1728,9 +1736,15 @@ void DeviceController::resetScenarioStart() noexcept { void DeviceController::failScenarioStart(const QString& message) { if (scenarioStage_ == ScenarioStage::idle) return; + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "TXN_FAILURE session=%1 boot=%2 token=%3 reason=%4") + .arg(sessionGeneration_).arg(scenarioBoot_).arg(scenarioToken_).arg(message)); resetScenarioStart(); // Even if START ACK was lost after a valid commit, issue STOP. It is not // safe to conclude that the physical publisher is stopped from a timeout. + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "FAIL_SAFE_STOP_REQUEST session=%1 reason=unverified_start") + .arg(sessionGeneration_)); static_cast(sendCommand(QStringLiteral("STOP"))); setError(message); } @@ -1854,6 +1868,10 @@ void DeviceController::processLine(const QString& rawLine) { failScenarioStart(QStringLiteral("SV commit ACK identity/hash mismatch.")); } else { scenarioSignalGeneration_ = scenarioCommitted.captured(3).toULongLong(); + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "CFG_COMMITTED session=%1 token=%2 signal_generation=%3") + .arg(sessionGeneration_).arg(scenarioToken_) + .arg(scenarioSignalGeneration_)); scenarioStage_ = ScenarioStage::awaiting_readback; if (!sendCommand(QStringLiteral("CFG SHOW %1").arg(scenarioToken_))) failScenarioStart(QStringLiteral("Unable to request firmware-applied SV readback.")); @@ -1866,6 +1884,10 @@ void DeviceController::processLine(const QString& rawLine) { failScenarioStart(QStringLiteral("SV firmware readback differs from committed scenario.")); } else { scenarioStage_ = ScenarioStage::awaiting_start_ack; + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "CFG_VERIFIED session=%1 boot=%2 token=%3 signal_generation=%4") + .arg(sessionGeneration_).arg(scenarioBoot_).arg(scenarioToken_) + .arg(scenarioSignalGeneration_)); const QString hash = QString::number(scenarioHash_, 16).toUpper() .rightJustified(16, QLatin1Char('0')); if (!sendCommand(QStringLiteral("START %1 %2 %3") @@ -1897,6 +1919,10 @@ void DeviceController::processLine(const QString& rawLine) { // Publish verified RUNNING before clearing the pending START phase. // Otherwise QML can briefly see neither RUNNING nor STARTING and // bounce the button back to START during a successful ACK handoff. + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "START_ACK_VERIFIED session=%1 boot=%2 token=%3 signal_generation=%4") + .arg(sessionGeneration_).arg(scenarioBoot_).arg(scenarioToken_) + .arg(scenarioSignalGeneration_)); setRunning(true); resetScenarioStart(); return; @@ -1905,15 +1931,26 @@ void DeviceController::processLine(const QString& rawLine) { // SV lifecycle acknowledgements are not PTP lifecycle acknowledgements. // Never report 4I+4V output RUNNING merely because PTP START succeeded. // Bare/unmatched START text is never evidence of a verified 8-channel START. - if (line.contains(QStringLiteral("STOP accepted: SV transmission suppressed"), Qt::CaseInsensitive)) + if (line.contains(QStringLiteral("STOP accepted: SV transmission suppressed"), Qt::CaseInsensitive)) { + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "STOP_ACK_OBSERVED session=%1 boot=%2 prior_running=%3") + .arg(sessionGeneration_).arg(identity_.bootId).arg(running_ ? 1 : 0)); setRunning(false); + } auto match = kStateExpression.match(line); if (match.hasMatch()) { const bool observedRunning = match.captured(1).compare(QStringLiteral("RUNNING"), Qt::CaseInsensitive) == 0; // Unsolicited RUNNING telemetry may race the token-bound START ACK. // It is neither success nor failure evidence while the commit gate is active. - if (scenarioStage_ == ScenarioStage::idle) setRunning(observedRunning); + if (scenarioStage_ == ScenarioStage::idle && running_ != observedRunning) { + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "STATE_READBACK session=%1 boot=%2 running=%3 prior=%4 signal_generation=%5") + .arg(sessionGeneration_).arg(identity_.bootId) + .arg(observedRunning ? 1 : 0).arg(running_ ? 1 : 0) + .arg(match.captured(2))); + setRunning(observedRunning); + } signalGeneration_ = match.captured(2); emit telemetryChanged(); } From 51ca844453cce8dd0ebdb911c482a880fe83ee45 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:16:20 +0700 Subject: [PATCH 05/11] fix(serial): reserve one bounded coalesced control lease heartbeat slot --- apps/arstack_studio/src/DeviceIoWorker.hpp | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/apps/arstack_studio/src/DeviceIoWorker.hpp b/apps/arstack_studio/src/DeviceIoWorker.hpp index b83594b29..00cbdd7cf 100644 --- a/apps/arstack_studio/src/DeviceIoWorker.hpp +++ b/apps/arstack_studio/src/DeviceIoWorker.hpp @@ -169,6 +169,7 @@ public slots: bool reportRejection); void queuePriorityPtpStop(); void queuePrioritySvStop(); + void queuePriorityHeartbeat(); void pumpWriteQueue(); void completeActiveWrite(); void processReadyRead(); @@ -186,6 +187,10 @@ public slots: QByteArray pendingRx_; QQueue commandQueue_; bool svStopPending_{false}; + // One coalesced safety-lease keepalive slot, outside normal 64-item FIFO. + // STOP priority remains higher. This is transport queue ownership, not + // a duplicate firmware RUNNING/LOCK state. + bool heartbeatPending_{false}; PendingCommand activeCommand_; QString lastPort_; From 3774c4d1adb56477f0c8d31184d8d6ff0d6d41d8 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:16:41 +0700 Subject: [PATCH 06/11] fix(serial): schedule lease heartbeat ahead of CFG queue without bypassing STOP --- apps/arstack_studio/src/DeviceIoWorker.cpp | 27 ++++++++++++++++++---- 1 file changed, 22 insertions(+), 5 deletions(-) diff --git a/apps/arstack_studio/src/DeviceIoWorker.cpp b/apps/arstack_studio/src/DeviceIoWorker.cpp index c194086c4..3bad2b79b 100644 --- a/apps/arstack_studio/src/DeviceIoWorker.cpp +++ b/apps/arstack_studio/src/DeviceIoWorker.cpp @@ -77,8 +77,7 @@ void DeviceIoWorker::initialize() { heartbeatTimer_->stop(); return; } - static_cast(enqueueCommandsInternal( - {QStringLiteral("HEARTBEAT")}, true, false, false)); + queuePriorityHeartbeat(); }); connect(serial_, &QSerialPort::readyRead, this, &DeviceIoWorker::processReadyRead); @@ -123,6 +122,7 @@ void DeviceIoWorker::shutdown(const bool requestSvStop, const bool requestPtpSto if (heartbeatTimer_ != nullptr) heartbeatTimer_->stop(); if (writeGapTimer_ != nullptr) writeGapTimer_->stop(); heartbeatEnabled_ = false; + heartbeatPending_ = false; probeQueue_.clear(); genericProbeActive_ = false; @@ -297,6 +297,7 @@ void DeviceIoWorker::closePortInternal(const bool emitRelease) { if (heartbeatTimer_ != nullptr) heartbeatTimer_->stop(); if (writeGapTimer_ != nullptr) writeGapTimer_->stop(); heartbeatEnabled_ = false; + heartbeatPending_ = false; identityConfirmed_ = false; identifyAttempts_ = 0; pendingRx_.clear(); @@ -451,6 +452,17 @@ void DeviceIoWorker::queuePrioritySvStop() { pumpWriteQueue(); } +void DeviceIoWorker::queuePriorityHeartbeat() { + // The 2.5-second firmware control lease must not be starved by a saturated + // 64-command queue or an exclusive profile CFG transaction. A single + // coalesced keepalive uses the same QSerialPort owner and normal pacing; + // it never bypasses a pending safety STOP or interrupts an active write. + // A disconnected/stalled serial port still fails closed in firmware. + if (!(writeActive_ && activeCommand_.text == QStringLiteral("HEARTBEAT"))) + heartbeatPending_ = true; + pumpWriteQueue(); +} + void DeviceIoWorker::queuePriorityPtpStop() { // Bounded (64 entries) and infrequent: revoke every unsent PTP START. // Preserve all other queued commands; STOP runs after the active write. @@ -474,7 +486,8 @@ void DeviceIoWorker::queuePriorityPtpStop() { void DeviceIoWorker::pumpWriteQueue() { if (serial_ == nullptr || !serial_->isOpen() || writeActive_ || - (!svStopPending_ && !ptpStopPending_ && commandQueue_.isEmpty())) return; + (!svStopPending_ && !ptpStopPending_ && !heartbeatPending_ && + commandQueue_.isEmpty())) return; // bytesToWrite()==0 proves only host/driver drain, not ESP console line // consumption. Throttle ordinary writes; reserved STOPs always bypass. if (!svStopPending_ && !ptpStopPending_ && writeGapTimer_ != nullptr && @@ -490,6 +503,10 @@ void DeviceIoWorker::pumpWriteQueue() { ptpStopPending_ = false; activeCommand_ = PendingCommand{ QStringLiteral("PTP STOP"), QByteArrayLiteral("PTP STOP\n"), false, false}; + } else if (heartbeatPending_) { + heartbeatPending_ = false; + activeCommand_ = PendingCommand{ + QStringLiteral("HEARTBEAT"), QByteArrayLiteral("HEARTBEAT\n"), true, false}; } else { activeCommand_ = commandQueue_.dequeue(); } @@ -568,11 +585,11 @@ void DeviceIoWorker::setHeartbeatEnabled(const bool enabled, const quint64 gener if (heartbeatTimer_ == nullptr) return; if (!enabled || serial_ == nullptr || !serial_->isOpen() || !identityConfirmed_) { + heartbeatPending_ = false; heartbeatTimer_->stop(); return; } - static_cast(enqueueCommandsInternal( - {QStringLiteral("HEARTBEAT")}, true, false, false)); + queuePriorityHeartbeat(); if (!heartbeatTimer_->isActive()) heartbeatTimer_->start(); } From 24971925d7c19e2067ba9466dcf5a70368117701 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:17:25 +0700 Subject: [PATCH 07/11] test(studio): heartbeat reserved outside saturated CFG FIFO; STOP still preempts --- .../src/DeterministicSessionHarness.cpp | 25 +++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/apps/arstack_studio/src/DeterministicSessionHarness.cpp b/apps/arstack_studio/src/DeterministicSessionHarness.cpp index 711613f78..d849083a9 100644 --- a/apps/arstack_studio/src/DeterministicSessionHarness.cpp +++ b/apps/arstack_studio/src/DeterministicSessionHarness.cpp @@ -62,6 +62,7 @@ class DeterministicSessionHarness final { {"ABC live SET encoder remains consistent and bounded", abcSetpointBatchContract()}, {"PTP STOP full queue uses bounded priority slot", ptpSafetyStopBypassesFullQueue()}, {"SV STOP remains responsive with full command queue", svPriorityStopBypassesFullQueue()}, + {"control lease heartbeat coalesces outside saturated exclusive queue", heartbeatKeepsBoundedSafetySlotUnderExclusiveLoad()}, {"PTP STOP requires firmware ACK and stopped readback", ptpStopConfirmationCannotBeGuessed()}, {"PTP STOP timeout blocks restart pending manual recovery", ptpUnverifiedStopBlocksRestart()}, {"App teardown must stop PTP without SV output", ptpOnlyShutdownIntent()}, @@ -978,6 +979,30 @@ class DeterministicSessionHarness final { return cancelled && worker.svStopPending_ && worker.commandQueue_.isEmpty(); } + static bool heartbeatKeepsBoundedSafetySlotUnderExclusiveLoad() { + DeviceIoWorker worker; + // Normal 64-command FIFO is saturated by an exclusive CFG batch. + // A 700ms lease heartbeat must remain deliverable without growing + // this FIFO; safety STOP must still own the highest priority. + for (int i = 0; i < DeviceIoWorker::commandQueueCapacity(); ++i) { + worker.commandQueue_.enqueue(DeviceIoWorker::PendingCommand{ + QStringLiteral("CFG SET IA 1000 0 0"), + QByteArrayLiteral("CFG SET IA 1000 0 0\n"), false, true}); + } + worker.exclusiveCommandsRemaining_ = DeviceIoWorker::commandQueueCapacity(); + worker.queuePriorityHeartbeat(); // isolated, no live COM needed + worker.queuePriorityHeartbeat(); // repeated keepalive coalesces + if (!worker.heartbeatPending_ || + worker.commandQueue_.size() != DeviceIoWorker::commandQueueCapacity()) + return false; + worker.queuePrioritySvStop(); + if (!worker.svStopPending_ || !worker.heartbeatPending_ || + !worker.commandQueue_.isEmpty()) + return false; // STOP does not wait behind keepalive + worker.heartbeatPending_ = false; // explicit session deactivation + return !worker.heartbeatPending_ && worker.svStopPending_; + } + static bool ptpSafetyStopBypassesFullQueue() { DeviceIoWorker worker; for (int i = 0; i < DeviceIoWorker::commandQueueCapacity(); ++i) { From c7aa7951983167b11bc4e5e51fe55ebea1286cbb Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:18:25 +0700 Subject: [PATCH 08/11] fix(studio): timestamp lifecycle evidence in millisecond UTC for PCAP correlation --- apps/arstack_studio/src/DeviceController.cpp | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/apps/arstack_studio/src/DeviceController.cpp b/apps/arstack_studio/src/DeviceController.cpp index b40d0f3f8..8bf0b883f 100644 --- a/apps/arstack_studio/src/DeviceController.cpp +++ b/apps/arstack_studio/src/DeviceController.cpp @@ -1811,7 +1811,9 @@ void DeviceController::setError(const QString& message) { } void DeviceController::appendLog(const QString& direction, const QString& line) { - const QString stamp = QDateTime::currentDateTime().toString(QStringLiteral("HH:mm:ss")); + // Correlate operator START/STOP and firmware ACKs to UTC PCAP/flight + // evidence at millisecond resolution; remains a bounded UI-side log. + const QString stamp = QDateTime::currentDateTimeUtc().toString(Qt::ISODateWithMs); logText_.append(QStringLiteral("[%1] %2 %3\n").arg(stamp, direction, line)); constexpr qsizetype kMaxChars = 60000; constexpr qsizetype kKeepChars = 48000; From 810d6378ef437d7d4e6a5289535037e9e620d655 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:20:31 +0700 Subject: [PATCH 09/11] test(studio): enforce cold 10-live and warm 10-phase + 3-MAC safety invariants --- .../tests/check_operator_workspace.py | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/apps/arstack_studio/tests/check_operator_workspace.py b/apps/arstack_studio/tests/check_operator_workspace.py index 1d0978790..795f09028 100644 --- a/apps/arstack_studio/tests/check_operator_workspace.py +++ b/apps/arstack_studio/tests/check_operator_workspace.py @@ -59,12 +59,19 @@ def main() -> None: and "measured_pairs() const noexcept" in sv_gate, "PTP startup must compensate GPTimer enable delay and expose early acquisition measurements") require("SvLocalRefAcquisition local_acquisition;" in firmware_source - and "local_acquisition.observe(" in firmware_source + and "local_acquisition.observe_preflight(" in firmware_source + and "local_acquisition.observe_live(" in firmware_source and "local_acquisition.reset();" in firmware_source - and "clean=%lu/%lu" in firmware_source + and "live_clean=%lu/%lu warm_phase=%lu/%lu live_age=%lu" in firmware_source and "kRequiredCleanEpochs = 10U" in sv_gate - and "check_no_intermitttent_local_at_start()" in sv_tests, - "LOCAL REF startup must require ten clean real epochs and immediately revoke on faults") + and "kWarmRequiredLiveEpochs = 3U" in sv_gate + and "kMaxWarmMacAcquisitionEpochs = 8U" in sv_gate + and "if (had_mac_evidence_) reset();" in sv_gate + and "check_no_intermitttent_local_at_start()" in sv_tests + and "check_warm_phase_preflight_cannot_fake_canonical_mac()" in sv_tests + and "check_warm_preflight_negative_session_and_clock_faults()" in sv_tests, + "LOCAL REF: ten LIVE epochs for COLD, ten stable phase-only PREFLIGHT epochs " + "plus three verified LIVE MAC epochs for WARM; invalidate on loss of evidence") phase_header = (project_root / "include/ariec61850/time_sync/sv_ptp_phase_authority.hpp").read_text(encoding="utf-8") phase_tests = (project_root / "tests/test_sv_ptp_phase_authority.cpp").read_text(encoding="utf-8") require("g_preflight_phase_clock_active" in firmware_source From 6a85ee723e9674d2fbfa55e0325ccb96dc5411d1 Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:21:49 +0700 Subject: [PATCH 10/11] fix(studio): distinguish forced firmware STOP and lease expiry from operator STOP ACK --- apps/arstack_studio/src/DeviceController.cpp | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-) diff --git a/apps/arstack_studio/src/DeviceController.cpp b/apps/arstack_studio/src/DeviceController.cpp index 8bf0b883f..bcdf1af98 100644 --- a/apps/arstack_studio/src/DeviceController.cpp +++ b/apps/arstack_studio/src/DeviceController.cpp @@ -1934,11 +1934,26 @@ void DeviceController::processLine(const QString& rawLine) { // Never report 4I+4V output RUNNING merely because PTP START succeeded. // Bare/unmatched START text is never evidence of a verified 8-channel START. if (line.contains(QStringLiteral("STOP accepted: SV transmission suppressed"), Qt::CaseInsensitive)) { + // Firmware may emit this prefix for a forced publisher shutdown. + // Never mislabel a fail-safe board-originated STOP as an operator ACK. + const bool forced = line.contains(QStringLiteral("fail-closed runtime"), + Qt::CaseInsensitive); appendLog(QStringLiteral("SVTX"), QStringLiteral( - "STOP_ACK_OBSERVED session=%1 boot=%2 prior_running=%3") + "%1 session=%2 boot=%3 prior_running=%4") + .arg(forced ? QStringLiteral("RUNTIME_FAIL_SAFE_STOP_OBSERVED") + : QStringLiteral("STOP_ACK_OBSERVED")) .arg(sessionGeneration_).arg(identity_.bootId).arg(running_ ? 1 : 0)); setRunning(false); } + if (line.contains(QStringLiteral("Control session lease expired"), Qt::CaseInsensitive) || + line.contains(QStringLiteral("Control session heartbeat could not rearm"), Qt::CaseInsensitive) || + line.contains(QStringLiteral("SV transport fault:"), Qt::CaseInsensitive)) { + // Real firmware-originated reasons survive any later STATE=STOPPED + // poll; the GUI must not attribute these events to the operator. + appendLog(QStringLiteral("SVTX"), QStringLiteral( + "FIRMWARE_STOP_CAUSE session=%1 boot=%2 detail=%3") + .arg(sessionGeneration_).arg(identity_.bootId).arg(line)); + } auto match = kStateExpression.match(line); if (match.hasMatch()) { From d21d66e2872de4cd2423fce78efd0bb7e677d3bc Mon Sep 17 00:00:00 2001 From: Ari Sulistiono Date: Wed, 21 Oct 2026 07:22:16 +0700 Subject: [PATCH 11/11] test(studio): distinguish physical lease/fail-safe STOP from operator STOP ACK --- .../src/DeterministicSessionHarness.cpp | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/apps/arstack_studio/src/DeterministicSessionHarness.cpp b/apps/arstack_studio/src/DeterministicSessionHarness.cpp index d849083a9..b8adce749 100644 --- a/apps/arstack_studio/src/DeterministicSessionHarness.cpp +++ b/apps/arstack_studio/src/DeterministicSessionHarness.cpp @@ -63,6 +63,7 @@ class DeterministicSessionHarness final { {"PTP STOP full queue uses bounded priority slot", ptpSafetyStopBypassesFullQueue()}, {"SV STOP remains responsive with full command queue", svPriorityStopBypassesFullQueue()}, {"control lease heartbeat coalesces outside saturated exclusive queue", heartbeatKeepsBoundedSafetySlotUnderExclusiveLoad()}, + {"board fail-safe STOP is not mislabelled as operator STOP ACK", forcedFirmwareStopRetainsCauseAndIsNotOperatorAck()}, {"PTP STOP requires firmware ACK and stopped readback", ptpStopConfirmationCannotBeGuessed()}, {"PTP STOP timeout blocks restart pending manual recovery", ptpUnverifiedStopBlocksRestart()}, {"App teardown must stop PTP without SV output", ptpOnlyShutdownIntent()}, @@ -979,6 +980,23 @@ class DeterministicSessionHarness final { return cancelled && worker.svStopPending_ && worker.commandQueue_.isEmpty(); } + static bool forcedFirmwareStopRetainsCauseAndIsNotOperatorAck() { + Fixture f; + auto& d = f.device; + d.processLine(QStringLiteral( + "STOP accepted: SV transmission suppressed by fail-closed runtime")); + if (!d.logText_.contains(QStringLiteral("RUNTIME_FAIL_SAFE_STOP_OBSERVED")) || + d.logText_.contains(QStringLiteral("STOP_ACK_OBSERVED"))) + return false; + d.processLine(QStringLiteral( + "Control session lease expired after 2500 ms; SV transmission stopped")); + if (!d.logText_.contains(QStringLiteral("FIRMWARE_STOP_CAUSE")) || + !d.logText_.contains(QStringLiteral("lease expired"))) + return false; + d.processLine(QStringLiteral("STOP accepted: SV transmission suppressed")); + return d.logText_.contains(QStringLiteral("STOP_ACK_OBSERVED")); + } + static bool heartbeatKeepsBoundedSafetySlotUnderExclusiveLoad() { DeviceIoWorker worker; // Normal 64-command FIFO is saturated by an exclusive CFG batch.