From e1b03de5b3b982a2faf046c6f8b1a68c7384e26e Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Wed, 19 Aug 2026 17:00:59 +0200 Subject: [PATCH] fix(agent): recover ESP completion after a forced mid-ESP reboot MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Seven sits-d Cloud PCs enrolled the same day with identical configuration (~138 required apps at the user-ESP gate, DeviceGuard/DmaGuard device-assigned). The two that finished AccountSetup before the coalesced reboot landed succeeded; the five the reboot killed in Stage=EspAccountSetup never derived a completion again and ended Incomplete on healthy devices. Two defects behind that: ShellCoreTracker.BackfillRecentEspExitEvents() has existed since session 772fe502 but no caller ever invoked it, so the Shell-Core watcher only saw records written after Start(). Every agent restart silently dropped an ESP exit (62407) or Hello-wizard start (62404) from its downtime. EspAndHelloHost.Start() now calls it, and the fixed 5-minute window is sized to the actual downtime when the previous run died to a reboot (LastBootUtc, clamped to 360 min). The user-apps-settled synthesis ran only on the EspExited edge. When the ESP page exits with apps still in flight the single attempt misses and nothing re-checks — 8110e262 and a89aac2d both reached 138/138 apps, 0 failed, and still never completed. The exit edge is now recorded and the synthesis re-evaluated from ImeLogTracker.OnAppStateChanged. No new completion path: the gate conditions are unchanged, this only gives the existing conservative check a second look. The fire-once claim moves to Interlocked (edge and re-check run on different threads) and the re-check does not re-emit app_install_starved. Rules: ANALYZE-ESP-005 gains on_event:session_stalled so a hung session produces a finding at the 60-minute stall instead of staying finding-less for hours (verified against 8110e262 — fired, confidence 95). New ANALYZE-APP-016 turns the already-emitted app_install_starved events into a customer finding and, unlike ANALYZE-APP-015, fires even on a succeeded session: 3b9291aa was recorded Succeeded with 99 required apps that never started installing. ANALYZE-APP-015 and ANALYZE-ESP-001 were considered for the stall trigger and deliberately left alone — APP-015 is the documented worked example of the terminal-precondition trap, and ESP-001's phase_duration gate on a still-open phase is unverified mid-run. Co-Authored-By: Claude Opus 5 (1M context) --- docs/agent/post-reboot-completion-recovery.md | 108 +++++++++++ docs/index.md | 1 + docs/log.md | 4 + docs/rules/analyze-rule-triggers.md | 4 + rules/analyze/ANALYZE-APP-016.json | 113 +++++++++++ rules/analyze/ANALYZE-ESP-005.json | 5 +- rules/dist/analyze-rules.json | 117 +++++++++++- .../EspAndHelloTrackerStarvedAppsTests.cs | 48 +++++ ...lloTrackerUserAppsSettledSynthesisTests.cs | 79 ++++++++ .../ShellCoreTrackerEspExitBackfillTests.cs | 180 ++++++++++++++++++ .../DefaultComponentFactoryOrderingTests.cs | 36 ++++ .../SystemSignals/EspAndHelloTracker.cs | 63 +++++- .../SystemSignals/ShellCoreTracker.cs | 29 ++- .../Orchestration/DefaultComponentFactory.cs | 62 +++++- .../Orchestration/Hosts/EspAndHelloHost.cs | 40 +++- .../Runtime/AgentRuntimeHost.cs | 11 +- 16 files changed, 883 insertions(+), 17 deletions(-) create mode 100644 docs/agent/post-reboot-completion-recovery.md create mode 100644 rules/analyze/ANALYZE-APP-016.json create mode 100644 src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/ShellCoreTrackerEspExitBackfillTests.cs diff --git a/docs/agent/post-reboot-completion-recovery.md b/docs/agent/post-reboot-completion-recovery.md new file mode 100644 index 00000000..05fdde0f --- /dev/null +++ b/docs/agent/post-reboot-completion-recovery.md @@ -0,0 +1,108 @@ +--- +type: Concept +title: Post-Reboot Completion Recovery — surviving the forced mid-ESP restart +description: Why an agent restarted by a mid-ESP reboot used to lose the AccountSetup completion for the rest of the session (orphaned Shell-Core backfill + edge-only user-apps-settled synthesis), and the two mechanisms that recover it — a downtime-sized ESP-exit replay and a level-triggered re-check of the settled user-ESP apps. +resource: /src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals +tags: + - agent + - esp + - completion + - reboot + - recovery +timestamp: 2026-08-19T00:00:00+02:00 +--- + +# Post-Reboot Completion Recovery + +A device-assigned policy that Windows flags as reboot-required (DeviceGuard/VBS, +DmaGuard — see [MDM Reboot Coalescing](mdm-reboot-coalescing.md)) forces a restart in the +middle of the ESP. The agent is killed (`previousExit=reboot_kill`), the user signs in a +second time, and AccountSetup finishes. Until 2026-08-19 the session did **not** finish +with it: the agent waited for signals whose window had already closed, emitted +`session_stalled` after 60 minutes, and ran out at the max-lifetime watchdog — verdict +`Incomplete`, "No Device Setup completion or explicit failure signal observed before +timeout", on devices that were completely healthy. + +# Schema + +The AccountSetup gate opens on one of two evidence pairs: + +| Path | Evidence | +|---|---| +| Registry | `AccountSetupCategory.Status.categorySucceeded` confirmed by Windows | +| Synthesis | Shell-Core normal ESP exit (62407) **and** every required user-ESP app terminal with zero failures | + +The synthesis exists because a policy-skipped user-ESP app leaves the registry's Apps +subcategory permanently `inProgress`, starving the registry path (session `caa6cf50`). + +Two independent defects made the synthesis unreachable after a reboot. + +## Defect 1 — the ESP-exit replay was never wired up + +`ShellCoreTracker.BackfillRecentEspExitEvents()` had existed since session `772fe502` but +**no caller ever invoked it**. The Shell-Core `EventLogWatcher` only delivers records +written after `Start()`, so every agent restart silently dropped an ESP exit (62407) or +Hello-wizard start (62404) that occurred while the agent was down. + +`EspAndHelloHost.Start()` now calls it. Ordering is Start-then-backfill: a record written +between the two is observed twice, which the design already tolerates (Shell-Core emits +62407 at every ESP phase transition; the reducer's `ShouldTransitionToAwaitingHello` +picks the genuine post-AccountSetup one). The reverse order could drop a record, which +costs the session its completion. + +The fixed 5-minute lookback cannot span a reboot, so the window is now sized to the +downtime: on `previousExit=reboot_kill` the factory passes `PreviousExitSummary.LastBootUtc` +and the lookback becomes "everything since the boot that killed us", clamped to +`ShellCoreTracker.BackfillLookbackMaxMinutes` (360 — the agent's max lifetime). Every other +exit type keeps the 5-minute default. + +## Defect 2 — the synthesis was edge-triggered + +`MaybeSynthesizeAccountSetupCompleteFromSettledUserApps()` ran **only** from `OnEspExited`. +On a tenant with a large required-app set the ESP page exits while apps are still in +flight: the single attempt misses, emits `app_install_starved` for the apps that never +started, and nothing ever re-checks — not even when every tracked app reaches a terminal +state minutes later. + +The ESP exit is an **edge** (it happens once); settled user-ESP apps are a **level** (they +can be reached later). `EspAndHelloTracker` now records the edge in `_espExitObserved` and +exposes `ReevaluateUserAppsSettledSynthesis()`, chained into `ImeLogTracker.OnAppStateChanged` +in `DefaultComponentFactory` (same preserve-previous pattern `DeliveryOptimizationHost` +uses). Every terminal app transition gives the synthesis another look. + +This adds **no new completion path**. The gate conditions are unchanged — real ESP exit, +every required user-ESP app terminal, zero failures. The re-check only grants the existing, +deliberately conservative check a second opportunity. Two guards keep it cheap and safe: +the fire-once claim is an `Interlocked.CompareExchange` (the re-check runs on the IME log +thread, the edge on the Shell-Core watcher thread), and the re-check path suppresses +`app_install_starved` emission so the one-shot warning does not become a per-transition +stream. + +# Examples + +Tenant `sits-d.cloud`, 2026-08-19, seven Windows 365 Cloud PCs, identical configuration +(~138 required apps at the user-ESP gate, DeviceGuard + DmaGuard device-assigned): + +* `08fc6bda`, `3b9291aa` — `RebootCount=0`. AccountSetup finished before the coalesced + reboot landed. Succeeded. +* `cb4a485a`, `e7ba63c9`, `8110e262`, `a89aac2d`, `3d6278fb` — `RebootCount>=1`. The agent + was killed in `Stage=EspAccountSetup`, and no completion was ever derived again. All five + ended `Incomplete` on healthy devices. + +`8110e262` and `a89aac2d` are the sharpest evidence for defect 2: both reached +`App summary: 138/138 completed, 0 failed` and still never completed, because the settled +level arrived after the exit edge had already been consumed. + +`3b9291aa` shows the independent starvation problem the same tenant has: 99 +`app_install_starved` events (required apps that never started installing) on a session +that was nevertheless recorded as `Succeeded` — surfaced from now on by `ANALYZE-APP-016`. + +# Citations + +* `src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/ShellCoreTracker.cs` — `BackfillRecentEspExitEvents(int)`, `ClampLookbackMinutes` +* `src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspAndHelloTracker.cs` — `_espExitObserved`, `ReevaluateUserAppsSettledSynthesis`, `MaybeSynthesizeAccountSetupCompleteFromSettledUserApps` +* `src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/EspAndHelloHost.cs` — `Start()` ordering +* `src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DefaultComponentFactory.cs` — lookback sizing, `OnAppStateChanged` chaining +* `src/Agent/AutopilotMonitor.Agent.V2/Runtime/AgentRuntimeHost.cs` — `previousBootUtc` hand-off +* [MDM Reboot Coalescing](mdm-reboot-coalescing.md) — the policy attribution for the reboot itself +* [Decision Engine](decision-engine.md) — the AccountSetup gate and completion arms diff --git a/docs/index.md b/docs/index.md index 39f7cdb4..dc2f9874 100644 --- a/docs/index.md +++ b/docs/index.md @@ -24,6 +24,7 @@ https://docs.autopilotmonitor.com (separate repository). * [Agent Endpoint Migration](agent/endpoint-migration.md) - How the backend re-homes agents to a new API base URL via the config channel (backend move or per-tenant region move): live-fetch-only, allowlist-validated on both sides, one hop, kill wins. * [Gather Rule Debug Log](agent/gather-rule-debug-log.md) - EnableGatherRuleDebugLog (ConfigVersion 36): the per-tenant local trace file that explains every gather-rule evaluation decision — scope skips, on_change suppression, empty collector results, logparser position/parse-mode outcomes — for rules that produce no timeline events. * [MDM Reboot Coalescing](agent/mdm-reboot-coalescing.md) - Attributing the mid-ESP coalesced reboot ("second sign-in") to the device-assigned policy URIs that forced it: aggregated DM-Enterprise 2800 observations (neutral, flush-time watermark) + the ANALYZE-ESP-005 advisory gated on an actually-observed reboot. +* [Post-Reboot Completion Recovery](agent/post-reboot-completion-recovery.md) - Why a forced mid-ESP reboot used to cost the session its AccountSetup completion for good (the Shell-Core ESP-exit backfill was never wired to a caller, and the user-apps-settled synthesis only ran on the exit edge), and the two recoveries: a replay window sized to the agent's downtime, plus a level-triggered re-check on every terminal IME app transition. * [Secure Boot CA-2023 Detection](agent/secureboot-ca2023-detection.md) - Why ANALYZE-SEC-001 v3 reads the UEFI db/KEK variables directly instead of trusting the SecureBoot\Servicing registry, and how the one-sided uefiCa2023FirmwareConfirmed marker plus a not_exists precondition give absence-tolerant suppression across old and new agents. * [Continue-Anyway Observation Mode](agent/continue-anyway-observation.md) - EnableEspContinueAnywayObservation (ConfigVersion 37, operator-set): Device-phase ESP terminal failures on Continue-Anyway profiles get a bounded 60-min observation instead of an immediate hard fail; the DAD-validated real-user desktop + Hello gate detect the true end, the session completes Succeeded + EspSoftFailure (amber "with issues" badge), expiry un-defangs to the original esp_terminal_failure. * [Registry App-State Second Pillar](agent/registry-app-state-pillar.md) - IME's authoritative per-app state read straight from the registry (Win32Apps EnforcementStateMessage, EspTrackingWin32Apps, StatusServiceReports) via a snapshot-and-diff watcher; registry/log reconciliation doubles as the built-in IME log-pattern drift alarm. diff --git a/docs/log.md b/docs/log.md index e798fc5f..d3375d88 100644 --- a/docs/log.md +++ b/docs/log.md @@ -2,6 +2,10 @@ ## 2026-08-19 +* **New**: `agent/post-reboot-completion-recovery.md` — a forced mid-ESP reboot (DeviceGuard/DmaGuard) used to cost the session its AccountSetup completion permanently. Two defects: `ShellCoreTracker.BackfillRecentEspExitEvents()` existed but had no caller, so every agent restart dropped an ESP exit (62407) written while it was down; and the user-apps-settled synthesis was edge-triggered on `EspExited` only, so apps settling afterwards never re-opened the gate. `EspAndHelloHost.Start()` now backfills with a lookback sized to the downtime (`previousExit=reboot_kill` → since `LastBootUtc`, clamped to 360 min), and `ReevaluateUserAppsSettledSynthesis()` is chained into `ImeLogTracker.OnAppStateChanged`. No new completion path — the gate conditions are unchanged. Evidence: sits-d Cloud PCs, five `Incomplete` sessions on healthy devices, two of them at `138/138 apps, 0 failed`. + +* **Update**: `rules/analyze-rule-triggers.md` — `on_event:session_stalled` documented as an established interim trigger for the never-terminal stuck session (one emission per session, no throttle needed). `ANALYZE-ESP-005` carries it: both its conditions are monotonic and it has no terminal precondition, and it fires at confidence 95 on the sits-d stalled stream. `ANALYZE-APP-015` deliberately does NOT — it is the worked example of the terminal-precondition trap (lint 1) — and `ANALYZE-ESP-001` does not either, because its `phase_duration` gate on a still-open phase is unverified mid-run. New `ANALYZE-APP-016` ("Required Apps Never Started — ESP Apps Gate Starved") turns the existing `app_install_starved` events into a customer-facing finding and, unlike `ANALYZE-APP-015`, fires even when the session succeeded — session `3b9291aa` was recorded `Succeeded` with 99 required apps that never started installing. + * **New**: `script-publishing.md` — the customer script publishing chain. `.github/scripts/Publish-BootstrapScripts.ps1` becomes the single owner (dev render, version-bump guard, uploads, version oracles, alias verification), called both by the new `publish-scripts.yml` (push to `main` on `scripts/Bootstrap/**` and `scripts/CustomerSetup/**`) and by the `publish_as_stable` branch of `build-agent.yml`. Script publishing no longer waits for an agent release. Blobs are published in a deterministic CRLF/UTF-8-no-BOM form so byte comparisons do not depend on the checkout; the Pester + ASCII gates move into the reusable `bootstrap-script-gates.yml` and block the upload; `AdminConfiguration.LatestBootstrapV2ScriptVersion` now has exactly one writer. The version-bump guard compares a code fingerprint (PowerShell token stream without comments, newlines and line continuations), so only behaviour changes require a `$ScriptVersion` bump — comment and formatting changes publish with a warning. ## 2026-08-18 diff --git a/docs/rules/analyze-rule-triggers.md b/docs/rules/analyze-rule-triggers.md index 4f1783ba..4e8e38a8 100644 --- a/docs/rules/analyze-rule-triggers.md +++ b/docs/rules/analyze-rule-triggers.md @@ -101,6 +101,10 @@ Interim evaluation changes what a rule's conditions mean mid-flight. Three new l - WG battery rule (sits-d): `evaluateOn: ["enrollment_end", "whiteglove_sealed"]` — technician gets the channel alert at the bench; Part-2 terminal pass finalizes or resolves the finding. - Hybrid-affinity stuck (esa): ANALYZE-ID-004 gets `evaluateOn: ["enrollment_end", "on_event:hybrid_login_pending"]` — the second overdue-login event (threshold 65) produces a live finding on the still-InProgress session. ANALYZE-APP-015 stays `enrollment_end`-only until its conditions are hardened (lint 1). +- Stuck after a forced mid-ESP reboot (sits-d Cloud PCs, 2026-08-19): `on_event:session_stalled` is the established trigger for the never-terminal stuck session. The agent emits `session_stalled` exactly once per session (60-minute stall probe), so the trigger is rare by construction and needs no throttle. Five Cloud PCs sat at `InProgress` with **zero findings** for hours — a mid-ESP reboot had killed the agent in `Stage=EspAccountSetup` — before the max-lifetime watchdog eventually terminalised them as `Incomplete`. ANALYZE-ESP-005 carries the trigger and fires on that stream at confidence 95 (verified against session `8110e262`): both its conditions (`mdm_policy_reboot_required.firstRebootUri` exists, `system_reboot_detected` count ≥ 1) are **monotonic** and it has no terminal preconditions, so lint 1 does not apply. ANALYZE-APP-016 is interim-safe for the same reason (`app_install_starved` count ≥ 1 only ever grows). + + Two rules were considered and deliberately **not** given the trigger: ANALYZE-APP-015 is the worked example of lint 1 above and stays `enrollment_end`-only; ANALYZE-ESP-001 gates on `phase_duration` of a phase that is still open mid-run, and that evaluation is not pinned by a test — an unverified trigger is not worth a possible false positive on every slow DeviceSetup. + # Product Decisions (settled 2026-08-14) 1. Notify-on-resolve (a "finding healed" message)? **No** (v1) — resolution is visible in UI/MCP. diff --git a/rules/analyze/ANALYZE-APP-016.json b/rules/analyze/ANALYZE-APP-016.json new file mode 100644 index 00000000..7ab27399 --- /dev/null +++ b/rules/analyze/ANALYZE-APP-016.json @@ -0,0 +1,113 @@ +{ + "$schema": "../schema/analyze-rule.schema.json", + "ruleId": "ANALYZE-APP-016", + "title": "Required Apps Never Started — ESP Apps Gate Starved", + "description": "One or more required user-ESP apps never started installing while the ESP AccountSetup apps gate waited on them — the agent observed the ESP page exit with those apps still in a non-terminal, never-started state. Unlike ANALYZE-APP-015 (which reports that completion was DEFERRED because of a pending app, and stays silent once the session reaches a terminal verdict) this rule reports the delivery gap itself and fires regardless of the final outcome: an enrollment that Windows called done while required apps never ran is a successful enrollment with missing software, and the operator must see it.", + "severity": "warning", + "category": "apps", + "version": "1.0.0", + "author": "Autopilot Monitor", + "enabled": true, + "evaluateOn": [ + "enrollment_end", + "whiteglove_sealed", + "on_event:session_stalled" + ], + "trigger": "single", + "baseConfidence": 75, + "confidenceThreshold": 70, + "conditions": [ + { + "signal": "starved_apps_present", + "source": "event_count", + "eventType": "app_install_starved", + "operator": "count_gte", + "value": "1", + "required": true + }, + { + "signal": "many_starved_apps", + "source": "event_count", + "eventType": "app_install_starved", + "operator": "count_gte", + "value": "5", + "required": false + }, + { + "signal": "appName", + "source": "event_type", + "eventType": "app_install_starved", + "dataField": "appName", + "operator": "exists", + "value": "", + "required": false + }, + { + "signal": "state", + "source": "event_type", + "eventType": "app_install_starved", + "dataField": "state", + "operator": "exists", + "value": "", + "required": false + } + ], + "confidenceFactors": [ + { + "signal": "many_starved_apps", + "condition": "exists", + "weight": 15 + }, + { + "signal": "appName", + "condition": "exists", + "weight": 10 + } + ], + "explanation": "At least one **required** app assigned to the user ESP never started installing. The Intune Management Extension never moved it out of its initial state (`{{state}}`) — it did not download, did not install, and did not fail — while the ESP AccountSetup apps gate was waiting on it. First app observed: `{{appName}}`.\n\nEvery starved app has its own `app_install_starved` timeline event carrying `appId`, `appName` and `state` — open the timeline and filter on that event type for the complete list.\n\nThis is a **delivery** problem, not an install error, and it is invisible in the Intune console: the app simply never appears. Typical causes:\n\n- far more required apps targeted at the ESP than the gate can service in the available window,\n- requirement rules that are never met on this device (OS / architecture / registry / script checks),\n- an unsatisfied dependency or supersedence chain,\n- an app that needs a context unavailable during provisioning (e.g. a VPN client waiting on a portal sign-in),\n- a mid-ESP reboot that cut the gate short — check whether the mid-ESP reboot advisory also fired for this session.\n\nNote that this finding is independent of the session verdict. A session can be marked **Succeeded** and still be missing every app listed here.", + "remediation": [ + { + "title": "Shrink the ESP blocking set", + "steps": [ + "Open the Enrollment Status Page profile and review the blocking app list — every required app there must finish before the user reaches the desktop.", + "Move apps that do not have to be present at first logon from *required* to *available*, or remove them from the ESP's blocking apps selection.", + "Prefer a small, deliberately chosen blocking set (security agent, VPN, management tooling) over the full application catalogue." + ] + }, + { + "title": "Unblock the individual apps", + "steps": [ + "Collect the app names from the `app_install_starved` timeline events in this session.", + "For each app, review its requirement rules and dependencies in Intune — IntuneManagementExtension.log records every requirement evaluation.", + "Verify the assignment actually targets the signed-in user (user-targeted apps need an established Entra user affinity; check the hybrid user-affinity finding if it also fired).", + "Re-run an enrollment and confirm the apps now reach a terminal state before the ESP exits." + ] + }, + { + "title": "Rule out a truncated gate", + "steps": [ + "Check whether a mid-ESP reboot was observed for this session — a forced restart during AccountSetup cuts the apps gate short and can starve everything still queued.", + "If so, reassign the reboot-forcing device policies to user groups so the restart lands after AccountSetup." + ] + } + ], + "relatedDocs": [ + { + "title": "Microsoft Learn: Enrollment Status Page — blocking apps", + "url": "https://learn.microsoft.com/en-us/intune/intune-service/enrollment/windows-enrollment-status" + }, + { + "title": "Microsoft Learn: Win32 app requirement rules", + "url": "https://learn.microsoft.com/en-us/intune/intune-service/apps/apps-win32-add" + } + ], + "markSessionAsFailedDefault": false, + "tags": [ + "apps", + "esp", + "starvation", + "assignment", + "blocking", + "delivery-gap" + ] +} diff --git a/rules/analyze/ANALYZE-ESP-005.json b/rules/analyze/ANALYZE-ESP-005.json index 433ffcd7..311eda0a 100644 --- a/rules/analyze/ANALYZE-ESP-005.json +++ b/rules/analyze/ANALYZE-ESP-005.json @@ -5,12 +5,13 @@ "description": "Attributes an observed enrollment reboot to device-assigned MDM policies that Windows flagged as reboot-required. Fires ONLY when both facts are present in the session: at least one actually-observed reboot (system_reboot_detected) AND reboot-required policy flags (mdm_policy_reboot_required). Policy flags alone — e.g. from a user-policy sync during AccountSetup — force no reboot and stay advisory-silent.", "severity": "warning", "category": "esp", - "version": "1.2.0", + "version": "1.3.0", "author": "Autopilot Monitor", "enabled": true, "evaluateOn": [ "enrollment_end", - "whiteglove_sealed" + "whiteglove_sealed", + "on_event:session_stalled" ], "trigger": "single", "baseConfidence": 70, diff --git a/rules/dist/analyze-rules.json b/rules/dist/analyze-rules.json index 64581134..dacd7625 100644 --- a/rules/dist/analyze-rules.json +++ b/rules/dist/analyze-rules.json @@ -831,6 +831,118 @@ "pending" ] }, + { + "ruleId": "ANALYZE-APP-016", + "title": "Required Apps Never Started — ESP Apps Gate Starved", + "description": "One or more required user-ESP apps never started installing while the ESP AccountSetup apps gate waited on them — the agent observed the ESP page exit with those apps still in a non-terminal, never-started state. Unlike ANALYZE-APP-015 (which reports that completion was DEFERRED because of a pending app, and stays silent once the session reaches a terminal verdict) this rule reports the delivery gap itself and fires regardless of the final outcome: an enrollment that Windows called done while required apps never ran is a successful enrollment with missing software, and the operator must see it.", + "severity": "warning", + "category": "apps", + "version": "1.0.0", + "author": "Autopilot Monitor", + "enabled": true, + "evaluateOn": [ + "enrollment_end", + "whiteglove_sealed", + "on_event:session_stalled" + ], + "trigger": "single", + "baseConfidence": 75, + "confidenceThreshold": 70, + "conditions": [ + { + "signal": "starved_apps_present", + "source": "event_count", + "eventType": "app_install_starved", + "operator": "count_gte", + "value": "1", + "required": true + }, + { + "signal": "many_starved_apps", + "source": "event_count", + "eventType": "app_install_starved", + "operator": "count_gte", + "value": "5", + "required": false + }, + { + "signal": "appName", + "source": "event_type", + "eventType": "app_install_starved", + "dataField": "appName", + "operator": "exists", + "value": "", + "required": false + }, + { + "signal": "state", + "source": "event_type", + "eventType": "app_install_starved", + "dataField": "state", + "operator": "exists", + "value": "", + "required": false + } + ], + "confidenceFactors": [ + { + "signal": "many_starved_apps", + "condition": "exists", + "weight": 15 + }, + { + "signal": "appName", + "condition": "exists", + "weight": 10 + } + ], + "explanation": "At least one **required** app assigned to the user ESP never started installing. The Intune Management Extension never moved it out of its initial state (`{{state}}`) — it did not download, did not install, and did not fail — while the ESP AccountSetup apps gate was waiting on it. First app observed: `{{appName}}`.\n\nEvery starved app has its own `app_install_starved` timeline event carrying `appId`, `appName` and `state` — open the timeline and filter on that event type for the complete list.\n\nThis is a **delivery** problem, not an install error, and it is invisible in the Intune console: the app simply never appears. Typical causes:\n\n- far more required apps targeted at the ESP than the gate can service in the available window,\n- requirement rules that are never met on this device (OS / architecture / registry / script checks),\n- an unsatisfied dependency or supersedence chain,\n- an app that needs a context unavailable during provisioning (e.g. a VPN client waiting on a portal sign-in),\n- a mid-ESP reboot that cut the gate short — check whether the mid-ESP reboot advisory also fired for this session.\n\nNote that this finding is independent of the session verdict. A session can be marked **Succeeded** and still be missing every app listed here.", + "remediation": [ + { + "title": "Shrink the ESP blocking set", + "steps": [ + "Open the Enrollment Status Page profile and review the blocking app list — every required app there must finish before the user reaches the desktop.", + "Move apps that do not have to be present at first logon from *required* to *available*, or remove them from the ESP's blocking apps selection.", + "Prefer a small, deliberately chosen blocking set (security agent, VPN, management tooling) over the full application catalogue." + ] + }, + { + "title": "Unblock the individual apps", + "steps": [ + "Collect the app names from the `app_install_starved` timeline events in this session.", + "For each app, review its requirement rules and dependencies in Intune — IntuneManagementExtension.log records every requirement evaluation.", + "Verify the assignment actually targets the signed-in user (user-targeted apps need an established Entra user affinity; check the hybrid user-affinity finding if it also fired).", + "Re-run an enrollment and confirm the apps now reach a terminal state before the ESP exits." + ] + }, + { + "title": "Rule out a truncated gate", + "steps": [ + "Check whether a mid-ESP reboot was observed for this session — a forced restart during AccountSetup cuts the apps gate short and can starve everything still queued.", + "If so, reassign the reboot-forcing device policies to user groups so the restart lands after AccountSetup." + ] + } + ], + "relatedDocs": [ + { + "title": "Microsoft Learn: Enrollment Status Page — blocking apps", + "url": "https://learn.microsoft.com/en-us/intune/intune-service/enrollment/windows-enrollment-status" + }, + { + "title": "Microsoft Learn: Win32 app requirement rules", + "url": "https://learn.microsoft.com/en-us/intune/intune-service/apps/apps-win32-add" + } + ], + "markSessionAsFailedDefault": false, + "tags": [ + "apps", + "esp", + "starvation", + "assignment", + "blocking", + "delivery-gap" + ] + }, { "ruleId": "ANALYZE-CORR-003", "title": "Proxy Configuration Causing Download Failure", @@ -2069,12 +2181,13 @@ "description": "Attributes an observed enrollment reboot to device-assigned MDM policies that Windows flagged as reboot-required. Fires ONLY when both facts are present in the session: at least one actually-observed reboot (system_reboot_detected) AND reboot-required policy flags (mdm_policy_reboot_required). Policy flags alone — e.g. from a user-policy sync during AccountSetup — force no reboot and stay advisory-silent.", "severity": "warning", "category": "esp", - "version": "1.2.0", + "version": "1.3.0", "author": "Autopilot Monitor", "enabled": true, "evaluateOn": [ "enrollment_end", - "whiteglove_sealed" + "whiteglove_sealed", + "on_event:session_stalled" ], "trigger": "single", "baseConfidence": 70, diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerStarvedAppsTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerStarvedAppsTests.cs index 7810b11e..d52629a4 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerStarvedAppsTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerStarvedAppsTests.cs @@ -170,5 +170,53 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring Assert.Empty(f.StarvedPosts()); Assert.Empty(coordinator.StarvedAppsReported); } + + [Fact] + public void Reevaluate_does_not_re_emit_starved_warnings() + { + // sits-d Cloud-PC fix (2026-08-19): the synthesis re-check now runs on EVERY IME + // app-state transition. It must not turn the one-shot starvation warning into a + // per-transition stream — the re-check path suppresses the emission entirely + // (the per-appId dedupe would swallow the duplicates, but walking the probe + // hundreds of times on the IME hot path is waste, not safety). + using var f = new Fixture(); + using var coordinator = f.BuildCoordinator( + () => false, + () => new[] { StarvedApp("app-1", "Contoso Backgrounds") }); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.TriggerEspExitedForTest(Fixed); + var afterExit = f.StarvedPosts().Count; + Assert.Equal(1, afterExit); + + for (var i = 0; i < 10; i++) coordinator.ReevaluateUserAppsSettledSynthesis(); + + Assert.Equal(afterExit, f.StarvedPosts().Count); + Assert.Single(coordinator.StarvedAppsReported); + } + + [Fact] + public void Starved_apps_that_settle_later_still_complete_the_enrollment() + { + // The real sits-d shape: the ESP exits with apps still starved (warning emitted), + // the apps then all settle, and the re-check must open the gate — the warning + // already on the timeline is history, not a permanent veto. + using var f = new Fixture(); + var settled = false; + using var coordinator = f.BuildCoordinator( + () => settled, + () => new[] { StarvedApp("app-1", "Contoso Backgrounds") }); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.TriggerEspExitedForTest(Fixed); + Assert.Single(f.StarvedPosts()); + Assert.DoesNotContain(f.Ingress.Posted, p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete); + + settled = true; + coordinator.ReevaluateUserAppsSettledSynthesis(); + + Assert.Equal(1, f.Ingress.Posted.Count(p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete)); + Assert.Single(f.StarvedPosts()); + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerUserAppsSettledSynthesisTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerUserAppsSettledSynthesisTests.cs index debc3a89..bf429069 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerUserAppsSettledSynthesisTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/EspAndHelloTrackerUserAppsSettledSynthesisTests.cs @@ -159,5 +159,84 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring var posted = Assert.Single(f.Ingress.Posted); Assert.Equal(DecisionSignalKind.EspExiting, posted.Kind); } + + // ------------------------------------------------------------------------------ + // sits-d Cloud-PC fix (2026-08-19) — the synthesis is no longer edge-only. + // Sessions 8110e262 / a89aac2d: the ESP page exited while 138 required user-ESP apps + // were still in flight, they all reached a terminal state (0 failed) minutes later, + // and because nothing re-checked, the enrollment never completed. + // ------------------------------------------------------------------------------ + + [Fact] + public void Reevaluate_after_apps_settle_synthesizes_without_a_second_exit() + { + using var f = new Fixture(); + var settled = false; + using var coordinator = f.BuildCoordinator(() => settled); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.TriggerEspExitedForTest(Fixed); + Assert.DoesNotContain(f.Ingress.Posted, p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete); + + // The apps settle later; only the IME app-state callback fires — there is NO second + // ESP exit on a real device, which is exactly why the edge-only version starved. + settled = true; + coordinator.ReevaluateUserAppsSettledSynthesis(); + + Assert.Equal(1, f.Ingress.Posted.Count(p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete)); + Assert.True(coordinator.UserAppsSettledSynthesisFiredForTest); + + var info = Assert.Single(f.TrackerPostSink.Posted); + var data = Assert.IsAssignableFrom>(info.TypedPayload); + Assert.Equal("esp_exited_user_apps_settled_category_unresolved", data["fallbackReason"]); + } + + [Fact] + public void Reevaluate_without_an_observed_esp_exit_never_synthesizes() + { + // The gate needs BOTH facts. Settled apps alone must never open it — otherwise every + // quiet moment during AccountSetup would look like completion. + using var f = new Fixture(); + using var coordinator = f.BuildCoordinator(() => true); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.ReevaluateUserAppsSettledSynthesis(); + coordinator.ReevaluateUserAppsSettledSynthesis(); + + Assert.Empty(f.Ingress.Posted); + Assert.Empty(f.TrackerPostSink.Posted); + Assert.False(coordinator.UserAppsSettledSynthesisFiredForTest); + } + + [Fact] + public void Reevaluate_is_idempotent_after_the_synthesis_fired() + { + // The IME callback fires per app-state transition — on these tenants that is 138+ + // times. The synthesis must stay fire-once. + using var f = new Fixture(); + using var coordinator = f.BuildCoordinator(() => true); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.TriggerEspExitedForTest(Fixed); + for (var i = 0; i < 20; i++) coordinator.ReevaluateUserAppsSettledSynthesis(); + + Assert.Equal(1, f.Ingress.Posted.Count(p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete)); + Assert.Single(f.TrackerPostSink.Posted); + } + + [Fact] + public void Reevaluate_stays_silent_while_apps_are_still_unsettled() + { + using var f = new Fixture(); + using var coordinator = f.BuildCoordinator(() => false); + using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock); + + coordinator.TriggerEspExitedForTest(Fixed); + for (var i = 0; i < 5; i++) coordinator.ReevaluateUserAppsSettledSynthesis(); + + var posted = Assert.Single(f.Ingress.Posted); + Assert.Equal(DecisionSignalKind.EspExiting, posted.Kind); + Assert.False(coordinator.UserAppsSettledSynthesisFiredForTest); + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/ShellCoreTrackerEspExitBackfillTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/ShellCoreTrackerEspExitBackfillTests.cs new file mode 100644 index 00000000..2a8c369a --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/ShellCoreTrackerEspExitBackfillTests.cs @@ -0,0 +1,180 @@ +#nullable enable +using System; +using System.Collections.Generic; +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.Tests.Harness; +using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration; +using Xunit; + +namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring +{ + /// + /// sits-d Cloud-PC fix (2026-08-19) — Shell-Core ESP-exit backfill on restart. + /// + /// The backfill has existed since session 772fe502 but no caller ever invoked it, so the + /// Shell-Core watcher only saw events written after Start(). An agent restart + /// therefore lost any ESP exit (62407) that happened while it was down — after a forced + /// mid-ESP reboot that is exactly the window the AccountSetup completion lands in, and five + /// sits-d Cloud-PC sessions hung until the server-side timeout as a result. + /// + /// + public sealed class ShellCoreTrackerEspExitBackfillTests + { + private static readonly DateTime ClockNow = new DateTime(2026, 8, 19, 8, 43, 16, DateTimeKind.Utc); + + // Shell-Core 62407 wording for the normal ESP teardown (matches OOBE_ESP.*Exiting). + private const string EspExitDescription = + "BootstrapStatus: OOBE_ESP - Exiting page due to Account Setup completion."; + + private static ShellCoreTracker MakeTracker(TempDirectory tmp, VirtualClock clock) + { + var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info); + return new ShellCoreTracker( + sessionId: "S1", + tenantId: "T1", + post: new InformationalEventPost(new FakeSignalIngressSink(), clock), + logger: logger, + helloTracker: null); + } + + [Fact] + public void Backfilled_esp_exit_raises_EspExited_with_the_original_source_time() + { + using var tmp = new TempDirectory(); + using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow)); + + var order = new List(); + EspExitedEventArgs? captured = null; + tracker.FinalizingSetupPhaseTriggered += (_, reason) => order.Add($"finalizing:{reason}"); + tracker.EspExited += (_, args) => { order.Add("exited"); captured = args; }; + + // The exit happened while the agent was dead across the reboot. + var duringDowntime = ClockNow.AddMinutes(-11); + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: EspExitDescription, + occurredAtUtc: duringDowntime); + + Assert.Equal(new[] { "finalizing:esp_exiting", "exited" }, order); + Assert.NotNull(captured); + // The historical time must survive the replay — collapsing to now would date the + // completion after the reboot and skew every duration derived from it. + Assert.Equal(duringDowntime, captured!.OccurredAtUtc); + } + + [Fact] + public void Backfill_is_single_shot_across_repeated_records() + { + // The replay walks every record in the window; only the first ESP exit may raise. + using var tmp = new TempDirectory(); + using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow)); + + var exits = 0; + tracker.EspExited += (_, __) => exits++; + + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: EspExitDescription, + occurredAtUtc: ClockNow.AddMinutes(-11)); + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: EspExitDescription, + occurredAtUtc: ClockNow.AddMinutes(-9)); + + Assert.Equal(1, exits); + } + + [Fact] + public void Live_event_after_a_backfilled_exit_still_raises_by_design() + { + // The host starts the watcher BEFORE backfilling, so a record written in between is + // observed twice. Pinning that this is BENIGN, not a defect: Shell-Core emits 62407 + // at every ESP phase transition anyway, the tracker deliberately does not dedup live + // exits, and the reducer (ShouldTransitionToAwaitingHello) picks the genuine + // post-AccountSetup occurrence. The fire-once guards that DO matter sit downstream — + // the Hello-wizard rail and the user-apps-settled synthesis. Start-then-backfill is + // still the right order: a duplicate costs nothing, a dropped record costs the + // session's completion. + using var tmp = new TempDirectory(); + using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow)); + + var exits = 0; + tracker.EspExited += (_, __) => exits++; + + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: EspExitDescription, + occurredAtUtc: ClockNow.AddMinutes(-2)); + + tracker.ProcessEvent( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: EspExitDescription, + timestamp: ClockNow, + providerName: "Microsoft-Windows-Shell-Core", + isBackfill: false); + + Assert.Equal(2, exits); + } + + [Fact] + public void Backfilled_hello_wizard_start_is_single_shot_across_repeated_records() + { + // The 62404 rail matters just as much as the ESP exit: an agent restarted while the + // user sits inside the Hello wizard would otherwise never observe the wizard start + // (session 772fe502) — the original reason the backfill was written. Like the ESP + // exit, the single-shot guard covers the REPLAY; a later live event raises again and + // is absorbed downstream (HelloTracker once-guard, adapter dedup flag, engine + // set-once fact). + using var tmp = new TempDirectory(); + using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow)); + + var wizardStarts = 0; + tracker.HelloWizardStarted += (_, __) => wizardStarts++; + + const string aadHello = "CloudExperienceHost web app activity started. CXID: 'AADHello'."; + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppStarted, + description: aadHello, + occurredAtUtc: ClockNow.AddMinutes(-3)); + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppStarted, + description: aadHello, + occurredAtUtc: ClockNow.AddMinutes(-2)); + + Assert.Equal(1, wizardStarts); + } + + [Fact] + public void Backfilled_unrelated_record_is_ignored() + { + using var tmp = new TempDirectory(); + using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow)); + + var exits = 0; + tracker.EspExited += (_, __) => exits++; + + tracker.HandleBackfillRecord( + eventId: ShellCoreTracker.EventId_ShellCore_WebAppEvent, + description: "BootstrapStatus: some other page transition.", + occurredAtUtc: ClockNow.AddMinutes(-1)); + + Assert.Equal(0, exits); + } + + [Theory] + [InlineData(0, 1)] + [InlineData(-42, 1)] + [InlineData(5, 5)] + [InlineData(ShellCoreTracker.BackfillLookbackMaxMinutes, ShellCoreTracker.BackfillLookbackMaxMinutes)] + [InlineData(ShellCoreTracker.BackfillLookbackMaxMinutes + 1, ShellCoreTracker.BackfillLookbackMaxMinutes)] + [InlineData(int.MaxValue, ShellCoreTracker.BackfillLookbackMaxMinutes)] + public void Lookback_is_clamped_to_a_sane_window(int requested, int expected) + { + // int.MaxValue matters: the query multiplies minutes by 60_000, so an unclamped + // value would overflow into a negative timediff and silently match nothing. + Assert.Equal(expected, ShellCoreTracker.ClampLookbackMinutes(requested)); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DefaultComponentFactoryOrderingTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DefaultComponentFactoryOrderingTests.cs index 70b94174..8ae349a6 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DefaultComponentFactoryOrderingTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/DefaultComponentFactoryOrderingTests.cs @@ -3,6 +3,7 @@ using System.Collections.Generic; using System.Linq; using AutopilotMonitor.Agent.V2.Core.Configuration; using AutopilotMonitor.Agent.V2.Core.Logging; +using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime; using AutopilotMonitor.Agent.V2.Core.Orchestration; using AutopilotMonitor.Agent.V2.Core.Tests.Harness; using AutopilotMonitor.Shared.Models; @@ -130,5 +131,40 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration } } } + + [Fact] + public void Ime_app_state_callback_is_chained_into_the_user_apps_settled_recheck() + { + // sits-d Cloud-PC fix (2026-08-19): the AccountSetup synthesis is re-evaluated on every + // terminal IME app transition, which only works while the factory keeps this chain + // wired. It is five lines that a refactor can drop silently and whose absence costs a + // whole class of sessions their completion — so pin it here. + var surfaces = CreateSurfaces(); + var hosts = surfaces.Hosts; + try + { + var imeHost = hosts.OfType().Single(); + var handler = imeHost.Tracker.OnAppStateChanged; + + Assert.NotNull(handler); + + // Invoking it must reach the re-check without throwing. The re-check is a no-op + // here (no ESP exit observed), which is the point — it must stay cheap and silent + // on the IME hot path until both facts are in. + var pkg = new AppPackageState("app-1", listPos: 0); + var ex = Record.Exception(() => handler!( + pkg, + AppInstallationState.Installing, + AppInstallationState.Installed)); + Assert.Null(ex); + } + finally + { + foreach (var host in hosts) + { + try { host.Dispose(); } catch { /* construction-only test — best-effort cleanup */ } + } + } + } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspAndHelloTracker.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspAndHelloTracker.cs index 98260c83..1d3261a1 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspAndHelloTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspAndHelloTracker.cs @@ -1,5 +1,6 @@ using System; using System.Collections.Generic; +using System.Threading; using AutopilotMonitor.Agent.V2.Core.Logging; using AutopilotMonitor.Agent.V2.Core.Orchestration; using AutopilotMonitor.Shared; @@ -46,7 +47,17 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals // Session caa6cf50 gate-starvation fix (2026-06-11) — fire-once guard for the // user-ESP-apps-settled AccountSetup synthesis (see MaybeSynthesizeAccountSetupComplete). - private bool _userAppsSettledSynthesisFired; + // Interlocked rather than a plain bool: since the sits-d Cloud-PC fix the synthesis is + // ALSO re-evaluated from the IME app-state-change thread, so two threads can reach the + // guard concurrently (Shell-Core watcher thread + IME log thread). + private int _userAppsSettledSynthesisFired; + + // sits-d Cloud-PC fix (2026-08-19) — set once a Shell-Core normal ESP exit has been + // observed (live OR backfill). The synthesis needs two facts: the ESP exit is an EDGE + // that happens once, the settled user-ESP apps are a LEVEL that may only be reached + // minutes later. Recording the edge lets ReevaluateUserAppsSettledSynthesis re-check + // the level afterwards instead of losing the completion for the rest of the session. + private volatile bool _espExitObserved; // Liveness plan PR3 — one-shot-per-appId dedupe for app_install_starved emissions. // Written from the Shell-Core watcher thread (esp_exited path), read at termination by @@ -320,6 +331,37 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals /// public void BackfillRecentEspExitEvents() => _shellCoreTracker?.BackfillRecentEspExitEvents(); + /// + /// Same backfill with an explicit lookback window. Called by EspAndHelloHost right + /// after — see the host for why the window widens after a reboot. + /// + public void BackfillRecentEspExitEvents(int lookbackMinutes) + => _shellCoreTracker?.BackfillRecentEspExitEvents(lookbackMinutes); + + /// + /// sits-d Cloud-PC fix (2026-08-19) — re-check the user-apps-settled AccountSetup + /// synthesis after the ESP exit has already been observed. Wired to the IME tracker's + /// app-state-change callback in DefaultComponentFactory. + /// + /// Before this, the synthesis ran ONLY on the EspExited edge. When the ESP page + /// exits while user-ESP apps are still in flight (the normal case on a tenant with a + /// large required-app set), the single attempt misses and nothing re-checks — even once + /// every tracked app has reached a terminal state minutes later. Sessions 8110e262 and + /// a89aac2d reached 138/138 apps with 0 failed and still never completed. + /// + /// + /// Adds NO new completion path: the gate conditions inside the synthesis are unchanged + /// (real ESP exit + every required user-ESP app terminal + zero failures). This only + /// grants the existing, deliberately conservative check a second look. + /// + /// + public void ReevaluateUserAppsSettledSynthesis() + { + if (!_espExitObserved) return; + if (Volatile.Read(ref _userAppsSettledSynthesisFired) != 0) return; + MaybeSynthesizeAccountSetupCompleteFromSettledUserApps(emitStarvedOnMiss: false); + } + // ===================================================================== // Lifecycle // ===================================================================== @@ -675,6 +717,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals try { EspExited?.Invoke(this, args); } catch (Exception ex) { _logger.Error("Error forwarding EspExited", ex); } + // Record the edge BEFORE the synthesis attempt so a later app-state change can + // re-run it even when the apps are not settled yet at this instant. + _espExitObserved = true; + // Session caa6cf50 gate-starvation fix: a Shell-Core normal exit while IME's // user-ESP app tracking is fully settled is alternative evidence that // AccountSetup completed. Raised AFTER the EspExited forward so the reducer @@ -704,9 +750,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals /// conservative stall behaviour. /// /// - private void MaybeSynthesizeAccountSetupCompleteFromSettledUserApps() + private void MaybeSynthesizeAccountSetupCompleteFromSettledUserApps(bool emitStarvedOnMiss = true) { - if (_userAppsSettledSynthesisFired) return; + if (Volatile.Read(ref _userAppsSettledSynthesisFired) != 0) return; bool settled; try { settled = _userEspAppsSettledProbe(); } @@ -722,11 +768,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals // operator with an anonymous "session hangs in AccountSetup". One-shot per // appId; apps that are alive (Downloading/Installing) or failed are excluded // by the probe itself. - EmitStarvedUserEspApps(trigger: "esp_exited_user_apps_not_settled"); + // Only on the ESP-exit edge: the re-evaluation path passes false so a repeated + // miss cannot re-walk the probe on every single app-state change (the per-appId + // dedupe would swallow the events anyway — this keeps the work off the hot path). + if (emitStarvedOnMiss) + EmitStarvedUserEspApps(trigger: "esp_exited_user_apps_not_settled"); return; } - _userAppsSettledSynthesisFired = true; + // Claim the single synthesis slot; a concurrent caller that loses the race returns. + if (Interlocked.CompareExchange(ref _userAppsSettledSynthesisFired, 1, 0) != 0) return; _logger.Warning( "EspAndHelloTracker: ESP exited normally with all tracked user-ESP apps terminal (0 failed) " + "but AccountSetupCategory.Status never confirmed categorySucceeded — treating AccountSetup as complete " + @@ -820,6 +871,6 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals // Test seam for the user-apps-settled synthesis — drives OnEspExited with the live // handler signature, mirroring TriggerEspExitedForTest's contract. - internal bool UserAppsSettledSynthesisFiredForTest => _userAppsSettledSynthesisFired; + internal bool UserAppsSettledSynthesisFiredForTest => Volatile.Read(ref _userAppsSettledSynthesisFired) != 0; } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/ShellCoreTracker.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/ShellCoreTracker.cs index 0f875428..0a0a0b94 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/ShellCoreTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/ShellCoreTracker.cs @@ -34,6 +34,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals internal const int EventId_ShellCore_WebAppEvent = 62407; internal const int BackfillLookbackMinutes = 5; + /// + /// Upper bound for the caller-supplied backfill lookback. Matches the agent's max + /// lifetime (360 min) — a window wider than the agent can ever live would only widen + /// the blast radius of a stale Shell-Core record without recovering anything the + /// current enrollment could still act on. + /// + internal const int BackfillLookbackMaxMinutes = 360; + private static readonly HashSet TrackedShellCoreEventIds = new HashSet { EventId_ShellCore_WebAppStarted, @@ -356,11 +364,28 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals /// unavailable — an agent restart while the user sits inside the Hello wizard would /// otherwise lose the wizard-start observation (session 772fe502). /// - public void BackfillRecentEspExitEvents() + /// Clamps a caller-supplied lookback into [1, ]. + internal static int ClampLookbackMinutes(int lookbackMinutes) + { + if (lookbackMinutes < 1) return 1; + if (lookbackMinutes > BackfillLookbackMaxMinutes) return BackfillLookbackMaxMinutes; + return lookbackMinutes; + } + + public void BackfillRecentEspExitEvents() => BackfillRecentEspExitEvents(BackfillLookbackMinutes); + + /// + /// Same recovery with a caller-chosen lookback. A restart after a mid-ESP reboot must + /// reach back over the whole downtime (agent dead from the restart until the post-reboot + /// logon re-launches it), which the 5-minute default cannot span — the ESP exit that ends + /// AccountSetup then lands in the gap and the session never observes it. The value is + /// clamped to [1, ]. + /// + public void BackfillRecentEspExitEvents(int lookbackMinutes) { try { - var lookbackMs = BackfillLookbackMinutes * 60 * 1000; + var lookbackMs = ClampLookbackMinutes(lookbackMinutes) * 60 * 1000; var query = new EventLogQuery( ShellCoreEventLogChannel, PathType.LogName, diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DefaultComponentFactory.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DefaultComponentFactory.cs index c1f1e2e0..a7b39ec5 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DefaultComponentFactory.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DefaultComponentFactory.cs @@ -74,13 +74,22 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration private readonly string _stateDirectory; private readonly Persistence.StartupEventGate? _startupEventGate; + /// + /// OS boot time when the previous agent run was killed by a reboot (reboot_kill), + /// otherwise null. Widens the Shell-Core ESP-exit backfill so a completion signal written + /// while the agent was down is still recovered — see the backfill block in + /// . + /// + private readonly DateTime? _previousBootUtc; + public DefaultComponentFactory( AgentConfiguration agentConfig, AgentConfigResponse remoteConfig, NetworkMetrics? networkMetrics, string agentVersion, string stateDirectory, - Persistence.StartupEventGate? startupEventGate = null) + Persistence.StartupEventGate? startupEventGate = null, + DateTime? previousBootUtc = null) { _agentConfig = agentConfig ?? throw new ArgumentNullException(nameof(agentConfig)); _remoteConfig = remoteConfig ?? throw new ArgumentNullException(nameof(remoteConfig)); @@ -88,6 +97,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration _agentVersion = string.IsNullOrEmpty(agentVersion) ? "unknown" : agentVersion; _stateDirectory = stateDirectory ?? throw new ArgumentNullException(nameof(stateDirectory)); _startupEventGate = startupEventGate; + _previousBootUtc = previousBootUtc; } public CollectorSurfaces CreateCollectorHosts( @@ -150,6 +160,29 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration // on esp_exiting events long after Start. ImeLogHost? imeLogHostRef = null; + // sits-d Cloud-PC fix (2026-08-19): after a mid-ESP reboot the agent is dead from the + // forced restart until the post-reboot logon re-launches it. The Shell-Core ESP exit + // that ends AccountSetup can land anywhere in that window, and the 5-minute default + // backfill is far too narrow to reach it. Widen to "everything since the boot that + // killed us" — the exit we care about is by definition after that boot. Clamped to + // ShellCoreTracker.BackfillLookbackMaxMinutes inside the tracker. + var espExitBackfillLookbackMinutes = ShellCoreTracker.BackfillLookbackMinutes; + if (_previousBootUtc.HasValue) + { + var sinceBoot = DateTime.UtcNow - _previousBootUtc.Value; + if (sinceBoot > TimeSpan.Zero) + { + var sinceBootMinutes = (int)Math.Ceiling(sinceBoot.TotalMinutes) + 1; + if (sinceBootMinutes > espExitBackfillLookbackMinutes) + { + espExitBackfillLookbackMinutes = sinceBootMinutes; + logger.Info( + "DefaultComponentFactory: previous run died to a reboot — widening the Shell-Core " + + $"ESP-exit backfill to {espExitBackfillLookbackMinutes} min (since boot {_previousBootUtc.Value:o})"); + } + } + } + var espAndHelloHost = new EspAndHelloHost( sessionId: sessionId, tenantId: tenantId, @@ -174,7 +207,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration // covers Store/WinGet apps invisible to the starved/correlation paths. packageStatesProbe: () => imeLogHostRef?.AllKnownPackageStates - ?? Array.Empty()); + ?? Array.Empty(), + espExitBackfillLookbackMinutes: espExitBackfillLookbackMinutes); hosts.Add(espAndHelloHost); // Hybrid User-Driven completion-gap fix (2026-05-01): the AadJoinHost notifies @@ -309,6 +343,30 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration hosts.Add(imeLogHost); imeLogHostRef = imeLogHost; + // sits-d Cloud-PC fix (2026-08-19): the user-apps-settled AccountSetup synthesis used + // to run ONLY on the EspExited edge. On a tenant with a large required-app set the ESP + // page exits while apps are still in flight, the single attempt misses, and nothing + // ever re-checks — sessions 8110e262 / a89aac2d reached 138/138 apps with 0 failed and + // still never completed. Chain into the tracker's app-state callback (same + // preserve-previous pattern DeliveryOptimizationHost uses) so every terminal app + // transition gives the synthesis another look. Cheap: the re-check returns immediately + // unless the ESP exit was already observed and the synthesis has not fired yet. + var previousAppStateChanged = imeLogHost.Tracker.OnAppStateChanged; + imeLogHost.Tracker.OnAppStateChanged = (pkg, oldState, newState) => + { + try { previousAppStateChanged?.Invoke(pkg, oldState, newState); } + catch (Exception ex) + { + logger.Warning($"DefaultComponentFactory: previous OnAppStateChanged handler threw: {ex.Message}"); + } + + try { espAndHelloHost.ReevaluateUserAppsSettledSynthesis(); } + catch (Exception ex) + { + logger.Warning($"DefaultComponentFactory: user-apps-settled re-check threw: {ex.Message}"); + } + }; + if (collectors.StallProbeEnabled) { hosts.Add(new StallProbeHost( diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/EspAndHelloHost.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/EspAndHelloHost.cs index f907d67a..0e31c330 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/EspAndHelloHost.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/Hosts/EspAndHelloHost.cs @@ -14,6 +14,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration private readonly EspAndHelloTracker _tracker; private readonly EspAndHelloTrackerAdapter _adapter; + private readonly int _espExitBackfillLookbackMinutes; private int _disposed; /// @@ -73,8 +74,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration bool isDevicePreparation = false, Func? userEspAppsSettledProbe = null, Func>? starvedUserEspAppsProbe = null, - Func>? packageStatesProbe = null) + Func>? packageStatesProbe = null, + int espExitBackfillLookbackMinutes = ShellCoreTracker.BackfillLookbackMinutes) { + _espExitBackfillLookbackMinutes = espExitBackfillLookbackMinutes; if (ingress == null) throw new ArgumentNullException(nameof(ingress)); if (clock == null) throw new ArgumentNullException(nameof(clock)); var post = new InformationalEventPost(ingress, clock); @@ -100,9 +103,42 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration _adapter = new EspAndHelloTrackerAdapter(_tracker, ingress, clock); } - public void Start() => _tracker.Start(); + /// + /// Starts the tracker and then replays recent Shell-Core ESP-exit / Hello-wizard records. + /// + /// The backfill has existed since session 772fe502 but was never wired to a caller, so + /// the Shell-Core watcher only ever saw events written AFTER . Any + /// agent restart therefore lost an ESP exit (62407) or Hello-wizard start (62404) that + /// happened while the agent was down — and after a mid-ESP reboot that is exactly the + /// window the completion signal lands in (sits-d Cloud PCs, 2026-08-19: five sessions + /// hung in AccountSetup until the server-side timeout while the devices were fine). + /// + /// + /// Ordering is deliberate: Start first, then backfill. A record written between the two + /// is observed twice, and that is by design tolerable — the tracker dedups the REPLAY + /// (single-shot per rail) but never the live stream, because Shell-Core emits 62407 at + /// every ESP phase transition anyway. Duplicates are absorbed downstream: the reducer + /// (ShouldTransitionToAwaitingHello) picks the genuine post-AccountSetup exit, and + /// the Hello rail has the HelloTracker once-guard plus the adapter's dedup flag. The + /// reverse order could drop a record entirely, which costs the session its completion — + /// a duplicate costs nothing. + /// + /// + public void Start() + { + _tracker.Start(); + _tracker.BackfillRecentEspExitEvents(_espExitBackfillLookbackMinutes); + } + public void Stop() => _tracker.Stop(); + /// + /// Re-checks the user-apps-settled AccountSetup synthesis — see + /// . Driven by the IME + /// tracker's app-state-change callback (wired in DefaultComponentFactory). + /// + public void ReevaluateUserAppsSettledSynthesis() => _tracker.ReevaluateUserAppsSettledSynthesis(); + private void OnTrackerWhiteGloveCompleted(object sender, EventArgs e) => WhiteGloveCompleted?.Invoke(this, e); diff --git a/src/Agent/AutopilotMonitor.Agent.V2/Runtime/AgentRuntimeHost.cs b/src/Agent/AutopilotMonitor.Agent.V2/Runtime/AgentRuntimeHost.cs index f8a79100..2e3a1742 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2/Runtime/AgentRuntimeHost.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2/Runtime/AgentRuntimeHost.cs @@ -79,13 +79,22 @@ namespace AutopilotMonitor.Agent.V2.Runtime // write to the same state file; per-enrollment lifecycle like the other state files. var startupEventGate = new AutopilotMonitor.Agent.V2.Core.Persistence.StartupEventGate(stateSubdir, logger); + // sits-d Cloud-PC fix (2026-08-19): a reboot_kill means the agent was down across the + // forced mid-ESP restart. Hand the boot timestamp to the factory so the Shell-Core + // ESP-exit backfill can reach back over the whole downtime instead of 5 minutes. + var previousBootUtc = + string.Equals(previousExit?.ExitType, "reboot_kill", StringComparison.OrdinalIgnoreCase) + ? previousExit?.LastBootUtc + : null; + var componentFactory = new DefaultComponentFactory( agentConfig: agentConfig, remoteConfig: remoteConfig, networkMetrics: auth.NetworkMetrics, agentVersion: agentVersion, stateDirectory: stateSubdir, - startupEventGate: startupEventGate); + startupEventGate: startupEventGate, + previousBootUtc: previousBootUtc); var whiteGloveSealingPatternIds = (System.Collections.Generic.IReadOnlyCollection)remoteConfig.WhiteGloveSealingPatternIds ?? Array.Empty();