Compare commits

..

4 Commits

Author SHA1 Message Date
Oliver Kieselbach 7a131af74d agent(summary): DevicePrep app-wave settle wait + Office/CSP row in summary dialog
Session bc803955 (DevicePrep, Succeeded) rendered "No application data
available" although the M365 CSP package installed during prep and IME
delivered 12 required user apps 9 seconds after final-status was written.

- EnrollmentTerminationHandler: bounded settle wait (20s, 250ms poll) before
  the dialog snapshot - DevicePreparation-only and only while the tracker has
  zero packages, so Classic pays nothing. Root cause of the lost race is IME
  AppWorkload.log flush latency (~10-20s), not the 100ms tracker poll.
  Dialog, starved sweep and app_tracking_summary all see settled data.
- FinalStatusBuilder: synthetic "Microsoft 365 Apps" row from the Office C2R
  detector's persisted lifecycle state (Office CSP installs never flow through
  the IME Win32 pipeline). Prepended to the Device bucket, counted in
  appSummary; Preinstalled state deliberately excluded. No SummaryDialog.exe
  change needed - it renders packageStatesByPhase generically.
- OfficeInstallStateData: CompletedAtUtc + VersionReached stamped on terminal
  persists (duration/version for the row); older state files load fail-soft.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-08-18 10:57:46 +02:00
Oliver Kieselbach e750cfe9dd feat(web): gap badge on timeline rows after multi-hour/day time gaps
Timeline rows render time-of-day only, so a large gap between adjacent
events (and the date change it implies) was invisible without expanding
event details. Rows following a gap >= 1h now show an amber chip
(e.g. "+3h" / "+19d"); hovering reveals the full date. Applies to both
the phase timeline and raw mode, using the same display timestamp as
the row (backfilled events keep their event-log time).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-08-18 10:39:36 +02:00
Oliver Kieselbach 3629728d93 feat(time-attribution): PriorEnrollmentResidue quality flag (v2) + WG-signal comment fix
Session f475e697: a device re-enrolled without a wipe (IME log residue from a
previous enrollment) completes its pre-installed apps as instant detections,
pulling the phase anchors ~6.5 min ahead of the real ESP page — the breakdown
was mechanically exact but semantically wrong, and entered fleet stats as clean.

- New duration-critical flag PriorEnrollmentResidue, set on
  historic_ime_replay_detected; excluded from fleet segment stats via the
  existing DurationCriticalFlags mask. registry_app_baseline successes are
  deliberately NOT a trigger (by-design normal for WDP Batch-1) — pinned by test.
- AttributionVersion 1 -> 2 so the maintenance sweep recomputes in-retention
  breakdowns and flags old residue sessions retroactively (rule 8).
- Web: flag label in TimeAttributionLane; docs: quality-flags section.
- Stale comment fix: SaveWhiteGloveSuccessResult is NOT a WhiteGlove indicator
  on Win11 25H2+ (validated 2026-08-18 against user-driven sessions) —
  observability only, consumed nowhere for classification.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-08-18 10:39:11 +02:00
Oliver Kieselbach e521fd5cf4 fix(ime-archive): heal provenance.json lost behind the write-once 409 path
Daily-review finding: the MSI upload is write-once (If-None-Match:*), so a
first attempt that died between the MSI and the provenance upload funneled
every retry into the 409 short-circuit — which returned "Archived" without
ever writing provenance.json (permanently lost). The 409 path now checks for
the sidecar and, when missing, rehashes the ARCHIVED bytes and writes it;
heal failures ride the normal retryable ladder.

Also closes the review's test gaps: ImeMsiArchiveQueueWorker + producer
worker-level tests (internal QueueClient test ctors, SessionDeletionWorker
pattern), CorporateIdentifierValidator null/whitespace + OData special-char
+ page-cap-transient tests, registry observer helper tests
(TerminalOutcome/ChangedFields/ClassifyStatusServiceStatus).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-08-18 10:21:26 +02:00
24 changed files with 1317 additions and 50 deletions
+16 -1
View File
@@ -58,6 +58,21 @@ timestamp runs backward are dropped (`ClockSkewDropped`).
| Complete, `desktop_arrived` event | `desktop_handoff` |
| Failed | attribution ends — tail stays unattributed |
## Quality flags (AttributionVersion 2)
Duration-critical flags (`ClockSkewDropped`, `PartialObservation`,
`WhiteGloveAnchorsIncomplete`, `PriorEnrollmentResidue`) exclude a breakdown from fleet
segment statistics with a disclosed count; the blocking-set flags (`BlockingSetUnknown`,
`BlockingSetTruncated`) only limit per-app evidence and never gate fleet stats.
`PriorEnrollmentResidue` (v2) fires on `historic_ime_replay_detected`: the IME log on disk
predates the enrollment, so the device was re-enrolled without a wipe — pre-installed apps
complete as instant detections and pull the phase anchors ahead of the real ESP page
(session f475e697: AccountSetup anchor 6.5 min early, 457 s misattributed to
`identity_hello`). `registry_app_baseline` successes are deliberately NOT a trigger — they
are by-design normal for Windows Device Preparation (DPP Batch-1 apps install before the
agent exists) and would starve that class's aggregates.
## ESP-blocking apps (positive evidence only)
Per-app intervals use EVENT timestamps (first started/download event → LAST terminal
@@ -117,7 +132,7 @@ gap before the first part-2 phase declaration is unattributed, not guessed.
# Citations
* `src/Backend/AutopilotMonitor.Functions/Helpers/TimeAttributionCalculator.cs` — calculator + semantics (AttributionVersion 1).
* `src/Backend/AutopilotMonitor.Functions/Helpers/TimeAttributionCalculator.cs` — calculator + semantics (AttributionVersion 2).
* `src/Backend/AutopilotMonitor.Functions/Services/TableStorageService.TimeAttribution.cs` — persistence.
* `src/Backend/AutopilotMonitor.Functions/Services/MaintenanceService.Aggregation.cs` — sweep + aggregation.
* `src/Backend/AutopilotMonitor.Functions.Tests/TimeAttributionCalculatorTests.cs` — golden fixtures pinning the invariant.
+1
View File
@@ -2,6 +2,7 @@
## 2026-08-18
* **Update**: `backend/time-attribution.md` — AttributionVersion 1 → 2: new duration-critical quality flag `PriorEnrollmentResidue` (fires on `historic_ime_replay_detected`; a re-enrollment without wipe pulls the phase anchors ahead of the real ESP page, so the segments are excluded from fleet stats; `registry_app_baseline` successes deliberately not a trigger — by-design normal for WDP). Added the quality-flags section.
* **Update**: `agent/logs-and-persistence.md`, `agent/overview.md`, `agent/gather-rule-debug-log.md` — log files renamed to unified kebab-case: `agent.log` (date rotation dropped; size segments `agent-NNN.log`), `bootstrap-script.log` (was `bootstrap_agent.log`), `bootstrap-msi.log` (was `msi-bootstrap.log`), `crash-*.log`, `gather-rules-debug.log`, `ime-pattern-matches.log`. Old names still appear in archives from pre-rename agents.
* **New**: `agent/registry-app-state-pillar.md` — the registry second pillar for IME app state (audit follow-up): snapshot-and-diff watcher on `HKLM\...\IntuneManagementExtension` (Win32Apps / EspTrackingWin32Apps / StatusServiceReports), `registry_app_state` + `app_state_reconciliation` events, silent startup baseline, WDP reuse notes.
@@ -56,6 +56,42 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Office
Assert.Equal(1, loaded.PeakDo.DownloadMode);
}
[Fact]
public void Save_then_load_roundtrips_terminal_metadata()
{
// Session bc803955 — CompletedAtUtc/VersionReached feed the summary dialog's
// synthetic Office row (duration + version).
using var tmp = new TempDirectory();
var sut = new OfficeInstallStatePersistence(tmp.Path, NewLogger(tmp.Path));
var completedAt = new DateTime(2026, 6, 8, 12, 3, 22, DateTimeKind.Utc);
sut.Save(new OfficeInstallStateData
{
State = OfficeInstallStateData.StateCompleted,
CompletedAtUtc = completedAt,
VersionReached = "16.0.20228.20190",
});
var loaded = sut.Load();
Assert.Equal(completedAt, loaded!.CompletedAtUtc);
Assert.Equal("16.0.20228.20190", loaded.VersionReached);
}
[Fact]
public void Load_tolerates_state_files_from_older_agents_without_terminal_metadata()
{
using var tmp = new TempDirectory();
var sut = new OfficeInstallStatePersistence(tmp.Path, NewLogger(tmp.Path));
// Pre-terminal-metadata wire format (verbatim shape from a live 2.0.1404 session).
File.WriteAllText(sut.StateFilePath,
"{\"State\":\"Completed\",\"StartedAtUtc\":\"2026-08-18T07:56:16.8208141Z\",\"StartedTrigger\":\"registry\"}");
var loaded = sut.Load();
Assert.Equal(OfficeInstallStateData.StateCompleted, loaded!.State);
Assert.Null(loaded.CompletedAtUtc);
Assert.Null(loaded.VersionReached);
}
[Fact]
public void Save_overwrites_a_previous_state()
{
@@ -59,6 +59,71 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
public void ClassifyEnforcementState_bands(int state, string expected)
=> Assert.Equal(expected, ImeRegistryAppStateObserver.ClassifyEnforcementState(state));
[Theory]
[InlineData(1000, "installed")]
[InlineData(1999, "installed")]
[InlineData(3000, "failed")]
[InlineData(2000, "notApplicable")]
[InlineData(2999, "notApplicable")]
[InlineData(0, null)]
[InlineData(999, null)]
[InlineData(3001, null)]
[InlineData(4000, null)]
public void ClassifyStatusServiceStatus_bands(int status, string? expected)
=> Assert.Equal(expected, ImeRegistryAppStateObserver.ClassifyStatusServiceStatus(status));
[Fact]
public void TerminalOutcome_prefers_enforcement_state_then_status_service()
{
// Enforcement state alone decides when terminal.
Assert.Equal("success", ImeRegistryAppStateObserver.TerminalOutcome(Entry(enforcementState: 1000)));
Assert.Equal("error", ImeRegistryAppStateObserver.TerminalOutcome(Entry(enforcementState: 5003)));
// Non-terminal enforcement bands defer to the StatusService pillar.
Assert.Null(ImeRegistryAppStateObserver.TerminalOutcome(Entry(enforcementState: 2009)));
Assert.Equal("error", ImeRegistryAppStateObserver.TerminalOutcome(
Entry(enforcementState: 2009, statusServiceStatus: 3000)));
Assert.Equal("success", ImeRegistryAppStateObserver.TerminalOutcome(Entry(statusServiceStatus: 1000)));
Assert.Equal("error", ImeRegistryAppStateObserver.TerminalOutcome(Entry(statusServiceStatus: 3000)));
// requirementsNotMet / notApplicable / empty entries are not judgeable.
Assert.Null(ImeRegistryAppStateObserver.TerminalOutcome(Entry(enforcementState: 3000)));
Assert.Null(ImeRegistryAppStateObserver.TerminalOutcome(Entry(statusServiceStatus: 2500)));
Assert.Null(ImeRegistryAppStateObserver.TerminalOutcome(Entry()));
}
[Fact]
public void ChangedFields_reports_each_field_and_ignores_espPhase_casing()
{
var prev = Entry(enforcementState: 2009, errorCode: null, exitCode: null,
statusServiceStatus: null, espTracked: false, espPhase: "DevicePreparation");
var next = Entry(enforcementState: 1000, errorCode: 0, exitCode: 0,
statusServiceStatus: 1000, espTracked: true, espPhase: "devicepreparation");
var changed = ImeRegistryAppStateObserver.ChangedFields(prev, next);
Assert.Equal(
new[] { "enforcementState", "errorCode", "exitCode", "statusServiceStatus", "espTracked" },
changed);
// Case-only espPhase difference is not a change; identity diffs to empty.
Assert.DoesNotContain("espPhase", changed);
Assert.Empty(ImeRegistryAppStateObserver.ChangedFields(next, next));
}
[Fact]
public void ChangedFields_null_previous_reports_populated_fields_of_new_entry()
{
var fresh = Entry(enforcementState: 2000, espTracked: true, espPhase: "AccountSetup");
var changed = ImeRegistryAppStateObserver.ChangedFields(null, fresh);
Assert.Contains("enforcementState", changed);
Assert.Contains("espTracked", changed);
Assert.Contains("espPhase", changed);
// Fields that are null on both sides are not "changes" for a brand-new entry.
Assert.DoesNotContain("errorCode", changed);
Assert.DoesNotContain("exitCode", changed);
Assert.DoesNotContain("statusServiceStatus", changed);
}
[Fact]
public void DiffSnapshots_reports_only_changed_fields()
{
@@ -264,6 +329,20 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
return (sink, clock, observer);
}
private static AppRegistryEntry Entry(
int? enforcementState = null, long? errorCode = null, int? exitCode = null,
int? statusServiceStatus = null, bool espTracked = false, string? espPhase = null)
{
var entry = new AppRegistryEntry($"{ImeRegistrySnapshot.DeviceContext}|{App1}", ImeRegistrySnapshot.DeviceContext, App1);
entry.EnforcementState = enforcementState;
entry.ErrorCode = errorCode;
entry.ExitCode = exitCode;
entry.StatusServiceStatus = statusServiceStatus;
entry.EspTracked = espTracked;
entry.EspPhase = espPhase;
return entry;
}
private static ImeRegistrySnapshot Snapshot(params (string appId, int enforcementState, long? errorCode)[] apps)
{
var snapshot = new ImeRegistrySnapshot();
@@ -165,6 +165,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
public IReadOnlyCollection<string> StarvedAlreadyReportedOverride { get; set; } = Array.Empty<string>();
public List<string> TerminationActionLog { get; } = new List<string>();
public TimeSpan SpoolDrainPeriodOverride { get; set; } = TimeSpan.Zero;
// Session bc803955 — DevicePrep app-wave settle wait. Zero (default) disables the
// wait so the existing timing-sensitive tests stay untouched; the dedicated settle
// tests opt in with a real budget.
public TimeSpan DevicePrepAppSettleWaitOverride { get; set; } = TimeSpan.Zero;
// WG Part-1 straggler-ordering fix — the production wiring passes
// orchestrator.StopCollectorHosts, whose collectors emit their one-shot
// stop-time stragglers (network_bandwidth_estimate, …) through Post during
@@ -210,7 +214,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
stopPeripheralCollectors: StopPeripheralCollectorsHook,
// Zero out the timing ceremony for tests — production paths are covered by
// the dedicated V1-parity tests below which opt back in via their own Rig.
lateEventGracePeriod: TimeSpan.Zero);
lateEventGracePeriod: TimeSpan.Zero,
devicePrepAppSettleWait: DevicePrepAppSettleWaitOverride);
}
public void Dispose() => Tmp.Dispose();
@@ -317,6 +322,91 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
Assert.True(File.Exists(statusPath), "final-status.json should be written even when ShowEnrollmentSummary=false");
}
// ---- Session bc803955 — DevicePrep app-wave settle wait ----
private static DecisionState DevicePrepState(SessionStage stage) =>
new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1"))
{
Stage = stage,
ScenarioProfile = new EnrollmentScenarioProfile(
mode: EnrollmentMode.DevicePreparation,
joinMode: EnrollmentJoinMode.Unknown,
espConfig: EspConfig.Unknown,
preProvisioningSide: PreProvisioningSide.None,
confidence: ProfileConfidence.Medium,
evidenceOrdinal: 1,
reason: "test"),
}.Build();
[Fact]
public void Handle_devicePrep_settle_wait_catches_late_app_wave_for_dialog()
{
using var rig = new Rig();
rig.State = DevicePrepState(SessionStage.Completed);
rig.DevicePrepAppSettleWaitOverride = TimeSpan.FromSeconds(10);
// Simulate the IME user-context sync landing AFTER termination handling began
// (AppWorkload.log flush latency) — the wave arrives 500ms in, well before the
// 10s budget; the settle loop must pick it up and the dialog must render it.
var waveThread = new Thread(() =>
{
Thread.Sleep(500);
var app = new AppPackageState("app-late", 0);
app.UpdateState(AppInstallationState.Downloading);
TestHelpers.SetTargeted(app, AppTargeted.User);
rig.Packages.Add(app);
});
waveThread.Start();
var sw = System.Diagnostics.Stopwatch.StartNew();
rig.Build().Handle(sender: null!,
Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
sw.Stop();
waveThread.Join();
var statusJson = File.ReadAllText(Path.Combine(rig.StateDir, SummaryDialogLauncher.FinalStatusFileName));
Assert.Contains("\"totalApps\": 1", statusJson);
// Early exit: the wave arrived at ~500ms — the handler must not sit out the full 10s.
Assert.True(sw.Elapsed < TimeSpan.FromSeconds(8),
$"settle wait should exit early once packages arrive (took {sw.Elapsed.TotalSeconds:0.0}s)");
}
[Fact]
public void Handle_devicePrep_settle_wait_is_bounded_when_no_apps_arrive()
{
using var rig = new Rig();
rig.State = DevicePrepState(SessionStage.Completed);
rig.DevicePrepAppSettleWaitOverride = TimeSpan.FromMilliseconds(600);
var sw = System.Diagnostics.Stopwatch.StartNew();
rig.Build().Handle(sender: null!,
Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
sw.Stop();
// Budget elapsed (>=600ms) and the dialog still rendered — just without app data.
Assert.True(sw.Elapsed >= TimeSpan.FromMilliseconds(600),
$"bounded wait should consume its budget when no data arrives (took {sw.Elapsed.TotalMilliseconds:0}ms)");
var statusJson = File.ReadAllText(Path.Combine(rig.StateDir, SummaryDialogLauncher.FinalStatusFileName));
Assert.Contains("\"totalApps\": 0", statusJson);
}
[Fact]
public void Handle_non_devicePrep_does_not_wait_even_with_empty_packages()
{
using var rig = new Rig();
// Classic/unknown mode + empty package list — the settle wait must not engage.
rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.Completed }.Build();
rig.DevicePrepAppSettleWaitOverride = TimeSpan.FromSeconds(10);
var sw = System.Diagnostics.Stopwatch.StartNew();
rig.Build().Handle(sender: null!,
Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
sw.Stop();
Assert.True(sw.Elapsed < TimeSpan.FromSeconds(8),
$"non-DevicePrep termination must not settle-wait (took {sw.Elapsed.TotalSeconds:0.0}s)");
}
[Fact]
public void Handle_writes_enrollment_complete_marker_on_non_whiteglove_terminal()
{
@@ -1,8 +1,10 @@
#nullable enable
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Termination;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
@@ -508,6 +510,121 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
Assert.Null(status.SignalTimestamps);
}
// ---- Session bc803955 — synthetic Office row from the C2R detector's persisted state ----
private static FinalStatus BuildWithOffice(OfficeInstallStateData? officeState, IReadOnlyList<AppPackageState>? packages = null) =>
FinalStatusBuilder.Build(StateWith(SessionStage.Completed),
Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed),
packageStates: packages, agentStartTimeUtc: StartUtc, officeState: officeState);
[Fact]
public void Build_office_completed_adds_device_row_with_duration_and_counts()
{
var office = new OfficeInstallStateData
{
State = OfficeInstallStateData.StateCompleted,
StartedAtUtc = StartUtc.AddMinutes(1),
CompletedAtUtc = StartUtc.AddMinutes(4).AddSeconds(22),
VersionReached = "16.0.20228.20190",
};
var status = BuildWithOffice(office);
var row = Assert.Single(status.PackageStatesByPhase["Device"]);
Assert.Equal("Microsoft 365 Apps (16.0.20228.20190)", row.AppName);
Assert.Equal("Installed", row.State);
Assert.True(row.IsCompleted);
Assert.False(row.IsError);
Assert.Equal(202, row.DurationSeconds);
Assert.Equal(office.StartedAtUtc.Value.ToString("o"), row.StartedAt);
Assert.Equal(1, status.AppSummary.TotalApps);
Assert.Equal(1, status.AppSummary.CompletedApps);
Assert.Equal(0, status.AppSummary.ErrorCount);
Assert.Equal(1, status.AppSummary.AppsByPhase["Device"]);
}
[Fact]
public void Build_office_active_row_is_installing_without_completion()
{
var office = new OfficeInstallStateData
{
State = OfficeInstallStateData.StateActive,
StartedAtUtc = StartUtc.AddMinutes(1),
};
var status = BuildWithOffice(office);
var row = Assert.Single(status.PackageStatesByPhase["Device"]);
Assert.Equal("Microsoft 365 Apps", row.AppName);
Assert.Equal("Installing", row.State);
Assert.False(row.IsCompleted);
Assert.Null(row.DurationSeconds);
Assert.Equal(1, status.AppSummary.TotalApps);
Assert.Equal(0, status.AppSummary.CompletedApps);
}
[Fact]
public void Build_office_failed_row_counts_device_error()
{
var office = new OfficeInstallStateData
{
State = OfficeInstallStateData.StateFailed,
StartedAtUtc = StartUtc.AddMinutes(1),
CompletedAtUtc = StartUtc.AddMinutes(2),
};
var status = BuildWithOffice(office);
var row = Assert.Single(status.PackageStatesByPhase["Device"]);
Assert.Equal("Error", row.State);
Assert.True(row.IsError);
Assert.True(row.IsCompleted); // Error is terminal — mirrors IsCompleted()
Assert.Equal(1, status.AppSummary.ErrorCount);
Assert.Equal(1, status.AppSummary.DeviceErrors);
}
[Theory]
[InlineData(OfficeInstallStateData.StatePreinstalled)]
[InlineData("garbage")]
[InlineData(null)]
public void Build_office_preinstalled_or_unknown_adds_no_row(string? state)
{
var office = state == null ? null : new OfficeInstallStateData { State = state };
var status = BuildWithOffice(office);
Assert.Empty(status.PackageStatesByPhase);
Assert.Equal(0, status.AppSummary.TotalApps);
}
[Fact]
public void Build_office_row_is_prepended_before_ime_device_apps()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
var list = new AppPackageStateList(logger);
var imeApp = new AppPackageState("app-1", 0);
imeApp.UpdateState(AppInstallationState.Installed);
TestHelpers.SetTargeted(imeApp, AppTargeted.Device);
list.Add(imeApp);
var office = new OfficeInstallStateData
{
State = OfficeInstallStateData.StateCompleted,
StartedAtUtc = StartUtc,
CompletedAtUtc = StartUtc.AddMinutes(3),
};
var status = BuildWithOffice(office, list);
Assert.Equal(2, status.PackageStatesByPhase["Device"].Count);
Assert.StartsWith("Microsoft 365 Apps", status.PackageStatesByPhase["Device"][0].AppName);
Assert.Equal(2, status.AppSummary.TotalApps);
Assert.Equal(2, status.AppSummary.CompletedApps);
Assert.Equal(2, status.AppSummary.AppsByPhase["Device"]);
}
}
/// <summary>Mini helper for reflection-based field setters — AppPackageState.Targeted is a private-set property.</summary>
@@ -194,7 +194,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// <summary>
/// True when DeviceSetup contains a SaveWhiteGloveSuccessResult subcategory with state "succeeded".
/// This is a definitive WhiteGlove (Pre-Provisioning) confirmation signal from the ESP registry.
/// NOT a WhiteGlove indicator on Win11 25H2+ — Windows writes it in every enrollment
/// (see <see cref="ProvisioningStatusTracker.HasSaveWhiteGloveSuccessResult"/>). Observability only.
/// </summary>
public bool HasSaveWhiteGloveSuccessResult => _provisioningTracker?.HasSaveWhiteGloveSuccessResult ?? false;
@@ -107,7 +107,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
private bool _deviceSetupProvisioningCompleteFired;
// Fire-once guard for AccountSetupProvisioningComplete event (session 330f73f3 fix)
private bool _accountSetupProvisioningCompleteFired;
// WhiteGlove confirmation: DeviceSetup registry contains SaveWhiteGloveSuccessResult=succeeded
// DeviceSetup registry contains SaveWhiteGloveSuccessResult=succeeded. NOT a WhiteGlove
// indicator on Win11 25H2+ (see HasSaveWhiteGloveSuccessResult) — observability only.
private bool _saveWhiteGloveSuccessResultSeen;
// Track SaveWhiteGloveSuccessResult state transitions for observability (null → notStarted → succeeded)
private string _lastSaveWhiteGloveState;
@@ -226,8 +227,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// <summary>
/// True when DeviceSetup registry JSON contains a SaveWhiteGloveSuccessResult property
/// with subcategoryState=succeeded. This is a definitive WhiteGlove (Pre-Provisioning)
/// confirmation signal — Windows only writes this property during White Glove flows.
/// with subcategoryState=succeeded. NOT a WhiteGlove indicator: on Win11 25H2 (build
/// 26200+) Windows writes this property as a trivially-succeeding step in EVERY
/// enrollment (validated 2026-08-18 — user-driven sessions f475e697/c601a24b/4219203f
/// all carry it). Kept for observability only (whiteglove_signal_* raw dumps); must not
/// be used for classification. Reliable WhiteGlove anchors are ModernDeployment
/// EventID 509 and the Shell-Core WhiteGlove-success events.
/// </summary>
public bool HasSaveWhiteGloveSuccessResult
{
@@ -891,10 +896,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
string categoryStatusMessage = SafeGetString(root, "categoryStatusMessage");
var subcategories = ParseSubcategories(root);
// Detect WhiteGlove signal in DeviceSetup category.
// SaveWhiteGloveSuccessResult is NOT a *Subcategory-suffixed property, so
// ParseSubcategories skips it. We scan the raw JSON explicitly.
// Track state transitions for full observability (notStarted → succeeded).
// Track the SaveWhiteGloveSuccessResult transitions in the DeviceSetup
// category (observability only — NOT a WhiteGlove indicator on 25H2+, see
// HasSaveWhiteGloveSuccessResult). It is NOT a *Subcategory-suffixed
// property, so ParseSubcategories skips it; we scan the raw JSON explicitly.
if (string.Equals(categoryLabel, "DeviceSetup", StringComparison.OrdinalIgnoreCase))
{
foreach (var prop in root.EnumerateObject())
@@ -919,7 +924,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
_saveWhiteGloveSuccessResultSeen = true;
_logger.Info("ProvisioningStatusTracker: SaveWhiteGloveSuccessResult=succeeded " +
"— WhiteGlove confirmation signal");
"(observability only — not a WhiteGlove indicator on 25H2+)");
}
}
break;
@@ -300,7 +300,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
{
_state = DetectorState.Terminal;
EmitLifecycle(Constants.EventTypes.OfficeInstallCompleted, snap, EventSeverity.Info, "Completed", isTerminal: true, coreBinariesPresent: true);
PersistState(OfficeInstallStateData.StateCompleted);
PersistState(OfficeInstallStateData.StateCompleted, snap);
return CompletionOutcome.Completed;
}
@@ -405,7 +405,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
if (_state == DetectorState.Terminal) return;
_state = DetectorState.Terminal;
EmitLifecycle(Constants.EventTypes.OfficeInstallFailed, snap, EventSeverity.Error, "Failed", isTerminal: true);
PersistState(OfficeInstallStateData.StateFailed);
PersistState(OfficeInstallStateData.StateFailed, snap);
}
/// <summary>
@@ -444,15 +444,20 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
/// (the resume is what delivers a completion missed across a mid-install reboot).
/// Caller holds the lock.
/// </summary>
private void PersistState(string state)
private void PersistState(string state, OfficeC2RSnapshot? snap = null)
{
if (_statePersistence == null) return;
_lastStatePersistUtc = _clock.UtcNow;
var isTerminal = state == OfficeInstallStateData.StateCompleted
|| state == OfficeInstallStateData.StateFailed;
_statePersistence.Save(new OfficeInstallStateData
{
State = state,
StartedAtUtc = _startedAtUtc,
StartedTrigger = _startedTrigger,
// Terminal-only metadata for the summary dialog's Office row (duration + version).
CompletedAtUtc = isTerminal ? _clock.UtcNow : (DateTime?)null,
VersionReached = isTerminal ? snap?.VersionToReport : null,
PeakDo = OfficeDoPeakData.FromSample(_peakDo),
});
}
@@ -105,6 +105,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
public DateTime? StartedAtUtc { get; set; }
public string? StartedTrigger { get; set; }
/// <summary>Stamped only on the two terminal persists (Completed/Failed) — basis for the
/// summary dialog's Office row duration. Null on Active/Preinstalled and on state files
/// written by older agents (fail-soft deserialization).</summary>
public DateTime? CompletedAtUtc { get; set; }
/// <summary>Office build reached at the terminal transition (snapshot's VersionToReport).
/// Null when the snapshot had none or on older state files.</summary>
public string? VersionReached { get; set; }
/// <summary>Highest-bytes DO sample seen — basis for the doSummary on a resumed completion.</summary>
public OfficeDoPeakData? PeakDo { get; set; }
@@ -8,6 +8,7 @@ using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Interop;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Runtime;
using AutopilotMonitor.Agent.V2.Core.Security;
@@ -56,6 +57,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
public sealed class EnrollmentTerminationHandler
{
private static readonly TimeSpan DefaultLateEventGrace = TimeSpan.FromMilliseconds(2000);
/// <summary>
/// Session bc803955 — on DevicePreparation the IME user-context app sync starts only
/// after desktop arrival and its log lines reach disk with 10-20s flush latency, so the
/// dialog snapshot raced it and rendered an empty Applications section 9 seconds before
/// the tracker learned about 12 pending apps. Bounded settle wait before the summary
/// build; DevicePrep-only and only while the tracker has zero packages, so Classic (data
/// long settled) and populated DevicePrep sessions pay nothing. Installs are never
/// delayed — this only holds the dialog snapshot.
/// </summary>
private static readonly TimeSpan DefaultDevicePrepAppSettleWait = TimeSpan.FromSeconds(20);
private static readonly TimeSpan AppSettlePollInterval = TimeSpan.FromMilliseconds(250);
// Option 1 (WG Part 1 graceful-exit hardening, 2026-04-30): poll cadence for the
// active spool-empty drain. 50ms is short enough that we exit the bounded wait
// within ~one cadence after the last upload is acknowledged, but long enough that
@@ -90,6 +103,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
private readonly AgentAnalyzerManager _analyzerManager;
private readonly InformationalEventPost _post;
private readonly TimeSpan _lateEventGracePeriod;
private readonly TimeSpan _devicePrepAppSettleWait;
// L4 (delta review 2026-07-02): epoch anchor for boot-time derivation. Captured as a
// (monotonic tick, wall clock) pair at construction so the boot timestamp used by the
@@ -113,7 +127,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
AgentAnalyzerManager analyzerManager = null,
InformationalEventPost post = null,
Action stopPeripheralCollectors = null,
TimeSpan? lateEventGracePeriod = null)
TimeSpan? lateEventGracePeriod = null,
TimeSpan? devicePrepAppSettleWait = null)
{
_session = session ?? throw new ArgumentNullException(nameof(session));
_appTracking = appTracking ?? throw new ArgumentNullException(nameof(appTracking));
@@ -126,6 +141,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
_post = post;
_stopPeripheralCollectors = stopPeripheralCollectors;
_lateEventGracePeriod = lateEventGracePeriod ?? DefaultLateEventGrace;
_devicePrepAppSettleWait = devicePrepAppSettleWait ?? DefaultDevicePrepAppSettleWait;
_configuration = session.Configuration;
_stateDirectory = session.StateDirectory;
@@ -182,6 +198,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
}
else
{
// Session bc803955 — give the IME user-context app wave a bounded chance
// to land BEFORE the dialog snapshot, the starved sweep and the
// app_tracking_summary below all read package states. DevicePrep-only,
// no-op when the tracker already has data.
WaitForImeAppSettleIfDevicePrep(state);
RunBuildAndLaunchDialog(state, args);
}
}
@@ -378,6 +399,59 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
}
}
/// <summary>
/// Bounded settle wait for the IME app wave on DevicePreparation sessions (see
/// <see cref="DefaultDevicePrepAppSettleWait"/>). Returns immediately for every other
/// scenario mode and whenever the tracker already reports packages. Poll is cheap
/// (in-memory read-model access), so a fine 250ms interval keeps the early exit tight.
/// </summary>
private void WaitForImeAppSettleIfDevicePrep(DecisionState state)
{
try
{
if (state == null || _devicePrepAppSettleWait <= TimeSpan.Zero) return;
if (state.ScenarioProfile.Mode != EnrollmentMode.DevicePreparation) return;
var packages = TryGetPackageStates();
if (packages != null && packages.Count > 0) return;
_logger.Info(
$"EnrollmentTerminationHandler: DevicePreparation session with no IME app data yet — waiting up to " +
$"{_devicePrepAppSettleWait.TotalSeconds:0}s for the user-context app wave before building the summary " +
"(installs are not delayed; this only holds the dialog snapshot).");
var deadline = DateTime.UtcNow + _devicePrepAppSettleWait;
while (DateTime.UtcNow < deadline)
{
Thread.Sleep(AppSettlePollInterval);
packages = TryGetPackageStates();
if (packages != null && packages.Count > 0)
{
_logger.Info($"EnrollmentTerminationHandler: IME app data arrived during settle wait ({packages.Count} package(s)).");
return;
}
}
_logger.Info("EnrollmentTerminationHandler: app settle wait elapsed without IME app data — summary reflects Office/CSP state only.");
}
catch (Exception ex)
{
_logger.Warning($"EnrollmentTerminationHandler: app settle wait failed: {ex.Message}");
}
}
/// <summary>
/// Fail-soft read of the Office C2R lifecycle state persisted by
/// <see cref="OfficeInstallDetector"/> — feeds the summary dialog's synthetic
/// "Microsoft 365 Apps" row (Office CSP installs never flow through the IME Win32
/// pipeline, so the package-state list cannot represent them).
/// </summary>
private OfficeInstallStateData TryLoadOfficeInstallState()
{
try { return new OfficeInstallStatePersistence(_stateDirectory, _logger).Load(); }
catch { return null; }
}
private void RunBuildAndLaunchDialog(DecisionState state, EnrollmentTerminatedEventArgs args)
{
try
@@ -385,7 +459,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
var packages = TryGetPackageStates();
var timings = TryGetAppTimings();
var status = FinalStatusBuilder.Build(state, args, packages, _agentStartTimeUtc, timings,
deviceBootUtc: ObservationCoverage.DeviceBootUtc(_bootAnchorTickMs, _bootAnchorUtc));
deviceBootUtc: ObservationCoverage.DeviceBootUtc(_bootAnchorTickMs, _bootAnchorUtc),
officeState: TryLoadOfficeInstallState());
SummaryDialogLauncher.WriteAndLaunch(status, _configuration, _stateDirectory, _logger, _dialogExePathOverride);
if (_configuration.ShowEnrollmentSummary)
@@ -2,6 +2,7 @@
using System;
using System.Collections.Generic;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.DecisionCore.State;
@@ -30,7 +31,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
IReadOnlyList<AppPackageState>? packageStates,
DateTime agentStartTimeUtc,
IReadOnlyDictionary<string, AppInstallTiming>? appTimings = null,
DateTime? deviceBootUtc = null)
DateTime? deviceBootUtc = null,
OfficeInstallStateData? officeState = null)
{
if (state == null) throw new ArgumentNullException(nameof(state));
if (terminated == null) throw new ArgumentNullException(nameof(terminated));
@@ -78,9 +80,85 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
PackageStatesByPhase = BuildPackageStatesByPhase(packageStates, timings),
};
AddOfficeRow(status, officeState);
return status;
}
/// <summary>
/// Session bc803955 — the Office C2R install (Office CSP app type / M365 "CSP" package)
/// never flows through the IME Win32 pipeline, so <see cref="BuildAppSummary"/> cannot see
/// it and a DevicePreparation session whose only app activity is Office rendered
/// "No application data available". Synthesize one package row from the
/// <see cref="OfficeInstallDetector"/>'s persisted lifecycle state instead. Preinstalled
/// is deliberately skipped — that state marks resident OEM/consumer Office, not an
/// enrollment install.
/// </summary>
private static void AddOfficeRow(FinalStatus status, OfficeInstallStateData? officeState)
{
if (officeState == null) return;
string rowState;
bool isCompleted = false, isError = false;
switch (officeState.State)
{
case OfficeInstallStateData.StateActive:
rowState = AppInstallationState.Installing.ToString();
break;
case OfficeInstallStateData.StateCompleted:
rowState = AppInstallationState.Installed.ToString();
isCompleted = true;
break;
case OfficeInstallStateData.StateFailed:
rowState = AppInstallationState.Error.ToString();
isError = true;
isCompleted = true; // mirrors IsCompleted(): Error counts as terminal
break;
default:
return; // Preinstalled / unknown — not an enrollment install
}
double? duration = officeState.StartedAtUtc.HasValue && officeState.CompletedAtUtc.HasValue
? Math.Max(0, (officeState.CompletedAtUtc.Value - officeState.StartedAtUtc.Value).TotalSeconds)
: (double?)null;
var name = string.IsNullOrEmpty(officeState.VersionReached)
? "Microsoft 365 Apps"
: $"Microsoft 365 Apps ({officeState.VersionReached})";
var row = new FinalStatusPackageInfo
{
AppName = name,
State = rowState,
IsError = isError,
IsCompleted = isCompleted,
Targeted = AppTargeted.Device.ToString(),
StartedAt = officeState.StartedAtUtc?.ToString("o"),
CompletedAt = officeState.CompletedAtUtc?.ToString("o"),
DurationSeconds = duration,
};
var phaseKey = AppTargeted.Device.ToString();
if (!status.PackageStatesByPhase.TryGetValue(phaseKey, out var bucket))
{
bucket = new List<FinalStatusPackageInfo>();
status.PackageStatesByPhase[phaseKey] = bucket;
}
// Office installs during device prep / device ESP — before any IME-tracked app.
bucket.Insert(0, row);
var summary = status.AppSummary;
summary.TotalApps++;
if (isCompleted) summary.CompletedApps++;
if (isError)
{
summary.ErrorCount++;
summary.DeviceErrors++;
}
if (!summary.AppsByPhase.TryGetValue(phaseKey, out var cnt)) cnt = 0;
summary.AppsByPhase[phaseKey] = cnt + 1;
}
/// <summary>
/// Schema 2 — derives a human-readable explanation rendered as the dialog's failure
/// banner. Returns <c>null</c> for successful terminal outcomes (succeeded /
@@ -0,0 +1,124 @@
using System;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;
using Azure;
using Azure.Storage.Queues;
using Azure.Storage.Queues.Models;
using AutopilotMonitor.Functions.Services.Ime;
using AutopilotMonitor.Shared.Models;
using Microsoft.Extensions.Logging.Abstractions;
using Moq;
using Newtonsoft.Json;
using Xunit;
namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Producer tests for the ime-msi-archive queue (daily review 2026-08-18: previously
/// untested). Contract: the caller is the ingest path's fire-and-forget continuation, so
/// NOTHING may throw — version-less envelopes are skipped, send failures are swallowed,
/// and a failed CreateIfNotExists is retried on the next enqueue instead of latching.
/// </summary>
public class AzureQueueImeMsiArchiveProducerTests
{
private const string Version = "1.104.102.0";
[Fact]
public async Task EnqueueAsync_sends_envelope_json_and_ensures_queue_once()
{
var (producer, queue, sentBodies) = BuildSut();
await producer.EnqueueAsync(Envelope());
await producer.EnqueueAsync(Envelope());
Assert.Equal(2, sentBodies.Count);
var roundTripped = JsonConvert.DeserializeObject<ImeMsiArchiveEnvelope>(sentBodies[0])!;
Assert.Equal(Version, roundTripped.Version);
Assert.Equal(ImeMsiArchiver.CanonicalMsiUrl, roundTripped.MsiDownloadUrl);
Assert.Equal("11111111-1111-1111-1111-111111111111", roundTripped.TenantId);
// Queue existence is ensured once, then latched — not re-checked per message.
queue.Verify(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()),
Times.Once);
}
[Fact]
public async Task EnqueueAsync_skips_envelope_without_version()
{
var (producer, queue, sentBodies) = BuildSut();
await producer.EnqueueAsync(new ImeMsiArchiveEnvelope { Version = string.Empty });
await producer.EnqueueAsync(null!);
Assert.Empty(sentBodies);
queue.Verify(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()),
Times.Never);
}
[Fact]
public async Task EnqueueAsync_send_failure_is_swallowed()
{
var (producer, queue, _) = BuildSut();
queue.Setup(q => q.SendMessageAsync(It.IsAny<string>(), It.IsAny<CancellationToken>()))
.ThrowsAsync(new RequestFailedException(503, "queue busy"));
// Fire-and-forget continuation on the ingest path — must never throw.
await producer.EnqueueAsync(Envelope());
}
[Fact]
public async Task EnqueueAsync_retries_queue_creation_after_failure()
{
var (producer, queue, sentBodies) = BuildSut();
queue.SetupSequence(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()))
.ThrowsAsync(new RequestFailedException(500, "storage down"))
.ReturnsAsync((Response?)null);
await producer.EnqueueAsync(Envelope()); // ensure fails — not latched
await producer.EnqueueAsync(Envelope()); // ensure retried and succeeds
queue.Verify(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()),
Times.Exactly(2));
// Both messages were still attempted (fail-soft send after a failed ensure).
Assert.Equal(2, sentBodies.Count);
}
// ============================================================ Helpers ====
private static ImeMsiArchiveEnvelope Envelope() => new()
{
Version = Version,
MsiDownloadUrl = ImeMsiArchiver.CanonicalMsiUrl,
MsiMatchedBy = "productVersion",
TenantId = "11111111-1111-1111-1111-111111111111",
SessionId = "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa",
EnqueuedAt = DateTime.UtcNow,
};
private static (AzureQueueImeMsiArchiveProducer Producer, Mock<QueueClient> Queue, List<string> SentBodies) BuildSut()
{
var queue = new Mock<QueueClient>();
var sentBodies = new List<string>();
queue.Setup(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()))
.ReturnsAsync((Response?)null);
queue.Setup(q => q.SendMessageAsync(It.IsAny<string>(), It.IsAny<CancellationToken>()))
.Returns<string, CancellationToken>((body, _) =>
{
sentBodies.Add(body);
var receipt = QueuesModelFactory.SendReceipt(
"msg", DateTimeOffset.UtcNow, DateTimeOffset.UtcNow.AddMinutes(7),
"pop", DateTimeOffset.UtcNow);
return Task.FromResult(Response.FromValue(receipt, new Mock<Response>().Object));
});
var producer = new AzureQueueImeMsiArchiveProducer(
queue.Object, NullLogger<AzureQueueImeMsiArchiveProducer>.Instance);
return (producer, queue, sentBodies);
}
}
@@ -247,4 +247,64 @@ public class CorporateIdentifierValidatorTests
Assert.False(result.IsValid);
Assert.True(result.IsTransient);
}
[Theory]
[InlineData(null, "Virtual Machine", Serial)]
[InlineData("Microsoft Corporation", null, Serial)]
[InlineData("Microsoft Corporation", "Virtual Machine", null)]
[InlineData("", "Virtual Machine", Serial)]
[InlineData("Microsoft Corporation", "", Serial)]
[InlineData("Microsoft Corporation", "Virtual Machine", "")]
[InlineData(" ", "Virtual Machine", Serial)]
[InlineData("Microsoft Corporation", "Virtual Machine", " ")]
public async Task ValidateAsync_missingHeaderComponent_isDefinitive_withoutGraphCall(
string? manufacturer, string? model, string? serial)
{
// Agents that fail to read a hardware property send the header empty — that is a
// definitive rejection (retries cannot conjure the value), and Graph must not be hit.
var (sut, handler) = BuildSut(Json("""{"value":[]}"""));
var result = await sut.ValidateAsync(TenantId, manufacturer, model, serial);
Assert.False(result.IsValid);
Assert.False(result.IsTransient);
Assert.Contains("not provided", result.ErrorMessage);
Assert.Empty(handler.Requests);
}
[Fact]
public async Task ValidateAsync_specialCharsInSerial_neverReachOdataFilter()
{
// The contains() narrowing uses the NORMALIZED (alphanumeric-only) serial, so an
// OData-breaking quote in a raw serial can neither corrupt nor inject into the filter.
const string hostileSerial = "O'Brien-123'&$top=9999";
var (sut, handler) = BuildSut(Json("""{"value":[]}"""));
var result = await sut.ValidateAsync(TenantId, "Microsoft Corporation", "Virtual Machine", hostileSerial);
Assert.False(result.IsValid);
var url = Uri.UnescapeDataString(Assert.Single(handler.Requests).RequestUri!.ToString());
Assert.Contains("contains(importedDeviceIdentifier,'OBRIEN123TOP9999')", url);
Assert.DoesNotContain("O'Brien", url);
}
[Fact]
public async Task ValidateAsync_pageCapExceeded_isTransient_andNotCached()
{
// Stopping mid-list must NOT be classified "not found" — a cached false negative would
// block a legitimately registered device for the negative-cache TTL.
var (sut, handler) = BuildSut(Json("""
{"value":[{"importedDeviceIdentityType":"manufacturerModelSerial","importedDeviceIdentifier":"DELL,XPS,OTHER1"}],
"@odata.nextLink":"https://graph.microsoft.com/beta/deviceManagement/importedDeviceIdentities?$skiptoken=more"}
"""));
var result = await sut.ValidateAsync(TenantId, "Microsoft Corporation", "Virtual Machine", Serial);
Assert.False(result.IsValid);
Assert.True(result.IsTransient);
Assert.Contains("page budget", result.ErrorMessage);
// Filtered scan pages up to its cap of 5, and the in-call retry runs a second sweep —
// proof the transient path went through the retry loop instead of caching.
Assert.Equal(10, handler.Requests.Count);
}
}
@@ -0,0 +1,261 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using Azure;
using Azure.Storage.Queues;
using Azure.Storage.Queues.Models;
using AutopilotMonitor.Functions.Services;
using AutopilotMonitor.Functions.Services.Ime;
using AutopilotMonitor.Shared.DataAccess;
using AutopilotMonitor.Shared.Models;
using Microsoft.Extensions.Caching.Memory;
using Microsoft.Extensions.Logging.Abstractions;
using Moq;
using Newtonsoft.Json;
using Xunit;
namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Worker-level tests for the ime-msi-archive queue consumer (daily review 2026-08-18:
/// previously untested). The worker's contract: merge the archiver's outcome onto the
/// ImeVersionHistory row on EVERY attempt (also failures, so operators see a stuck
/// download), delete the message for terminal outcomes, rethrow for retryable ones
/// (visibility-timeout ladder), pause — not drop — while ImeMsiArchivingEnabled is off,
/// and drop version-less envelopes without invoking the archiver.
/// </summary>
public class ImeMsiArchiveQueueWorkerTests
{
private const string Version = "1.104.102.0";
[Fact]
public async Task Worker_success_merges_row_and_deletes_message()
{
var harness = new Harness();
harness.Archiver.Result = new ImeMsiArchiveResult(
true, ImeMsiArchiver.Statuses.Archived, Retryable: false,
$"{Version}/IntuneWindowsAgent.msi", "abc123", 42L, ImeMsiArchiver.CanonicalMsiUrl);
harness.EnqueueMessage(JsonConvert.SerializeObject(Envelope()));
await harness.RunUntilAsync(() => harness.MainQueueDeleted());
harness.Repo.Verify(r => r.UpdateImeVersionArchiveInfoAsync(
Version, ImeMsiArchiver.Statuses.Archived,
$"{Version}/IntuneWindowsAgent.msi", "abc123", 42L, ImeMsiArchiver.CanonicalMsiUrl),
Times.Once);
harness.MainQueue.Verify(q => q.DeleteMessageAsync(
It.IsAny<string>(), It.IsAny<string>(), It.IsAny<CancellationToken>()),
Times.Once);
}
[Fact]
public async Task Worker_retryable_failure_merges_row_but_leaves_message()
{
var harness = new Harness();
harness.Archiver.Result = new ImeMsiArchiveResult(
false, ImeMsiArchiver.Statuses.FailedDownload, Retryable: true,
null, null, null, ImeMsiArchiver.CanonicalMsiUrl);
harness.EnqueueMessage(JsonConvert.SerializeObject(Envelope()));
await harness.RunUntilAsync(() => harness.Archiver.Calls > 0);
// Row always tells the truth — the failure status IS merged...
harness.Repo.Verify(r => r.UpdateImeVersionArchiveInfoAsync(
Version, ImeMsiArchiver.Statuses.FailedDownload,
null, null, null, ImeMsiArchiver.CanonicalMsiUrl),
Times.AtLeastOnce);
// ...but the message stays for the visibility-timeout retry → poison ladder.
harness.MainQueue.Verify(q => q.DeleteMessageAsync(
It.IsAny<string>(), It.IsAny<string>(), It.IsAny<CancellationToken>()),
Times.Never);
}
[Fact]
public async Task Worker_permanent_failure_merges_row_and_completes_message()
{
var harness = new Harness();
harness.Archiver.Result = new ImeMsiArchiveResult(
false, ImeMsiArchiver.Statuses.FailedTooLarge, Retryable: false,
null, null, 999L, ImeMsiArchiver.CanonicalMsiUrl);
harness.EnqueueMessage(JsonConvert.SerializeObject(Envelope()));
await harness.RunUntilAsync(() => harness.MainQueueDeleted());
harness.Repo.Verify(r => r.UpdateImeVersionArchiveInfoAsync(
Version, ImeMsiArchiver.Statuses.FailedTooLarge,
null, null, 999L, ImeMsiArchiver.CanonicalMsiUrl),
Times.Once);
harness.MainQueue.Verify(q => q.DeleteMessageAsync(
It.IsAny<string>(), It.IsAny<string>(), It.IsAny<CancellationToken>()),
Times.Once);
}
[Fact]
public async Task Worker_pauses_while_archiving_disabled()
{
var harness = new Harness(archivingEnabled: false);
harness.EnqueueMessage(JsonConvert.SerializeObject(Envelope()));
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
// Pause, not drop: no receive, no archive attempt — the message parks in the queue.
harness.MainQueue.Verify(q => q.ReceiveMessagesAsync(
It.IsAny<int>(), It.IsAny<TimeSpan>(), It.IsAny<CancellationToken>()),
Times.Never);
Assert.Equal(0, harness.Archiver.Calls);
}
[Fact]
public async Task Worker_drops_envelope_without_version_before_archiver()
{
var harness = new Harness();
harness.EnqueueMessage(JsonConvert.SerializeObject(new ImeMsiArchiveEnvelope
{
Version = string.Empty,
EnqueuedAt = DateTime.UtcNow,
}));
await harness.RunUntilAsync(() => harness.MainQueueDeleted());
Assert.Equal(0, harness.Archiver.Calls);
harness.Repo.Verify(r => r.UpdateImeVersionArchiveInfoAsync(
It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string?>(),
It.IsAny<string?>(), It.IsAny<long?>(), It.IsAny<string?>()),
Times.Never);
}
// ============================================================ Helpers ====
private static ImeMsiArchiveEnvelope Envelope() => new()
{
Version = Version,
MsiDownloadUrl = ImeMsiArchiver.CanonicalMsiUrl,
MsiMatchedBy = "productVersion",
TenantId = "11111111-1111-1111-1111-111111111111",
SessionId = "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa",
EnqueuedAt = DateTime.UtcNow,
};
/// <summary>Scripted archiver — the worker only consumes the classified result.</summary>
private sealed class StubArchiver : ImeMsiArchiver
{
private int _calls;
public ImeMsiArchiveResult Result { get; set; } = new(
true, Statuses.Archived, Retryable: false, null, null, null, null);
public int Calls => Volatile.Read(ref _calls);
public override Task<ImeMsiArchiveResult> ArchiveAsync(
ImeMsiArchiveEnvelope envelope, CancellationToken cancellationToken = default)
{
Interlocked.Increment(ref _calls);
return Task.FromResult(Result);
}
}
/// <summary>Mock-queue poll-loop harness, same shape as SessionDeletionWorkerTests.</summary>
private sealed class Harness
{
public Mock<QueueClient> MainQueue { get; }
public Mock<QueueClient> PoisonQueue { get; }
public StubArchiver Archiver { get; } = new();
public Mock<ISessionRepository> Repo { get; } = new();
public ImeMsiArchiveQueueWorker Sut { get; }
private readonly Queue<QueueMessage> _pendingMessages = new();
public Harness(bool archivingEnabled = true)
{
MainQueue = new Mock<QueueClient>();
PoisonQueue = new Mock<QueueClient>();
MainQueue.Setup(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()))
.ReturnsAsync((Response?)null);
PoisonQueue.Setup(q => q.CreateIfNotExistsAsync(
It.IsAny<IDictionary<string, string>>(), It.IsAny<CancellationToken>()))
.ReturnsAsync((Response?)null);
MainQueue.Setup(q => q.ReceiveMessagesAsync(
It.IsAny<int>(), It.IsAny<TimeSpan>(), It.IsAny<CancellationToken>()))
.Returns<int, TimeSpan?, CancellationToken>((maxMessages, _, _) =>
{
var batch = new List<QueueMessage>();
lock (_pendingMessages)
{
while (batch.Count < maxMessages && _pendingMessages.Count > 0)
batch.Add(_pendingMessages.Dequeue());
}
return Task.FromResult(Response.FromValue(batch.ToArray(), new Mock<Response>().Object));
});
MainQueue.Setup(q => q.DeleteMessageAsync(
It.IsAny<string>(), It.IsAny<string>(), It.IsAny<CancellationToken>()))
.ReturnsAsync(new Mock<Response>().Object);
MainQueue.Setup(q => q.UpdateMessageAsync(
It.IsAny<string>(), It.IsAny<string>(),
It.IsAny<string>(), It.IsAny<TimeSpan>(), It.IsAny<CancellationToken>()))
.Returns<string, string, string, TimeSpan, CancellationToken>((_, _, _, vis, _) =>
{
var updated = QueuesModelFactory.UpdateReceipt(
"pop-extended-" + Guid.NewGuid().ToString("N"),
DateTimeOffset.UtcNow.Add(vis));
return Task.FromResult(Response.FromValue(updated, new Mock<Response>().Object));
});
var adminConfig = new Mock<AdminConfigurationService>(
Mock.Of<IConfigRepository>(),
NullLogger<AdminConfigurationService>.Instance,
new MemoryCache(new MemoryCacheOptions()));
adminConfig.Setup(a => a.GetConfigurationAsync())
.ReturnsAsync(new AdminConfiguration { ImeMsiArchivingEnabled = archivingEnabled });
Sut = new ImeMsiArchiveQueueWorker(
MainQueue.Object, PoisonQueue.Object,
Archiver, Repo.Object, adminConfig.Object,
NullLogger<ImeMsiArchiveQueueWorker>.Instance,
pollInterval: TimeSpan.FromMilliseconds(50));
}
public void EnqueueMessage(string body)
{
var msg = QueuesModelFactory.QueueMessage(
messageId: "msg-" + Guid.NewGuid().ToString("N"),
popReceipt: "pop-" + Guid.NewGuid().ToString("N"),
body: new BinaryData(body),
dequeueCount: 1);
lock (_pendingMessages) _pendingMessages.Enqueue(msg);
}
public async Task RunForAsync(TimeSpan duration)
{
using var cts = new CancellationTokenSource(duration);
try { await Sut.StartAsync(cts.Token); }
catch (OperationCanceledException) { }
try { await Task.Delay(duration, cts.Token); }
catch (OperationCanceledException) { }
try { await Sut.StopAsync(CancellationToken.None); }
catch (OperationCanceledException) { }
}
public async Task RunUntilAsync(Func<bool> condition, TimeSpan? timeout = null)
{
var deadline = DateTime.UtcNow + (timeout ?? TimeSpan.FromSeconds(10));
using var cts = new CancellationTokenSource();
try { await Sut.StartAsync(cts.Token); }
catch (OperationCanceledException) { }
while (!condition() && DateTime.UtcNow < deadline)
await Task.Delay(25);
cts.Cancel();
try { await Sut.StopAsync(CancellationToken.None); }
catch (OperationCanceledException) { }
}
public bool MainQueueDeleted() =>
MainQueue.Invocations.Any(i => i.Method.Name == nameof(QueueClient.DeleteMessageAsync));
}
}
@@ -194,6 +194,7 @@ public class ImeMsiArchiverTests
var archiver = new RecordingArchiver
{
UploadException = new RequestFailedException(409, "BlobAlreadyExists"),
ProvenanceExists = true,
};
var result = await archiver.ArchiveAsync(Envelope());
@@ -202,6 +203,101 @@ public class ImeMsiArchiverTests
Assert.Equal(ImeMsiArchiver.Statuses.Archived, result.Status);
Assert.False(result.Retryable);
Assert.Equal($"{Version}/IntuneWindowsAgent.msi", result.BlobPath);
// Sidecar already there — the re-delivery must not rewrite it.
Assert.Equal(0, archiver.ProvenanceCalls);
}
// =========================================================================
// Provenance-write gap (daily review 2026-08-18): MSI upload is write-once,
// so a first attempt that dies between the MSI and the provenance upload
// funnels every retry into the 409 path — which must heal the sidecar.
// =========================================================================
[Fact]
public async Task ArchiveAsync_ProvenanceUploadFails_RetryableError()
{
var archiver = new RecordingArchiver
{
ProvenanceException = new RequestFailedException(500, "storage hiccup"),
};
var result = await archiver.ArchiveAsync(Envelope());
Assert.False(result.Success);
Assert.Equal(ImeMsiArchiver.Statuses.FailedError, result.Status);
Assert.True(result.Retryable);
}
[Fact]
public async Task ArchiveAsync_RedeliveryWithMissingProvenance_HealsSidecarFromArchivedBytes()
{
// The archived blob's content deliberately differs from this attempt's re-download —
// the healed provenance must describe the ARCHIVED bytes, not the fresh download.
var archivedPayload = new byte[1024];
new Random(7).NextBytes(archivedPayload);
var expectedSha = Convert.ToHexString(SHA256.HashData(archivedPayload)).ToLowerInvariant();
var archiver = new RecordingArchiver
{
UploadException = new RequestFailedException(409, "BlobAlreadyExists"),
ProvenanceExists = false,
ArchivedPayload = archivedPayload,
};
var result = await archiver.ArchiveAsync(Envelope());
Assert.True(result.Success);
Assert.Equal(ImeMsiArchiver.Statuses.Archived, result.Status);
Assert.False(result.Retryable);
Assert.Equal(expectedSha, result.Sha256);
Assert.Equal(archivedPayload.Length, result.SizeBytes);
Assert.Equal(1, archiver.ProvenanceCalls);
Assert.Equal($"{Version}/provenance.json", archiver.ProvenanceLastPath);
Assert.Contains(expectedSha, archiver.ProvenanceLastJson);
Assert.Contains(Version, archiver.ProvenanceLastJson);
}
[Fact]
public async Task ArchiveAsync_ProvenanceFailure_ThenRedelivery_EndsHealed()
{
// THE regression scenario end to end on one instance: attempt 1 uploads the MSI but
// the provenance write dies; attempt 2 (queue re-delivery) gets 409 on the write-once
// MSI and must still produce the sidecar.
var archiver = new RecordingArchiver
{
ProvenanceException = new RequestFailedException(500, "storage hiccup"),
};
var first = await archiver.ArchiveAsync(Envelope());
Assert.False(first.Success);
Assert.True(first.Retryable);
archiver.ProvenanceException = null;
archiver.UploadException = new RequestFailedException(409, "BlobAlreadyExists");
archiver.ProvenanceExists = false; // attempt 1 never landed the sidecar
var second = await archiver.ArchiveAsync(Envelope());
Assert.True(second.Success);
Assert.Equal(ImeMsiArchiver.Statuses.Archived, second.Status);
Assert.Equal($"{Version}/provenance.json", archiver.ProvenanceLastPath);
Assert.NotNull(second.Sha256);
}
[Fact]
public async Task ArchiveAsync_HealFails_RetryableError()
{
// Heal errors ride the normal retry ladder — the next re-delivery tries again.
var archiver = new RecordingArchiver
{
UploadException = new RequestFailedException(409, "BlobAlreadyExists"),
ProvenanceExists = false,
ArchivedOpenException = new RequestFailedException(500, "read failed"),
};
var result = await archiver.ArchiveAsync(Envelope());
Assert.False(result.Success);
Assert.Equal(ImeMsiArchiver.Statuses.FailedError, result.Status);
Assert.True(result.Retryable);
Assert.Equal(0, archiver.ProvenanceCalls);
}
// =========================================================================
@@ -288,6 +384,10 @@ public class ImeMsiArchiverTests
public int MaxDownloadSizeMB { get; set; } = 250;
public Exception? DownloadException { get; set; }
public Exception? UploadException { get; set; }
public Exception? ProvenanceException { get; set; }
public bool ProvenanceExists { get; set; } = true;
public byte[]? ArchivedPayload { get; set; }
public Exception? ArchivedOpenException { get; set; }
public int DownloadCalls { get; private set; }
public string? DownloadLastUrl { get; private set; }
@@ -326,10 +426,20 @@ public class ImeMsiArchiverTests
protected override Task UploadProvenanceAsync(string blobPath, string json, CancellationToken cancellationToken)
{
if (ProvenanceException is not null) throw ProvenanceException;
ProvenanceCalls++;
ProvenanceLastPath = blobPath;
ProvenanceLastJson = json;
return Task.CompletedTask;
}
protected override Task<bool> ProvenanceExistsAsync(string blobPath, CancellationToken cancellationToken)
=> Task.FromResult(ProvenanceExists);
protected override Task<Stream> OpenArchivedMsiAsync(string blobPath, CancellationToken cancellationToken)
{
if (ArchivedOpenException is not null) throw ArchivedOpenException;
return Task.FromResult<Stream>(new MemoryStream(ArchivedPayload ?? Payload));
}
}
}
@@ -197,6 +197,53 @@ public class TimeAttributionCalculatorTests
Assert.True(b.QualityFlags.HasFlag(TimeAttributionFlags.PartialObservation));
}
// ── prior-enrollment residue ────────────────────────────────────────────
[Fact]
public void HistoricImeReplay_SetsPriorEnrollmentResidue_AndExcludesFromFleetStats()
{
// Re-enrollment without a wipe (session f475e697): the surviving IME log pulls the
// phase anchors ahead of the real ESP page — the segments must be flagged as unfit.
var events = new List<EnrollmentEvent>
{
Evt(T0, "agent_started", EnrollmentPhase.DeviceSetup),
Evt(T0.AddSeconds(2), "historic_ime_replay_detected"),
Evt(T0.AddMinutes(1), "esp_phase_changed", EnrollmentPhase.AppsDevice),
Evt(T0.AddMinutes(10), "enrollment_complete"),
};
var b = TimeAttributionCalculator.Compute(
Input(events, completedAt: T0.AddMinutes(10), durationSeconds: 600))!;
AssertExactPartition(b);
Assert.True(b.QualityFlags.HasFlag(TimeAttributionFlags.PriorEnrollmentResidue));
Assert.True(TimeAttributionFlagQuality.ExcludesFromFleetStats(b.QualityFlags));
}
[Fact]
public void RegistryAppBaseline_Alone_DoesNotSetResidueFlag()
{
// A registry_app_baseline with successes is by-design normal for WDP (DPP Batch-1
// apps install before the agent exists) — treating it as residue would starve the
// device_preparation class's fleet aggregates. Only the IME-log replay signal counts.
var events = new List<EnrollmentEvent>
{
Evt(T0, "agent_started", EnrollmentPhase.DeviceSetup),
Evt(T0.AddSeconds(2), "registry_app_baseline", data: new Dictionary<string, object>
{
["totalApps"] = "3", ["successCount"] = "3",
["errorCount"] = "0", ["inProgressCount"] = "0",
}),
Evt(T0.AddMinutes(10), "enrollment_complete"),
};
var b = TimeAttributionCalculator.Compute(
Input(events, completedAt: T0.AddMinutes(10), durationSeconds: 600))!;
AssertExactPartition(b);
Assert.False(b.QualityFlags.HasFlag(TimeAttributionFlags.PriorEnrollmentResidue));
}
// ── WhiteGlove: two windows in ONE session, pause never attributed ──────
[Fact]
@@ -70,7 +70,9 @@ public sealed class TimeAttributionInput
public static class TimeAttributionCalculator
{
/// <summary>Bump on any semantic change so aggregates never mix definitions (truthfulness rule 8).</summary>
public const int CurrentVersion = 1;
// v2: PriorEnrollmentResidue flag — sessions whose phase anchors are distorted by
// pre-enrollment state on disk are now flagged and excluded from fleet segment stats.
public const int CurrentVersion = 2;
/// <summary>
/// Enrollment class for fleet aggregation — classes are NEVER mixed in one aggregate (a
@@ -164,6 +166,15 @@ public static class TimeAttributionCalculator
if (events.Any(e => e.EventType == Constants.EventTypes.AgentLateStart))
flags |= TimeAttributionFlags.PartialObservation;
// Prior-enrollment residue (session f475e697): an IME log predating this enrollment
// means the disk was not wiped — pre-installed apps complete as instant detections and
// pull the phase anchors ahead of the real ESP page, so the segment durations lie.
// historic_ime_replay_detected is the ONLY trigger on purpose: registry_app_baseline
// with successes is by-design normal for WDP (DPP Batch-1 apps install before the
// agent exists) and would starve that class's aggregates (see DurationCriticalFlags).
if (events.Any(e => e.EventType == Constants.EventTypes.HistoricImeReplayDetected))
flags |= TimeAttributionFlags.PriorEnrollmentResidue;
return new SessionTimeBreakdown
{
TenantId = input.TenantId,
@@ -37,6 +37,18 @@ namespace AutopilotMonitor.Functions.Services.Ime
_queueClient = queueFactory.Create(Constants.QueueNames.ImeMsiArchive);
}
/// <summary>
/// Test seam: construct directly with a mock <see cref="QueueClient"/>. Mirrors
/// <see cref="Deletion.SessionDeletionProducer"/>'s internal test ctor.
/// </summary>
internal AzureQueueImeMsiArchiveProducer(
QueueClient queueClient,
ILogger<AzureQueueImeMsiArchiveProducer> logger)
{
_queueClient = queueClient;
_logger = logger;
}
public async Task EnqueueAsync(ImeMsiArchiveEnvelope envelope, CancellationToken cancellationToken = default)
{
if (envelope is null) return;
@@ -39,6 +39,26 @@ namespace AutopilotMonitor.Functions.Services.Ime
_adminConfigService = adminConfigService ?? throw new ArgumentNullException(nameof(adminConfigService));
}
/// <summary>
/// Test seam: construct directly with mock <see cref="Azure.Storage.Queues.QueueClient"/>
/// instances so the poll loop can be exercised without Azurite. Mirrors
/// <see cref="Deletion.SessionDeletionWorker"/>'s internal test ctor.
/// </summary>
internal ImeMsiArchiveQueueWorker(
Azure.Storage.Queues.QueueClient mainQueue,
Azure.Storage.Queues.QueueClient poisonQueue,
ImeMsiArchiver archiver,
ISessionRepository sessionRepo,
AdminConfigurationService adminConfigService,
ILogger<ImeMsiArchiveQueueWorker> logger,
TimeSpan? pollInterval = null)
: base(mainQueue, poisonQueue, logger, pollInterval)
{
_archiver = archiver ?? throw new ArgumentNullException(nameof(archiver));
_sessionRepo = sessionRepo ?? throw new ArgumentNullException(nameof(sessionRepo));
_adminConfigService = adminConfigService ?? throw new ArgumentNullException(nameof(adminConfigService));
}
/// <summary>Download can legitimately take minutes — extend visibility while working.</summary>
protected override bool UseHeartbeat => true;
@@ -34,7 +34,9 @@ namespace AutopilotMonitor.Functions.Services.Ime
/// <c>IntuneWindowsAgent.msi</c> are accepted; anything else falls back to the canonical
/// versionless CDN URL — safe for a NEW version, because "new" is by definition what
/// that URL currently serves. The blob write uses If-None-Match:* so a queue re-delivery
/// can never overwrite an existing archive entry.
/// can never overwrite an existing archive entry; the 409 path additionally heals a
/// provenance sidecar the first attempt failed to write (see
/// <see cref="CompleteExistingArchiveAsync"/>).
/// </para>
/// </summary>
public class ImeMsiArchiver
@@ -179,34 +181,18 @@ namespace AutopilotMonitor.Functions.Services.Ime
catch (RequestFailedException ex) when (ex.Status == 409)
{
// Queue re-delivery after a successful upload: the archive already has
// this version — that IS the desired end state.
_logger.LogInformation(
"ImeMsiArchiver: blob {BlobPath} already exists — treating re-delivery as archived",
blobPath);
return new ImeMsiArchiveResult(true, Statuses.Archived, Retryable: false,
blobPath, null, null, sourceUrl);
// this version — that IS the desired end state. But if the first
// attempt died between the MSI and the provenance upload, the sidecar
// is missing and this 409 pre-empts the happy path's provenance write
// on every future retry — so it must be healed here.
return await CompleteExistingArchiveAsync(
envelope, version, blobPath, sourceUrl, linked.Token);
}
sha256 = guarded.Sha256Hex;
totalBytes = guarded.TotalBytes;
}
var provenance = new
{
version,
url = sourceUrl,
urlFromEvent = sourceUrl != CanonicalMsiUrl,
msiMatchedBy = envelope.MsiMatchedBy,
sha256,
msiBytes = totalBytes,
firstSeenTenantId = envelope.TenantId,
firstSeenSessionId = envelope.SessionId,
archivedAtUtc = DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ssZ"),
};
await UploadProvenanceAsync(
$"{version}/provenance.json",
System.Text.Json.JsonSerializer.Serialize(provenance,
new System.Text.Json.JsonSerializerOptions { WriteIndented = true }),
linked.Token);
await WriteProvenanceAsync(envelope, version, sourceUrl, sha256, totalBytes, linked.Token);
_logger.LogInformation(
"ImeMsiArchiver: archived {Version} ({SizeBytes} bytes, sha256 {Sha256}) from {SourceUrl}",
@@ -247,6 +233,72 @@ namespace AutopilotMonitor.Functions.Services.Ime
}
}
/// <summary>
/// Re-delivery landed on an already-archived version (409 on the write-once MSI
/// upload). Normally the provenance sidecar exists too and there is nothing to do —
/// but when the first attempt died between the MSI and the provenance upload
/// (transient storage failure, host shutdown), the sidecar would otherwise be lost
/// FOREVER: the 409 short-circuit pre-empts the happy path's provenance write on
/// every retry. Hash and size are recomputed from the ARCHIVED bytes, not this
/// attempt's re-download, so the provenance describes the blob it sits next to.
/// Failures propagate into the caller's catch ladder (retryable), so the queue
/// retries the heal until it lands.
/// </summary>
private async Task<ImeMsiArchiveResult> CompleteExistingArchiveAsync(
ImeMsiArchiveEnvelope envelope, string version, string blobPath, string sourceUrl,
CancellationToken cancellationToken)
{
if (await ProvenanceExistsAsync($"{version}/provenance.json", cancellationToken))
{
_logger.LogInformation(
"ImeMsiArchiver: blob {BlobPath} already exists — treating re-delivery as archived",
blobPath);
return new ImeMsiArchiveResult(true, Statuses.Archived, Retryable: false,
blobPath, null, null, sourceUrl);
}
string sha256;
long totalBytes;
using (var archived = await OpenArchivedMsiAsync(blobPath, cancellationToken))
using (var hashing = new HashingCappedReadStream(archived, maxBytes: 0))
{
await hashing.CopyToAsync(Stream.Null, cancellationToken);
sha256 = hashing.Sha256Hex;
totalBytes = hashing.TotalBytes;
}
await WriteProvenanceAsync(envelope, version, sourceUrl, sha256, totalBytes, cancellationToken);
_logger.LogInformation(
"ImeMsiArchiver: healed missing provenance for already-archived {Version} ({SizeBytes} bytes, sha256 {Sha256})",
version, totalBytes, sha256);
return new ImeMsiArchiveResult(true, Statuses.Archived, Retryable: false,
blobPath, sha256, totalBytes, sourceUrl);
}
private async Task WriteProvenanceAsync(
ImeMsiArchiveEnvelope envelope, string version, string sourceUrl,
string sha256, long totalBytes, CancellationToken cancellationToken)
{
var provenance = new
{
version,
url = sourceUrl,
urlFromEvent = sourceUrl != CanonicalMsiUrl,
msiMatchedBy = envelope.MsiMatchedBy,
sha256,
msiBytes = totalBytes,
firstSeenTenantId = envelope.TenantId,
firstSeenSessionId = envelope.SessionId,
archivedAtUtc = DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ssZ"),
};
await UploadProvenanceAsync(
$"{version}/provenance.json",
System.Text.Json.JsonSerializer.Serialize(provenance,
new System.Text.Json.JsonSerializerOptions { WriteIndented = true }),
cancellationToken);
}
// -------- Test seams (production defaults hit Azure / the network) --------
/// <summary>Fetches the platform admin configuration (size cap).</summary>
@@ -280,6 +332,20 @@ namespace AutopilotMonitor.Functions.Services.Ime
}, cancellationToken);
}
/// <summary>True when the provenance sidecar already exists in the archive container.</summary>
protected virtual async Task<bool> ProvenanceExistsAsync(string blobPath, CancellationToken cancellationToken)
{
var containerClient = _blobStorage.GetContainerClient(Constants.BlobContainers.ImeArchive);
return (await containerClient.GetBlobClient(blobPath).ExistsAsync(cancellationToken)).Value;
}
/// <summary>Opens the already-archived installer blob for the provenance-heal rehash.</summary>
protected virtual async Task<Stream> OpenArchivedMsiAsync(string blobPath, CancellationToken cancellationToken)
{
var containerClient = _blobStorage.GetContainerClient(Constants.BlobContainers.ImeArchive);
return await containerClient.GetBlobClient(blobPath).OpenReadAsync(cancellationToken: cancellationToken);
}
/// <summary>Uploads the provenance sidecar (overwrite allowed — it is derived data).</summary>
protected virtual async Task UploadProvenanceAsync(string blobPath, string json, CancellationToken cancellationToken)
{
@@ -61,7 +61,17 @@ namespace AutopilotMonitor.Shared.Models
/// event, missing ResumedAt, or a derived part-1 length that contradicts the stored
/// combined duration) — the two-window split is best-effort rather than event-anchored.
/// </summary>
WhiteGloveAnchorsIncomplete = 16
WhiteGloveAnchorsIncomplete = 16,
/// <summary>
/// The device carries state from a previous enrollment (<c>historic_ime_replay_detected</c>:
/// the IME log on disk predates this enrollment by more than the staleness threshold — the
/// machine was re-enrolled without a wipe). Pre-installed apps then complete as instant
/// detections, which pulls the phase anchors far ahead of the real ESP page (session
/// f475e697: the AccountSetup anchor fired 6.5 min before device setup actually finished),
/// so the segment durations misrepresent the enrollment.
/// </summary>
PriorEnrollmentResidue = 32
}
/// <summary>
@@ -74,7 +84,8 @@ namespace AutopilotMonitor.Shared.Models
{
/// <summary>
/// Flags that make the SEGMENT DURATIONS themselves untrustworthy — dropped anchors,
/// underobserved early phases, best-effort WhiteGlove window boundaries. Only these
/// underobserved early phases, best-effort WhiteGlove window boundaries, phase anchors
/// distorted by prior-enrollment residue. Only these
/// exclude a breakdown from fleet segment statistics. The blocking-set flags
/// (<see cref="TimeAttributionFlags.BlockingSetUnknown"/> / BlockingSetTruncated) say
/// nothing about the measured spans — they only limit per-app blocking evidence, which
@@ -85,7 +96,8 @@ namespace AutopilotMonitor.Shared.Models
public const TimeAttributionFlags DurationCriticalFlags =
TimeAttributionFlags.ClockSkewDropped |
TimeAttributionFlags.PartialObservation |
TimeAttributionFlags.WhiteGloveAnchorsIncomplete;
TimeAttributionFlags.WhiteGloveAnchorsIncomplete |
TimeAttributionFlags.PriorEnrollmentResidue;
/// <summary>True when the breakdown's segment durations are unfit for fleet statistics.</summary>
public static bool ExcludesFromFleetStats(TimeAttributionFlags flags)
@@ -180,8 +180,12 @@ export default function EventTimeline({
<div className="bg-white shadow rounded-lg p-4">
<h2 className="text-sm font-semibold text-gray-700 mb-3">Raw Events ({sortedBySequence.length})</h2>
<div className="divide-y divide-gray-100">
{sortedBySequence.map((ev) => (
<RawEventRow key={ev.eventId || `${ev.sessionId}-${ev.sequence}`} event={ev} />
{sortedBySequence.map((ev, i) => (
<RawEventRow
key={ev.eventId || `${ev.sessionId}-${ev.sequence}`}
event={ev}
prevDisplayTime={i > 0 ? getDisplayTime(sortedBySequence[i - 1]) : null}
/>
))}
</div>
</div>
@@ -341,11 +345,12 @@ function PhaseSection({
{isExpanded && (
<div className="space-y-3">
{events.map((event) => (
{events.map((event, i) => (
<EventRow
key={event.eventId || `${event.sessionId}-${event.sequence}`}
event={event}
showScriptOutput={showScriptOutput}
prevDisplayTime={i > 0 ? getDisplayTime(events[i - 1]) : null}
/>
))}
</div>
@@ -372,7 +377,32 @@ const BACKFILL_TOOLTIP =
"If enrollment progressed afterwards, this error was already resolved by a retry. " +
"The timestamp shown is the original event-log time.";
function EventRow({ event, showScriptOutput }: { event: EnrollmentEvent; showScriptOutput?: boolean }) {
// Display timestamp of a row: backfilled events show the original event-log time.
function getDisplayTime(event: EnrollmentEvent): Date {
return getBackfillInfo(event).recordedAt ?? new Date(event.timestamp);
}
// Rows render time-of-day only, so a multi-hour/multi-day gap to the previous row
// (and the date change it implies) is invisible without expanding event details.
// Shown on the row AFTER the gap; hover reveals the full date.
function GapBadge({ prevTime, eventTime }: { prevTime: Date | null; eventTime: Date }) {
if (!prevTime) return null;
const gapMs = eventTime.getTime() - prevTime.getTime();
if (gapMs < 60 * 60 * 1000) return null;
const label = gapMs >= 48 * 60 * 60 * 1000
? `+${Math.round(gapMs / (24 * 60 * 60 * 1000))}d`
: `+${Math.round(gapMs / (60 * 60 * 1000))}h`;
return (
<span
className="px-1.5 py-0.5 rounded text-xs font-medium bg-amber-50 text-amber-700 whitespace-nowrap flex-shrink-0"
title={`${label} after the previous event — ${eventTime.toLocaleString()}`}
>
⏱ {label}
</span>
);
}
function EventRow({ event, showScriptOutput, prevDisplayTime }: { event: EnrollmentEvent; showScriptOutput?: boolean; prevDisplayTime?: Date | null }) {
const [showDetails, setShowDetails] = useState(false);
const [showRaw, setShowRaw] = useState(false);
const [copied, setCopied] = useState(false);
@@ -458,6 +488,7 @@ function EventRow({ event, showScriptOutput }: { event: EnrollmentEvent; showScr
<span className="text-gray-400 font-sans"> (reported {new Date(event.timestamp).toLocaleTimeString()})</span>
)}
</span>
<GapBadge prevTime={prevDisplayTime ?? null} eventTime={recordedAt ?? new Date(event.timestamp)} />
<SeverityBadge severity={event.severity} />
{isBackfilled && (
<span
@@ -786,7 +817,7 @@ function EventRow({ event, showScriptOutput }: { event: EnrollmentEvent; showScr
);
}
function RawEventRow({ event }: { event: EnrollmentEvent }) {
function RawEventRow({ event, prevDisplayTime }: { event: EnrollmentEvent; prevDisplayTime?: Date | null }) {
const [expanded, setExpanded] = useState(false);
const detailData = useMemo(() => normalizeEventDataForDisplay(event.data), [event.data]);
const hasDetails = detailData && Object.keys(detailData).length > 0;
@@ -806,6 +837,7 @@ function RawEventRow({ event }: { event: EnrollmentEvent }) {
<div className="flex items-start gap-2">
<span className="text-gray-400 w-8 text-right flex-shrink-0">{event.sequence}</span>
<span className="text-gray-500 flex-shrink-0">{(recordedAt ?? new Date(event.timestamp)).toLocaleTimeString()}</span>
<GapBadge prevTime={prevDisplayTime ?? null} eventTime={recordedAt ?? new Date(event.timestamp)} />
<span className={`flex-shrink-0 w-14 ${sevColor[event.severity] || "text-gray-500"}`}>{event.severity}</span>
{isBackfilled && (
<span className="text-slate-500 flex-shrink-0" title={BACKFILL_TOOLTIP}>⟲</span>
@@ -64,6 +64,7 @@ const FLAG_LABELS: Record<string, string> = {
BlockingSetUnknown: "ESP blocking set unknown",
BlockingSetTruncated: "ESP blocking list truncated",
WhiteGloveAnchorsIncomplete: "Pre-provisioning window estimated",
PriorEnrollmentResidue: "Device re-enrolled without wipe — phase timing unreliable",
};
function formatDuration(totalSeconds: number): string {