From 4bc2435ec561dc032059fe5e3592ccefeac15523 Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Mon, 27 Jul 2026 09:59:20 +0200 Subject: [PATCH] fix(agent): audit Q1/Q2/Q5 source fixes - timing re-arm, esp_config re-emits, serial trim Q1 (AppInstallTiming): a terminal->active transition (IME retry path, e.g. Error->Downloading or Skipped->Downloading) re-arms CompletedAtUtc so the final terminal payload covers first-start -> last-terminal instead of freezing at the first terminal state. Plus a negative-duration guard in AppInstallTiming.DurationSeconds (inverted endpoints -> null, field omitted) - observed in production as durationSeconds=-2342 on a Skipped-then-retried user-scope app (session 66f1c5e1). Q2 (esp_config_detected): the ESP blocking lists are read too early - device lists grow progressively, user-scope S- lists appear only after sign-in (88 of 89 prod sessions had an empty user list at last emission). DeviceInfoHost now re-collects the ESP configuration as phase-driven one-shots: apps sub-phase declaration (AppsDevice/AppsUser phase_transition = first app activity) and AccountSetup detection. The StartupEventGate keeps unchanged payloads silent (fingerprint covers list contents), so only grown lists actually re-emit. F1 EspBlocking resolution (latest list-bearing emission) benefits without backend change. Q5 (HardwareInfo): WMI values (serial, manufacturer, model) trimmed at the source via NormalizeWmiValue; whitespace-only collapses to the "Unknown" sentinel the retry logic already treats as unresolved. Attach-window investigation (11a3b67a): NO agent fix - hypothesis disproved against two real agent logs (diag bundles db5ce007/2.0.1337, 4a9e9273/2.0.1379). "completed without started" first apps were already installed (WinGet detection-only, zero install lines in AppWorkload.log); pre-attach replay provably works (pattern-match log). PR0's HasMeasuredDuration already handles the class server-side. Duplicate app_install_completed (66f1c5e1): mechanism narrowed to an in-process re-read of exactly one AppWorkload rotation window (<24h-old lines, historic suppression not applicable) - documented as follow-up, no fix without a bundle-bearing repro per lessons.md. Verified: solution build clean, Agent V2 Core 2058/2058 (14 new tests), DecisionCore 493/493. No ConfigVersion bump, no new event types, decision rail untouched. Co-Authored-By: Claude Fable 5 --- .../DeviceInfoCollectorEspRefreshTests.cs | 108 ++++++++++++++++++ .../DeviceInfoHostTriggerTests.cs | 36 ++++++ .../Security/HardwareInfoNormalizeTests.cs | 33 ++++++ .../ImeLogTrackerAdapterTimingTests.cs | 82 +++++++++++++ .../Enrollment/Ime/AppInstallTiming.cs | 15 ++- .../DeviceInfo/DeviceInfoCollector.cs | 17 +++ .../Orchestration/Hosts/DeviceInfoHost.cs | 89 ++++++++++++++- .../Security/HardwareInfo.cs | 20 +++- .../SignalAdapters/ImeLogTrackerAdapter.cs | 27 ++++- 9 files changed, 410 insertions(+), 17 deletions(-) create mode 100644 src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/DeviceInfo/DeviceInfoCollectorEspRefreshTests.cs create mode 100644 src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Security/HardwareInfoNormalizeTests.cs diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/DeviceInfo/DeviceInfoCollectorEspRefreshTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/DeviceInfo/DeviceInfoCollectorEspRefreshTests.cs new file mode 100644 index 00000000..112c9b3f --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/DeviceInfo/DeviceInfoCollectorEspRefreshTests.cs @@ -0,0 +1,108 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using AutopilotMonitor.Agent.V2.Core.Logging; +using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals; +using AutopilotMonitor.Agent.V2.Core.Orchestration; +using AutopilotMonitor.Agent.V2.Core.Persistence; +using AutopilotMonitor.Agent.V2.Core.Tests.Harness; +using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration; +using AutopilotMonitor.DecisionCore.Engine; +using AutopilotMonitor.DecisionCore.Signals; +using Xunit; +using SharedEventTypes = AutopilotMonitor.Shared.Constants.EventTypes; +using DeviceInfoCollector = AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo.DeviceInfoCollector; + +namespace AutopilotMonitor.Agent.V2.Core.Tests.DeviceInfo +{ + /// + /// Audit Q2 — + /// re-reads the ESP blocking lists and re-emits esp_config_detected exactly when the + /// payload changed: the registry lists grow progressively (one timestamped subkey per CSP + /// status write) and the user-scope lists appear only after sign-in, so the early emissions + /// are structurally partial. The StartupEventGate keeps an unchanged re-read silent. + /// Probe overrides are static slots → serialized with the other probe-driven suites. + /// + [Collection("SerialThreading")] + public sealed class DeviceInfoCollectorEspRefreshTests + { + private static readonly DateTime T0 = new DateTime(2026, 7, 27, 10, 0, 0, DateTimeKind.Utc); + + private const string DeviceApp1 = "11111111-1111-1111-1111-111111111111"; + private const string DeviceApp2 = "22222222-2222-2222-2222-222222222222"; + private const string UserApp1 = "33333333-3333-3333-3333-333333333333"; + + private static EspTrackingInfoSnapshot Snapshot(string[] deviceApps, string[] userApps) + { + var all = deviceApps.Concat(userApps).Distinct().ToArray(); + return new EspTrackingInfoSnapshot( + msiProductCodes: Array.Empty(), + modernAppPfns: Array.Empty(), + win32AppIds: all, + userWin32AppIds: userApps, + msiCount: 0, + modernCount: 0, + win32Count: all.Length); + } + + private static IReadOnlyList EspConfigEvents(FakeSignalIngressSink ingress) => + ingress.Posted + .Where(p => p.Kind == DecisionSignalKind.InformationalEvent + && p.Payload != null + && p.Payload.TryGetValue(SignalPayloadKeys.EventType, out var et) + && et == SharedEventTypes.EspConfigDetected) + .ToList(); + + private static IReadOnlyList TypedList(FakeSignalIngressSink.PostedSignal signal, string key) + { + var data = Assert.IsAssignableFrom>(signal.TypedPayload); + return Assert.IsAssignableFrom>(data[key]); + } + + [Fact] + public void Refresh_reemits_when_lists_grew_and_stays_silent_when_unchanged() + { + using var tmp = new TempDirectory(); + var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info); + var ingress = new FakeSignalIngressSink(); + var clock = new VirtualClock(T0); + var collector = new DeviceInfoCollector( + "session-1", "tenant-1", + new InformationalEventPost(ingress, clock), logger, + signalIngress: null, clock: clock, + startupGate: new StartupEventGate(tmp.Path, logger)); + + using var skip = new EspSkipConfigurationProbe.ScopedFullOverride( + _ => new EspFirstSyncSnapshot( + skipUser: false, skipDevice: false, + blockInStatusPage: null, syncFailureTimeoutMinutes: null)); + + // Early read (agent start / DeviceSetup detection): partial device list, empty user list. + using (new EspTrackingInfoProbe.ScopedOverride(_ => Snapshot(new[] { DeviceApp1 }, Array.Empty()))) + { + collector.CollectEspConfiguration(); + } + var afterEarly = EspConfigEvents(ingress); + Assert.Single(afterEarly); + Assert.Empty(TypedList(afterEarly[0], "espTrackedUserWin32AppIds")); + + // Apps sub-phase opened: the device list grew and sign-in populated the user list. + using (new EspTrackingInfoProbe.ScopedOverride(_ => Snapshot(new[] { DeviceApp1, DeviceApp2 }, new[] { UserApp1 }))) + { + collector.RefreshEspConfiguration(DeviceInfoHost.EspConfigTriggerAppsUser); + } + var afterGrowth = EspConfigEvents(ingress); + Assert.Equal(2, afterGrowth.Count); + Assert.Contains(DeviceApp2, TypedList(afterGrowth[1], "espTrackedWin32AppIds")); + Assert.Equal(new[] { UserApp1 }, TypedList(afterGrowth[1], "espTrackedUserWin32AppIds")); + + // A later trigger with an UNCHANGED registry state re-reads but emits nothing — + // the StartupEventGate suppresses the identical payload. + using (new EspTrackingInfoProbe.ScopedOverride(_ => Snapshot(new[] { DeviceApp1, DeviceApp2 }, new[] { UserApp1 }))) + { + collector.RefreshEspConfiguration(DeviceInfoHost.EspConfigTriggerAccountSetup); + } + Assert.Equal(2, EspConfigEvents(ingress).Count); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DeviceInfoHostTriggerTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DeviceInfoHostTriggerTests.cs index 5fe05a1c..fb93b07f 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DeviceInfoHostTriggerTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DeviceInfoHostTriggerTests.cs @@ -37,5 +37,41 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration Assert.False(DeviceInfoHost.IsEndTrigger(DecisionSignalKind.EspPhaseChanged, null)); Assert.False(DeviceInfoHost.IsEndTrigger(DecisionSignalKind.InformationalEvent, Phase("FinalizingSetup"))); } + + // Audit Q2 — the payload shape the adapter's apps sub-phase declaration produces on the + // ingress rail (InformationalEventPost: eventType + declared phase enum name). + private static IReadOnlyDictionary SubPhaseDeclaration(string declaredPhase) => + new Dictionary + { + { SignalPayloadKeys.EventType, AutopilotMonitor.Shared.Constants.EventTypes.PhaseTransition }, + { AutopilotMonitor.Agent.V2.Core.Telemetry.Events.EventTimelineEmitter.PhaseParamKey, declaredPhase }, + }; + + [Fact] + public void Apps_subphase_declarations_classify_as_esp_config_refresh_triggers() + { + Assert.Equal(DeviceInfoHost.EspConfigTriggerAppsDevice, + DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.InformationalEvent, SubPhaseDeclaration("AppsDevice"))); + Assert.Equal(DeviceInfoHost.EspConfigTriggerAppsUser, + DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.InformationalEvent, SubPhaseDeclaration("AppsUser"))); + // Non-apps phase declarations (e.g. the reducer's Finalizing entry) never classify. + Assert.Null(DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.InformationalEvent, SubPhaseDeclaration("FinalizingSetup"))); + // A phase_transition without a declared phase never classifies. + Assert.Null(DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.InformationalEvent, + new Dictionary { { SignalPayloadKeys.EventType, AutopilotMonitor.Shared.Constants.EventTypes.PhaseTransition } })); + } + + [Fact] + public void AccountSetup_phase_classifies_as_the_user_setup_refresh_trigger() + { + Assert.Equal(DeviceInfoHost.EspConfigTriggerAccountSetup, + DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.EspPhaseChanged, Phase("AccountSetup"))); + // DeviceSetup is the enrollment-start trigger, not an ESP-config refresh. + Assert.Null(DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.EspPhaseChanged, Phase("DeviceSetup"))); + Assert.Null(DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.EspPhaseChanged, null)); + // Unrelated informational events never classify. + Assert.Null(DeviceInfoHost.ClassifyEspConfigRefreshTrigger(DecisionSignalKind.InformationalEvent, + new Dictionary { { SignalPayloadKeys.EventType, "esp_config_detected" } })); + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Security/HardwareInfoNormalizeTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Security/HardwareInfoNormalizeTests.cs new file mode 100644 index 00000000..342d30fd --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Security/HardwareInfoNormalizeTests.cs @@ -0,0 +1,33 @@ +using AutopilotMonitor.Agent.V2.Core.Security; +using Xunit; + +namespace AutopilotMonitor.Agent.V2.Core.Tests.Security +{ + /// + /// Audit Q5 — WMI hardware values are trimmed at the source. BIOS serials become device + /// identity keys downstream (F2 device history joins on TenantId + serial), so padding + /// must never leave the agent; whitespace-only values collapse to the "Unknown" sentinel + /// the retry logic already treats as unresolved. + /// + public sealed class HardwareInfoNormalizeTests + { + [Theory] + [InlineData(" PF60H941 ", "PF60H941")] + [InlineData("PF60H941", "PF60H941")] + [InlineData("\tLENOVO \r\n", "LENOVO")] + [InlineData("Unknown", "Unknown")] + public void Trims_whitespace_at_the_source(string raw, string expected) + => Assert.Equal(expected, HardwareInfo.NormalizeWmiValue(raw)); + + [Theory] + [InlineData("")] + [InlineData(" ")] + [InlineData("\t\r\n")] + public void Empty_and_whitespace_only_collapse_to_the_Unknown_sentinel(string raw) + => Assert.Equal("Unknown", HardwareInfo.NormalizeWmiValue(raw)); + + [Fact] + public void Null_collapses_to_the_Unknown_sentinel() + => Assert.Equal("Unknown", HardwareInfo.NormalizeWmiValue(null)); + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterTimingTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterTimingTests.cs index 3e4b3658..7c07c240 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterTimingTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/SignalAdapters/ImeLogTrackerAdapterTimingTests.cs @@ -243,5 +243,87 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters Assert.Equal(firstStamp, adapter.AppTimings["app-P"].StartedAtUtc); } + + [Fact] + public void Terminal_to_active_retry_rearms_CompletedAt_and_final_terminal_covers_total_occupancy() + { + // Audit Q1: the IME retry path (Error -> Downloading -> Installed is permitted by + // AppPackageState.UpdateState). Pre-fix, CompletedAt froze at the first Error, so + // the final Installed payload carried the first failure's completedAt/duration. + using var f = new ImeLogTrackerAdapterFixture(T0); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + var app = new AppPackageState("app-R", 0); + + adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing); + f.Clock.Advance(TimeSpan.FromSeconds(5)); + adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Error); + f.Clock.Advance(TimeSpan.FromSeconds(10)); + adapter.TriggerAppStateFromTest(app, AppInstallationState.Error, AppInstallationState.Downloading); + + // Re-armed while active again: the retry's download event carries no completedAt, + // and the FIRST start stamp is kept. + Assert.Null(adapter.AppTimings["app-R"].CompletedAtUtc); + var retryDownload = f.InfoEvent(SharedEventTypes.AppDownloadStarted); + Assert.False(retryDownload.Payload!.ContainsKey("completedAt")); + Assert.False(retryDownload.Payload.ContainsKey("durationSeconds")); + Assert.Equal(T0.ToString("o"), retryDownload.Payload["startedAt"]); + + f.Clock.Advance(TimeSpan.FromSeconds(20)); + adapter.TriggerAppStateFromTest(app, AppInstallationState.Downloading, AppInstallationState.Installed); + + var timing = adapter.AppTimings["app-R"]; + Assert.Equal(T0, timing.StartedAtUtc); + Assert.Equal(T0.AddSeconds(35), timing.CompletedAtUtc); + Assert.Equal(35.0, timing.DurationSeconds); + + var completed = Assert.Single(f.InfoEvents(SharedEventTypes.AppInstallComplete)); + Assert.Equal("35.00", completed.Payload!["durationSeconds"]); + Assert.Equal(T0.AddSeconds(35).ToString("o"), completed.Payload["completedAt"]); + } + + [Fact] + public void Skipped_then_retried_app_emits_positive_duration_from_retry_start() + { + // Production regression (session 66f1c5e1, audit Q1): a user-scope app evaluated + // Skipped during DeviceSetup (terminal, no start observed), retried after sign-in + // (Skipped -> Downloading is permitted), Installed later. Pre-fix payload: + // completedAt frozen at the early Skip + startedAt from the retry -> + // durationSeconds=-2342. Post-fix: retry re-arms, duration covers retry-start -> + // final terminal. + using var f = new ImeLogTrackerAdapterFixture(T0); + using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock); + var app = new AppPackageState("app-S", 0); + + adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Skipped); + Assert.Null(adapter.AppTimings["app-S"].StartedAtUtc); + Assert.Equal(T0, adapter.AppTimings["app-S"].CompletedAtUtc); + + f.Clock.Advance(TimeSpan.FromSeconds(60)); + adapter.TriggerAppStateFromTest(app, AppInstallationState.Skipped, AppInstallationState.Downloading); + f.Clock.Advance(TimeSpan.FromSeconds(30)); + adapter.TriggerAppStateFromTest(app, AppInstallationState.Downloading, AppInstallationState.Installed); + + var timing = adapter.AppTimings["app-S"]; + Assert.Equal(T0.AddSeconds(60), timing.StartedAtUtc); + Assert.Equal(T0.AddSeconds(90), timing.CompletedAtUtc); + Assert.Equal(30.0, timing.DurationSeconds); + + var completedEvents = f.InfoEvents(SharedEventTypes.AppInstallComplete); + Assert.Equal(2, completedEvents.Count); + Assert.Equal("30.00", completedEvents[1].Payload!["durationSeconds"]); + } + + [Fact] + public void Inverted_endpoints_yield_null_DurationSeconds() + { + // Negative guard (audit Q1): endpoints stamped from out-of-order source lines must + // never surface as a negative durationSeconds (observed -2342s in production). The + // payload emitter omits the field when DurationSeconds is null. + var inverted = new AppInstallTiming(startedAtUtc: T0.AddSeconds(100), completedAtUtc: T0); + Assert.Null(inverted.DurationSeconds); + + var wellOrdered = new AppInstallTiming(startedAtUtc: T0, completedAtUtc: T0.AddSeconds(100)); + Assert.Equal(100.0, wellOrdered.DurationSeconds); + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/AppInstallTiming.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/AppInstallTiming.cs index dc803baf..4f8fe7c8 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/AppInstallTiming.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/AppInstallTiming.cs @@ -10,9 +10,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime /// the app_tracking_summary terminal event. /// /// StartedAtUtc is recorded on the first lifecycle transition into Downloading / - /// Installing / InProgress. CompletedAtUtc is recorded on the first transition to a - /// terminal state (Installed / Skipped / Postponed / Error). Both are "set-once" — subsequent - /// identical-state events do not overwrite an earlier stamp. + /// Installing / InProgress and never overwritten. CompletedAtUtc is recorded on a + /// transition to a terminal state (Installed / Skipped / Postponed / Error) and re-armed + /// to null when the app goes terminal → active again (IME retry / re-evaluation, + /// audit Q1) — so the final terminal event carries first-start → last-terminal. /// /// public sealed class AppInstallTiming @@ -30,10 +31,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime /// /// Elapsed time from first Downloading/Installing transition to terminal state, in /// seconds. null when either endpoint is missing (e.g. app still installing, - /// or the adapter missed the start event because it came online mid-install). + /// or the adapter missed the start event because it came online mid-install) — and + /// null when the endpoints are inverted (CompletedAt before StartedAt: log lines + /// from different source files can be processed out of chronological order; observed in + /// production as durationSeconds=-2342 on a Skipped-then-retried user-scope app, + /// audit Q1). A negative duration is never a real measurement, so it is not emitted. /// public double? DurationSeconds => - StartedAtUtc.HasValue && CompletedAtUtc.HasValue + StartedAtUtc.HasValue && CompletedAtUtc.HasValue && CompletedAtUtc.Value >= StartedAtUtc.Value ? (CompletedAtUtc.Value - StartedAtUtc.Value).TotalSeconds : (double?)null; } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Telemetry/DeviceInfo/DeviceInfoCollector.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Telemetry/DeviceInfo/DeviceInfoCollector.cs index 5037d1f2..0c923cbd 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Telemetry/DeviceInfo/DeviceInfoCollector.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Telemetry/DeviceInfo/DeviceInfoCollector.cs @@ -114,6 +114,23 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo CollectTpmStatus(); } + /// + /// Re-reads the ESP configuration (skip flags + ESPTrackingInfo blocking lists) and + /// re-emits esp_config_detected when the payload changed. Audit Q2: the earlier + /// emissions (agent start, DeviceSetup detection) fire before the registry lists are + /// complete — the ESP writes one timestamped subkey per CSP status write, so the + /// device-scope list grows progressively and the user-scope S-<SID> lists + /// appear only after sign-in. Called by as + /// phase-driven one-shots (apps sub-phase opened, AccountSetup detected) — never on a + /// timer. The StartupEventGate keeps an unchanged payload silent, so a re-collect that + /// found nothing new emits nothing. + /// + public void RefreshEspConfiguration(string trigger) + { + _logger.Info($"EnrollmentTracker: re-collecting ESP configuration (trigger={trigger})"); + CollectEspConfiguration(); + } + /// /// Re-collects device info that may change during enrollment (e.g. BitLocker enabled via policy). /// Called at enrollment complete / FinalizingSetup transition to capture final state. diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/DeviceInfoHost.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/DeviceInfoHost.cs index 6dbc9ec5..cd8eeadb 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/DeviceInfoHost.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/DeviceInfoHost.cs @@ -36,6 +36,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration /// CollectAtEnd — once, on FinalizingSetup or desktop arrival /// (whichever comes first; desktop arrival also covers no-ESP / WDP v2). Re-fetches /// BitLocker (commonly enabled via policy DURING enrollment) + the active NIC. + /// RefreshEspConfiguration — audit Q2, one-shot per trigger: the ESP + /// blocking lists in the registry grow progressively (device scope) and the user-scope + /// lists appear only after sign-in, so the early emissions are structurally partial. + /// Re-collected when the apps sub-phase opens (first app activity in DeviceSetup / + /// AccountSetup — the adapter's phase_transition declaration) and when the + /// AccountSetup ESP phase itself is detected. Phase-driven one-shots, never a timer + /// (no-heartbeat policy). /// /// /// Duplicate-event cost is zero: every re-collected event runs through the collector's @@ -46,6 +53,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration { public string Name => "DeviceInfoCollector"; + // ESP-config refresh trigger labels (audit Q2) — also the values passed to + // DeviceInfoCollector.RefreshEspConfiguration for the agent-log line. + internal const string EspConfigTriggerAppsDevice = "apps_phase_device"; + internal const string EspConfigTriggerAppsUser = "apps_phase_user"; + internal const string EspConfigTriggerAccountSetup = "account_setup_detected"; + private readonly Monitoring.Telemetry.DeviceInfo.DeviceInfoCollector _collector; private readonly AgentLogger _logger; @@ -58,6 +71,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration private int _endCollected; private int _disposed; + // Audit Q2 — fire-once latches per ESP-config refresh trigger. Guarded by _espConfigLock + // instead of three Interlocked ints so the membership test + add stays one atomic step. + private readonly object _espConfigLock = new object(); + private readonly HashSet _espConfigRefreshesFired = new HashSet(StringComparer.Ordinal); + public DeviceInfoHost( string sessionId, string tenantId, @@ -100,6 +118,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration private void OnSignalPosted(DecisionSignalKind kind, IReadOnlyDictionary? payload) { + HandleEspConfigRefreshTrigger(kind, payload); + var startTrigger = IsEnrollmentStartTrigger(kind, payload); var endTrigger = IsEndTrigger(kind, payload); if (!startTrigger && !endTrigger) return; @@ -111,10 +131,6 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration var runEndCollect = endTrigger && Interlocked.Exchange(ref _endCollected, 1) == 0; if (!runStartRefresh && !runEndCollect) return; - // Both one-shots done → nothing left to observe. - if (Volatile.Read(ref _enrollmentStartCollected) == 1 && Volatile.Read(ref _endCollected) == 1) - Unsubscribe(); - var trigger = kind == DecisionSignalKind.DesktopArrived ? "desktop_arrived" : "esp_phase_changed"; _logger.Info($"DeviceInfoHost: trigger '{trigger}' — scheduling re-collect (enrollmentStart={runStartRefresh}, end={runEndCollect})."); @@ -134,6 +150,32 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration }); } + /// + /// Audit Q2 — ESP-config refresh one-shots. Each trigger label fires at most once per + /// agent run; the collector's StartupEventGate keeps an unchanged payload silent, so + /// the worst case is one silent registry re-read per trigger. The subscription stays + /// armed for the host's lifetime (unlike the start/end pair there is no "all triggers + /// seen" point that is guaranteed to arrive — SkipUser enrollments never enter + /// AccountSetup); the per-signal cost is a few dictionary lookups. + /// + private void HandleEspConfigRefreshTrigger(DecisionSignalKind kind, IReadOnlyDictionary? payload) + { + var trigger = ClassifyEspConfigRefreshTrigger(kind, payload); + if (trigger == null) return; + + lock (_espConfigLock) + { + if (!_espConfigRefreshesFired.Add(trigger)) return; + } + + _logger.Info($"DeviceInfoHost: ESP-config refresh trigger '{trigger}' — scheduling re-collect."); + Task.Run(() => + { + try { _collector.RefreshEspConfiguration(trigger); } + catch (Exception ex) { _logger.Warning($"DeviceInfoHost: ESP-config refresh threw: {ex.Message}"); } + }); + } + /// First DeviceSetup phase signal — MDM enrollment has populated the registry surface. internal static bool IsEnrollmentStartTrigger(DecisionSignalKind kind, IReadOnlyDictionary? payload) { @@ -156,6 +198,45 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration && string.Equals(phase, nameof(EnrollmentPhase.FinalizingSetup), StringComparison.Ordinal); } + /// + /// Audit Q2 — maps a posted signal to an ESP-config refresh trigger label, or + /// null when the signal is not one. Two trigger families: + /// + /// The adapter's apps sub-phase declaration (phase_transition + /// InformationalEvent with phase AppsDevice/AppsUser — fired on the first app + /// activity in an ESP phase): by then IME is actively processing the blocking set, + /// so the device-scope ESPTrackingInfo lists are as complete as they get. + /// The AccountSetup ESP phase (UserSetup detection): sign-in has happened, so + /// the user-scope S-<SID> lists exist now — production showed 88 of 89 + /// sessions with an EMPTY user list at the last pre-fix emission. + /// + /// + internal static string? ClassifyEspConfigRefreshTrigger(DecisionSignalKind kind, IReadOnlyDictionary? payload) + { + if (payload == null) return null; + + if (kind == DecisionSignalKind.InformationalEvent + && payload.TryGetValue(SignalPayloadKeys.EventType, out var eventType) + && string.Equals(eventType, AutopilotMonitor.Shared.Constants.EventTypes.PhaseTransition, StringComparison.Ordinal) + && payload.TryGetValue(Telemetry.Events.EventTimelineEmitter.PhaseParamKey, out var declaredPhase)) + { + if (string.Equals(declaredPhase, nameof(EnrollmentPhase.AppsDevice), StringComparison.Ordinal)) + return EspConfigTriggerAppsDevice; + if (string.Equals(declaredPhase, nameof(EnrollmentPhase.AppsUser), StringComparison.Ordinal)) + return EspConfigTriggerAppsUser; + return null; + } + + if (kind == DecisionSignalKind.EspPhaseChanged + && payload.TryGetValue(SignalPayloadKeys.EspPhase, out var espPhase) + && string.Equals(espPhase, nameof(EnrollmentPhase.AccountSetup), StringComparison.Ordinal)) + { + return EspConfigTriggerAccountSetup; + } + + return null; + } + public void Stop() => Unsubscribe(); public void Dispose() diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Security/HardwareInfo.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Security/HardwareInfo.cs index 9a643d1c..85a8ec73 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Security/HardwareInfo.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Security/HardwareInfo.cs @@ -93,7 +93,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Security { using (obj) { - manufacturer = obj["Manufacturer"]?.ToString() ?? Unknown; + manufacturer = NormalizeWmiValue(obj["Manufacturer"]?.ToString()); if (manufacturer.IndexOf("lenovo", StringComparison.OrdinalIgnoreCase) >= 0) { using (var lenovoSearcher = new ManagementObjectSearcher("SELECT Version FROM Win32_ComputerSystemProduct")) @@ -103,7 +103,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Security { using (lenovoObj) { - model = lenovoObj["Version"]?.ToString() ?? Unknown; + model = NormalizeWmiValue(lenovoObj["Version"]?.ToString()); } break; } @@ -111,7 +111,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Security } else { - model = obj["Model"]?.ToString() ?? Unknown; + model = NormalizeWmiValue(obj["Model"]?.ToString()); } } } @@ -132,7 +132,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Security { using (obj) { - serialNumber = obj["SerialNumber"]?.ToString() ?? Unknown; + serialNumber = NormalizeWmiValue(obj["SerialNumber"]?.ToString()); } } } @@ -154,5 +154,17 @@ namespace AutopilotMonitor.Agent.V2.Core.Security private static bool IsResolved(string value) => !string.IsNullOrWhiteSpace(value) && !string.Equals(value, Unknown, StringComparison.OrdinalIgnoreCase); + + /// + /// Trims a raw WMI string value at the source (audit Q5: BIOS serials are used as device + /// identity keys downstream — F2 device history joins on them — so padding must never + /// leave the agent). Whitespace-only and empty values collapse to the "Unknown" sentinel, + /// matching the null fallback so the retry logic treats them as unresolved. + /// + internal static string NormalizeWmiValue(string raw) + { + if (string.IsNullOrWhiteSpace(raw)) return Unknown; + return raw.Trim(); + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs index fbd0d0b0..a6cef7ef 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/SignalAdapters/ImeLogTrackerAdapter.cs @@ -132,7 +132,9 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters // Plan §5 Fix 4c — per-app install-lifecycle timing captured from state transitions. // StartedAtUtc on first Downloading/Installing/InProgress transition (set-once); - // CompletedAtUtc on first terminal transition (Installed/Skipped/Postponed/Error). + // CompletedAtUtc on terminal transition (Installed/Skipped/Postponed/Error), re-armed + // to null on a terminal→active transition (IME retry, audit Q1) so the final terminal + // stamp reflects the last outcome instead of freezing at the first one. // Surfaced via to peripheral consumers (FinalStatusBuilder, // app_tracking_summary emission in EnrollmentTerminationHandler). private readonly Dictionary _appTimings = @@ -691,10 +693,20 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters } /// - /// Plan §5 Fix 4c — set-once per-app install-lifecycle timing. Called for every - /// state transition, no-op for duplicate stamps. Returns the up-to-date + /// Plan §5 Fix 4c — per-app install-lifecycle timing. Called for every state + /// transition, no-op for duplicate stamps. Returns the up-to-date /// so the emitter can inline the values on the /// current event's payload without a second dictionary lookup. + /// + /// Audit Q1: a terminal→active transition (the IME retry path — permits e.g. Error→Downloading and + /// Skipped→Downloading) re-arms Completed to null, so the NEXT terminal + /// transition stamps a fresh CompletedAt. StartedAt keeps its first value — the final + /// terminal payload then covers first-start → last-terminal (total occupancy across + /// attempts) instead of freezing at the first failure. Observed pre-fix: a user-scope + /// app Skipped early in DeviceSetup, retried after sign-in, emitted its final + /// Installed event with the stale early CompletedAt (durationSeconds=-2342). + /// /// private AppInstallTiming UpdateAppTiming(string appId, AppInstallationState newState, DateTime now) { @@ -702,13 +714,20 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters { _appTimings.TryGetValue(appId, out var current); + // Terminal→active (retry): the earlier terminal stamp no longer describes this + // app's outcome — re-arm so the next terminal transition stamps fresh. + if (current.Completed != null && IsLifecycleActive(newState)) + { + current.Completed = null; + } + // First lifecycle-active transition → record StartedAt. if (current.Started == null && IsLifecycleActive(newState)) { current.Started = now; } - // First terminal transition → record CompletedAt. + // Terminal transition → record CompletedAt (fresh after a re-arm). if (current.Completed == null && IsCompletedState(newState)) { current.Completed = now;