fix(agent+web): honest script durations — runtime vs IME reporting latency, live counter for platform scripts

Remediation rows showed "8m" for scripts that ran seconds: durationSeconds was measured HS-SCRIPT-START -> HS-NEW-RESULT, and IME writes that line only after its batched service report. The early-signal (HS-COMPLIANCE) completion carried no duration at all because it never read the cycle-start map. Agent: - HS-COMPLIANCE early-signal completions now PEEK _healthScriptStartTimes and emit the actual run time (durationBasis=script_runtime); HS-NEW-RESULT keeps consuming the entry and stamps its phases cycle_including_reporting_latency. - durationBasis now comes from the emitting handler (ScriptExecutionState. DurationBasis) instead of pauschal per scriptType. - Platform scripts emit the live script_started signal too (gated on pending- slot creation so the duplicate agentexecutor+ime start line stays one signal). Web: - Reducer normalizes durationBasis: runtime -> durationSeconds, cycle -> reportedAfterSeconds (legacy events without basis infer from scriptType, so old remediation cycle values are never displayed as run time again). - Dedupe merges both timings across the early/late emissions instead of dropping the runtime when the more complete HS-NEW-RESULT entry wins. - Card run time = max of phase runtimes; "Reported after Xm" shown in the expanded Details strip (per UX decision), never on the compact row. Inert for new events until agent redeploy; web deploy alone already fixes the misleading display of stored data. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-10-24 12:42:38 +00:00 · 2026-07-09 19:20:12 +02:00
parent 831bd1f37b
commit 7afa03aaf1
9 changed files with 383 additions and 35 deletions
@@ -0,0 +1,110 @@
+using System;
+using System.Collections.Generic;
+using System.IO;
+using AutopilotMonitor.Agent.V2.Core.Logging;
+using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
+using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
+using AutopilotMonitor.Shared.Models;
+using Newtonsoft.Json;
+using Xunit;
+
+namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
+{
+    /// <summary>
+    /// Platform scripts emit the same live <c>OnScriptStarted</c> signal health scripts always
+    /// had, so the UI shows a running indicator for them too. The start line fires twice per
+    /// execution (agentexecutor + ime source), so the signal is gated on pending-slot creation —
+    /// exactly once per execution, re-armed after the execution completes.
+    /// </summary>
+    public sealed class ImeLogTrackerPlatformScriptStartedTests
+    {
+        private static readonly string[] RequiredPatternIds =
+        {
+            "PS-AGENT-INVOCATION", "PS-AGENT-SCRIPT-START", "PS-SCRIPT-RESULT",
+        };
+
+        // Same shipped-pattern loading approach as ImeLogTrackerPlatformScriptContaminationTests:
+        // guard the real regex contract rather than a stale inline copy.
+        private static List<ImeLogPattern> ScriptPatterns()
+        {
+            var dir = FindRulesPatternDir();
+            var byId = new Dictionary<string, ImeLogPattern>(StringComparer.OrdinalIgnoreCase);
+            foreach (var file in Directory.GetFiles(dir, "*.json"))
+            {
+                var pattern = JsonConvert.DeserializeObject<ImeLogPattern>(File.ReadAllText(file));
+                if (pattern?.PatternId != null)
+                    byId[pattern.PatternId] = pattern;
+            }
+
+            var result = new List<ImeLogPattern>();
+            foreach (var id in RequiredPatternIds)
+            {
+                Assert.True(byId.TryGetValue(id, out var p),
+                    $"Shipped IME pattern '{id}' not found under {dir}.");
+                result.Add(p!);
+            }
+            return result;
+        }
+
+        private static string FindRulesPatternDir()
+        {
+            var dir = new DirectoryInfo(AppContext.BaseDirectory);
+            while (dir != null)
+            {
+                var candidate = Path.Combine(dir.FullName, "rules", "ime-log-patterns");
+                if (Directory.Exists(candidate)) return candidate;
+                dir = dir.Parent;
+            }
+            throw new DirectoryNotFoundException(
+                $"Could not locate rules/ime-log-patterns walking up from {AppContext.BaseDirectory}");
+        }
+
+        private const string PlatformId = "c3e0124c-4936-4bfd-afcc-c7fe1d84d104";
+
+        private const string PlatformStartLine =
+            @"Adding argument powershell with value C:\Program Files (x86)\Microsoft Intune Management Extension\Policies\Scripts\00000000-0000-0000-0000-000000000000_c3e0124c-4936-4bfd-afcc-c7fe1d84d104.ps1 to the named argument list.";
+
+        private const string PlatformResultLine =
+            "[PowerShell] User Id = 00000000-0000-0000-0000-000000000000, " +
+            "Policy id = " + PlatformId + ", policy result = Success";
+
+        [Fact]
+        public void Platform_start_emits_OnScriptStarted_once_per_execution()
+        {
+            using var tmp = new TempDirectory();
+            var started = new List<ScriptStartedInfo>();
+            var tracker = new ImeLogTracker(tmp.Path, ScriptPatterns(), new AgentLogger(tmp.Path, AgentLogLevel.Info));
+            tracker.OnScriptStarted = info => started.Add(info);
+
+            tracker.ProcessLogMessageForTest("ExecutorLog AgentExecutor gets invoked");
+            tracker.ProcessLogMessageForTest(PlatformStartLine);
+            // Duplicate start line for the same execution (the line fires from both the
+            // agentexecutor and the ime source) — must NOT emit a second started signal.
+            tracker.ProcessLogMessageForTest(PlatformStartLine);
+
+            var info = Assert.Single(started);
+            Assert.Equal(PlatformId, info.PolicyId);
+            Assert.Equal("platform", info.ScriptType);
+        }
+
+        [Fact]
+        public void Platform_rerun_after_completion_emits_OnScriptStarted_again()
+        {
+            using var tmp = new TempDirectory();
+            var started = new List<ScriptStartedInfo>();
+            var tracker = new ImeLogTracker(tmp.Path, ScriptPatterns(), new AgentLogger(tmp.Path, AgentLogLevel.Info));
+            tracker.OnScriptStarted = info => started.Add(info);
+
+            // Run 1: start → authoritative result (removes the pending slot).
+            tracker.ProcessLogMessageForTest("ExecutorLog AgentExecutor gets invoked");
+            tracker.ProcessLogMessageForTest(PlatformStartLine);
+            tracker.ProcessLogMessageForTest(PlatformResultLine);
+
+            // Run 2 (IME re-evaluation of the same policy) begins a new execution.
+            tracker.ProcessLogMessageForTest("ExecutorLog AgentExecutor gets invoked");
+            tracker.ProcessLogMessageForTest(PlatformStartLine);
+
+            Assert.Equal(2, started.Count);
+        }
+    }
+}
@@ -164,6 +164,52 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters

            var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
            Assert.Equal("65.00", info.Payload!["durationSeconds"]);
+            // HS-NEW-RESULT is written only after IME's batched report to the service, so this
+            // value overstates the script run time — the basis names that so consumers (Web
+            // "Reported after", MCP) never display it as the run time.
+            Assert.Equal("cycle_including_reporting_latency", info.Payload["durationBasis"]);
+        }
+
+        [Fact]
+        public void HealthScriptDetection_early_signal_emits_runtime_duration_and_keeps_cycle_start()
+        {
+            using var f = new ImeLogTrackerAdapterFixture(T0);
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+
+            // Detection script started 20s ago; the HS-COMPLIANCE line is logged right after the
+            // script exits, so the early-signal completion carries the ACTUAL run time.
+            f.Tracker.SeedHealthScriptStartForTesting(
+                "75d14a95-d49f-473d-9d65-d4b006bc7468", T0.AddSeconds(-20));
+            f.Tracker.HandleHealthScriptDetectionResultForTest(
+                "75d14a95-d49f-473d-9d65-d4b006bc7468", "True", "pre");
+
+            var early = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
+            Assert.Equal("20.00", early.Payload!["durationSeconds"]);
+            Assert.Equal("script_runtime", early.Payload["durationBasis"]);
+
+            // The early signal must only PEEK the cycle start — the consolidated HS-NEW-RESULT
+            // arriving 45s later still times the whole cycle from the same start (65s total).
+            f.Clock.Advance(TimeSpan.FromSeconds(45));
+            f.Tracker.HandleHealthScriptResultJson(DetectOnlyResultJson);
+
+            var all = f.InfoEvents(SharedEventTypes.ScriptCompleted);
+            Assert.Equal(2, all.Count);
+            Assert.Equal("65.00", all[1].Payload!["durationSeconds"]);
+            Assert.Equal("cycle_including_reporting_latency", all[1].Payload["durationBasis"]);
+        }
+
+        [Fact]
+        public void HealthScriptDetection_early_signal_without_observed_start_omits_duration()
+        {
+            using var f = new ImeLogTrackerAdapterFixture(T0);
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+
+            f.Tracker.HandleHealthScriptDetectionResultForTest(
+                "75d14a95-d49f-473d-9d65-d4b006bc7468", "True", "pre");
+
+            var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
+            Assert.False(info.Payload!.ContainsKey("durationSeconds"));
+            Assert.False(info.Payload.ContainsKey("durationBasis"));
        }

        [Fact]
@@ -227,6 +227,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
                        // source) but the earliest wins.
                        StartedAtUtc = LastMatchedLogTimestamp ?? DateTime.UtcNow,
                    };
+                    // Live "running" indicator — same signal health scripts emit. Gated on slot
+                    // creation so the duplicate start line (agentexecutor + ime source) doesn't
+                    // double-emit for the same execution.
+                    try { OnScriptStarted?.Invoke(new ScriptStartedInfo { PolicyId = id, ScriptType = "platform" }); }
+                    catch (Exception ex) { _logger.Warning($"ImeLogTracker: OnScriptStarted handler threw: {ex.Message}"); }
                }
                _lastPlatformScriptPolicyId = id;
                // Started lines fire twice per script (agentexecutor + ime source) and carry no
@@ -624,6 +629,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
                RunContext = runContext,
                Stdout = stdout,
                Stderr = stderr,
+                // The compliance line is logged right after the (pre/post) detection script
+                // exits, so cycle-start → this line is the actual execution time — unlike the
+                // HS-NEW-RESULT path whose end stamp includes IME's batched reporting latency.
+                // Peek only: HS-NEW-RESULT still consumes + removes the entry for cycle timing.
+                StartedAtUtc = _healthScriptStartTimes.TryGetValue(id, out var earlyStart)
+                    ? earlyStart
+                    : (DateTime?)null,
+                DurationBasis = "script_runtime",
            };

            _logger.Info($"ImeLogTracker: health-script {scriptPart} early-signal for {id}: " +
@@ -866,7 +879,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
                ErrorDetails = errorDetails,
                // Cycle start (HS-SCRIPT-START). Every phase carries the same cycle start so the
                // adapter computes the total run duration; the Web surfaces it once at card level.
-                StartedAtUtc = startedAtUtc
+                StartedAtUtc = startedAtUtc,
+                // End stamp is the HS-NEW-RESULT line — written only after IME's batched report
+                // to the service, so this duration overstates the actual script execution time.
+                DurationBasis = "cycle_including_reporting_latency"
            };

        private static string TryGetString(JsonElement parent, string name)
@@ -88,13 +88,26 @@ public class ScriptExecutionState

    /// <summary>Top-level <c>Info.ErrorDetails</c> string from the <c>[HS] new result</c> JSON.</summary>
    public string ErrorDetails { get; set; }
+
+    /// <summary>
+    /// Semantics of the duration derived from <see cref="StartedAtUtc"/> → completion, surfaced
+    /// as <c>durationBasis</c> next to <c>durationSeconds</c> on the emitted event:
+    /// <c>"script_runtime"</c> — completion stamp is the script's own end signal (platform
+    /// PS-SCRIPT-RESULT / AgentExecutor exit, or the health-script HS-COMPLIANCE line logged
+    /// right after the detection script exits); <c>"cycle_including_reporting_latency"</c> —
+    /// completion stamp is the HS-NEW-RESULT line, which IME only writes after its batched
+    /// report to the Microsoft service (30 s – minutes after the scripts actually finished),
+    /// so the value systematically overstates the run time. Set by the emitting handler; when
+    /// null the adapter falls back to the scriptType-based default (remediation → cycle).
+    /// </summary>
+    public string DurationBasis { get; set; }
 }

 /// <summary>
-/// Lightweight live-progress signal emitted when IME logs the start of a script
-/// (currently only health scripts via the <c>HS-SCRIPT-START</c> pattern).
-/// Gives the UI a "running" indicator before the consolidated final result arrives
-/// (which may be 30 s – 3 min later).
+/// Lightweight live-progress signal emitted when IME logs the start of a script —
+/// health scripts via the <c>HS-SCRIPT-START</c> pattern, platform scripts on
+/// pending-slot creation from their start line. Gives the UI a "running" indicator
+/// before the final result arrives (health scripts: 30 s – 3 min later).
 /// </summary>
 public class ScriptStartedInfo
 {
@@ -849,19 +849,22 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
            // against clock skew between the (possibly clock-derived) completion stamp and start.
            //
            // L19 (delta review 2026-07-02): the same field name carries two different semantics —
-            // platform scripts measure start→result (≈ script runtime), remediation scripts measure
-            // HS-SCRIPT-START→HS-NEW-RESULT (the whole cycle INCLUDING IME's 30 s–3 min batched
-            // reporting latency, i.e. systematically longer than the script ran). `durationBasis`
-            // names which one applies so downstream consumers never compare the two as equals.
+            // start→own-end-signal (≈ script runtime) vs HS-SCRIPT-START→HS-NEW-RESULT (the whole
+            // cycle INCLUDING IME's 30 s–3 min batched reporting latency, i.e. systematically
+            // longer than the script ran). `durationBasis` names which one applies so downstream
+            // consumers never compare the two as equals. The emitting handler stamps the basis on
+            // the state (health-script early-signal completions are script_runtime too); the
+            // scriptType fallback covers states from paths that predate the field.
            if (script.StartedAtUtc.HasValue)
            {
                var durationSeconds = (now - script.StartedAtUtc.Value).TotalSeconds;
                if (durationSeconds >= 0)
                {
                    data["durationSeconds"] = durationSeconds.ToString("F2", culture);
-                    data["durationBasis"] = IsRemediation(script.ScriptType)
-                        ? "cycle_including_reporting_latency"
-                        : "script_runtime";
+                    data["durationBasis"] = script.DurationBasis
+                        ?? (IsRemediation(script.ScriptType)
+                            ? "cycle_including_reporting_latency"
+                            : "script_runtime");
                }
            }

@@ -1 +1 @@
-1279
+1281
@@ -191,8 +191,10 @@ function ScriptCardView({ card, showScriptOutput, latestBootstrapVersion, displa
  const remediationStatusLabel = mapRemediationStatus(remediationStatus);
  const cardDisplayName = lookupScriptDisplayName(displayNamesByRefKey, card.scriptType, card.policyId);

-  // Whole-cycle run duration (HS-SCRIPT-START → HS-NEW-RESULT). Shown once on the header so the
-  // user sees how long the remediation ran without the same number repeated on every phase row.
+  // Actual cycle run time (max of the phases' cumulative script_runtime durations). Shown once
+  // on the header so the user sees how long the remediation ran without the same number repeated
+  // on every phase row. The reporting-latency-inflated cycle value lives in the phase details
+  // ("Reported after"), never here.
  const cardDurationLabel = formatScriptDuration(card.durationSeconds);
  const isCardSlow = card.durationSeconds != null && card.durationSeconds >= STALE_RUNNING_THRESHOLD_SECONDS;

@@ -335,12 +337,16 @@ function ScriptItemRow({ item, showScriptOutput, latestBootstrapVersion, nested,
    statusText = item.result ?? (item.state === "Success" ? "Success" : "Failed");
  }

-  // Run duration (from the agent's start→completion timing). Surfaced for every completed
-  // script so slow / inefficient scripts stand out; styled amber past the stale threshold
-  // (10 min) since at that range a script is a plausible enrollment-pipeline blocker. Suppressed
-  // on nested phase rows: a remediation cycle's phases all carry the same whole-cycle duration,
-  // which is shown once on the parent card header instead of repeated on each phase.
+  // Actual run time (from the agent's start → own-end-signal timing). Surfaced for every
+  // completed script so slow / inefficient scripts stand out; styled amber past the stale
+  // threshold (10 min) since at that range a script is a plausible enrollment-pipeline blocker.
+  // Suppressed on nested phase rows' compact line — the parent card header already shows the
+  // cycle run time — but still listed in each phase's details panel alongside "Reported after"
+  // (the cycle value inflated by IME's batched reporting latency, kept out of the compact row
+  // so it is never mistaken for the run time).
  const durationLabel = item.state !== "Running" && !nested ? formatScriptDuration(item.durationSeconds) : null;
+  const detailDurationLabel = item.state !== "Running" ? formatScriptDuration(item.durationSeconds) : null;
+  const reportedAfterLabel = item.state !== "Running" ? formatScriptDuration(item.reportedAfterSeconds) : null;
  const isSlowDuration = item.durationSeconds != null && item.durationSeconds >= STALE_RUNNING_THRESHOLD_SECONDS;

  const hasStdout = item.state !== "Running" && showScriptOutput !== false && item.stdout && item.stdout.trim().length > 0;
@@ -473,7 +479,12 @@ function ScriptItemRow({ item, showScriptOutput, latestBootstrapVersion, nested,
            {!nested && item.runContext && <span><span className="font-medium text-gray-700">Context:</span> {item.runContext}</span>}
            {!nested && item.targetType != null && <span><span className="font-medium text-gray-700">Target:</span> {item.targetType === 2 ? "Device" : "User"}</span>}
            {item.exitCode != null && <span><span className="font-medium text-gray-700">Exit Code:</span> <span className="font-mono">{item.exitCode}</span></span>}
-            {durationLabel && <span><span className="font-medium text-gray-700">Duration:</span> <span className={`font-mono ${isSlowDuration ? "text-amber-600" : ""}`}>{durationLabel}</span></span>}
+            {detailDurationLabel && <span><span className="font-medium text-gray-700">Duration:</span> <span className={`font-mono ${isSlowDuration ? "text-amber-600" : ""}`}>{detailDurationLabel}</span></span>}
+            {reportedAfterLabel && (
+              <span title="Time from script start until IME reported the result to the Intune service — includes IME's batched reporting delay, so it is longer than the script actually ran">
+                <span className="font-medium text-gray-700">Reported after:</span> <span className="font-mono">{reportedAfterLabel}</span>
+              </span>
+            )}
            {item.result && <span><span className="font-medium text-gray-700">Result:</span> {item.result}</span>}
            {item.complianceResult && <span><span className="font-medium text-gray-700">Compliance:</span> {item.complianceResult === "True" ? "Compliant" : "Non-compliant"}</span>}
            {!nested && remediationStatusLabel && <span><span className="font-medium text-gray-700">Status:</span> {remediationStatusLabel}</span>}
@@ -798,4 +798,110 @@ describe("reduceScriptEvents — durationSeconds", () => {
    ]);
    expect(item.durationSeconds).toBeUndefined();
  });
+
+  // ── durationBasis normalization: run time vs "reported after" (cycle incl. IME latency) ──
+  it("platform durations stay run time (no reportedAfter) — legacy events without a basis field", () => {
+    const [item] = reduceScriptEvents([
+      finalEvent({ data: { policyId: "p1", scriptType: "platform", result: "Success", durationSeconds: "42.00" } }),
+    ]);
+    expect(item.durationSeconds).toBe(42);
+    expect(item.reportedAfterSeconds).toBeUndefined();
+  });
+
+  it("legacy remediation duration (no basis field) is treated as reportedAfter, NOT run time", () => {
+    // Pre-basis agents measured remediation durations to the HS-NEW-RESULT line, which IME
+    // only writes after its batched service report — displaying that as run time was the
+    // user-reported "script ran seconds, list says 8m" bug. Old data must never regress.
+    const [item] = reduceScriptEvents([
+      finalEvent({
+        data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection",
+                exitCode: "1", complianceResult: "False", durationSeconds: "480.00" },
+      }),
+    ]);
+    expect(item.durationSeconds).toBeUndefined();
+    expect(item.reportedAfterSeconds).toBe(480);
+  });
+
+  it("remediation duration with basis script_runtime (early-signal emission) is real run time", () => {
+    const [item] = reduceScriptEvents([
+      finalEvent({
+        data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection",
+                exitCode: "0", complianceResult: "True",
+                durationSeconds: "20.00", durationBasis: "script_runtime" },
+      }),
+    ]);
+    expect(item.durationSeconds).toBe(20);
+    expect(item.reportedAfterSeconds).toBeUndefined();
+  });
+
+  it("explicit cycle basis routes the value to reportedAfterSeconds (snake_case too)", () => {
+    const [item] = reduceScriptEvents([
+      finalEvent({
+        data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection",
+                exit_code: "0", compliance_result: "True",
+                duration_seconds: "95.00", duration_basis: "cycle_including_reporting_latency" },
+      }),
+    ]);
+    expect(item.durationSeconds).toBeUndefined();
+    expect(item.reportedAfterSeconds).toBe(95);
+  });
+
+  it("dedupe merges the early-signal run time with the late HS-NEW-RESULT reportedAfter", () => {
+    // The two-stage remediation emission: early HS-COMPLIANCE carries the run time, the
+    // later (more complete) HS-NEW-RESULT carries the cycle value. The completeness winner
+    // must keep BOTH timings — dropping the run time was the "counter said 20s, list says
+    // 8m" mismatch.
+    const [item] = reduceScriptEvents([
+      finalEvent({
+        eventType: "script_completed", ts: 0,
+        data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection",
+                exitCode: "0", complianceResult: "True",
+                durationSeconds: "20.00", durationBasis: "script_runtime" },
+      }),
+      finalEvent({
+        eventType: "script_completed", ts: 74,
+        data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection",
+                exitCode: "0", complianceResult: "True",
+                stdout: "LocalAdminIsEnabled=False",
+                remediationStatus: "4", targetType: "2", runContext: "System",
+                durationSeconds: "94.00", durationBasis: "cycle_including_reporting_latency" },
+      }),
+    ]);
+    // Late event wins on completeness (stdout, remediationStatus, runContext)…
+    expect(item.stdout).toBe("LocalAdminIsEnabled=False");
+    expect(item.remediationStatus).toBe(4);
+    // …but the early run time survives the merge alongside the cycle value.
+    expect(item.durationSeconds).toBe(20);
+    expect(item.reportedAfterSeconds).toBe(94);
+  });
+});
+
+describe("groupScriptItems — card durationSeconds is the max phase run time", () => {
+  const item = (overrides: Partial<ScriptItem>): ScriptItem => ({
+    policyId: "p1",
+    scriptType: "remediation",
+    state: "Success",
+    timestamp: ts(0),
+    ...overrides,
+  });
+
+  it("multi-phase cycle takes the max (phase runtimes are cumulative from the cycle start)", () => {
+    const cards = groupScriptItems([
+      item({ scriptPart: "detection", complianceResult: "False", exitCode: 1, remediationStatus: 2, durationSeconds: 8, timestamp: ts(0) }),
+      item({ scriptPart: "remediation", exitCode: 0, remediationStatus: 2, reportedAfterSeconds: 300, timestamp: ts(1) }),
+      item({ scriptPart: "post-detection", complianceResult: "True", exitCode: 0, remediationStatus: 2, durationSeconds: 25, timestamp: ts(2) }),
+    ]);
+    expect(cards[0].isCycle).toBe(true);
+    expect(cards[0].durationSeconds).toBe(25);
+  });
+
+  it("phases with only reportedAfterSeconds contribute nothing to the card run time", () => {
+    // Legacy cycle: every phase carried only the reporting-latency-inflated value → the
+    // header shows no run time at all (the details panels still show "Reported after").
+    const cards = groupScriptItems([
+      item({ scriptPart: "detection", complianceResult: "False", exitCode: 1, remediationStatus: 3, reportedAfterSeconds: 480, timestamp: ts(0) }),
+      item({ scriptPart: "post-detection", complianceResult: "False", exitCode: 1, remediationStatus: 3, reportedAfterSeconds: 480, timestamp: ts(2) }),
+    ]);
+    expect(cards[0].durationSeconds).toBeUndefined();
+  });
 });
@@ -27,12 +27,22 @@ export interface ScriptItem {
  stdout?: string;
  stderr?: string;
  /**
-   * Observed run duration in seconds (start line → completion), surfaced by the agent on
-   * every platform-script completion. Lets the UI flag slow / inefficient scripts. Absent
-   * when the agent never saw the script's start line (e.g. a completion observed on replay
-   * without a matching start).
+   * Actual script run time in seconds (start line → the script's own end signal). Only
+   * populated from events whose durationBasis is "script_runtime" — platform scripts and
+   * health-script early-signal (HS-COMPLIANCE) completions. Absent when the agent never
+   * saw the start line, or when only the cycle-basis value is known (see
+   * reportedAfterSeconds).
   */
  durationSeconds?: number;
+  /**
+   * Whole-cycle duration in seconds measured to the HS-NEW-RESULT line, which IME only
+   * writes after its batched report to the Microsoft service — systematically longer than
+   * the scripts actually ran (30 s – minutes of reporting latency). Populated from events
+   * with durationBasis "cycle_including_reporting_latency" (and from legacy remediation
+   * events that predate the basis field, which measured the same span). Shown as
+   * "Reported after Xm" in the details panel, never as the run duration.
+   */
+  reportedAfterSeconds?: number;
  state: "Running" | "Success" | "Failed";
  timestamp: string;
  bootstrapVersion?: string | null;
@@ -91,10 +101,11 @@ export interface ScriptCard {
  /** First-phase timestamp; used for sorting cards chronologically in the UI. */
  timestamp: string;
  /**
-   * Cycle-level run duration in seconds. For platform / single-phase cards this is the lone
-   * phase's duration; for multi-phase remediation cycles every phase event carries the same
-   * whole-cycle duration (HS-SCRIPT-START → HS-NEW-RESULT), so we lift it once onto the card
-   * header rather than repeating it on each nested phase row. Absent when no phase reported one.
+   * Card-level actual run time in seconds. Phases carry cumulative script_runtime durations
+   * measured from the same cycle start (detection ≤ post-detection), so the max across
+   * phases is the execution time through the latest observed phase. Shown once on the card
+   * header rather than repeated on each nested phase row. Absent when no phase reported a
+   * runtime-basis duration (e.g. legacy events that only carried the cycle-basis value).
   */
  durationSeconds?: number;
 }
@@ -123,6 +134,7 @@ function dataCompleteness(item: ScriptItem): number {
  if (item.stderr && item.stderr.length > 0) score += 1;
  if (item.runContext) score += 1;
  if (item.durationSeconds != null) score += 1;
+  if (item.reportedAfterSeconds != null) score += 1;
  return score;
 }

@@ -239,7 +251,24 @@ export function reduceScriptEvents(events: ScriptInputEvent[]): ScriptItem[] {
    if (policyId) policyIdsWithFinal.add(`${policyId}-${scriptType}`);

    const exitCode = toNumber(d.exitCode ?? d.exit_code);
-    const durationSeconds = toNumber(d.durationSeconds ?? d.duration_seconds);
+
+    // Duration normalization — the wire field durationSeconds carries two different
+    // semantics, named by durationBasis (see the ScriptItem field docs):
+    //   "script_runtime"                     → actual run time → durationSeconds
+    //   "cycle_including_reporting_latency"  → HS-NEW-RESULT stamp incl. IME's batched
+    //                                          reporting delay → reportedAfterSeconds
+    // Legacy events predate the basis field: platform durations were always measured to
+    // the script's own result line (runtime), remediation durations to HS-NEW-RESULT
+    // (cycle) — infer accordingly so old data is never displayed as run time when it
+    // isn't one.
+    const rawDuration = toNumber(d.durationSeconds ?? d.duration_seconds);
+    const rawBasis = d.durationBasis ?? d.duration_basis;
+    const isCycleBasis = typeof rawBasis === "string"
+      ? rawBasis === "cycle_including_reporting_latency"
+      : scriptType === "remediation";
+    const durationSeconds = isCycleBasis ? undefined : rawDuration;
+    const reportedAfterSeconds = isCycleBasis ? rawDuration : undefined;
+
    const remediationStatus = toNumber(d.remediationStatus ?? d.remediation_status);
    const targetType = toNumber(d.targetType ?? d.target_type);
    const errorCode = toNumber(d.errorCode ?? d.error_code);
@@ -277,14 +306,24 @@ export function reduceScriptEvents(events: ScriptInputEvent[]): ScriptItem[] {
      stdout,
      stderr,
      durationSeconds,
+      reportedAfterSeconds,
      state: isFailureSignal ? "Failed" : "Success",
      timestamp: evt.timestamp,
      bootstrapVersion: scriptType === "platform" ? extractBootstrapVersion(stdout) : null,
    };

+    // Keep the most-complete entry, but merge the duration fields across both: the
+    // early-signal emission carries the runtime, the later HS-NEW-RESULT emission the
+    // cycle value — whichever entry wins on completeness must not drop the other's timing.
    const existing = finalsByKey.get(key);
-    if (!existing || dataCompleteness(candidate) > dataCompleteness(existing)) {
+    if (!existing) {
      finalsByKey.set(key, candidate);
+    } else {
+      const winner = dataCompleteness(candidate) > dataCompleteness(existing) ? candidate : existing;
+      const loser = winner === candidate ? existing : candidate;
+      winner.durationSeconds ??= loser.durationSeconds;
+      winner.reportedAfterSeconds ??= loser.reportedAfterSeconds;
+      finalsByKey.set(key, winner);
    }
  }

@@ -488,10 +527,14 @@ export function groupScriptItems(items: ScriptItem[]): ScriptCard[] {
        : (first.result ?? (first.state === "Failed" ? "Failed" : "Success"));
    }

-    // Cycle-level duration: phases of a remediation cycle all carry the same whole-cycle
-    // duration, so the first defined value is representative. Platform / single-phase cards
-    // inherit their lone phase's duration (rendered on the row itself, not the header).
-    const cardDuration = phases.map(p => p.durationSeconds).find(d => d != null);
+    // Card-level run time: phase runtimes are cumulative from the same cycle start
+    // (detection ≤ post-detection), so the max is the execution time through the latest
+    // observed phase. Platform / single-phase cards inherit their lone phase's duration
+    // (rendered on the row itself, not the header).
+    const phaseDurations = phases
+      .map(p => p.durationSeconds)
+      .filter((d): d is number => d != null);
+    const cardDuration = phaseDurations.length > 0 ? Math.max(...phaseDurations) : undefined;

    cards.push({
      policyId: first.policyId,