feat(agent): outcome-calibrated agent_late_start severity and phrasing

Fleet data (2026-07-28, agent 2.0.1380) showed the late-start detector was outcome-blind: tenant 659c3a90 collected 12 Warnings with the post-mortem/ hung-script note on enrollments that succeeded — the bootstrap merely ran late in the ESP queue and the agent observed the healthy final minutes live. New pure helper ObservationCoverage.DescribeLateStart: - Succeeded -> Info with a tail-only-coverage note (IME-replay hint, bootstrap-ordering review if recurring); no alarm framing. - Failed/TimedOut -> Warning with the existing post-mortem/hung-script note. - oobeStateAtAgentStart refines the message only: "completed" = pure post-mortem, "in_progress" = live tail observed; not_started/unavailable add no claim (value flips to not_started after mid-OOBE reboots and "completed" is routine on post-desktop restarts). The coverage gate (10 min boot-to-start / 5 min uptime) is unchanged, and the OOBE state is deliberately NOT a gate: the canonical hung-script failure (f148976f) terminates on the still-shown ESP screen, i.e. with OOBE reading in_progress. 8 new tests (outcome x oobe-state matrix); V2.Core suite 2067 green. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-10-24 12:42:38 +00:00 · 2026-07-28 12:53:17 +02:00
parent 3ec716a3ec
commit 0ec481b479
3 changed files with 147 additions and 8 deletions
@@ -1,5 +1,7 @@
 using System;
+using AutopilotMonitor.Agent.V2.Core.Orchestration;
 using AutopilotMonitor.Agent.V2.Core.Termination;
+using AutopilotMonitor.Shared.Models;
 using Xunit;

 namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
@@ -70,5 +72,82 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
            Assert.Equal(0, bootToStart, 0);
            Assert.Equal(10, uptime, 0);
        }
+
+        // --- DescribeLateStart: outcome-calibrated severity + phrasing (fleet 2026-07-28) ---
+
+        private static void Describe(
+            EnrollmentTerminationOutcome outcome, string oobeState,
+            out EventSeverity severity, out string message, out string note)
+            => ObservationCoverage.DescribeLateStart(
+                outcome, oobeState, bootToStartSeconds: 34 * 60, uptimeSeconds: 30,
+                out severity, out message, out note);
+
+        [Fact]
+        public void Failed_outcome_is_a_warning_with_the_hung_script_post_mortem_note()
+        {
+            Describe(EnrollmentTerminationOutcome.Failed, "in_progress",
+                out var severity, out var message, out var note);
+
+            Assert.Equal(EventSeverity.Warning, severity);
+            Assert.Contains("low coverage of the enrollment window", message);
+            Assert.Contains("post-mortem", note);
+            Assert.Contains("hung ahead of the bootstrap", note);
+        }
+
+        [Fact]
+        public void TimedOut_outcome_is_a_warning_like_a_failure()
+        {
+            Describe(EnrollmentTerminationOutcome.TimedOut, "in_progress",
+                out var severity, out _, out var note);
+
+            Assert.Equal(EventSeverity.Warning, severity);
+            Assert.Contains("post-mortem", note);
+        }
+
+        [Fact]
+        public void Succeeded_outcome_is_an_info_about_tail_only_coverage_without_alarm_framing()
+        {
+            // The 659c3a90 shape: healthy enrollment, bootstrap merely ran late in the ESP queue.
+            Describe(EnrollmentTerminationOutcome.Succeeded, "in_progress",
+                out var severity, out _, out var note);
+
+            Assert.Equal(EventSeverity.Info, severity);
+            Assert.Contains("succeeded", note);
+            Assert.Contains("IME log replay", note);
+            Assert.DoesNotContain("post-mortem", note);
+            Assert.DoesNotContain("hung", note);
+        }
+
+        [Fact]
+        public void Oobe_completed_at_start_phrases_a_pure_post_mortem()
+        {
+            Describe(EnrollmentTerminationOutcome.Failed, "completed",
+                out _, out var message, out _);
+
+            Assert.Contains("OOBE was already completed when the agent started", message);
+        }
+
+        [Fact]
+        public void Oobe_in_progress_at_start_phrases_the_live_tail()
+        {
+            Describe(EnrollmentTerminationOutcome.Failed, "in_progress",
+                out _, out var message, out _);
+
+            Assert.Contains("OOBE was still in progress at agent start", message);
+            Assert.Contains("final 30s live", message);
+        }
+
+        [Theory]
+        [InlineData("not_started")]  // flips in after a mid-OOBE reboot — not interpretable
+        [InlineData("unavailable")]  // WinRT contract absent / read failed
+        [InlineData("unknown_3")]    // unexpected enum value
+        public void Uninterpretable_oobe_states_add_no_claim_to_the_message(string oobeState)
+        {
+            Describe(EnrollmentTerminationOutcome.Failed, oobeState,
+                out _, out var message, out _);
+
+            Assert.DoesNotContain("OOBE", message);
+            Assert.EndsWith("low coverage of the enrollment window.", message);
+        }
    }
 }
@@ -623,12 +623,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
        }

        /// <summary>
-        /// Emits a one-shot <c>agent_late_start</c> Warning when the agent had low observation
+        /// Emits a one-shot <c>agent_late_start</c> event when the agent had low observation
        /// coverage: it started a long time after device boot AND lived only briefly before this
        /// terminal outcome (gate in <see cref="ObservationCoverage"/>). Such a session looks like a
        /// normal multi-minute failure in the list (StartedAt is back-dated to the earliest replayed
-        /// IME-log event) but the agent actually observed only the end-state — so the operator should
-        /// read the diagnosis as a post-mortem reconstruction, not live evidence. No state mutation.
+        /// IME-log event) but the agent actually observed only the end-state. Severity and phrasing
+        /// are outcome-calibrated via <see cref="ObservationCoverage.DescribeLateStart"/>: a failure
+        /// stays a Warning with the post-mortem/hung-script note, a success is an Info about
+        /// tail-only coverage (fleet 2026-07-28: tenant 659c3a90 collected 12 Warnings on healthy
+        /// enrollments whose bootstrap merely ran late). No state mutation.
        /// </summary>
        private void MaybeEmitAgentLateStart(EnrollmentTerminatedEventArgs args)
        {
@@ -642,21 +645,24 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                        out var bootToStartSeconds, out var uptimeSeconds))
                    return;

+                ObservationCoverage.DescribeLateStart(
+                    args.Outcome, _oobeStateAtAgentStart, bootToStartSeconds, uptimeSeconds,
+                    out var severity, out var message, out var note);
+
                _logger.Info(
                    $"EnrollmentTerminationHandler: low observation coverage — agent started " +
                    $"{bootToStartSeconds / 60.0:F1} min after boot and lived {uptimeSeconds:F0}s; " +
-                    $"emitting agent_late_start.");
+                    $"emitting agent_late_start ({severity}, outcome {args.Outcome}).");

                _post.Emit(new EnrollmentEvent
                {
                    SessionId = _configuration.SessionId,
                    TenantId = _configuration.TenantId,
                    EventType = Constants.EventTypes.AgentLateStart,
-                    Severity = EventSeverity.Warning,
+                    Severity = severity,
                    Source = "EnrollmentTerminationHandler",
                    Phase = EnrollmentPhase.Unknown,
-                    Message = $"Agent started {bootToStartSeconds / 60.0:F0} min after boot and observed only " +
-                              $"{uptimeSeconds:F0}s before terminating ({args.Outcome}) — low coverage of the enrollment window.",
+                    Message = message,
                    Data = new Dictionary<string, object>
                    {
                        { "bootToAgentStartSeconds", Math.Round(bootToStartSeconds, 1) },
@@ -665,7 +671,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                        { "agentStartUtc", _agentStartTimeUtc.ToString("o") },
                        { "oobeStateAtAgentStart", _oobeStateAtAgentStart },
                        { "outcome", args.Outcome.ToString() },
-                        { "note", "The agent's bootstrap (an Intune platform script) ran only near the end of the enrollment, so the agent observed the already-decided end-state rather than the failure window. Treat the diagnosis as a post-mortem; check for a platform/remediation script that hung ahead of the bootstrap (see script_timeout_suspected)." },
+                        { "note", note },
                    },
                    ImmediateUpload = true,
                });
@@ -1,6 +1,8 @@
 #nullable enable
 using System;
 using System.Runtime.InteropServices;
+using AutopilotMonitor.Agent.V2.Core.Orchestration;
+using AutopilotMonitor.Shared.Models;

 namespace AutopilotMonitor.Agent.V2.Core.Termination
 {
@@ -76,5 +78,57 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            uptimeSeconds = Math.Max(0, uptime.TotalSeconds);
            return bootToStart >= LateStartBootThreshold && uptime <= LowCoverageUptime;
        }
+
+        /// <summary>
+        /// Severity + operator-facing phrasing for the <c>agent_late_start</c> event, calibrated
+        /// by fleet data (2026-07-28): the gate alone is outcome-blind and attached a
+        /// "post-mortem / check for a hung script" Warning to sessions that in fact succeeded —
+        /// there the late bootstrap is deployment hygiene, not an alarm. The OOBE state refines
+        /// the phrasing but must never gate: the canonical hung-script failure terminates on the
+        /// still-shown ESP screen, i.e. with OOBE reading <c>in_progress</c>.
+        /// </summary>
+        /// <param name="outcome">Terminal outcome the enrollment reached.</param>
+        /// <param name="oobeStateAtAgentStart"><see cref="Monitoring.Interop.OobeStateReader"/>
+        /// sample taken at THIS process's start. Only <c>completed</c> / <c>in_progress</c> are
+        /// interpreted; <c>not_started</c> flips in after mid-OOBE reboots and <c>completed</c> is
+        /// routine for post-desktop restarts, so no claim is phrased from the other values.</param>
+        /// <param name="bootToStartSeconds">From <see cref="IsLowObservationCoverage"/>.</param>
+        /// <param name="uptimeSeconds">From <see cref="IsLowObservationCoverage"/>.</param>
+        internal static void DescribeLateStart(
+            EnrollmentTerminationOutcome outcome,
+            string oobeStateAtAgentStart,
+            double bootToStartSeconds,
+            double uptimeSeconds,
+            out EventSeverity severity,
+            out string message,
+            out string note)
+        {
+            var succeeded = outcome == EnrollmentTerminationOutcome.Succeeded;
+            severity = succeeded ? EventSeverity.Info : EventSeverity.Warning;
+
+            message = $"Agent started {bootToStartSeconds / 60.0:F0} min after boot and observed only " +
+                      $"{uptimeSeconds:F0}s before terminating ({outcome}) — low coverage of the enrollment window.";
+            switch (oobeStateAtAgentStart)
+            {
+                case "completed":
+                    message += " OOBE was already completed when the agent started — the diagnosis is a " +
+                               "post-mortem reconstruction, not live observation.";
+                    break;
+                case "in_progress":
+                    message += $" OOBE was still in progress at agent start — the agent did observe the " +
+                               $"final {uptimeSeconds:F0}s live.";
+                    break;
+            }
+
+            note = succeeded
+                ? "The agent's bootstrap (an Intune platform script) ran late in the enrollment, so only the " +
+                  "final stretch was observed live; earlier timeline entries are reconstructed from IME log " +
+                  "replay. The enrollment itself succeeded. If this recurs across sessions, review which " +
+                  "platform/remediation scripts run ahead of the bootstrap (see script_timeout_suspected)."
+                : "The agent's bootstrap (an Intune platform script) ran only near the end of the enrollment, " +
+                  "so the agent observed the already-decided end-state rather than the failure window. Treat " +
+                  "the diagnosis as a post-mortem; check for a platform/remediation script that hung ahead of " +
+                  "the bootstrap (see script_timeout_suspected).";
+        }
    }
 }