diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterUserSessionGateTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterUserSessionGateTests.cs new file mode 100644 index 00000000..c8dd2f6d --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterUserSessionGateTests.cs @@ -0,0 +1,167 @@ +using System.Collections.Generic; +using System.Linq; +using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime; +using AutopilotMonitor.Agent.V2.Core.SignalAdapters; +using AutopilotMonitor.Agent.V2.Core.Tests.Harness; +using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration; +using AutopilotMonitor.DecisionCore.Signals; +using SharedEventTypes = AutopilotMonitor.Shared.Constants.EventTypes; +using Xunit; + +namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters +{ + /// + /// Sessions 14690fc2/6cb01530 hardening (2026-07-10): IME writes its "Completed user + /// session N" line at the end of EVERY user-session processing pass — the first + /// post-reboot pass completed with 13–18 required apps still pending and arm C stamped + /// the session Succeeded 5 minutes later mid-install. The adapter must defer the + /// signal while required + /// Install-intent user-ESP apps are pending, and post it on the first pass-completion + /// after they settle. Error counts as terminal (GRS owns retries) so a failed app can + /// never park the signal — and with it the AdvisoryCompletion conjunction — forever. + /// + public sealed class ImeLogTrackerAdapterUserSessionGateTests + { + private static AppPackageState AddApp( + ImeLogTracker tracker, + string id, + AppIntent intent, + AppInstallationState state) + { + var pkg = tracker.PackageStates.GetPackage(id, createIfNotFound: true); + pkg.UpdateIntent(intent); + if (state == AppInstallationState.Installed) + { + pkg.UpdateState(AppInstallationState.Installing); + } + if (state != AppInstallationState.Unknown) + { + pkg.UpdateState(state); + } + return pkg; + } + + private static IReadOnlyList DeferralTraces(ImeLogTrackerAdapterFixture f) => + f.InfoEvents(SharedEventTypes.AgentTrace) + .Where(p => p.Payload!.TryGetValue("decision", out var d) + && d == "ime_user_session_completion_deferred") + .ToList(); + + [Fact] + public void Pending_required_install_app_defers_signal_and_emits_oneshot_deferral_trace() + { + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + AddApp(f.Tracker, "app-pending", AppIntent.Install, AppInstallationState.Unknown); + + adapter.TriggerUserSessionCompletedFromTest(); + adapter.TriggerUserSessionCompletedFromTest(); // second pass, still pending + + Assert.Empty(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + Assert.Empty(f.InfoEvents(SharedEventTypes.ImeUserSessionCompleted)); + + var trace = Assert.Single(DeferralTraces(f)); + Assert.Equal("1", trace.Payload!["pendingRequiredInstallApps"]); + Assert.Contains("app-pending", trace.Payload["pendingAppNames"]); + } + + [Fact] + public void Signal_posts_on_next_pass_after_pending_app_settles() + { + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + var pkg = AddApp(f.Tracker, "app-pending", AppIntent.Install, AppInstallationState.Unknown); + + adapter.TriggerUserSessionCompletedFromTest(); + Assert.Empty(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + + pkg.UpdateState(AppInstallationState.Installing); + pkg.UpdateState(AppInstallationState.Installed); + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + Assert.Single(f.InfoEvents(SharedEventTypes.ImeUserSessionCompleted)); + } + + [Fact] + public void Error_state_app_counts_as_terminal_and_does_not_defer() + { + // A permanently failed app must not park the signal: the AdvisoryCompletion + // conjunction needs the IME fact, and blocking it would flip an otherwise + // completed enrollment into a 30-minute-backstop Failed. + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + AddApp(f.Tracker, "app-failed", AppIntent.Install, AppInstallationState.Error); + AddApp(f.Tracker, "app-installed", AppIntent.Install, AppInstallationState.Installed); + + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + Assert.Empty(DeferralTraces(f)); + } + + [Fact] + public void Pending_uninstall_intent_app_does_not_defer() + { + // The ESP apps gate does not block on uninstalls (session a4537c36) — a pending + // system-app removal must not delay the completion signal. + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + AddApp(f.Tracker, "app-uninstall-pending", AppIntent.Uninstall, AppInstallationState.Unknown); + + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + } + + [Fact] + public void Outside_AccountSetup_phase_posts_as_before() + { + // Pre-anchor completions (defaultuser0 / technician frame) keep their existing + // semantics — DecisionCore's IsImeUserSessionGenuine guard already prevents them + // from ever triggering completion, and the M2 recording rule needs the stamp. + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("DeviceSetup"); + AddApp(f.Tracker, "app-pending", AppIntent.Install, AppInstallationState.Unknown); + + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + Assert.Empty(DeferralTraces(f)); + } + + [Fact] + public void No_tracked_apps_posts_signal() + { + // Zero user-scope apps assigned is a legitimate immediate completion — an empty + // catalog must not defer (fail-open to the pre-hardening behaviour). + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + } + + [Fact] + public void Fire_once_preserved_after_signal_posts() + { + using var f = new ImeLogTrackerAdapterFixture(); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + f.Tracker.SeedCurrentPhaseForTesting("AccountSetup"); + AddApp(f.Tracker, "app-installed", AppIntent.Install, AppInstallationState.Installed); + + adapter.TriggerUserSessionCompletedFromTest(); + adapter.TriggerUserSessionCompletedFromTest(); + + Assert.Single(f.DecisionSignals(DecisionSignalKind.ImeUserSessionCompleted)); + Assert.Single(f.InfoEvents(SharedEventTypes.ImeUserSessionCompleted)); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs index 6375c042..5691a1dc 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs @@ -321,6 +321,53 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime } } + /// + /// Sessions 14690fc2/6cb01530 arm-C hardening (2026-07-10): returns the required + /// user-ESP Install-intent apps that have NOT reached a terminal state + /// (Installed / Skipped / Postponed / Error) in the current AccountSetup phase. + /// IME writes its Completed user session N line at the end of EVERY + /// user-session processing pass — including a first pass that merely enumerated the + /// app catalog — so ImeLogTrackerAdapter defers the + /// ImeUserSessionCompleted decision signal while this list is non-empty. + /// + /// Unlike , + /// counts as settled here: IME delivered its verdict for that app (GRS re-tries hours + /// later, far outside the enrollment window), and blocking the signal on a failed app + /// would starve the AdvisoryCompletion conjunction into failing sessions whose user + /// has long been at the desktop. Uninstall-intent apps are excluded for the same + /// reason as in . Non-AccountSetup phases return + /// empty — pre-anchor completions keep their existing (never completion-triggering) + /// semantics. Same thread-safety contract as the sibling probes: snapshot copy, any + /// race-induced exception returns an empty list (fail-open to the pre-hardening + /// behaviour rather than parking completion on a probe bug). + /// + /// + public IReadOnlyList GetPendingRequiredUserEspInstallApps() + { + try + { + if (!string.Equals(_lastEspPhaseDetected, "AccountSetup", StringComparison.OrdinalIgnoreCase)) + return Array.Empty(); + + var apps = new List(_packageStates); + if (apps.Count == 0) return Array.Empty(); + + var pending = new List(); + foreach (var pkg in apps) + { + if (pkg == null || pkg.Intent != AppIntent.Install) continue; + if (pkg.IsCompleted) continue; // terminal incl. Error + pending.Add(pkg); + } + return pending; + } + catch (Exception ex) + { + _logger.Debug($"ImeLogTracker: GetPendingRequiredUserEspInstallApps probe threw: {ex.Message}"); + return Array.Empty(); + } + } + /// /// Liveness plan PR3 — returns the required user-ESP apps that are STARVING the /// AccountSetup apps gate: tracked in the current AccountSetup phase, Install intent diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs index 7a1abdb1..b08c0e58 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs @@ -34,7 +34,10 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters /// /// OnEspPhaseChanged(phase) → /// (dedup per distinct phase value — Reducer Plan §2.1a idempotenz-Anforderung). - /// OnUserSessionCompleted() → (fire-once). + /// OnUserSessionCompleted() → (fire-once; + /// deferred while required user-ESP Install-intent apps are still pending — IME's + /// "Completed user session" line fires per processing pass, see + /// ). /// OnAppStateChanged(app, old, new) → /// (state=Installed/Skipped/Postponed) oder (state=Error). /// Dedup pro (AppId, terminal-state-tuple). @@ -86,6 +89,9 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters // Dedup state for DecisionSignals. private string? _lastEspPhase; private bool _userSessionCompletedPosted; + // One-shot flag for the user-session-completion deferral trace event — the INFO log + // line repeats per suppressed pass, the timeline event fires once per agent run. + private bool _userSessionDeferralNoted; private bool _sealingPatternPosted; // Fires once per session when a Platform Script stdout contains the Autopilot-Monitor // bootstrap marker line. Lets MCP report "which device runs which bootstrap version". @@ -385,6 +391,23 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters private void EmitUserSessionCompleted() { + // Sessions 14690fc2/6cb01530 hardening (2026-07-10): IME writes its "Completed + // user session N" line at the end of EVERY user-session processing pass, not when + // user-scope enforcement is done — both field sessions had 13–18 required apps + // still pending when the first post-reboot pass completed, and arm C + // (ShouldTransitionToAwaitingHello) stamped the session Succeeded 5 minutes later + // mid-install. Defer the decision signal while required Install-intent user-ESP + // apps are pending; the fire-once flag stays unclaimed, so the completion line of + // a later pass re-evaluates and posts once the apps have settled. Error counts as + // terminal in the probe (GRS owns retries), so a permanently failed app cannot + // park the signal — and with it the AdvisoryCompletion conjunction — forever. + var pendingApps = _tracker.GetPendingRequiredUserEspInstallApps(); + if (pendingApps.Count > 0) + { + NoteUserSessionCompletionDeferred(pendingApps); + return; + } + lock (_lock) { if (_userSessionCompletedPosted) return; @@ -406,7 +429,7 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters evidence: new Evidence( kind: EvidenceKind.Derived, identifier: "ime-log-tracker-v1", - summary: "IME user session completed (all user-scope apps finished)", + summary: "IME user session completed (no required user-scope apps pending)", derivationInputs: derivationInputs)); var data = new Dictionary(StringComparer.Ordinal) @@ -429,6 +452,52 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters _logger?.Info($"ImeAdapter: user session completed -> posting ImeUserSessionCompleted (patternId={patternId ?? "(none)"})"); } + /// + /// Observability for the deferred user-session completion (sessions 14690fc2/6cb01530): + /// an INFO log line per suppressed pass plus a one-shot agent_trace timeline + /// event, so a field session shows WHY ime_user_session_completed arrived late + /// (or never) without needing the diagnostics ZIP. + /// + private void NoteUserSessionCompletionDeferred(IReadOnlyList pendingApps) + { + const int maxNames = 10; + var names = new List(Math.Min(pendingApps.Count, maxNames)); + foreach (var pkg in pendingApps) + { + if (names.Count >= maxNames) break; + if (pkg == null) continue; + names.Add(string.IsNullOrEmpty(pkg.Name) ? pkg.Id : pkg.Name!); + } + var namesJoined = string.Join("; ", names) + + (pendingApps.Count > maxNames ? $" (+{pendingApps.Count - maxNames} more)" : string.Empty); + + _logger?.Info( + $"ImeAdapter: IME 'Completed user session' line observed but {pendingApps.Count} required user-ESP app(s) still pending -> deferring ImeUserSessionCompleted (pending: {namesJoined})"); + + lock (_lock) + { + if (_userSessionDeferralNoted) return; + _userSessionDeferralNoted = true; + } + + var now = ResolveOccurredAt(out var derivedFromClock, out var rawSourceTs); + var data = new Dictionary(StringComparer.Ordinal) + { + ["decision"] = "ime_user_session_completion_deferred", + ["pendingRequiredInstallApps"] = pendingApps.Count.ToString(System.Globalization.CultureInfo.InvariantCulture), + ["pendingAppNames"] = namesJoined, + }; + TagDerivedTimestamp(data, derivedFromClock, rawSourceTs); + + _post.Emit( + eventType: SharedEventTypes.AgentTrace, + source: SourceLabel, + message: $"IME user-session completion line observed while {pendingApps.Count} required user app(s) pending — completion signal deferred until they settle", + severity: EventSeverity.Info, + data: data, + occurredAtUtc: now); + } + private void EmitAppState(AppPackageState app, AppInstallationState oldState, AppInstallationState newState) { if (app == null || string.IsNullOrEmpty(app.Id)) return;