fix(agent): emit platform-script completion from AgentExecutor exit code when IME result is late

V2 emitted script_completed for platform scripts ONLY on the IME PS-SCRIPT-RESULT
line (IntuneManagementExtension.log). The AgentExecutor.log exit code + stdout merely
filled _pendingPlatformScripts and never emitted on their own. IME logs its policy
result after its batch-send to the service, so scripts that finish shortly before the
(often short) Autopilot enrollment ends were silently dropped — the buffer is neither
persisted nor flushed on dispose. Field-confirmed on session d1da052d: 4 platform
scripts ran, only the long-running one (whose IME result was logged in time) reached
the backend.

Add a deadline-based fallback in the live polling loop: a pending platform script with
a known exit code but no PS-SCRIPT-RESULT within a 15s grace is emitted from the exit
code (0 -> Success, else Failed), tagged resultSource=agentexecutor_fallback so the
provenance is honest. A force pass runs on shutdown. Dedup via _platformScriptResultEmitted
prevents a double emit when the authoritative result arrives after the fallback; a fresh
scriptStarted clears the marker so IME re-evaluations/retries of the same policy emit again.
The fallback event binds to the script's own exit timestamp (not the last-matched line)
and omits the stale patternId.

Reuses script_completed/script_failed (no new event type, no ConfigVersion bump, no MCP
catalog change). V2-only; legacy V1 agent unchanged. 1516/1516 V2.Core tests green.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-06-19 16:32:10 +02:00
parent 1f61f6c4fb
commit 9a0211e17f
6 changed files with 465 additions and 4 deletions
@@ -0,0 +1,189 @@
using System;
using System.Collections.Generic;
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 Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
/// <summary>
/// Regression cover for the AgentExecutor exit-code fallback: platform scripts that complete
/// (exit code captured from AgentExecutor.log) but whose authoritative IME PS-SCRIPT-RESULT
/// line never arrives before the deadline must still surface a completion event — otherwise a
/// device that ran N platform scripts in quick succession surfaces only the one that happened
/// to get its IME result logged in time (field bug, session d1da052d…).
/// </summary>
public sealed class ImeLogTrackerPlatformScriptFallbackTests
{
private static ImeLogTracker BuildTracker(TempDirectory tmp, out List<ScriptExecutionState> emitted)
{
var captured = new List<ScriptExecutionState>();
emitted = captured;
var tracker = new ImeLogTracker(
logFolder: tmp.Path,
patterns: new List<ImeLogPattern>(),
logger: new AgentLogger(tmp.Path, AgentLogLevel.Info));
tracker.OnScriptCompleted = s => captured.Add(s);
return tracker;
}
[Fact]
public void Fallback_emits_completion_when_ime_result_never_arrives()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("dece354a", exitCode: 0, exitObservedAtUtc: observedAt, stdout: "Script start.\nScript end.");
// Well past the grace window — should emit.
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
var script = Assert.Single(emitted);
Assert.Equal("dece354a", script.PolicyId);
Assert.Equal("platform", script.ScriptType);
Assert.Equal(0, script.ExitCode);
Assert.Equal("Success", script.Result);
Assert.Equal("agentexecutor_fallback", script.ResultSource);
Assert.Equal("Script start.\nScript end.", script.Stdout);
}
[Fact]
public void Fallback_holds_until_grace_period_elapses()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("60b43a2e", exitCode: 0, exitObservedAtUtc: observedAt);
// Inside the grace window — IME might still log its result; do not emit yet.
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(5));
Assert.Empty(emitted);
// Past the grace window — emit.
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
Assert.Single(emitted);
}
[Fact]
public void Force_flush_ignores_grace_period()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("846cea22", exitCode: 0, exitObservedAtUtc: observedAt);
// Shutdown flush right after exit — grace not elapsed, but force emits anyway.
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(1), force: true);
Assert.Single(emitted);
}
[Fact]
public void Nonzero_exit_code_emits_failed_result()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("bad5c0de", exitCode: 1, exitObservedAtUtc: observedAt);
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
var script = Assert.Single(emitted);
Assert.Equal(1, script.ExitCode);
Assert.Equal("Failed", script.Result);
Assert.Equal("agentexecutor_fallback", script.ResultSource);
}
[Fact]
public void Script_without_exit_code_is_not_emitted()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
// Started but no exit code yet → still running, must not be emitted even on force flush.
tracker.SeedPendingPlatformScriptForTesting("running", exitCode: null, exitObservedAtUtc: null);
tracker.FlushStalePlatformScriptResults(DateTime.UtcNow, force: true);
Assert.Empty(emitted);
}
[Fact]
public void Real_ime_result_after_fallback_does_not_double_emit()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("dece354a", exitCode: 0, exitObservedAtUtc: observedAt);
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
Assert.Single(emitted);
// IME finally logs its PS-SCRIPT-RESULT line — must NOT produce a second event.
tracker.CompletePlatformScriptFromImeResultForTesting("dece354a", "Success");
Assert.Single(emitted);
}
[Fact]
public void Fallback_event_carries_script_exit_timestamp_for_emit()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("dece354a", exitCode: 0, exitObservedAtUtc: observedAt);
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
// The exit-observed timestamp must travel on the emitted state so the adapter can bind
// the event to it instead of an unrelated "last matched" line parsed during the grace.
var script = Assert.Single(emitted);
Assert.Equal(observedAt, script.ExitObservedAtUtc);
Assert.Equal("agentexecutor_fallback", script.ResultSource);
}
[Fact]
public void Same_policy_can_emit_again_after_a_fresh_run()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var firstRun = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
// Run 1 of policy X — fallback emits.
tracker.SeedPendingPlatformScriptForTesting("policyX", exitCode: 0, exitObservedAtUtc: firstRun);
tracker.FlushStalePlatformScriptResults(firstRun.AddSeconds(20));
Assert.Single(emitted);
// Run 2 of the SAME policy later in the same agent lifetime (IME re-evaluation / retry)
// must NOT be deduped away — the fresh start clears the prior emitted-marker.
var secondRun = firstRun.AddMinutes(30);
tracker.SeedPendingPlatformScriptForTesting("policyX", exitCode: 0, exitObservedAtUtc: secondRun);
tracker.FlushStalePlatformScriptResults(secondRun.AddSeconds(20));
Assert.Equal(2, emitted.Count);
}
[Fact]
public void Ime_result_before_fallback_wins_and_fallback_is_noop()
{
using var tmp = new TempDirectory();
var tracker = BuildTracker(tmp, out var emitted);
var observedAt = new DateTime(2026, 6, 19, 12, 59, 4, DateTimeKind.Utc);
tracker.SeedPendingPlatformScriptForTesting("35ed39d9", exitCode: 0, exitObservedAtUtc: observedAt);
// Authoritative result arrives in time (healthy path).
tracker.CompletePlatformScriptFromImeResultForTesting("35ed39d9", "Success");
var script = Assert.Single(emitted);
Assert.Equal("ime_policy_result", script.ResultSource);
// Later fallback pass must find nothing pending → no duplicate.
tracker.FlushStalePlatformScriptResults(observedAt.AddSeconds(20));
Assert.Single(emitted);
}
}
}
@@ -132,6 +132,63 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
Assert.Equal(sourceTs.ToString("o"), info.Payload!["completedAt"]);
}
[Fact]
public void ScriptCompleted_fallback_binds_to_exit_timestamp_and_drops_stale_patternId()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
// The exit-code fallback emits up to a grace period after the script's exit line, by
// which point an UNRELATED later line is the "last matched" one. The fallback event must
// bind to the script's own exit timestamp and must NOT inherit the stale patternId.
var exitAt = ClockNow.AddMinutes(-3);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-1); // unrelated later line
f.Tracker.LastMatchedPatternId = "UNRELATED-LATER-PATTERN";
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "dece354a",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
ResultSource = "agentexecutor_fallback",
ExitObservedAtUtc = exitAt,
});
var info = f.InfoEvent(SharedEventTypes.ScriptCompleted);
Assert.Equal(exitAt, info.OccurredAtUtc);
Assert.False(info.Payload!.ContainsKey("patternId"));
Assert.Equal("agentexecutor_fallback", info.Payload["resultSource"]);
}
[Fact]
public void ScriptCompleted_authoritative_path_keeps_patternId_and_last_matched_timestamp()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
// Regression guard: the normal IME-result path is unchanged — it still uses the
// last-matched timestamp + patternId (the PS-SCRIPT-RESULT line that drove the emit).
var sourceTs = ClockNow.AddMinutes(-2);
f.Tracker.LastMatchedLogTimestamp = sourceTs;
f.Tracker.LastMatchedPatternId = "PS-SCRIPT-RESULT";
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "35ed39d9",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
ResultSource = "ime_policy_result",
ExitObservedAtUtc = ClockNow.AddMinutes(-30), // present but must be ignored on this path
});
var info = f.InfoEvent(SharedEventTypes.ScriptCompleted);
Assert.Equal(sourceTs, info.OccurredAtUtc);
Assert.Equal("PS-SCRIPT-RESULT", info.Payload!["patternId"]);
Assert.Equal("ime_policy_result", info.Payload["resultSource"]);
}
[Fact]
public void WhiteGloveSealingPattern_uses_source_log_timestamp()
{
@@ -206,6 +206,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// Platform script: AgentExecutor.log entries create/enrich, IME log entries also create
if (!_pendingPlatformScripts.ContainsKey(id))
{
// A fresh start for this policy (no pending entry) begins a NEW execution.
// Clear any emitted-marker from a prior run so IME re-evaluations / retries of
// the same platform-script policy within one agent lifetime are not silently
// deduped away. Within a single run the start always precedes exit/result, so
// this never clears the current run's own marker.
_platformScriptResultEmitted.Remove(id);
_pendingPlatformScripts[id] = new ScriptExecutionState
{
PolicyId = id,
@@ -254,6 +260,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
if (script != null)
{
script.ExitCode = exitCode;
// Stamp when we learned the script's exit code so the deadline-based fallback
// (FlushStalePlatformScriptResults) can fire if IME never logs its authoritative
// PS-SCRIPT-RESULT line in time. Prefer the source CMTrace timestamp (already
// UTC-normalized by the parser) so replayed log content is dated correctly.
if (string.Equals(script.ScriptType, "platform", StringComparison.OrdinalIgnoreCase))
script.ExitObservedAtUtc = LastMatchedLogTimestamp ?? DateTime.UtcNow;
_logger.Debug($"ImeLogTracker: script exit code {exitCode} for {script.PolicyId}");
}
}
@@ -304,6 +316,20 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
if (string.IsNullOrEmpty(id)) return;
// Dedup: the deadline-based fallback (FlushStalePlatformScriptResults) may already have
// emitted this script from its AgentExecutor exit code because IME's authoritative
// PS-SCRIPT-RESULT line arrived late. The fallback carries the same exit code + stdout,
// so re-emitting here would duplicate the timeline entry and inflate counts. Drop the
// now-redundant pending entry and skip.
if (_platformScriptResultEmitted.Contains(id))
{
_logger.Debug($"ImeLogTracker: platform script {id} PS-SCRIPT-RESULT arrived after fallback emit — skipping duplicate");
_pendingPlatformScripts.Remove(id);
if (string.Equals(_lastPlatformScriptPolicyId, id, StringComparison.OrdinalIgnoreCase))
_lastPlatformScriptPolicyId = null;
return;
}
// Merge with pending AgentExecutor data if available
if (!_pendingPlatformScripts.TryGetValue(id, out var script))
{
@@ -315,15 +341,143 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
}
script.Result = result;
script.ResultSource = "ime_policy_result";
_logger.Info($"ImeLogTracker: platform script completed: {id}, result={result}, exit={script.ExitCode}");
EmitScriptEvent(script);
_platformScriptResultEmitted.Add(id);
_pendingPlatformScripts.Remove(id);
if (string.Equals(_lastPlatformScriptPolicyId, id, StringComparison.OrdinalIgnoreCase))
_lastPlatformScriptPolicyId = null;
}
/// <summary>
/// Grace period after a platform script's AgentExecutor exit code is observed before
/// <see cref="FlushStalePlatformScriptResults"/> emits a completion from that exit code.
/// IME logs its authoritative <c>PS-SCRIPT-RESULT</c> line within ~1 s of exit on healthy
/// reporting cycles, so 15 s lets the normal path win virtually always — the fallback is a
/// true safety net for the case where IME has not flushed its batch-send to the Microsoft
/// service before the (often short) Autopilot enrollment ends and the agent terminates.
/// </summary>
private static readonly TimeSpan PlatformScriptResultGrace = TimeSpan.FromSeconds(15);
/// <summary>
/// Policy IDs of platform scripts already emitted (via either the authoritative
/// PS-SCRIPT-RESULT path or the exit-code fallback). Guards against double emission when
/// both fire for the same script.
/// </summary>
private readonly HashSet<string> _platformScriptResultEmitted =
new HashSet<string>(StringComparer.OrdinalIgnoreCase);
/// <summary>
/// Emits a <c>script_completed</c>/<c>script_failed</c> for every pending platform script
/// that has a known AgentExecutor exit code but whose IME <c>PS-SCRIPT-RESULT</c> line has
/// not arrived within <see cref="PlatformScriptResultGrace"/>. Without this, scripts that
/// completed shortly before the agent terminates are silently dropped (the
/// <c>_pendingPlatformScripts</c> buffer is neither persisted nor flushed on dispose), so a
/// device that ran N platform scripts could surface only the long-running one that happened
/// to get its IME result logged in time. Result is derived from the exit code (0 → Success,
/// else Failed) and tagged <c>resultSource=agentexecutor_fallback</c> so the data is honest
/// about its provenance.
/// <para>
/// Runs on the single-threaded polling loop (no locking needed, same as the handlers).
/// <paramref name="force"/> bypasses the grace check for the final pass on shutdown.
/// </para>
/// </summary>
internal void FlushStalePlatformScriptResults(DateTime nowUtc, bool force = false)
{
if (_pendingPlatformScripts.Count == 0) return;
List<string> toRemove = null;
foreach (var kv in _pendingPlatformScripts)
{
var script = kv.Value;
// Already emitted by the authoritative path — just drop the stale buffer entry.
if (_platformScriptResultEmitted.Contains(script.PolicyId))
{
(toRemove ??= new List<string>()).Add(kv.Key);
continue;
}
// No exit code yet → the script is still running; nothing to emit.
if (!script.ExitCode.HasValue) continue;
if (!force)
{
if (!script.ExitObservedAtUtc.HasValue) continue;
if (nowUtc - script.ExitObservedAtUtc.Value < PlatformScriptResultGrace) continue;
}
script.Result = script.ExitCode.Value == 0 ? "Success" : "Failed";
script.ResultSource = "agentexecutor_fallback";
_logger.Info(
$"ImeLogTracker: platform script {script.PolicyId} result not seen within " +
$"{PlatformScriptResultGrace.TotalSeconds:F0}s{(force ? " (shutdown flush)" : "")} — " +
$"emitting from AgentExecutor exit code {script.ExitCode.Value} (fallback)");
EmitScriptEvent(script);
_platformScriptResultEmitted.Add(script.PolicyId);
(toRemove ??= new List<string>()).Add(kv.Key);
}
if (toRemove != null)
{
foreach (var key in toRemove)
{
_pendingPlatformScripts.Remove(key);
if (string.Equals(_lastPlatformScriptPolicyId, key, StringComparison.OrdinalIgnoreCase))
_lastPlatformScriptPolicyId = null;
}
}
}
/// <summary>Test seam: inject a pending platform script as if AgentExecutor.log had reported
/// its start + exit code, without an IME PS-SCRIPT-RESULT line.</summary>
internal void SeedPendingPlatformScriptForTesting(string policyId, int? exitCode, DateTime? exitObservedAtUtc, string stdout = null)
{
// Mirrors a fresh execution start: a new run clears any prior emitted-marker (see
// HandleScriptStarted) so re-runs of the same policy within one lifetime emit again.
_platformScriptResultEmitted.Remove(policyId);
_pendingPlatformScripts[policyId] = new ScriptExecutionState
{
PolicyId = policyId,
ScriptType = "platform",
ExitCode = exitCode,
ExitObservedAtUtc = exitObservedAtUtc,
Stdout = stdout,
};
_lastPlatformScriptPolicyId = policyId;
}
/// <summary>Test seam: simulate the authoritative IME PS-SCRIPT-RESULT path for a platform
/// script (same code as <see cref="HandleScriptCompleted"/> minus regex extraction).</summary>
internal void CompletePlatformScriptFromImeResultForTesting(string policyId, string result)
{
if (string.IsNullOrEmpty(policyId)) return;
if (_platformScriptResultEmitted.Contains(policyId))
{
_pendingPlatformScripts.Remove(policyId);
if (string.Equals(_lastPlatformScriptPolicyId, policyId, StringComparison.OrdinalIgnoreCase))
_lastPlatformScriptPolicyId = null;
return;
}
if (!_pendingPlatformScripts.TryGetValue(policyId, out var script))
script = new ScriptExecutionState { PolicyId = policyId, ScriptType = "platform" };
script.Result = result;
script.ResultSource = "ime_policy_result";
EmitScriptEvent(script);
_platformScriptResultEmitted.Add(policyId);
_pendingPlatformScripts.Remove(policyId);
if (string.Equals(_lastPlatformScriptPolicyId, policyId, StringComparison.OrdinalIgnoreCase))
_lastPlatformScriptPolicyId = null;
}
/// <summary>
/// Parses the IME <c>[HS] new result = {…}</c> JSON and emits one to three
/// <see cref="ScriptExecutionState"/> events covering the pre-detection,
@@ -486,6 +486,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
try
{
await CheckLogFilesAsync(token);
// Safety net: emit completions for platform scripts whose AgentExecutor
// exit code we already have but whose authoritative IME PS-SCRIPT-RESULT
// line never arrived within the grace period. Runs on this same loop
// thread (no locking) so it observes the buffer right after parsing.
FlushStalePlatformScriptResults(DateTime.UtcNow);
}
catch (OperationCanceledException) { break; }
catch (Exception ex)
@@ -508,6 +514,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
try { await Task.Delay(_pollingIntervalMs, token); } catch (OperationCanceledException) { break; }
}
// Final pass: force-flush any platform script that completed within the last grace
// window before shutdown (exit code known, IME result still pending). Best-effort —
// emits only while callbacks are still wired (i.e. the adapter hasn't been disposed).
try { FlushStalePlatformScriptResults(DateTime.UtcNow, force: true); }
catch (Exception ex) { _logger.Warning($"ImeLogTracker: shutdown script flush failed: {ex.Message}"); }
// Final state save on shutdown
if (_stateDirty)
{
@@ -33,6 +33,25 @@ public class ScriptExecutionState
/// <summary>"Success" or "Failed" (platform scripts).</summary>
public string Result { get; set; }
/// <summary>
/// Provenance of <see cref="Result"/> for platform scripts:
/// <c>"ime_policy_result"</c> — authoritative <c>PS-SCRIPT-RESULT</c> line from
/// <c>IntuneManagementExtension.log</c>; <c>"agentexecutor_fallback"</c> — derived from the
/// AgentExecutor.log exit code because IME never logged its policy-result line before the
/// deadline (short Autopilot enrollments end inside IME's batch-send gap). Surfaced as
/// <c>resultSource</c> on the emitted event so the UI/MCP can flag fallback-grounded results.
/// Null for health scripts and for events emitted before this field existed.
/// </summary>
public string ResultSource { get; set; }
/// <summary>
/// UTC timestamp at which the AgentExecutor.log exit-code line for this platform script was
/// observed. Drives the deadline check in
/// <see cref="ImeLogTracker.FlushStalePlatformScriptResults"/> — set only on the platform path
/// (PS-AGENT exit code); null until an exit code is seen.
/// </summary>
public System.DateTime? ExitObservedAtUtc { get; set; }
/// <summary>"True" or "False" compliance result (remediation detection / post-detection only).</summary>
public string ComplianceResult { get; set; }
@@ -262,8 +262,19 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
/// </para>
/// </summary>
private DateTime ResolveOccurredAt(out bool derivedFromClock, out DateTime? rawSourceTimestamp)
=> ResolveOccurredAt(null, out derivedFromClock, out rawSourceTimestamp);
/// <summary>
/// Overload that prefers an explicit source timestamp over
/// <see cref="ImeLogTracker.LastMatchedLogTimestamp"/>. Used by the platform-script
/// exit-code fallback: the fallback emit happens up to a grace period after the script's
/// exit line was parsed, by which point an unrelated later log line may be the "last
/// matched" one — so the fallback passes the script's own exit-observed timestamp here to
/// keep the event on the correct point of the timeline. Same staleness/skew clamp applies.
/// </summary>
private DateTime ResolveOccurredAt(DateTime? sourceTsOverride, out bool derivedFromClock, out DateTime? rawSourceTimestamp)
{
rawSourceTimestamp = _tracker.LastMatchedLogTimestamp;
rawSourceTimestamp = sourceTsOverride ?? _tracker.LastMatchedLogTimestamp;
if (rawSourceTimestamp.HasValue)
{
// CMTrace log timestamps from IME are emitted in UTC, but DateTimeKind may
@@ -794,6 +805,11 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
if (script.ExitCode.HasValue) data["exitCode"] = script.ExitCode.Value.ToString(culture);
if (!string.IsNullOrEmpty(script.RunContext)) data["runContext"] = script.RunContext!;
if (!string.IsNullOrEmpty(script.Result)) data["result"] = script.Result!;
// Provenance of the result: "ime_policy_result" (authoritative IME PS-SCRIPT-RESULT) vs
// "agentexecutor_fallback" (derived from the AgentExecutor exit code because IME never
// logged its result line before the deadline). Lets the UI/MCP flag fallback-grounded
// platform-script completions. Platform scripts only — null for health scripts.
if (!string.IsNullOrEmpty(script.ResultSource)) data["resultSource"] = script.ResultSource!;
if (!string.IsNullOrEmpty(script.ComplianceResult)) data["complianceResult"] = script.ComplianceResult!;
if (script.RemediationStatus.HasValue) data["remediationStatus"] = script.RemediationStatus.Value.ToString(culture);
if (script.TargetType.HasValue) data["targetType"] = script.TargetType.Value.ToString(culture);
@@ -801,10 +817,24 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
if (!string.IsNullOrEmpty(script.ErrorDetails)) data["errorDetails"] = script.ErrorDetails!;
if (!string.IsNullOrEmpty(script.Stdout)) data["stdout"] = script.Stdout!;
if (!string.IsNullOrEmpty(script.Stderr)) data["stderr"] = script.Stderr!;
var patternId = _tracker.LastMatchedPatternId;
if (!string.IsNullOrEmpty(patternId)) data["patternId"] = patternId!;
var now = ResolveOccurredAt(out var derivedFromClock, out var rawSourceTs);
// The exit-code fallback emits asynchronously to log parsing, so the tracker's
// "last matched" pattern/timestamp belong to an unrelated later line. Bind the event to
// the script's own exit-observed timestamp and omit the misleading patternId instead.
var isFallback = string.Equals(script.ResultSource, "agentexecutor_fallback", StringComparison.Ordinal);
if (!isFallback)
{
var patternId = _tracker.LastMatchedPatternId;
if (!string.IsNullOrEmpty(patternId)) data["patternId"] = patternId!;
}
bool derivedFromClock;
DateTime? rawSourceTs;
DateTime now;
if (isFallback && script.ExitObservedAtUtc.HasValue)
now = ResolveOccurredAt(script.ExitObservedAtUtc, out derivedFromClock, out rawSourceTs);
else
now = ResolveOccurredAt(out derivedFromClock, out rawSourceTs);
TagDerivedTimestamp(data, derivedFromClock, rawSourceTs);
var label = IsRemediation(script.ScriptType) ? "Remediation script" : "Platform script";