fix(p0): warm AUTO SV sync, non-starving lease heartbeat and Studio lifecycle evidence

apps/arstack_studio/src/DeterministicSessionHarness.cpp

@@ -62,6 +62,8 @@ 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()},
+            {"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()},
@@ -978,6 +980,47 @@ 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.
+        // 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) {

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<void>(sendCommand(QStringLiteral("STOP")));
     setError(message);
 }
@@ -1797,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;
@@ -1854,6 +1870,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 +1886,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 +1921,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 +1933,41 @@ 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)) {
+        // 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(
+            "%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()) {
         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();
     }

apps/arstack_studio/src/DeviceIoWorker.cpp

@@ -77,8 +77,7 @@ void DeviceIoWorker::initialize() {
             heartbeatTimer_->stop();
             return;
         }
-        static_cast<void>(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<void>(enqueueCommandsInternal(
-        {QStringLiteral("HEARTBEAT")}, true, false, false));
+    queuePriorityHeartbeat();
     if (!heartbeatTimer_->isActive()) heartbeatTimer_->start();
 }

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<PendingCommand> 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_;
 

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