Compare commits

...

14 Commits

Author SHA1 Message Date
Oliver Kieselbach fd7d3973e7 fix(agent): esp_policy_provider_stalled gains sidecar-missing arm (issue #106)
Customer follow-up corrected the field-case mechanics: TrackingPoliciesCreated=1
WAS set under the foreign ConfigMgr provider - the ESP ignores a foreign
provider's completion values and waits on the Intune-registered "Sidecar"
provider by name (renaming the key unblocks instantly without creating any
tracking entries). The completeness-keyed detector would have missed exactly
the incident it was built for.

- Arm 2: >=1 Setup\Apps provider registered without Sidecar, continuously for
  the 15-min dwell -> reason=sidecar_provider_missing; clock resets when
  Sidecar registers later (legitimate startup ordering); DevicePreparation-only
  snapshots don't activate it
- Arm 1 (continuously-incomplete providers) unchanged -> reason=provider_incomplete;
  sidecar-missing wins when both arms cross in one round (single event)
- Cross-restart fingerprint gains a "sidecarMissing" sentinel; payload adds
  reason + sidecarMissingForMinutes
- Regression test: ConfigMgr complete + Sidecar absent -> fires (previously
  classified healthy); probe/doc headers and OKF doc corrected, web event-type
  description updated

Evidence (research session c7e3db08): Intune's ESP-policy WAP payload always
registers Sidecar (ConfigMgr only via co-management settings policy, per
Niehaus' documented payload); Microsoft's ESP troubleshooting models app
tracking exclusively through the Sidecar subkey.

Agent tests 2043/2043, web tsc clean.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 16:48:50 +02:00
Oliver Kieselbach fd2b5c2da2 fix(ci): drop invalid SWA input, gate deploy on token via env guard
Azure/static-web-apps-deploy@v1 has no `skip_deploy_on_missing_secrets`
input (confirmed against its action.yml), so passing it did nothing but
emit an "Unexpected input(s)" warning — the intended "skip green on
Dependabot PRs" behaviour was never actually in effect.

Replace it with the documented mechanism: surface the deploy token as a
job-level env var and gate the deploy/close step with `if: env.DEPLOY_TOKEN
!= ''` (secrets cannot be referenced directly in an `if:`). On Dependabot
PRs the token is absent, so the step skips and the job stays green; real
deploys on main and internal PRs still run. Applied to both jobs.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 16:38:58 +02:00
Oliver Kieselbach a44e37a7c2 fix(metrics): keep full failure-reason text for fleet-health display
BuildFleetFailureReasons truncated each reason to a 50-char prefix + "..."
and used that as both the grouping key AND the display value. The full text
never reached the UI, so its tooltip/tap-to-expand had nothing to reveal and
near-identical rows were indistinguishable past the cut.

Group by the 50-char prefix as before (variants still collapse into one row),
but carry the longest full reason as the display value. The UI truncates and
expands it on demand, so the complete text is now available end-to-end.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 16:25:11 +02:00
Oliver Kieselbach d8a252562d fix(web): pin engines.node to 22.x so SWA/Oryx does not grab Node 24
The prior ">=22" made Oryx build with the highest available Node (24.13),
which the Static Web Apps runtime rejects: "Node version 24.13.0 is not
supported. Please use one of the following versions 18, 20, 22." Pin to
22.x so Oryx selects the SWA-supported major. CI setup-node '22' already
resolves to latest 22.x, so build and deploy now agree.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 16:23:17 +02:00
Oliver Kieselbach a5d12ba1d0 chore(ci): unify Node toolchain on 22 across CI + engines pins
Node 20 reached EOL (2026-04-30); Node 22 is the current maintenance LTS
and already the runtime the MCP container ships (node:22-slim). Straighten
the version skew so per-component CI major == deploy runtime == engines floor:

- ci.yml: web, mcp and guardrails setup-node 20 -> 22
- combine-rules.yml: setup-node 20 -> 22
- mcp package.json: add engines.node ">=22" (matches Dockerfile)
- web package.json: add engines.node ">=22" (first explicit pin; SWA/Oryx
  no longer picks a Node version implicitly)

engine-strict stays off (no .npmrc), so the pins are advisory and cannot
hard-break local installs on other Node versions.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 16:15:54 +02:00
Oliver Kieselbach 530c978bf8 fix(web): TruncatedLabel expands to full text, not just two lines
The expanded state used line-clamp-2, which re-truncated long values with an
ellipsis after two lines — unreadable on touch where the hover tooltip is
unavailable. Expand now wraps the entire string over as many lines as needed.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 15:11:54 +02:00
Oliver Kieselbach 09898d7ba0 feat(web): consistent truncate-with-tooltip + tap-to-expand across dashboard cards
Add reusable TruncatedLabel component: a single-line label that truncates
with an ellipsis, shows the full text as a native hover tooltip, and on
click/Enter/Space expands to two wrapped lines (touch-friendly). An
interactive={false} mode provides tooltip-only behaviour for use inside
already-clickable rows/links where an inner onClick would hijack navigation.

Apply it consistently to the long, dynamic label columns across:
- fleet-health: failure reasons, model + app ranked lists
- sla: top failing apps, violators failure reason
- geographic-performance: fastest/slowest location cards
- vulnerability exposure panel: CVE sample software
- agent metrics: top exception types
- progress + download/install: app-name labels
- admin software tabs: software names
- session reports (comment/adminNote) + ops events (message): tooltip-only

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-24 15:03:34 +02:00
Oliver Kieselbach 71eda93e8b fix(metrics): app-install failure rate over finished installs only
Second half of the terminal-only rate convention (follows 1cfc32c9, which
converted the enrollment success rates): app-install failureRate divided
by ALL install rows including "InProgress" ones — installs still running,
or orphaned when a session died mid-install — diluting every failure rate
customers see on the Apps dashboard and Fleet Health.

- New MetricsMath.TerminalFailureRatePct (Failed / (Failed + Succeeded),
  0 when nothing finished) shared by both aggregation sites
- MetricsMath.BuildAppMetricsPayload: per-app failureRate terminal-based
  (Fleet Health "Top Failing Apps"; subtitle now "% of N finished")
- AppsAnalyticsHelper: list, analytics summary, versionBreakdown,
  timeSeries and deviceModelBreakdown rates terminal-based; the
  duplicated trend block is deduplicated into ComputeFailureTrend, whose
  rates and >= 5-sample gate now run on finished installs per half; the
  device-model >= 5 sample floor likewise counts finished installs
- Web: InstallsTab "Avg Failure Rate" card computed over summed finished
  installs instead of totalInstalls

Tests: new AppsAnalyticsFailureRateTests (list/trend/analytics/model
cases incl. in-flight dilution and gate regressions) and a terminal-rate
case in MetricsMathAppPayloadTests. Backend 3223/3223, tsc clean,
vitest 602/602.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-24 10:01:28 +02:00
Oliver Kieselbach 1cfc32c9aa fix(metrics): success rate over finished enrollments only (geo + fleet health)
Customer feedback: the geographic performance pane showed a poor success
rate for a site mid-rollout because in-progress/pending sessions counted
against the rate. Success rate is an outcome quota — align Geo and Fleet
Health with the SLA convention already used by dashboard stats, usage
snapshots and the fleet rollup: Succeeded / (Succeeded + Failed).
Incomplete (terminal, non-failure) stays excluded.

- Geo: per-location SuccessRate over finished sessions; table badge and
  map tooltip render an em dash instead of a red 0% when nothing has
  finished yet
- Fleet Health: Stats.SuccessRate terminal-based; card shows "X of Y
  finished enrollments" and a neutral em dash state; per-model health
  gets a Failed count (additive wire field) so the client rate excludes
  in-flight devices; TopFailingModels FailureRate now failed/finished
- Tests: FleetHealthPayloadTests flipped to the new convention plus
  zero-finished, model-failed and in-flight-dilution cases; new
  GeographicMetricsSuccessRateTests pin the geo semantics

Backend 3216/3216, web tsc clean, vitest 602/602.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-24 09:47:31 +02:00
Oliver Kieselbach 11339c9868 fix(test): de-flake SessionDeletionWorkerTests via condition-gated runs
CI run 30047512186 failed Worker_drops_envelope_missing_required_fields_
without_invoking_handler: RunForAsync starts the BackgroundService poll loop
and waits a fixed 500ms wall-clock window — on a loaded CI runner (xUnit runs
test classes in parallel) the loop may not have processed the message before
the positive assertions (DeleteMessageAsync at least once) run. All ten
positive tests in the file shared that latent race; this run it hit the
malformed-envelope drop test.

Fix mirrors the watchdog event-gate de-flake: new Harness.RunUntilAsync
(condition, 10s ceiling, 25ms poll) runs the worker until the awaited side
effect is observable, then stops. Gates: ops-event recorded (last step of the
poison path, so send+delete+CAS are already done), main-queue delete for the
drop tests, >=3 visibility heartbeats for the heartbeat test. The kill-switch
test keeps the fixed window — a Times.Never expectation has no event to wait
for. OpsEventCalls capture is now lock-guarded so the condition poll can read
it while the worker thread appends.

16/16 worker tests green across 4 consecutive runs; full backend suite
3211/3211.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-24 00:03:10 +02:00
Oliver Kieselbach 540f543834 feat(agent): extend historic IME-replay suppression to app events + app aggregation
Part 2 of the eaf3d8c4 fix (follows 088c3b04). In that session 147 of 157 app
events were replayed from a previous enrollment's IME log — all 10 "installed
apps" were phantoms, polluting the timeline, AppInstallSummaries, MCP counts,
the app_tracking_summary header, culprit lists and final-status.json.

Rename (nothing deployed yet): historic_script_replay_detected →
historic_ime_replay_detected; SuppressIfHistoricReplay / IsHistoricImeReplay.

Agent:
- EmitAppState suppresses stale-replay transitions BEFORE the sub-phase
  declaration, timing bookkeeping and terminal-signal dedup — covers the
  informational event, the AppInstallCompleted/Failed DecisionSignal, the
  shadow download_progress and the summary snapshot. Behavior note: phantom
  terminal signals can no longer spuriously re-arm the AdvisoryCompletion
  window (app signals are otherwise observation-only — verified no completion
  gate reads them). EmitDoTelemetry gets the same guard.
- Tracker-level guard at the HandlePatternMatch choke point skips the 23
  app-mutating actions (incl. espphasedetected — a stale AccountSetup line
  would make fresh DeviceSetup lines bounce as "backward") for source lines
  >24h stale, so replayed apps never enter PackageStates, persistence,
  app_tracking_summary, culprit lists or final-status. New internal
  UtcNowProvider seam (no ctor change), threshold single-sourced as
  ImeLogTracker.HistoricReplayThreshold.
- SimulationMode now bypasses all replay suppression — 088c3b04 had broken
  the --replay-log-dir dev tool, which feeds historic lines on purpose.

Backend: IsHistoricImeReplay guard in AggregateAppInstallEvent keeps replayed
events out of AppInstallSummaries (SLA/dashboards/metrics inherit).

Web: generic lib/historicReplay.ts partition (scriptExecutions becomes a
wrapper); InstallProgress hides replayed installs with a muted note;
DownloadProgress filters silently.

MCP: get_session_summary filters replayed events — cleans appInstalls stats,
errorCount (replayed app_install_failed are Error-severity) and keyEvents.

Tests: +13 agent (app suppression, tracker guard), +1 backend, +7 web,
+6 MCP. Agent 2039, backend 3211, web 602, MCP 455 all green; drift test
validates the rename.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-23 23:43:59 +02:00
Oliver Kieselbach 088c3b0479 fix(agent): suppress historic IME-log script replay + timeline-consistent durations
Session eaf3d8c4: a previous enrollment's IME logs survived on disk (dated
2026-07-16, 7 days old) and the agent replayed them at startup — 156 phantom
script_completed events in a 7-minute session, each showing ~170h durations
(clock-clamped completion minus RAW stale start), plus an immediateUpload
flood (3x ingress_backpressure) and RemediationScriptCount inflated to 156.

Agent:
- Script events whose source line is >24h stale are suppressed entirely; a
  one-shot historic_script_replay_detected Info event (new EventType) dates
  the replayed window via earliestRejectedSourceTimestamp. Future-skew
  rejections and clock-only fallbacks still emit.
- durationSeconds now uses a timeline-consistent pair: on rejected-timestamp
  emissions the raw source completion pairs with the raw start (true runtime
  instead of cross-timeline garbage). 24h plausibility backstop omits
  implausible values; same consistency for script_timeout_suspected.
- Stale pending platform-script slots (>24h older than the current start
  line) are discarded so an old orphaned start can't pair with a fresh run
  (extracted HandlePlatformScriptStarted as internal test seam).

Web: partitionHistoricScriptEvents hides legacy-agent replay events (muted
"N historic executions hidden" note) and the reducer blanks >24h durations —
covers sessions recorded before the agent fix rolls out.

Backend: IsHistoricScriptReplay guard keeps replayed events from inflating
Platform-/RemediationScriptCount during the rollout window.

Registered historic_script_replay_detected in Constants.EventTypes, MCP
resource-catalog (script_events) + KEY_EVENT_TYPES, gather-rules eventTypes.

Tests: 8 agent (suppression/one-shot/raw-pair/backstop/slot-hardening),
8 web (partition/blanking), 10 backend (predicate). Agent 2026, backend
3210, web 595, MCP 449 all green.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-23 18:39:11 +02:00
Oliver Kieselbach 3224774752 fix(test): EDR-safe straggler replay — no more renamed system executable
The straggler integration test copied powershell.exe under a synthetic
agent name and launched it — textbook MITRE T1036.003 ("Rename Legitimate
Utilities"). Defender for Endpoint flagged the run ("System executable
renamed and launched", initiating process testhost.net48.exe) and ISOLATED
the dev machine.

Replaced with function shadowing: a harness script defines Get-Process /
Stop-Process stub functions (PowerShell resolves functions before cmdlets)
and dot-sources the cleanup script. The stubs report a live agent-named
straggler on every probe and record the kill, pinning the identical
contract — poll by NAME until the deadline, force-kill by NAME, then
delete — with zero process spawns, zero PE copies, nothing EDR-visible.

The production routine never renames or copies executables; the flagged
technique existed only in this test. Lesson recorded in tasks/lessons.md.

22/22 cleanup tests green.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-23 17:24:07 +02:00
Oliver Kieselbach e7ea431ccf feat(esp): recovery story for terminally reported ESP failures (session 4910a5a5)
DeviceSetup/Apps failed, the user pressed "Try again" ~23 min later, apps
recovered to 10/10 and DeviceSetup resolved - yet the advisory_completion
window un-defanged the stale failure and failed the live enrollment,
because the advisory variant was exempt from all re-arm/rebase guards.

Engine fix (DecisionCore):
- New facts EspAdvisoryFailureResolvedUtc + EspAdvisoryFailureCategory
  (state-borne; deadline payload would be lost on re-arm/rebase).
- TryResolveAdvisoryOnCategoryRecovery in both ProvisioningComplete
  handlers: category match sets the fact + emits
  esp_failure_advisory_resolved.
- Guards now (!hasAdvisoryAnchor || advisoryResolved): enforcement-progress
  re-arm, hello-never-observed promote and the reboot rebase apply again
  once the failure demonstrably un-happened; unresolved advisories keep
  the legacy un-defang exactly.
- Truthful terminal reason esp_recovered_without_completion_evidence
  (+ failureRecovered=true, LastFailureTrigger=DeadlineFired so the
  likely-stuck app promotion stays off).

Story events (agent tracker):
- esp_failure_retry_detected: failed subcategory leaves "failed" after the
  terminal fire - consistent with the user pressing "Try again".
- esp_failure_recovered: previously failed category reaches success.
- EspFailureDetectedEventArgs.LikelyCulpritApps (never-started first,
  cap 3) rides the EspTerminalFailure payload so esp_failure_advisory /
  enrollment_failed name the culprit app directly.

Surfacing: MCP resource-catalog, web timeline badges (Recovered /
User retry pills, culprit chip on advisory), gather-rule autocomplete,
ANALYZE-ESP-006 "ESP Failure Recovered After User Retry".

Tests: AdvisoryRecoveryTests (13, incl. the 527/611/635/671 field-ordinal
replay that no longer fails the session), EspFailureRecoveryStoryTests (5),
snapshot-builder guards 18 -> 20. All suites green (DecisionCore 493,
V2.Core 2018, Backend 3201, web vitest 589, MCP 449 incl. drift).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-23 17:03:44 +02:00
77 changed files with 3812 additions and 391 deletions
+3 -3
View File
@@ -63,7 +63,7 @@ jobs:
- uses: actions/setup-node@v7
with:
node-version: '20'
node-version: '22'
cache: npm
cache-dependency-path: src/Web/autopilot-monitor-web/package-lock.json
@@ -86,7 +86,7 @@ jobs:
- uses: actions/setup-node@v7
with:
node-version: '20'
node-version: '22'
cache: npm
cache-dependency-path: src/McpServer/autopilot-monitor-mcp/package-lock.json
@@ -106,7 +106,7 @@ jobs:
- uses: actions/setup-node@v7
with:
node-version: '20'
node-version: '22'
- name: Regenerate
run: node rules/scripts/combine.js
+1 -1
View File
@@ -26,7 +26,7 @@ jobs:
- uses: actions/setup-node@v7
with:
node-version: '20'
node-version: '22'
- name: Install ajv-cli
run: npm install -g ajv-cli ajv-formats
+11 -3
View File
@@ -21,6 +21,11 @@ jobs:
if: github.event_name == 'push' || github.event_name == 'workflow_dispatch' || (github.event_name == 'pull_request' && github.event.action != 'closed')
runs-on: ubuntu-latest
name: Build and Deploy Job
# Dependabot PRs run without repo secrets, so the deploy token is absent.
# Surface it as an env var so the deploy step can gate on it — secrets
# cannot be referenced directly in an `if:` expression.
env:
DEPLOY_TOKEN: ${{ secrets.AZURE_SWA_DEPLOY_TOKEN }}
steps:
- uses: actions/checkout@v7
with:
@@ -28,6 +33,9 @@ jobs:
fetch-depth: 0 # Full history needed for git-based sitemap lastmod dates
- name: Build And Deploy
id: builddeploy
# Skip (green) instead of failing when the token is missing (Dependabot
# PRs); real deploys on main and internal PRs still have it.
if: env.DEPLOY_TOKEN != ''
uses: Azure/static-web-apps-deploy@v1
env:
NEXT_PUBLIC_ENTRA_CLIENT_ID: ${{ vars.NEXT_PUBLIC_ENTRA_CLIENT_ID }}
@@ -39,9 +47,6 @@ jobs:
with:
azure_static_web_apps_api_token: ${{ secrets.AZURE_SWA_DEPLOY_TOKEN }}
repo_token: ${{ secrets.GITHUB_TOKEN }} # Used for Github integrations (i.e. PR comments)
# Dependabot PRs run without repo secrets, so the deploy token is absent.
# Skip (green) instead of failing the check; real deploys on main still have the token.
skip_deploy_on_missing_secrets: true
action: "upload"
###### Repository/Build Configurations - These values can be configured to match your app requirements. ######
# For more information regarding Static Web App workflow configurations, please visit: https://aka.ms/swaworkflowconfig
@@ -54,9 +59,12 @@ jobs:
if: github.event_name == 'pull_request' && github.event.action == 'closed'
runs-on: ubuntu-latest
name: Close Pull Request Job
env:
DEPLOY_TOKEN: ${{ secrets.AZURE_SWA_DEPLOY_TOKEN }}
steps:
- name: Close Pull Request
id: closepullrequest
if: env.DEPLOY_TOKEN != ''
uses: Azure/static-web-apps-deploy@v1
with:
azure_static_web_apps_api_token: ${{ secrets.AZURE_SWA_DEPLOY_TOKEN }}
+55 -29
View File
@@ -1,7 +1,7 @@
---
type: Concept
title: ESP Policy-Provider Stall Detection — the no-timeout Setup/Apps wait and the co-management Sidecar gap
description: Why a registered EnrollmentStatusTracking CSP policy provider that never sets TrackingPoliciesCreated parks the user ESP at "Apps (Identifying)" indefinitely, the pre-provisioning + ConfigMgr field case, and how the always-on esp_policy_provider_stalled tripwire (15-min wall-clock dwell, StartupEventGate cross-restart dedup) surfaces it.
description: Why the ESP's Apps wait is keyed to the Intune-registered "Sidecar" provider by name — a foreign provider (ConfigMgr) with TrackingPoliciesCreated=1 does not satisfy it — plus the classic never-completes stall, and how the always-on two-arm esp_policy_provider_stalled tripwire (reason=provider_incomplete | sidecar_provider_missing, 15-min wall-clock dwell, StartupEventGate cross-restart dedup) surfaces both.
resource: /src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/SystemSignals/EspPolicyProviderProbe.cs
tags:
- agent
@@ -9,7 +9,7 @@ tags:
- enrollment-status-tracking
- co-management
- stall-detection
timestamp: 2026-07-23T00:00:00+02:00
timestamp: 2026-07-24T00:00:00+02:00
---
# ESP Policy-Provider Stall Detection
@@ -42,37 +42,59 @@ exactly these registry paths. The same document states that ESP policy providers
aware of each other** and that **pre-provisioning is unsupported** with Autopilot into
co-management.
## The field case
## The field case (issue #106)
A tenant pre-provisions devices and installs the ConfigMgr client as a blocking app.
Occasionally the user-phase ESP reaches "Apps (Identifying)" and never leaves it — for
hours to days. On those devices `Device\Setup\Apps\PolicyProviders` contains **only a
`ConfigMgr` key (no `Sidecar`)** and `TrackingPoliciesCreated` is never set. Manually
renaming the key to `Sidecar` unblocks the ESP immediately (the IME then finds its
provider node and reports tracking-policies-created). The mechanism is exactly the
documented no-timeout wait; the unsupported pre-provisioning + co-management combination
explains why only some devices are affected. Why the Sidecar registration is missing or
displaced on those devices is not publicly documented — irrelevant for detection, since
the signature is deterministic.
`ConfigMgr` key (no `Sidecar`)** — and, per the customer's follow-up, **`TrackingPoliciesCreated=1`
IS set under it**. The provider is "complete" by the CSP value contract, yet the ESP
still waits. Manually renaming the key to `Sidecar` — which creates no tracking entries,
only satisfies the name — unblocks the ESP instantly.
The naive CSP-doc reading ("any provider with TrackingPoliciesCreated=1 satisfies the
wait") is therefore wrong for this case. What the evidence supports instead: provider
nodes are registered **by the Intune service at enrollment**, and its ESP-policy WAP
payload always registers `Sidecar` (ConfigMgr joins only via a co-management settings
policy — see the payload documented by Niehaus). The ESP waits on the provider it
expects **by name**; a foreign provider occupying the slot does not satisfy it,
regardless of its completion values. On the affected devices the CM client (installed
as a plain Win32 app, no co-management settings policy) evidently displaced the
Sidecar node — consistent with Microsoft's warning that providers "aren't currently
aware of others" and that pre-provisioning is unsupported with co-management. The exact
CloudExperienceHost mechanism is not publicly documented; the registry signature —
setupApps providers present, `Sidecar` absent — is deterministic either way.
## Detection
`EspPolicyProviderProbe` (fail-soft, static, `ScopedOverride` test seam — structural clone
of `EspTrackingInfoProbe`) enumerates all providers in both kinds and scopes.
`EspPolicyProviderStallDetector` evaluates a pure transition function on a 60-second tick
from the always-on `EspPolicyProviderStallHost`:
from the always-on `EspPolicyProviderStallHost` — **two arms**, same 15-minute wall-clock
dwell, one shared event type discriminated by `reason`:
* A provider **continuously incomplete for ≥ 15 minutes** (wall-clock) is stalled. The
dwell clock starts at first incomplete observation and resets on completion or
disappearance. Missing values parse as incomplete (fail-toward-observation).
* **Arm 1, `reason=provider_incomplete`** — a provider **continuously incomplete for
≥ 15 minutes**. The dwell clock starts at first incomplete observation and resets on
completion or disappearance. Missing values parse as incomplete
(fail-toward-observation). Catches e.g. Sidecar itself never reporting.
* **Arm 2, `reason=sidecar_provider_missing`** — **≥ 1 `Setup\Apps` provider registered
but none named `Sidecar`**, continuously for ≥ 15 minutes. Deliberately ignores
provider completeness (the field case had `TrackingPoliciesCreated=1`). Sidecar
registering later — the legitimate startup ordering — clears the condition and resets
the clock. DevicePreparation-only snapshots don't activate it.
* When both arms cross in the same round, ONE event is emitted and
`sidecar_provider_missing` wins as `reason` (it explains the hang regardless of the
foreign provider's state).
* Missing root key / empty provider list = normal early enrollment: clears all dwell
state, never fires.
* One `esp_policy_provider_stalled` **Warning** per newly stalled provider set
(`ImmediateUpload`), one-shot per provider in-process, cross-restart deduped via a
`StartupEventGate` fingerprint over the sorted currently-stalled key set — a restart
into the same stall stays silent, a new provider joining the stall re-reports.
* Payload: `providers[]` (full table: name, scope, kind, raw values, complete flag),
`stalledProviders[]` with `stalledForMinutes`, `sidecarRegistered`, `dwellMinutes`.
state (both arms), never fires.
* One `esp_policy_provider_stalled` **Warning** per newly stalled condition set
(`ImmediateUpload`), one-shot per condition in-process, cross-restart deduped via a
`StartupEventGate` fingerprint over the sorted currently-active fired conditions
(provider keys + a `sidecarMissing` sentinel) — a restart into the same stall stays
silent, a new condition joining re-reports.
* Payload: `reason`, `providers[]` (full table: name, scope, kind, raw values, complete
flag), `stalledProviders[]` with `stalledForMinutes`, `sidecarMissingForMinutes`
(arm 2 only), `sidecarRegistered`, `dwellMinutes`.
* **Purely observational**: emitted via `InformationalEventPost` (dispatch-guard exempt
pass-through) — never touches decision state. No config toggle, no ConfigVersion bump
(precedent: `disk_space_low`).
@@ -93,33 +115,37 @@ resource), so both the detector and the guardrail change ship with the agent rel
## Examples
Customer-case event (abbreviated):
Customer-case event (abbreviated) — note the provider is "complete" by CSP values, the
hang is carried entirely by `reason=sidecar_provider_missing`:
```json
{
"eventType": "esp_policy_provider_stalled",
"severity": "Warning",
"data": {
"reason": "sidecar_provider_missing",
"dwellMinutes": 15,
"sidecarRegistered": false,
"sidecarMissingForMinutes": 15.0,
"providers": [
{ "name": "ConfigMgr", "scope": "device", "kind": "setupApps",
"trackingPoliciesCreated": null, "installationState": null, "complete": false }
"trackingPoliciesCreated": 1, "installationState": null, "complete": true }
],
"stalledProviders": [
{ "name": "ConfigMgr", "scope": "device", "kind": "setupApps", "stalledForMinutes": 15.0 }
]
"stalledProviders": []
}
}
```
`sidecarRegistered=false` while `setupApps` providers exist is the co-management
signature; `sidecarRegistered=true` with a stalled third-party provider generalizes the
same contract violation.
`reason=sidecar_provider_missing` is the co-management signature;
`reason=provider_incomplete` with `sidecarRegistered=true` covers a stalled Sidecar or
third-party provider — the generalized contract violation.
# Citations
* EnrollmentStatusTracking CSP — <https://learn.microsoft.com/en-us/windows/client-management/mdm/enrollmentstatustracking-csp>
* Windows Autopilot into co-management (requirements, provider-conflict warning, troubleshooting registry paths) — <https://learn.microsoft.com/en-us/intune/configmgr/comanage/autopilot-enrollment>
* Troubleshoot the ESP (models app tracking exclusively via the `Sidecar` subkey) — <https://learn.microsoft.com/en-us/troubleshoot/mem/intune/device-enrollment/understand-troubleshoot-esp>
* Niehaus: the Intune ESP-policy WAP payload registering the provider nodes (`Sidecar` always, `ConfigMgr` only with a co-management settings policy) — <https://oofhours.com/2023/08/25/run-an-sccm-task-sequence-during-autopilot/>
* Niehaus: ESP tracks arbitrarily named providers when they are properly registered — <https://oofhours.com/2023/09/18/track-anything-using-esp/>
* Agent code: `EspPolicyProviderProbe.cs`, `EspPolicyProviderStallDetector.cs`, `EspPolicyProviderStallHost.cs` (SystemSignals / Orchestration.Hosts)
* Related: [MDM Reboot Coalescing](mdm-reboot-coalescing.md), [Gather-Rule Guardrails](../rules/gather-rule-guardrails.md)
+1 -1
View File
@@ -22,7 +22,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.
* [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.
* [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.
* [ESP Policy-Provider Stall Detection](agent/esp-policy-provider-stall.md) - The EnrollmentStatusTracking CSP's no-timeout Setup/Apps wait: a registered provider that never sets TrackingPoliciesCreated (co-management "ConfigMgr" without the IME's "Sidecar") parks the user ESP at "Apps (Identifying)" for days; the always-on esp_policy_provider_stalled tripwire and the SOFTWARE\Microsoft\Windows\Autopilot gather-rule allowlist entry that surface it.
* [ESP Policy-Provider Stall Detection](agent/esp-policy-provider-stall.md) - The EnrollmentStatusTracking CSP's no-timeout Setup/Apps wait is keyed to the Intune-registered "Sidecar" provider by NAME: co-management's "ConfigMgr" parks the user ESP at "Apps (Identifying)" for days even with TrackingPoliciesCreated=1 (issue #106); the always-on two-arm esp_policy_provider_stalled tripwire (provider_incomplete | sidecar_provider_missing) and the SOFTWARE\Microsoft\Windows\Autopilot gather-rule allowlist entry that surface it.
# Rules
+3 -1
View File
@@ -1,6 +1,8 @@
# Log
## 2026-07-23
## 2026-07-24
* **Update**: `agent/esp-policy-provider-stall.md` — the customer's follow-up on issue #106 corrected the field-case mechanics: `TrackingPoliciesCreated=1` WAS set under the foreign `ConfigMgr` provider, so the ESP ignores a foreign provider's completion values and waits on the Intune-registered `Sidecar` provider by name (the rename to `Sidecar` creates no tracking entries yet unblocks instantly). The completeness-keyed detector would have missed exactly this — the incident it was built for. The tripwire is now two-armed under one event type discriminated by `reason`: `provider_incomplete` (unchanged dwell on continuously-incomplete providers) and `sidecar_provider_missing` (≥ 1 Setup/Apps provider registered without `Sidecar`, completeness deliberately ignored, clock reset when Sidecar registers later). Sidecar-missing wins the `reason` when both arms cross in one round; the cross-restart fingerprint gains a `sidecarMissing` sentinel; payload adds `reason` and `sidecarMissingForMinutes`. Evidence for the name-keyed wait: Niehaus' documented Intune WAP payload always registers `Sidecar` (ConfigMgr only via a co-management settings policy) and Microsoft's ESP troubleshooting models app tracking exclusively through the Sidecar subkey.
* **Creation**: Added `agent/esp-policy-provider-stall.md` — a customer diagnosed that pre-provisioned devices with the ConfigMgr client as a blocking app occasionally park the user ESP at "Apps (Identifying)" for days: only a `ConfigMgr` provider is registered under `EnrollmentStatusTracking\Device\Setup\Apps\PolicyProviders` (no `Sidecar` = IME) and `TrackingPoliciesCreated` never becomes 1 — a wait the CSP defines without any timeout; renaming the key to `Sidecar` unblocks immediately. The agent now ships the always-on `esp_policy_provider_stalled` tripwire (60-s tick, 15-min continuous-incompleteness dwell, one-shot per provider, `StartupEventGate` fingerprint across restarts, purely observational via the InformationalEvent rail — no toggle, no ConfigVersion bump), generalized to any provider in both `Setup/Apps` and `DevicePreparation` kinds rather than hardcoding the ConfigMgr case. Companion change: `SOFTWARE\Microsoft\Windows\Autopilot` joins the gather-rule registry allowlist so tenants can target the subtree with custom rules (e.g. `not_exists` on the Sidecar key).
+90
View File
@@ -0,0 +1,90 @@
{
"$schema": "../schema/analyze-rule.schema.json",
"ruleId": "ANALYZE-ESP-006",
"title": "ESP Failure Recovered After User Retry",
"description": "Detects the recovery story: the ESP reported a terminal failure (typically DeviceSetup/Apps), the user most likely pressed 'Try again' on the failure page, the failed step re-ran and completed successfully. The earlier failure did not stick — the enrollment continued past it.",
"severity": "info",
"category": "esp",
"version": "1.0.0",
"enabled": true,
"baseConfidence": 85,
"conditions": [
{
"signal": "advisory",
"source": "event_type",
"eventType": "esp_failure_advisory",
"operator": "exists",
"value": "",
"required": true
},
{
"signal": "recovered",
"source": "event_type",
"eventType": "esp_failure_recovered",
"operator": "exists",
"value": "",
"required": true
},
{
"signal": "retry",
"source": "event_type",
"eventType": "esp_failure_retry_detected",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "category",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "category",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "failedSubcategory",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "failedSubcategory",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "likelyCulpritApps",
"source": "event_type",
"eventType": "esp_failure_advisory",
"dataField": "likelyCulpritApps",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "minutesSinceFailure",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "minutesSinceFailure",
"operator": "exists",
"value": "",
"required": false
}
],
"confidenceFactors": [
{ "signal": "retry", "condition": "exists", "weight": 10 },
{ "signal": "likelyCulpritApps", "condition": "exists", "weight": 5 }
],
"explanation": "The Enrollment Status Page reported a **failure** in the `{{category}}` phase (`{{failedSubcategory}}` subcategory, most likely app(s): `{{likelyCulpritApps}}`) — and then **recovered**: the failed step left its failed state and completed successfully about `{{minutesSinceFailure}}` min later.\n\nThat pattern is consistent with the user pressing **'Try again'** on the ESP failure page (the profile allows failure-page actions; the agent cannot observe the click itself). The failure the user saw was real, but it did not stick — the ESP re-ran the step, it succeeded, and the enrollment continued.\n\nRead the session timeline as one arc: `esp_failure_advisory` (the failure, with the likely culprit app) → `esp_failure_retry_detected` (the retry) → `esp_failure_recovered` (the recovery). If this pattern repeats across devices for the same app, that app's install is flaky on first attempt — fix the app rather than the devices. Any literal `{{…}}` placeholder means that detail was not recorded for this session.",
"remediation": [
{
"title": "Make the first install attempt stick",
"steps": [
"Check the likely culprit app(s) (`{{likelyCulpritApps}}`) in Intune: an app that fails on the first ESP pass but succeeds on retry usually has a dependency/ordering or detection-timing problem.",
"If the app shows 'never started installing' in esp_failure_settle_started, verify its assignment and applicability rules — ESP counted it as required, but IME never processed it.",
"If the pattern repeats across the tenant, consider removing the app from the ESP blocking list until the first-attempt install is reliable — users are seeing an avoidable failure screen.",
"No device-side action is needed for this session: the failure recovered and the enrollment continued."
]
}
],
"tags": ["esp", "recovery", "try-again", "retry", "continue-anyway", "enrollment"]
}
+104
View File
@@ -1884,6 +1884,110 @@
"user-experience"
]
},
{
"ruleId": "ANALYZE-ESP-006",
"title": "ESP Failure Recovered After User Retry",
"description": "Detects the recovery story: the ESP reported a terminal failure (typically DeviceSetup/Apps), the user most likely pressed 'Try again' on the failure page, the failed step re-ran and completed successfully. The earlier failure did not stick — the enrollment continued past it.",
"severity": "info",
"category": "esp",
"version": "1.0.0",
"enabled": true,
"baseConfidence": 85,
"conditions": [
{
"signal": "advisory",
"source": "event_type",
"eventType": "esp_failure_advisory",
"operator": "exists",
"value": "",
"required": true
},
{
"signal": "recovered",
"source": "event_type",
"eventType": "esp_failure_recovered",
"operator": "exists",
"value": "",
"required": true
},
{
"signal": "retry",
"source": "event_type",
"eventType": "esp_failure_retry_detected",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "category",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "category",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "failedSubcategory",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "failedSubcategory",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "likelyCulpritApps",
"source": "event_type",
"eventType": "esp_failure_advisory",
"dataField": "likelyCulpritApps",
"operator": "exists",
"value": "",
"required": false
},
{
"signal": "minutesSinceFailure",
"source": "event_type",
"eventType": "esp_failure_recovered",
"dataField": "minutesSinceFailure",
"operator": "exists",
"value": "",
"required": false
}
],
"confidenceFactors": [
{
"signal": "retry",
"condition": "exists",
"weight": 10
},
{
"signal": "likelyCulpritApps",
"condition": "exists",
"weight": 5
}
],
"explanation": "The Enrollment Status Page reported a **failure** in the `{{category}}` phase (`{{failedSubcategory}}` subcategory, most likely app(s): `{{likelyCulpritApps}}`) — and then **recovered**: the failed step left its failed state and completed successfully about `{{minutesSinceFailure}}` min later.\n\nThat pattern is consistent with the user pressing **'Try again'** on the ESP failure page (the profile allows failure-page actions; the agent cannot observe the click itself). The failure the user saw was real, but it did not stick — the ESP re-ran the step, it succeeded, and the enrollment continued.\n\nRead the session timeline as one arc: `esp_failure_advisory` (the failure, with the likely culprit app) → `esp_failure_retry_detected` (the retry) → `esp_failure_recovered` (the recovery). If this pattern repeats across devices for the same app, that app's install is flaky on first attempt — fix the app rather than the devices. Any literal `{{…}}` placeholder means that detail was not recorded for this session.",
"remediation": [
{
"title": "Make the first install attempt stick",
"steps": [
"Check the likely culprit app(s) (`{{likelyCulpritApps}}`) in Intune: an app that fails on the first ESP pass but succeeds on retry usually has a dependency/ordering or detection-timing problem.",
"If the app shows 'never started installing' in esp_failure_settle_started, verify its assignment and applicability rules — ESP counted it as required, but IME never processed it.",
"If the pattern repeats across the tenant, consider removing the app from the ESP blocking list until the first-attempt install is reliable — users are seeing an avoidable failure screen.",
"No device-side action is needed for this session: the failure recovered and the enrollment continued."
]
}
],
"tags": [
"esp",
"recovery",
"try-again",
"retry",
"continue-anyway",
"enrollment"
]
},
{
"ruleId": "ANALYZE-ID-001",
"title": "Expected Machine Certificate Not Found",
@@ -39,6 +39,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Harness
logFolder: Tmp.Path,
patterns: new List<ImeLogPattern>(),
logger: Logger);
// Mirror ImeLogHost wiring: the historic-replay guard judges staleness against the
// (virtual) agent clock so tests stay deterministic.
Tracker.UtcNowProvider = () => Clock.UtcNow;
}
public IReadOnlyList<FakeSignalIngressSink.PostedSignal> DecisionSignals(DecisionSignalKind kind) =>
@@ -0,0 +1,166 @@
using System;
using System.Collections.Generic;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Shared.Models;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
/// <summary>
/// Tracker-level historic-replay guard (session eaf3d8c4 part 2): source lines > 24 h older
/// than now are content from a previous enrollment whose IME log survived on disk. The guard
/// in <c>HandlePatternMatch</c> skips app-mutating actions for such lines so replayed apps
/// never enter <c>_packageStates</c> / phase snapshots / persistence — keeping
/// app_tracking_summary, culprit lists and final-status clean. Script actions pass through
/// (the adapter suppresses their emissions), and SimulationMode bypasses the guard entirely.
/// </summary>
public sealed class ImeLogTrackerHistoricReplayGuardTests
{
private static readonly DateTime Now = new DateTime(2026, 7, 23, 15, 42, 0, DateTimeKind.Utc);
private static List<ImeLogPattern> TestPatterns() => new List<ImeLogPattern>
{
new ImeLogPattern
{
PatternId = "T-POLICIES", Category = "always", Enabled = true,
Pattern = @"policies discovered = (?<policies>\[.*\])",
Action = "policiesDiscovered",
Parameters = new Dictionary<string, string>(),
},
new ImeLogPattern
{
PatternId = "T-INSTALLED", Category = "always", Enabled = true,
Pattern = @"app (?<id>[\w-]+) installed",
Action = "updateStateInstalled",
Parameters = new Dictionary<string, string>(),
},
new ImeLogPattern
{
PatternId = "T-ESP-PHASE", Category = "always", Enabled = true,
Pattern = @"In EspPhase: (?<espPhase>\w+)",
Action = "espPhaseDetected",
Parameters = new Dictionary<string, string>(),
},
new ImeLogPattern
{
PatternId = "T-SCRIPT-START", Category = "always", Enabled = true,
Pattern = @"script (?<id>[\w-]+) started",
Action = "scriptStarted",
Parameters = new Dictionary<string, string> { ["scriptType"] = "platform" },
},
};
private static ImeLogTracker BuildTracker(TempDirectory tmp)
{
var tracker = new ImeLogTracker(
logFolder: tmp.Path,
patterns: TestPatterns(),
logger: new AgentLogger(tmp.Path, AgentLogLevel.Info));
tracker.UtcNowProvider = () => Now;
return tracker;
}
private const string PoliciesLine = @"policies discovered = [{""Id"":""app-1"",""Name"":""App One""}]";
[Fact]
public void Stale_policies_line_does_not_populate_package_states()
{
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
tracker.ProcessLogMessageForTest(PoliciesLine, Now.AddDays(-7));
Assert.Empty(tracker.GetAllKnownPackageStates());
}
[Fact]
public void Fresh_relog_of_same_policies_is_tracked_after_stale_skip()
{
// IME re-logs the full policy JSON on every app-policy check-in — skipping the
// stale copy cannot starve the current enrollment.
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
tracker.ProcessLogMessageForTest(PoliciesLine, Now.AddDays(-7));
tracker.ProcessLogMessageForTest(PoliciesLine, Now.AddMinutes(-2));
var all = tracker.GetAllKnownPackageStates();
var pkg = Assert.Single(all);
Assert.Equal("app-1", pkg.Id);
}
[Fact]
public void Stale_state_update_against_fresh_app_is_skipped()
{
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
var stateChanges = 0;
tracker.OnAppStateChanged = (_, __, ___) => stateChanges++;
tracker.ProcessLogMessageForTest(PoliciesLine, Now.AddMinutes(-5)); // fresh discovery
tracker.ProcessLogMessageForTest("app app-1 installed", Now.AddDays(-7)); // stale mutation
Assert.Equal(0, stateChanges);
var pkg = Assert.Single(tracker.GetAllKnownPackageStates());
Assert.NotEqual(AppInstallationState.Installed, pkg.InstallationState);
}
[Fact]
public void Stale_esp_phase_line_does_not_block_fresh_phase_detection()
{
// A stale "AccountSetup" would advance _currentPhaseOrder and make the fresh
// enrollment's DeviceSetup bounce as "backward" — the guard must skip it.
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
var phases = new List<string>();
tracker.OnEspPhaseChanged = p => phases.Add(p);
tracker.ProcessLogMessageForTest("In EspPhase: AccountSetup", Now.AddDays(-7));
tracker.ProcessLogMessageForTest("In EspPhase: DeviceSetup", Now.AddMinutes(-1));
Assert.Equal(new[] { "DeviceSetup" }, phases);
}
[Fact]
public void Stale_script_line_still_reaches_script_handlers()
{
// Script tracker state is harmless for stale lines (adapter suppresses the
// emissions; the stale-slot hardening covers leftovers) — the guard must not
// swallow script actions.
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
var started = new List<ScriptStartedInfo>();
tracker.OnScriptStarted = i => started.Add(i);
tracker.ProcessLogMessageForTest("script aaaa1111-0000-0000-0000-000000000000 started", Now.AddDays(-7));
Assert.Single(started);
}
[Fact]
public void SimulationMode_bypasses_the_guard()
{
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
tracker.SimulationMode = true;
tracker.ProcessLogMessageForTest(PoliciesLine, Now.AddDays(-7));
Assert.Single(tracker.GetAllKnownPackageStates());
}
[Fact]
public void Lines_without_timestamp_are_not_treated_as_stale()
{
// Non-CMTrace lines carry no source timestamp (entry == null) — never stale.
using var tmp = new TempDirectory();
using var tracker = BuildTracker(tmp);
tracker.ProcessLogMessageForTest(PoliciesLine, sourceTimestampUtc: null);
Assert.Single(tracker.GetAllKnownPackageStates());
}
}
}
@@ -15,7 +15,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Runtime
/// <item>a locked tree must abort WITHOUT deleting anything (old script force-deleted
/// marker + state around the locks and orphaned the binaries),</item>
/// <item>a straggler agent process (the incident's second instance) must be found by
/// NAME, killed, and the cleanup must then complete,</item>
/// NAME, killed, and the cleanup must then complete — simulated via function
/// shadowing, NEVER by launching a renamed executable (EDR isolation, see the test),</item>
/// <item>concurrent cleanup scripts must be serialized by the lock file.</item>
/// </list>
/// Timings are dialed down via the test-only BuildCleanupScript parameters so each case
@@ -111,60 +112,55 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Runtime
}
[Fact]
public void Straggler_process_holding_the_tree_is_killed_and_cleanup_completes()
public void Straggler_agent_process_is_waited_on_and_force_killed_via_name_backstop()
{
// Full incident replay: a SECOND agent-named process (here: a renamed
// powershell.exe, matching how only the process NAME identifies agents) holds a
// file in the tree open. The old script waited on the launcher PID only and ran
// its force-delete against the live locks. The hardened script must find the
// straggler by name, kill it after the wait deadline, and then delete everything.
var fakeExe = Path.Combine(_root, _fakeProcessName + ".exe");
File.Copy(SystemPaths.PowerShell, fakeExe);
// Incident replay of the second-instance mechanics WITHOUT spawning a process:
// an earlier version of this test copied powershell.exe under the fake agent name
// and launched it — textbook MITRE T1036.003 ("Rename Legitimate Utilities"),
// which Defender for Endpoint answered with a machine ISOLATION on the dev box
// (see tasks/lessons.md). Instead, a harness script shadows Get-Process /
// Stop-Process with functions (PowerShell resolves functions before cmdlets, so
// the dot-sourced cleanup script binds to the stubs): Get-Process reports a live
// agent-named straggler on every probe; Stop-Process records the kill. This pins
// the same contract — the script polls by NAME until the deadline, then
// force-kills by NAME before deleting — with zero EDR-visible behavior.
var probeLog = Path.Combine(_root, "probe.log");
var cleanupScriptPath = Path.Combine(_root, $"cleanup-{Guid.NewGuid():N}.ps1");
File.WriteAllText(cleanupScriptPath, BuildScript(processWaitSeconds: 2));
var lockTarget = Path.Combine(_basePath, "Agent", "fake.exe").Replace("'", "''");
Process straggler = null;
try
{
straggler = Process.Start(new ProcessStartInfo
{
FileName = fakeExe,
Arguments = "-NoProfile -Command \"$f = [IO.File]::Open('" + lockTarget +
"', 'Open', 'Read', 'None'); Start-Sleep -Seconds 120\"",
UseShellExecute = false,
CreateNoWindow = true,
});
var harness = @"
$probeLog = 'LOG_PATH'
$global:AmProbeCount = 0
function Get-Process {
[CmdletBinding()]
param([string[]]$Name)
if ($Name -contains 'FAKE_NAME') {
$global:AmProbeCount++
Add-Content -Path $probeLog -Value ('probe ' + $global:AmProbeCount)
return [pscustomobject]@{ Name = 'FAKE_NAME'; Id = 424242 }
}
Microsoft.PowerShell.Management\Get-Process @PSBoundParameters
}
function Stop-Process {
[CmdletBinding()]
param([Parameter(ValueFromPipeline = $true)]$InputObject, [switch]$Force)
process { Add-Content -Path $probeLog -Value ('kill ' + $InputObject.Id + ' force=' + $Force) }
}
. 'SCRIPT_PATH'
"
.Replace("LOG_PATH", probeLog)
.Replace("FAKE_NAME", _fakeProcessName)
.Replace("SCRIPT_PATH", cleanupScriptPath);
// Give the straggler time to acquire its file handle before cleanup starts.
var acquireDeadline = DateTime.UtcNow.AddSeconds(20);
var acquired = false;
while (!acquired && DateTime.UtcNow < acquireDeadline)
{
try
{
using (File.Open(Path.Combine(_basePath, "Agent", "fake.exe"),
FileMode.Open, FileAccess.Read, FileShare.ReadWrite))
{
}
}
catch (IOException)
{
acquired = true; // share violation ⇒ straggler holds the file
}
if (!acquired) System.Threading.Thread.Sleep(200);
}
Assert.True(acquired, "straggler never acquired its file lock");
RunScript(harness);
RunScript(BuildScript(processWaitSeconds: 2));
Assert.True(straggler.HasExited, "straggler must be force-killed by the name-based backstop");
Assert.False(Directory.Exists(_basePath), "after the kill the tree must be fully deleted");
Assert.Empty(Directory.GetFileSystemEntries(_root, "*.del-*"));
}
finally
{
try { if (straggler != null && !straggler.HasExited) straggler.Kill(); } catch { }
try { straggler?.Dispose(); } catch { }
}
var log = File.ReadAllLines(probeLog);
Assert.Contains("kill 424242 force=True", log);
Assert.True(Array.FindAll(log, l => l.StartsWith("probe")).Length >= 2,
"script must poll by name in the wait loop AND re-probe for the kill backstop");
Assert.False(Directory.Exists(_basePath), "after the kill the tree must be fully deleted");
Assert.Empty(Directory.GetFileSystemEntries(_root, "*.del-*"));
Assert.False(File.Exists(LockPath));
}
[Fact]
@@ -0,0 +1,256 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.DecisionCore.Signals;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
{
/// <summary>
/// Session 4910a5a5 (2026-07-23) — post-terminal recovery story. Field sequence:
/// DeviceSetup/Apps failed (culprit app never started installing) → settle window expired
/// → terminal EspFailureDetected → the user pressed "Try again" ~23 min later → Apps left
/// the failed state → 10/10 installed → DeviceSetup resolved. Pre-fix, that recovery only
/// appeared as a generic <c>subcategory_state_change</c>. Coverage:
/// <list type="bullet">
/// <item><c>esp_failure_retry_detected</c> fires once when the failed subcategory leaves
/// the failed state AFTER the terminal fire.</item>
/// <item><c>esp_failure_recovered</c> fires once when the category then resolves to
/// success.</item>
/// <item>An in-settle-window recovery keeps emitting only
/// <c>esp_failure_settle_recovered</c> — the post-terminal pair stays silent.</item>
/// <item>Apps failures carry <c>LikelyCulpritApps</c> on the EspFailureDetected args,
/// never-started apps ranked first.</item>
/// </list>
/// </summary>
public sealed class EspFailureRecoveryStoryTests
{
private static readonly DateTime Fixed = new DateTime(2026, 7, 23, 4, 30, 0, DateTimeKind.Utc);
private sealed class Fixture : IDisposable
{
public TempDirectory Tmp { get; } = new TempDirectory();
public FakeSignalIngressSink Sink { get; } = new FakeSignalIngressSink();
public List<EspFailureDetectedEventArgs> EspFailures { get; } = new List<EspFailureDetectedEventArgs>();
public ProvisioningStatusTracker Tracker { get; }
public Fixture(Func<IReadOnlyList<AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppPackageState>>? packageStatesProbe = null)
{
var clock = new VirtualClock(Fixed);
var post = new InformationalEventPost(Sink, clock);
var logger = new AgentLogger(Tmp.Path, AgentLogLevel.Info);
Tracker = new ProvisioningStatusTracker(
sessionId: "S1",
tenantId: "T1",
post: post,
logger: logger,
appxScanner: new FakeAppxDeploymentFailureScanner(),
backgroundDispatcher: action => action(),
packageStatesProbe: packageStatesProbe);
Tracker.EspFailureDetected += (_, args) => EspFailures.Add(args);
}
public IReadOnlyList<(string EventType, IReadOnlyDictionary<string, object> Data)> CapturedEvents()
{
return Sink.Posted
.Where(p => p.Kind == DecisionSignalKind.InformationalEvent && p.Payload != null)
.Select(p =>
{
var eventType = p.Payload!.TryGetValue(SignalPayloadKeys.EventType, out var et) ? et : "";
var data = p.TypedPayload as IReadOnlyDictionary<string, object>
?? (IReadOnlyDictionary<string, object>)new Dictionary<string, object>();
return (eventType, data);
})
.ToList();
}
/// <summary>Drive the session-4910a5a5 shape up to the terminal fire.</summary>
public void DriveToTerminalDeviceSetupAppsFailure()
{
Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (9 of 10 installed)""}
}");
Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Apps (Error)""}
}");
Tracker.TriggerSettleTimerForTest("DeviceSetupCategory.Status");
}
public void Dispose()
{
Tracker.Dispose();
Tmp.Dispose();
}
}
[Fact]
public void PostTerminalRetry_EmitsRetryDetected_Once()
{
using var f = new Fixture();
f.DriveToTerminalDeviceSetupAppsFailure();
Assert.Single(f.EspFailures);
// "Try again": Apps leaves the failed state well after the settle window.
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (Working on it...)""}
}");
var retry = Assert.Single(f.CapturedEvents(), e => e.EventType == "esp_failure_retry_detected");
Assert.Equal("DeviceSetup", (string)retry.Data["category"]);
Assert.Equal("Apps", (string)retry.Data["subcategory"]);
Assert.Equal("failed", (string)retry.Data["previousState"]);
Assert.Equal("inProgress", (string)retry.Data["newState"]);
Assert.Equal("Provisioning_DeviceSetup_Apps_Failed", (string)retry.Data["failureType"]);
Assert.True(retry.Data.ContainsKey("minutesSinceFailure"));
// A later unrelated transition does not re-emit.
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Apps (10 of 10 installed)""}
}");
Assert.Single(f.CapturedEvents(), e => e.EventType == "esp_failure_retry_detected");
}
[Fact]
public void PostTerminalRecovery_EmitsRecovered_OnCategorySuccess()
{
using var f = new Fixture();
f.DriveToTerminalDeviceSetupAppsFailure();
// Retry → all apps installed → Windows resolves the category boolean.
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (Working on it...)""}
}");
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": true,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Apps (10 of 10 installed)""}
}");
var recovered = Assert.Single(f.CapturedEvents(), e => e.EventType == "esp_failure_recovered");
Assert.Equal("DeviceSetup", (string)recovered.Data["category"]);
Assert.Equal("Apps", (string)recovered.Data["failedSubcategory"]);
Assert.Equal("Provisioning_DeviceSetup_Apps_Failed", (string)recovered.Data["failureType"]);
Assert.True(recovered.Data.ContainsKey("minutesSinceFailure"));
// Duplicate category-success writes do not re-emit (fire-once).
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": true,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Security policies (1 of 1 applied)""},
""AppsSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Apps (10 of 10 installed, take 2)""}
}");
Assert.Single(f.CapturedEvents(), e => e.EventType == "esp_failure_recovered");
}
[Fact]
public void InSettleWindowRecovery_KeepsPostTerminalPairSilent()
{
using var f = new Fixture();
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (0 of 1 installed)""}
}");
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Apps (Error)""}
}");
// Recovery INSIDE the settle window — terminal fire is suppressed.
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (Working on it...)""}
}");
f.Tracker.TriggerSettleTimerForTest("DeviceSetupCategory.Status");
Assert.Empty(f.EspFailures);
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": true,
""AppsSubcategory"": {""subcategoryState"":""succeeded"",""subcategoryStatusText"":""Apps (1 of 1 installed)""}
}");
var events = f.CapturedEvents();
Assert.Contains(events, e => e.EventType == "esp_failure_settle_recovered");
Assert.DoesNotContain(events, e => e.EventType == "esp_failure_retry_detected");
Assert.DoesNotContain(events, e => e.EventType == "esp_failure_recovered");
}
[Fact]
public void AppsFailure_TerminalArgs_CarryLikelyCulprits_NeverStartedFirst()
{
var neverStarted = BuildApp("app-bg", "Teams Backgrounds v2",
AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Unknown,
downloadingSeen: false);
var startedButPending = BuildApp("app-slow", "Slow Installer",
AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Unknown,
downloadingSeen: true);
var installed = BuildApp("app-ok", "Falcon Sensor",
AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Installed,
downloadingSeen: true);
using var f = new Fixture(() => new[] { startedButPending, neverStarted, installed });
f.DriveToTerminalDeviceSetupAppsFailure();
var fired = Assert.Single(f.EspFailures);
Assert.Equal(2, fired.LikelyCulpritApps.Count);
// Never-started app ranked first — it starved the ESP gate without any IME event.
Assert.Equal("Teams Backgrounds v2", fired.LikelyCulpritApps[0]);
Assert.Equal("Slow Installer", fired.LikelyCulpritApps[1]);
}
[Fact]
public void NonAppsFailure_TerminalArgs_CarryNoCulprits()
{
var neverStarted = BuildApp("app-bg", "Teams Backgrounds v2",
AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Unknown,
downloadingSeen: false);
using var f = new Fixture(() => new[] { neverStarted });
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Working""}
}");
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Failed""}
}");
f.Tracker.TriggerSettleTimerForTest("DeviceSetupCategory.Status");
var fired = Assert.Single(f.EspFailures);
Assert.Empty(fired.LikelyCulpritApps);
}
private static AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppPackageState BuildApp(
string id, string name,
AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState state,
bool downloadingSeen)
{
var pkg = new AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppPackageState(id, 0);
pkg.UpdateName(name);
pkg.UpdateIntent(AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppIntent.Install);
pkg.UpdateTargeted(AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppTargeted.Device);
// DownloadingOrInstallingSeen is derived inside UpdateState (Downloading..Installing
// range) — drive it through a Downloading transition instead of setting it directly.
if (downloadingSeen)
pkg.UpdateState(AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Downloading);
if (state != AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Unknown
&& state != AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime.AppInstallationState.Downloading)
pkg.UpdateState(state);
return pkg;
}
}
}
@@ -74,14 +74,17 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
var previous = new Dictionary<string, DateTime> { ["setupApps|device|ConfigMgr"] = T0 };
var missing = EspPolicyProviderStallDetector.EvaluateStallTransition(
EspPolicyProviderSnapshot.Empty, previous, new HashSet<string>(), T0.AddHours(2), Dwell);
EspPolicyProviderSnapshot.Empty, previous, new HashSet<string>(), T0, false, T0.AddHours(2), Dwell);
Assert.Empty(missing.UpdatedFirstSeenUtc);
Assert.Empty(missing.NewlyStalled);
Assert.Null(missing.UpdatedSidecarMissingSinceUtc); // arm 2 resets too
Assert.Null(missing.SidecarMissingStalledForMinutes);
var registeredButEmpty = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(), previous, new HashSet<string>(), T0.AddHours(2), Dwell);
Snapshot(), previous, new HashSet<string>(), T0, false, T0.AddHours(2), Dwell);
Assert.Empty(registeredButEmpty.UpdatedFirstSeenUtc);
Assert.Empty(registeredButEmpty.NewlyStalled);
Assert.Null(registeredButEmpty.UpdatedSidecarMissingSinceUtc);
}
[Fact]
@@ -90,14 +93,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
var snapshot = Snapshot(SetupApps("ConfigMgr", tracking: null));
var round1 = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, new Dictionary<string, DateTime>(), new HashSet<string>(), T0, Dwell);
snapshot, new Dictionary<string, DateTime>(), new HashSet<string>(), null, false, T0, Dwell);
Assert.Equal(T0, round1.UpdatedFirstSeenUtc["setupApps|device|ConfigMgr"]);
Assert.Empty(round1.NewlyStalled);
var round2 = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, round1.UpdatedFirstSeenUtc, new HashSet<string>(), T0.AddMinutes(14), Dwell);
snapshot, round1.UpdatedFirstSeenUtc, new HashSet<string>(),
round1.UpdatedSidecarMissingSinceUtc, false, T0.AddMinutes(14), Dwell);
Assert.Equal(T0, round2.UpdatedFirstSeenUtc["setupApps|device|ConfigMgr"]); // first-seen preserved
Assert.Empty(round2.NewlyStalled);
Assert.Null(round2.SidecarMissingStalledForMinutes); // 14 min < dwell on arm 2 as well
}
[Fact]
@@ -107,7 +112,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
var seen = new Dictionary<string, DateTime> { ["setupApps|device|ConfigMgr"] = T0 };
var eval = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, seen, new HashSet<string>(), T0.AddMinutes(15), Dwell);
snapshot, seen, new HashSet<string>(), null, false, T0.AddMinutes(15), Dwell);
var stalled = Assert.Single(eval.NewlyStalled);
Assert.Equal("ConfigMgr", stalled.Provider.Name);
@@ -122,20 +127,20 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
// Completes mid-dwell → dropped from the map.
var completed = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 1)), seen, new HashSet<string>(), T0.AddMinutes(10), Dwell);
Snapshot(SetupApps("ConfigMgr", tracking: 1)), seen, new HashSet<string>(), null, false, T0.AddMinutes(10), Dwell);
Assert.Empty(completed.UpdatedFirstSeenUtc);
// Re-appears incomplete much later → dwell restarts from the new now, no stall yet.
var reappeared = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 0)), completed.UpdatedFirstSeenUtc,
new HashSet<string>(), T0.AddHours(3), Dwell);
new HashSet<string>(), null, false, T0.AddHours(3), Dwell);
Assert.Equal(T0.AddHours(3), reappeared.UpdatedFirstSeenUtc[key]);
Assert.Empty(reappeared.NewlyStalled);
// Disappearance behaves the same as completion.
var disappeared = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("Sidecar", tracking: 1)), new Dictionary<string, DateTime> { [key] = T0 },
new HashSet<string>(), T0.AddMinutes(20), Dwell);
new HashSet<string>(), null, false, T0.AddMinutes(20), Dwell);
Assert.False(disappeared.UpdatedFirstSeenUtc.ContainsKey(key));
}
@@ -147,7 +152,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
var fired = new HashSet<string>(StringComparer.OrdinalIgnoreCase) { "setupApps|device|ConfigMgr" };
var eval = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, seen, fired, T0.AddHours(5), Dwell);
snapshot, seen, fired, null, false, T0.AddHours(5), Dwell);
Assert.Empty(eval.NewlyStalled);
Assert.True(eval.UpdatedFirstSeenUtc.ContainsKey("setupApps|device|ConfigMgr")); // still tracked
@@ -162,7 +167,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
DevicePrep("ConfigMgr", installState: 1));
var eval = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, new Dictionary<string, DateTime>(), new HashSet<string>(), T0, Dwell);
snapshot, new Dictionary<string, DateTime>(), new HashSet<string>(), null, false, T0, Dwell);
Assert.Equal(3, eval.UpdatedFirstSeenUtc.Count);
Assert.Contains("setupApps|device|ConfigMgr", eval.UpdatedFirstSeenUtc.Keys);
@@ -179,6 +184,71 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
Assert.False(Snapshot(DevicePrep("Sidecar", installState: 3)).SidecarRegistered); // wrong kind
Assert.False(EspPolicyProviderSnapshot.Empty.SidecarRegistered);
}
// ------------------------------------------------- arm 2: sidecar-missing transition
[Fact]
public void Issue106_foreign_provider_complete_but_sidecar_missing_stalls_after_dwell()
{
// The actual field case: ConfigMgr with TrackingPoliciesCreated=1 — "complete" by the
// CSP value contract, arm 1 never fires — yet the ESP waits on the absent Sidecar.
var snapshot = Snapshot(SetupApps("ConfigMgr", tracking: 1));
var round1 = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, new Dictionary<string, DateTime>(), new HashSet<string>(), null, false, T0, Dwell);
Assert.Empty(round1.NewlyStalled); // arm 1 stays silent...
Assert.Equal(T0, round1.UpdatedSidecarMissingSinceUtc); // ...but arm 2 starts its clock
Assert.Null(round1.SidecarMissingStalledForMinutes);
var round2 = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, round1.UpdatedFirstSeenUtc, new HashSet<string>(),
round1.UpdatedSidecarMissingSinceUtc, false, T0.AddMinutes(15), Dwell);
Assert.Empty(round2.NewlyStalled);
Assert.Equal(15.0, round2.SidecarMissingStalledForMinutes!.Value, precision: 3);
}
[Fact]
public void Sidecar_registering_resets_the_sidecar_missing_clock()
{
// ConfigMgr first (legitimate startup ordering) → clock runs...
var round1 = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 1)),
new Dictionary<string, DateTime>(), new HashSet<string>(), null, false, T0, Dwell);
Assert.Equal(T0, round1.UpdatedSidecarMissingSinceUtc);
// ...Sidecar joins → condition clears, state resets.
var round2 = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 1), SetupApps("Sidecar", tracking: 0)),
round1.UpdatedFirstSeenUtc, new HashSet<string>(),
round1.UpdatedSidecarMissingSinceUtc, false, T0.AddMinutes(10), Dwell);
Assert.Null(round2.UpdatedSidecarMissingSinceUtc);
Assert.Null(round2.SidecarMissingStalledForMinutes);
// Sidecar gone again much later → clock restarts from the new now, no instant stall.
var round3 = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 1)),
round2.UpdatedFirstSeenUtc, new HashSet<string>(),
round2.UpdatedSidecarMissingSinceUtc, false, T0.AddHours(3), Dwell);
Assert.Equal(T0.AddHours(3), round3.UpdatedSidecarMissingSinceUtc);
Assert.Null(round3.SidecarMissingStalledForMinutes);
}
[Fact]
public void Sidecar_missing_one_shot_and_deviceprep_only_scoping()
{
// Already fired → never re-reported, but the clock keeps running.
var latched = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(SetupApps("ConfigMgr", tracking: 1)),
new Dictionary<string, DateTime>(), new HashSet<string>(), T0, true, T0.AddHours(5), Dwell);
Assert.Null(latched.SidecarMissingStalledForMinutes);
Assert.Equal(T0, latched.UpdatedSidecarMissingSinceUtc);
// DevicePreparation providers alone don't constitute the Setup/Apps wait — arm 2 off.
var devicePrepOnly = EspPolicyProviderStallDetector.EvaluateStallTransition(
Snapshot(DevicePrep("ConfigMgr", installState: 1)),
new Dictionary<string, DateTime>(), new HashSet<string>(), null, false, T0, Dwell);
Assert.Null(devicePrepOnly.UpdatedSidecarMissingSinceUtc);
}
}
/// <summary>
@@ -243,7 +313,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
Assert.Equal(EspPolicyProviderStallDetector.SourceLabel, evt.Payload[SignalPayloadKeys.Source]);
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(evt.TypedPayload);
// Both arms cross in the same round (ConfigMgr incomplete AND Sidecar absent) →
// ONE event; sidecar-missing is the dominant reason.
Assert.Equal(EspPolicyProviderStallDetector.ReasonSidecarMissing, data["reason"]);
Assert.Equal(false, data["sidecarRegistered"]);
Assert.Equal(15.0, data["sidecarMissingForMinutes"]);
Assert.Equal(EspPolicyProviderStallDetector.DwellMinutes, data["dwellMinutes"]);
var stalled = Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object>>>(data["stalledProviders"]);
var entry = Assert.Single(stalled);
@@ -252,6 +326,36 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
Assert.Equal(15.0, entry["stalledForMinutes"]);
}
[Fact]
public void Issue106_configmgr_complete_without_sidecar_still_emits_sidecar_missing()
{
// Regression test for the customer's follow-up on issue #106: TrackingPoliciesCreated=1
// WAS present under ConfigMgr — the provider looks "complete", arm 1 never fires, yet
// the ESP hangs because Sidecar is absent. Arm 2 must catch exactly this.
var configMgrComplete = new EspPolicyProviderSnapshot(new[]
{
new PolicyProviderState("ConfigMgr", "device", EspPolicyProviderProbe.KindSetupApps,
trackingPoliciesCreated: 1, installationState: null),
});
using var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => configMgrComplete);
var (sut, sink, clock) = BuildDetector();
sut.Tick();
Assert.Empty(StalledEvents(sink));
clock.Advance(TimeSpan.FromMinutes(EspPolicyProviderStallDetector.DwellMinutes));
sut.Tick();
var evt = Assert.Single(StalledEvents(sink));
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(evt.TypedPayload);
Assert.Equal(EspPolicyProviderStallDetector.ReasonSidecarMissing, data["reason"]);
Assert.Equal(false, data["sidecarRegistered"]);
Assert.Equal(15.0, data["sidecarMissingForMinutes"]);
Assert.Empty(Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object>>>(data["stalledProviders"]));
var providers = Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object?>>>(data["providers"]);
Assert.Equal(true, Assert.Single(providers)["complete"]); // the misleading "complete" is visible
}
[Fact]
public void Sidecar_complete_configmgr_incomplete_reports_only_configmgr_with_sidecar_flag()
{
@@ -264,7 +368,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
var evt = Assert.Single(StalledEvents(sink));
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(evt.TypedPayload);
Assert.Equal(EspPolicyProviderStallDetector.ReasonProviderIncomplete, data["reason"]); // arm 2 off — Sidecar is there
Assert.Equal(true, data["sidecarRegistered"]);
Assert.False(data.ContainsKey("sidecarMissingForMinutes"));
var stalled = Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object>>>(data["stalledProviders"]);
Assert.Equal("ConfigMgr", Assert.Single(stalled)["name"]);
var providers = Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object?>>>(data["providers"]);
@@ -0,0 +1,157 @@
using System;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.SignalAdapters;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.DecisionCore.Signals;
using AutopilotMonitor.Shared.Models;
using SharedEventTypes = AutopilotMonitor.Shared.Constants.EventTypes;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
{
/// <summary>
/// Historic-replay suppression for APP events (session eaf3d8c4 part 2): 147 of 157 app
/// events in that session were replayed from a previous enrollment's IME log — all 10
/// "installed apps" were phantoms. Stale app-state transitions and DO telemetry must be
/// suppressed BEFORE the sub-phase declaration, the timing bookkeeping and the terminal
/// DecisionSignal dedup, so fire-once flags stay unconsumed and no phantom
/// AppInstallCompleted/Failed reaches the engine (which could spuriously re-arm the
/// AdvisoryCompletion window). The script twin lives in
/// <see cref="ImeLogTrackerAdapterHistoricReplayTests"/>.
/// </summary>
public sealed class ImeLogTrackerAdapterHistoricAppReplayTests
{
private static readonly DateTime ClockNow = new DateTime(2026, 7, 23, 15, 42, 0, DateTimeKind.Utc);
[Fact]
public void Stale_terminal_app_transition_is_fully_suppressed()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = new AppPackageState("app-old", 0);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installed);
Assert.Empty(f.InfoEvents(SharedEventTypes.AppInstallComplete));
Assert.Empty(f.DecisionSignals(DecisionSignalKind.AppInstallCompleted));
// Shadow download_progress (status=completed) and the summary snapshot ride the
// same emit — both must be gone too.
Assert.Empty(f.InfoEvents(SharedEventTypes.DownloadProgress));
Assert.Empty(f.InfoEvents(SharedEventTypes.AppTrackingSummary));
// Timing bookkeeping must not be poisoned (feeds FinalStatusBuilder).
Assert.False(adapter.AppTimings.ContainsKey("app-old"));
Assert.Single(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
[Fact]
public void Fresh_run_after_suppressed_stale_run_fires_signal_timing_and_subphase()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = new AppPackageState("app-X", 0);
// Fresh ESP phase so the sub-phase declaration is armed.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-5);
adapter.TriggerEspPhaseFromTest("DeviceSetup");
// Stale replay of the same app — suppressed, must consume NEITHER the sub-phase
// fire-once NOR the terminal-signal dedup for this appId.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installed);
Assert.Empty(f.InfoEvents(SharedEventTypes.PhaseTransition));
Assert.Empty(f.DecisionSignals(DecisionSignalKind.AppInstallCompleted));
// The app genuinely runs in THIS enrollment.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-2);
adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-1);
adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installed);
Assert.Single(f.InfoEvents(SharedEventTypes.PhaseTransition)); // sub-phase fired fresh
Assert.Single(f.DecisionSignals(DecisionSignalKind.AppInstallCompleted)); // signal fired fresh
var timing = adapter.AppTimings["app-X"];
Assert.Equal(ClockNow.AddMinutes(-2), timing.StartedAtUtc); // fresh stamps, not stale
Assert.Equal(ClockNow.AddMinutes(-1), timing.CompletedAtUtc);
}
[Fact]
public void Stale_do_telemetry_is_suppressed_fresh_emits()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = new AppPackageState("app-do", 0);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerDoTelemetryFromTest(app);
Assert.Empty(f.InfoEvents(SharedEventTypes.DoTelemetry));
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-1);
adapter.TriggerDoTelemetryFromTest(app);
Assert.Single(f.InfoEvents(SharedEventTypes.DoTelemetry));
}
[Fact]
public void Oneshot_summary_is_shared_between_script_and_app_suppressions()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "aaa11111",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
});
adapter.TriggerAppStateFromTest(new AppPackageState("app-old", 0),
AppInstallationState.Installing, AppInstallationState.Installed);
Assert.Single(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
[Fact]
public void FutureSkew_app_transition_still_emits()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = new AppPackageState("app-skew", 0);
// Mid-enrollment clock jump — genuine current activity, stamped to the clock.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddHours(2);
adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installed);
var info = Assert.Single(f.InfoEvents(SharedEventTypes.AppInstallComplete));
Assert.Equal(ClockNow, info.OccurredAtUtc);
Assert.Equal("true", info.Payload!["derivedTimestamp"]);
Assert.Single(f.DecisionSignals(DecisionSignalKind.AppInstallCompleted));
Assert.Empty(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
[Fact]
public void SimulationMode_bypasses_suppression_for_apps_and_scripts()
{
// The --replay-log-dir dev tool intentionally feeds historic lines.
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
f.Tracker.SimulationMode = true;
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerAppStateFromTest(new AppPackageState("app-sim", 0),
AppInstallationState.Installing, AppInstallationState.Installed);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "bbb22222",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
});
Assert.Single(f.InfoEvents(SharedEventTypes.AppInstallComplete));
Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
Assert.Empty(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
}
}
@@ -0,0 +1,257 @@
using System;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.SignalAdapters;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using SharedEventTypes = AutopilotMonitor.Shared.Constants.EventTypes;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
{
/// <summary>
/// Historic-replay handling (session eaf3d8c4): a previous enrollment's IME log surviving
/// on disk made the agent replay week-old script activity — 156 phantom script_completed
/// events with ~170 h durations (clock-clamped completion minus RAW stale start) and an
/// immediate-upload flood. Script events whose source line is &gt; 24 h stale are now
/// suppressed entirely (one-shot <c>historic_ime_replay_detected</c> summary instead),
/// and durations are computed from a timeline-consistent timestamp pair with a 24 h
/// plausibility backstop.
/// </summary>
public sealed class ImeLogTrackerAdapterHistoricReplayTests
{
private static readonly DateTime ClockNow = new DateTime(2026, 7, 23, 15, 42, 0, DateTimeKind.Utc);
// ---------------------------------------------------------------------
// Suppression: stale (> 24 h past) source lines are a previous enrollment
// ---------------------------------------------------------------------
[Fact]
public void Stale_completion_is_suppressed_and_emits_oneshot_summary()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var ancient = ClockNow.AddDays(-7);
f.Tracker.LastMatchedLogTimestamp = ancient;
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "d78c1822",
ScriptType = "platform",
ExitCode = 0,
Result = "Failed",
StartedAtUtc = ancient.AddMinutes(-30),
// Bootstrap marker in stdout — week-old evidence must not drive the
// bootstrap-detected trace either.
Stdout = "Bootstrap script version: v2.0",
});
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptCompleted));
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptFailed));
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptTimeoutSuspected));
Assert.Empty(f.InfoEvents(SharedEventTypes.AgentTrace));
var summary = f.InfoEvent(SharedEventTypes.HistoricImeReplayDetected);
Assert.Equal(ancient.ToString("o"), summary.Payload!["earliestRejectedSourceTimestamp"]);
}
[Fact]
public void Summary_is_oneshot_across_started_and_completed_suppressions()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerScriptStartedFromTest(new ScriptStartedInfo { PolicyId = "aaa11111", ScriptType = "platform" });
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7).AddMinutes(1);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "aaa11111",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
});
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7).AddMinutes(2);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "bbb22222",
ScriptType = "remediation",
ScriptPart = "detection",
ExitCode = 0,
ComplianceResult = "True",
});
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptStarted));
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptCompleted));
// Exactly ONE summary regardless of how many replayed lines followed — and it dates
// the replay window from the FIRST (earliest) suppressed line.
var summary = Assert.Single(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
Assert.Equal(ClockNow.AddDays(-7).ToString("o"), summary.Payload!["earliestRejectedSourceTimestamp"]);
}
[Fact]
public void Fresh_events_after_suppression_emit_normally()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddDays(-7);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "aaa11111",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
});
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptCompleted));
// The agent catches up to current log content — normal emission resumes.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-2);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "ccc33333",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
StartedAtUtc = ClockNow.AddMinutes(-3),
});
var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
Assert.Equal("ccc33333", info.Payload!["policyId"]);
Assert.Equal("60.00", info.Payload["durationSeconds"]);
}
[Fact]
public void Clock_fallback_without_source_timestamp_still_emits()
{
// derivedFromClock with NO rejected source ts (synthetic/callback path) is not a
// replay — must emit, and must not trigger the summary.
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "ddd44444",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
});
var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
Assert.Equal("true", info.Payload!["derivedTimestamp"]);
Assert.False(info.Payload.ContainsKey("rejectedSourceTimestamp"));
Assert.Empty(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
// ---------------------------------------------------------------------
// Duration: timeline-consistent pair + plausibility backstop
// ---------------------------------------------------------------------
[Fact]
public void FutureSkew_completion_emits_with_clamped_stamp_and_raw_pair_duration()
{
// Mid-enrollment clock jump (WhiteGlove +1h CMTrace skew case): the source ts is
// rejected as future-skewed — NOT suppressed — and the duration must come from the
// raw source pair (both ends on the same skewed timeline), not clamped-now − raw-start.
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var skewed = ClockNow.AddHours(2);
f.Tracker.LastMatchedLogTimestamp = skewed;
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "eee55555",
ScriptType = "platform",
ExitCode = 0,
Result = "Success",
StartedAtUtc = skewed.AddSeconds(-360),
});
var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptCompleted));
Assert.Equal(ClockNow, info.OccurredAtUtc); // stamp: clamped to clock
Assert.Equal("true", info.Payload!["derivedTimestamp"]);
Assert.Equal(skewed.ToString("o"), info.Payload["rejectedSourceTimestamp"]);
Assert.Equal("360.00", info.Payload["durationSeconds"]); // duration: raw pair
Assert.Empty(f.InfoEvents(SharedEventTypes.HistoricImeReplayDetected));
}
[Fact]
public void FutureSkew_failed_platform_script_timeout_heuristic_uses_raw_pair()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var skewed = ClockNow.AddHours(2);
f.Tracker.LastMatchedLogTimestamp = skewed;
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "fff66666",
ScriptType = "platform",
ExitCode = 0,
Result = "Failed",
StartedAtUtc = skewed.AddMinutes(-26), // past the 25-min suspicion threshold
});
var suspected = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptTimeoutSuspected));
Assert.Equal("1560.00", suspected.Payload!["durationSeconds"]);
Assert.Equal(ClockNow, suspected.OccurredAtUtc);
}
[Fact]
public void Implausible_duration_above_24h_is_omitted()
{
// Fresh (accepted) completion paired with an ancient start — e.g. a stale pending
// slot a legacy path left behind. The duration would be a cross-run lie; omit it.
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddMinutes(-2);
adapter.TriggerScriptCompletedFromTest(new ScriptExecutionState
{
PolicyId = "abc12345",
ScriptType = "platform",
ExitCode = 0,
Result = "Failed",
StartedAtUtc = ClockNow.AddHours(-30),
});
var info = Assert.Single(f.InfoEvents(SharedEventTypes.ScriptFailed));
Assert.False(info.Payload!.ContainsKey("durationSeconds"));
Assert.False(info.Payload.ContainsKey("durationBasis"));
// The 30 h "duration" must not read as a hung script either.
Assert.Empty(f.InfoEvents(SharedEventTypes.ScriptTimeoutSuspected));
}
// ---------------------------------------------------------------------
// Tracker slot hardening: stale pending start must not pair with a fresh run
// ---------------------------------------------------------------------
[Fact]
public void Fresh_start_discards_stale_pending_slot_from_previous_enrollment()
{
using var f = new ImeLogTrackerAdapterFixture(ClockNow);
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
// Previous enrollment: replayed start line whose matching result never appeared
// (the script was mid-run when that enrollment ended).
f.Tracker.SeedPendingPlatformScriptForTesting("beef7777", exitCode: null, exitObservedAtUtc: null,
startedAtUtc: ClockNow.AddDays(-7));
// Same policy genuinely re-runs now — the fresh start must begin a NEW execution.
f.Tracker.LastMatchedLogTimestamp = ClockNow.AddSeconds(-90);
f.Tracker.HandlePlatformScriptStarted("beef7777");
f.Tracker.LastMatchedLogTimestamp = ClockNow;
f.Tracker.CompletePlatformScriptFromImeResultForTesting("beef7777", "Success", ClockNow);
var info = f.InfoEvent(SharedEventTypes.ScriptCompleted);
// Without the hardening the slot kept the 7-day-old start: the duration would have
// been dropped by the 24 h backstop (or, before that, shown as ~168 h).
Assert.Equal("90.00", info.Payload!["durationSeconds"]);
}
}
}
@@ -208,39 +208,60 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
}
else
{
// Platform script: AgentExecutor.log entries create/enrich, IME log entries also create
if (!_pendingPlatformScripts.ContainsKey(id))
{
// A fresh start for this policy (no pending entry) begins a NEW execution.
// Clear any emitted-marker from a prior run so IME re-evaluations / retries of
// the same platform-script policy within one agent lifetime are not silently
// deduped away. Within a single run the start always precedes exit/result, so
// this never clears the current run's own marker.
_platformScriptResultEmitted.Remove(id);
_pendingPlatformScripts[id] = new ScriptExecutionState
{
PolicyId = id,
ScriptType = "platform",
// Prefer the source CMTrace timestamp so a script that started before the
// agent launched (replayed log content) is dated to its real start, not now.
// Set only at slot creation: the start line fires twice (agentexecutor + ime
// source) but the earliest wins.
StartedAtUtc = LastMatchedLogTimestamp ?? DateTime.UtcNow,
};
// Live "running" indicator — same signal health scripts emit. Gated on slot
// creation so the duplicate start line (agentexecutor + ime source) doesn't
// double-emit for the same execution.
try { OnScriptStarted?.Invoke(new ScriptStartedInfo { PolicyId = id, ScriptType = "platform" }); }
catch (Exception ex) { _logger.Warning($"ImeLogTracker: OnScriptStarted handler threw: {ex.Message}"); }
}
_lastPlatformScriptPolicyId = id;
// Started lines fire twice per script (agentexecutor + ime source) and carry no
// outcome — the matching `platform script completed` line below carries result+exit
// and stays on Info. Keep starts on Debug so Info reflects script outcomes only.
_logger.Debug($"ImeLogTracker: platform script started: {id} (source: {source ?? "ime"})");
HandlePlatformScriptStarted(id, source);
}
}
// Platform script: AgentExecutor.log entries create/enrich, IME log entries also create.
// Internal so the stale-slot hardening is directly testable (the public path arrives via
// a regex Match).
internal void HandlePlatformScriptStarted(string id, string source = null)
{
// Stale-slot hardening (session eaf3d8c4): a replayed start line from a previous
// enrollment whose matching result never appeared (script was mid-run when that
// enrollment ended) leaves a pending slot with a days-old StartedAtUtc. When the
// same policy genuinely re-runs now, the fresh start must begin a NEW execution —
// otherwise the ancient start pairs with the fresh completion and the duration
// lies. > 24 h mirrors the adapter's source-timestamp staleness clamp.
var currentStartTs = LastMatchedLogTimestamp ?? DateTime.UtcNow;
if (_pendingPlatformScripts.TryGetValue(id, out var pendingSlot)
&& pendingSlot.StartedAtUtc.HasValue
&& currentStartTs - pendingSlot.StartedAtUtc.Value > TimeSpan.FromHours(24))
{
_logger.Debug($"ImeLogTracker: discarding stale pending platform-script slot for {id} (started {pendingSlot.StartedAtUtc:o})");
_pendingPlatformScripts.Remove(id);
}
if (!_pendingPlatformScripts.ContainsKey(id))
{
// A fresh start for this policy (no pending entry) begins a NEW execution.
// Clear any emitted-marker from a prior run so IME re-evaluations / retries of
// the same platform-script policy within one agent lifetime are not silently
// deduped away. Within a single run the start always precedes exit/result, so
// this never clears the current run's own marker.
_platformScriptResultEmitted.Remove(id);
_pendingPlatformScripts[id] = new ScriptExecutionState
{
PolicyId = id,
ScriptType = "platform",
// Prefer the source CMTrace timestamp so a script that started before the
// agent launched (replayed log content) is dated to its real start, not now.
// Set only at slot creation: the start line fires twice (agentexecutor + ime
// source) but the earliest wins.
StartedAtUtc = currentStartTs,
};
// Live "running" indicator — same signal health scripts emit. Gated on slot
// creation so the duplicate start line (agentexecutor + ime source) doesn't
// double-emit for the same execution.
try { OnScriptStarted?.Invoke(new ScriptStartedInfo { PolicyId = id, ScriptType = "platform" }); }
catch (Exception ex) { _logger.Warning($"ImeLogTracker: OnScriptStarted handler threw: {ex.Message}"); }
}
_lastPlatformScriptPolicyId = id;
// Started lines fire twice per script (agentexecutor + ime source) and carry no
// outcome — the matching `platform script completed` line below carries result+exit
// and stays on Info. Keep starts on Debug so Info reflects script outcomes only.
_logger.Debug($"ImeLogTracker: platform script started: {id} (source: {source ?? "ime"})");
}
// Routes line-by-line script-data handlers (context / exitCode / output) to the right
// accumulator based on the pattern's scriptType parameter. Health-script lines feed the
// single-slot _pendingHealthScript; platform-script lines feed _pendingPlatformScripts.
@@ -194,6 +194,27 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
}
}
// Actions that mutate app/phase tracking state (_packageStates, _phasePackageSnapshots,
// _currentPhaseOrder, DO telemetry) — the historic-replay guard skips these for source
// lines from a previous enrollment so replayed apps never enter tracked state,
// persistence, app_tracking_summary, culprit lists or final-status. Script actions are
// deliberately NOT here: their tracker state is harmless (stale-slot hardening covers
// leftovers) and the adapter suppresses their emissions. espphasedetected IS here — a
// stale "In EspPhase: AccountSetup" would advance _currentPhaseOrder and make the fresh
// enrollment's DeviceSetup lines bounce as "backward"; IME re-logs the phase constantly,
// so fresh lines re-deliver it immediately.
private static readonly HashSet<string> AppMutatingActions = new HashSet<string>(StringComparer.Ordinal)
{
"imeshutdown", "espphasedetected", "setcurrentapp",
"updatestateinstalled", "updatestatedownloading", "updatestateinstalling",
"updatestateskipped", "updatestateerror", "updatestatepostponed",
"captureexitcode", "capturehresult", "captureappversion",
"captureapptypewinget", "captureapptypemsi", "captureattemptnumber",
"capturedetectionresult", "esptrackstatus", "policiesdiscovered",
"ignorecompletedapp", "updatename", "updatewin32appstate",
"cancelstuckandsetcurrent", "updatedotelemetry",
};
private void HandlePatternMatch(CompiledPattern pattern, Match match, string message, CmTraceLogEntry entry)
{
LastMatchedPatternId = pattern.PatternId;
@@ -206,6 +227,19 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
try { OnPatternMatched?.Invoke(pattern.PatternId); }
catch (Exception ex) { _logger?.Warning($"OnPatternMatched handler threw: {ex.Message}"); }
// Historic-replay guard (session eaf3d8c4): a source line > 24 h older than now is
// content from a previous enrollment whose IME log survived on disk. App-mutating
// actions are skipped BEFORE _seenAppIds so replayed apps poison neither the tracked
// state nor the phase-change ignore list. SimulationMode (--replay-log-dir dev tool)
// replays historic logs on purpose and bypasses the guard.
var isStaleReplayLine = !SimulationMode && entry != null
&& (UtcNowProvider() - NormalizeUtc(entry.Timestamp)) > HistoricReplayThreshold;
if (isStaleReplayLine && AppMutatingActions.Contains(pattern.Action?.ToLower() ?? string.Empty))
{
_logger.Debug($"ImeLogTracker: skipped app action '{pattern.Action}' for historic line ({entry.Timestamp:o})");
return;
}
try
{
var id = match.Groups["id"]?.Value;
@@ -71,6 +71,23 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
public double SpeedFactor { get; set; } = 50;
private DateTime _lastLogTimestamp = DateTime.MinValue;
// Source log lines older than this relative to now are content from a previous
// enrollment (IME logs surviving a re-enrollment, session eaf3d8c4). Single source of
// truth shared with the adapter's ResolveOccurredAt clamp and replay suppression.
internal static readonly TimeSpan HistoricReplayThreshold = TimeSpan.FromHours(24);
// Deterministic-time seam for the historic-replay guard; production default is the
// system clock, ImeLogHost rewires it to the agent IClock, tests to their VirtualClock.
internal Func<DateTime> UtcNowProvider { get; set; } = () => DateTime.UtcNow;
/// <summary>
/// CMTrace timestamps from IME are emitted in UTC, but DateTimeKind may arrive as
/// Unspecified depending on the parser path. Normalize via SpecifyKind=Utc rather than
/// ToUniversalTime() to avoid double-conversion when Kind is already UTC.
/// </summary>
internal static DateTime NormalizeUtc(DateTime value) =>
value.Kind == DateTimeKind.Utc ? value : DateTime.SpecifyKind(value, DateTimeKind.Utc);
// Background task
private Task _pollingTask;
private CancellationTokenSource _cts;
@@ -1,4 +1,5 @@
using System;
using System.Collections.Generic;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
@@ -38,16 +39,30 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// </summary>
public string Category { get; }
/// <summary>
/// Session 4910a5a5: names of the tracked apps most likely behind an Apps-subcategory
/// failure (capped, never-started apps ranked first — those starve ESP's app gate
/// without ever producing an IME install event). Snapshot from
/// <c>ProvisioningStatusTracker.SnapshotTrackedAppsNotCompleted</c> at failure-arming
/// time; empty for non-Apps failures and event-log-derived failures. Propagated onto
/// the EspTerminalFailure signal payload so the DecisionEngine's
/// <c>esp_failure_advisory</c> / <c>enrollment_failed</c> events can name the culprit
/// directly.
/// </summary>
public IReadOnlyList<string> LikelyCulpritApps { get; }
public EspFailureDetectedEventArgs(
string failureType,
string errorCode = null,
string failedSubcategory = null,
string category = null)
string category = null,
IReadOnlyList<string> likelyCulpritApps = null)
{
FailureType = string.IsNullOrEmpty(failureType) ? "unknown" : failureType;
ErrorCode = string.IsNullOrEmpty(errorCode) ? null : errorCode;
FailedSubcategory = string.IsNullOrEmpty(failedSubcategory) ? null : failedSubcategory;
Category = string.IsNullOrEmpty(category) ? null : category;
LikelyCulpritApps = likelyCulpritApps ?? Array.Empty<string>();
}
}
}
@@ -35,13 +35,19 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// (registered during Autopilot-into-co-management, see the troubleshooting registry paths in
/// https://learn.microsoft.com/en-us/intune/configmgr/comanage/autopilot-enrollment). Microsoft
/// warns that ESP policy providers are not aware of each other and that pre-provisioning is
/// unsupported with co-management. Field case that motivated this probe: a pre-provisioned
/// device with the ConfigMgr client installed as a blocking app ended up with ONLY
/// <c>ConfigMgr</c> registered under <c>Device\Setup\Apps\PolicyProviders</c> (no
/// <c>Sidecar</c>) and <c>TrackingPoliciesCreated</c> never set — the user ESP hung at
/// "Apps (Identifying)" for hours to days; manually renaming the key to <c>Sidecar</c>
/// unblocked it immediately. <see cref="EspPolicyProviderStallDetector"/> turns this contract
/// into the <c>esp_policy_provider_stalled</c> tripwire.
/// unsupported with co-management. Field case that motivated this probe (issue #106): a
/// pre-provisioned device with the ConfigMgr client installed as a blocking app ended up with
/// ONLY <c>ConfigMgr</c> registered under <c>Device\Setup\Apps\PolicyProviders</c> (no
/// <c>Sidecar</c>) — and although <c>TrackingPoliciesCreated=1</c> WAS set under it, the user
/// ESP hung at "Apps (Identifying)" for hours to days; manually renaming the key to
/// <c>Sidecar</c> unblocked it immediately. So the ESP's Apps wait is keyed to the provider
/// the Intune service registered at enrollment (always <c>Sidecar</c>; ConfigMgr only joins
/// via a co-management settings policy — see the WAP payload documented in
/// https://oofhours.com/2023/08/25/run-an-sccm-task-sequence-during-autopilot/), and a
/// foreign provider's completion values do not satisfy it. Detection therefore keys on the
/// provider NAME topology, not only on completeness:
/// <see cref="EspPolicyProviderStallDetector"/> turns this contract into the two-arm
/// <c>esp_policy_provider_stalled</c> tripwire.
/// </para>
/// <para>
/// Fail-soft like <see cref="EspTrackingInfoProbe"/>: any failure is Debug-logged and yields
@@ -13,18 +13,30 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
/// <summary>
/// Turns the ESP policy-provider contract read by <see cref="EspPolicyProviderProbe"/> into
/// the one-shot <c>esp_policy_provider_stalled</c> Warning: a registered provider that stays
/// continuously incomplete for <see cref="DwellMinutes"/> minutes is reported once, with the
/// full provider table in the payload. See the probe's header for the CSP contract, the
/// official sources, and the co-management field case (ConfigMgr registered without Sidecar
/// → user ESP parked at "Apps (Identifying)" with no OS timeout) this tripwire exists for.
/// the one-shot <c>esp_policy_provider_stalled</c> Warning via two independent arms, each
/// with the same <see cref="DwellMinutes"/>-minute continuous-dwell rule and the full
/// provider table in the payload:
/// <list type="bullet">
/// <item><b>Arm 1 — <c>reason=provider_incomplete</c></b>: a registered provider stays
/// continuously incomplete (e.g. Sidecar itself never sets TrackingPoliciesCreated).</item>
/// <item><b>Arm 2 — <c>reason=sidecar_provider_missing</c></b>: at least one
/// <c>Setup\Apps</c> provider is registered but none of them is <c>Sidecar</c> (the IME).
/// This is the actual co-management field-case signature (issue #106): the foreign
/// <c>ConfigMgr</c> provider had <c>TrackingPoliciesCreated=1</c> — i.e. was "complete"
/// by the CSP value contract — yet the user ESP stayed parked at "Apps (Identifying)"
/// until the key was renamed to <c>Sidecar</c>. The ESP's Apps wait is keyed to the
/// Intune-registered provider by NAME, so provider completeness alone must not gate this
/// detection. See the probe's header for sources.</item>
/// </list>
/// <para>
/// Dwell semantics: the dwell clock per provider starts when it is first observed incomplete
/// and RESETS when the provider completes or disappears — only <i>continuously</i> incomplete
/// providers fire. A missing root key / empty provider list is normal early enrollment and
/// clears all dwell state (probe D4). Purely observational: emission goes through
/// <see cref="InformationalEventPost"/> (InformationalEvent pass-through, dispatch-guard
/// exempt), never into decision state.
/// Dwell semantics: arm 1's clock per provider starts when it is first observed incomplete
/// and RESETS when the provider completes or disappears; arm 2's clock starts when the
/// sidecar-missing condition is first observed and RESETS when Sidecar registers (covers the
/// legitimate "ConfigMgr registered before Sidecar" startup ordering) — only
/// <i>continuously</i> bad states fire. A missing root key / empty provider list is normal
/// early enrollment and clears all dwell state (probe D4). Purely observational: emission
/// goes through <see cref="InformationalEventPost"/> (InformationalEvent pass-through,
/// dispatch-guard exempt), never into decision state.
/// </para>
/// <para>
/// Duplicate suppression: in-process one-shot per provider key, plus a
@@ -44,6 +56,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
internal const string SourceLabel = "EspPolicyProviderStallDetector";
/// <summary>Payload <c>reason</c>: a registered provider stayed continuously incomplete (arm 1).</summary>
internal const string ReasonProviderIncomplete = "provider_incomplete";
/// <summary>Payload <c>reason</c>: Setup\Apps providers registered but Sidecar absent (arm 2 — dominant when both arms fire in one round).</summary>
internal const string ReasonSidecarMissing = "sidecar_provider_missing";
/// <summary>
/// Sentinel token representing the arm-2 condition in the cross-restart fingerprint.
/// Cannot collide with provider keys — those always contain <c>|</c> separators.
/// </summary>
private const string SidecarMissingFingerprintToken = "sidecarMissing";
private readonly string _sessionId;
private readonly string _tenantId;
private readonly InformationalEventPost _post;
@@ -57,6 +81,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
private readonly HashSet<string> _firedKeys =
new HashSet<string>(StringComparer.OrdinalIgnoreCase);
/// <summary>Arm-2 dwell state: first observation of "setupApps providers without Sidecar"; null = condition not active.</summary>
private DateTime? _sidecarMissingSinceUtc;
/// <summary>Arm-2 in-process one-shot latch (mirror of <see cref="_firedKeys"/>).</summary>
private bool _sidecarMissingFired;
public EspPolicyProviderStallDetector(
string sessionId,
string tenantId,
@@ -79,13 +109,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
internal void Tick()
{
var snapshot = EspPolicyProviderProbe.Read(_logger);
var eval = EvaluateStallTransition(snapshot, _firstSeenIncompleteUtc, _firedKeys, _clock.UtcNow, _dwell);
var eval = EvaluateStallTransition(
snapshot, _firstSeenIncompleteUtc, _firedKeys,
_sidecarMissingSinceUtc, _sidecarMissingFired, _clock.UtcNow, _dwell);
_firstSeenIncompleteUtc.Clear();
foreach (var kv in eval.UpdatedFirstSeenUtc)
_firstSeenIncompleteUtc[kv.Key] = kv.Value;
_sidecarMissingSinceUtc = eval.UpdatedSidecarMissingSinceUtc;
if (eval.NewlyStalled.Count > 0)
if (eval.NewlyStalled.Count > 0 || eval.SidecarMissingStalledForMinutes != null)
EmitStalled(snapshot, eval);
}
@@ -94,24 +127,29 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// registry, timer, or ingress (pattern: <c>PerformanceCollector.EvaluateDiskLowTransition</c>).
/// </summary>
/// <param name="snapshot">Current provider snapshot.</param>
/// <param name="firstSeenIncompleteUtc">Dwell state from the previous round (provider key → first-seen-incomplete).</param>
/// <param name="firstSeenIncompleteUtc">Arm-1 dwell state from the previous round (provider key → first-seen-incomplete).</param>
/// <param name="alreadyFired">Provider keys already reported this run (never re-report).</param>
/// <param name="sidecarMissingSinceUtc">Arm-2 dwell state from the previous round; null = condition was not active.</param>
/// <param name="sidecarMissingAlreadyFired">Arm-2 one-shot latch (never re-report).</param>
/// <param name="nowUtc">Evaluation timestamp.</param>
/// <param name="dwell">Continuous-incompleteness threshold.</param>
/// <param name="dwell">Continuous-condition threshold (shared by both arms).</param>
internal static StallEvaluation EvaluateStallTransition(
EspPolicyProviderSnapshot snapshot,
IReadOnlyDictionary<string, DateTime> firstSeenIncompleteUtc,
ISet<string> alreadyFired,
DateTime? sidecarMissingSinceUtc,
bool sidecarMissingAlreadyFired,
DateTime nowUtc,
TimeSpan dwell)
{
var result = new StallEvaluation();
// Missing root key or no registered providers = normal early enrollment: clear all
// dwell state (a provider must be continuously OBSERVED incomplete to accrue dwell).
// dwell state (a condition must be continuously OBSERVED to accrue dwell).
if (!snapshot.HasData || snapshot.Providers.Count == 0)
return result;
// Arm 1 — a registered provider continuously incomplete.
foreach (var provider in snapshot.Providers)
{
if (provider.IsComplete)
@@ -127,22 +165,44 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
result.NewlyStalled.Add(new StalledProvider(provider, stalledFor.TotalMinutes));
}
// Arm 2 — Setup\Apps providers registered, but none of them is Sidecar. Deliberately
// ignores provider completeness: the field case (issue #106) had ConfigMgr with
// TrackingPoliciesCreated=1 and the ESP still waited. Sidecar registering later
// (legitimate startup ordering) clears the condition and resets the clock.
if (HasSetupAppsProvider(snapshot) && !snapshot.SidecarRegistered)
{
var since = sidecarMissingSinceUtc ?? nowUtc;
result.UpdatedSidecarMissingSinceUtc = since;
var missingFor = nowUtc - since;
if (missingFor >= dwell && !sidecarMissingAlreadyFired)
result.SidecarMissingStalledForMinutes = missingFor.TotalMinutes;
}
return result;
}
private static bool HasSetupAppsProvider(EspPolicyProviderSnapshot snapshot)
=> snapshot.Providers.Any(p => p.Kind == EspPolicyProviderProbe.KindSetupApps);
private void EmitStalled(EspPolicyProviderSnapshot snapshot, StallEvaluation eval)
{
foreach (var stalled in eval.NewlyStalled)
_firedKeys.Add(stalled.Provider.Key);
if (eval.SidecarMissingStalledForMinutes != null)
_sidecarMissingFired = true;
// Cross-restart dedup: fingerprint = sorted set of all fired keys that are still
// incomplete. A restart into the same stall re-accrues dwell and lands on the same
// fingerprint → suppressed; a new provider joining the stall changes it → re-emitted.
// Cross-restart dedup: fingerprint = sorted set of all fired conditions that are
// still active (incomplete providers + the sidecar-missing sentinel). A restart into
// the same stall re-accrues dwell and lands on the same fingerprint → suppressed; a
// new condition joining the stall changes it → re-emitted.
var currentlyStalledKeys = snapshot.Providers
.Where(p => !p.IsComplete && _firedKeys.Contains(p.Key))
.Select(p => p.Key)
.OrderBy(k => k, StringComparer.OrdinalIgnoreCase)
.ToList();
if (_sidecarMissingFired && HasSetupAppsProvider(snapshot) && !snapshot.SidecarRegistered)
currentlyStalledKeys.Add(SidecarMissingFingerprintToken);
currentlyStalledKeys.Sort(StringComparer.OrdinalIgnoreCase);
var fingerprint = StartupEventGate.HashString(string.Join(";", currentlyStalledKeys));
if (_startupGate != null &&
!_startupGate.ShouldEmit(Constants.EventTypes.EspPolicyProviderStalled, fingerprint))
@@ -153,11 +213,30 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
return;
}
// Sidecar-missing is the dominant reason when both arms fire in one round: it
// explains the ESP hang regardless of the foreign providers' completeness.
var reason = eval.SidecarMissingStalledForMinutes != null
? ReasonSidecarMissing
: ReasonProviderIncomplete;
var messageParts = new List<string>();
if (eval.SidecarMissingStalledForMinutes != null)
{
var registeredNames = string.Join(", ", snapshot.Providers
.Where(p => p.Kind == EspPolicyProviderProbe.KindSetupApps)
.Select(p => $"{p.Name} ({p.Scope})"));
messageParts.Add(
$"expected IME provider '{EspPolicyProviderProbe.SidecarProviderName}' not registered for " +
$">= {DwellMinutes} min while Setup/Apps providers exist: {registeredNames}");
}
var stalledNames = string.Join(", ",
eval.NewlyStalled.Select(s => $"{s.Provider.Name} ({s.Provider.Scope}/{s.Provider.Kind})"));
if (eval.NewlyStalled.Count > 0)
messageParts.Add($"provider(s) incomplete for >= {DwellMinutes} min: {stalledNames}");
var data = new Dictionary<string, object>(StringComparer.Ordinal)
{
["reason"] = reason,
["dwellMinutes"] = DwellMinutes,
["sidecarRegistered"] = snapshot.SidecarRegistered,
["providers"] = snapshot.Providers.Select(p => new Dictionary<string, object?>(StringComparer.Ordinal)
@@ -177,6 +256,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
["stalledForMinutes"] = Math.Round(s.StalledForMinutes, 1),
}).ToList(),
};
if (eval.SidecarMissingStalledForMinutes != null)
data["sidecarMissingForMinutes"] = Math.Round(eval.SidecarMissingStalledForMinutes.Value, 1);
var message =
"ESP Setup/Apps tracking stalled: " + string.Join("; ", messageParts) +
" — the ESP waits on its app-tracking providers without any timeout";
_post.Emit(new EnrollmentEvent
{
@@ -188,27 +273,31 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
Source = SourceLabel,
Phase = EnrollmentPhase.Unknown,
ImmediateUpload = true,
Message = $"ESP policy provider(s) incomplete for >= {DwellMinutes} min: {stalledNames} " +
$"(sidecarRegistered={snapshot.SidecarRegistered}) — the ESP waits on " +
"Setup/Apps providers without any timeout",
Message = message,
Data = data
});
_startupGate?.MarkEmitted(Constants.EventTypes.EspPolicyProviderStalled);
_logger?.Warning(
$"EspPolicyProviderStallDetector: {stalledNames} incomplete for >= {DwellMinutes} min " +
$"(sidecarRegistered={snapshot.SidecarRegistered}).");
$"EspPolicyProviderStallDetector: {string.Join("; ", messageParts)} " +
$"(reason={reason}, sidecarRegistered={snapshot.SidecarRegistered}).");
}
/// <summary>Result of one <see cref="EvaluateStallTransition"/> round.</summary>
internal sealed class StallEvaluation
{
/// <summary>Next round's dwell state — only currently-incomplete providers survive.</summary>
/// <summary>Next round's arm-1 dwell state — only currently-incomplete providers survive.</summary>
public Dictionary<string, DateTime> UpdatedFirstSeenUtc { get; } =
new Dictionary<string, DateTime>(StringComparer.OrdinalIgnoreCase);
/// <summary>Providers that crossed the dwell threshold this round and were not yet reported.</summary>
/// <summary>Providers that crossed the dwell threshold this round and were not yet reported (arm 1).</summary>
public List<StalledProvider> NewlyStalled { get; } = new List<StalledProvider>();
/// <summary>Next round's arm-2 dwell state; null = sidecar-missing condition not active (reset).</summary>
public DateTime? UpdatedSidecarMissingSinceUtc { get; set; }
/// <summary>Non-null when the sidecar-missing condition crossed the dwell threshold this round and was not yet reported (arm 2).</summary>
public double? SidecarMissingStalledForMinutes { get; set; }
}
internal readonly struct StalledProvider
@@ -116,6 +116,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// failure details that fire after the settle window expires.
private Dictionary<string, Timer> _provisioningFailureSettleTimers;
private Dictionary<string, EspFailureDetectedEventArgs> _provisioningFailureSettleArgs;
// Session 4910a5a5 — post-terminal recovery story. Populated when the settle window
// expires and EspFailureDetected actually fires (terminal path); consumed by the
// esp_failure_retry_detected / esp_failure_recovered emitters so a late "Try again"
// recovery (23 min after the failure in the field session) is visible on the timeline
// instead of hiding inside a generic subcategory_state_change. Keyed by category-name.
private Dictionary<string, EspFailureDetectedEventArgs> _provisioningFailureTerminalArgs;
private Dictionary<string, DateTime> _provisioningFailureTerminalUtc;
private HashSet<string> _postFailureRetryEmitted;
private HashSet<string> _postFailureRecoveredEmitted;
// Session 2bc884b6: AppX enrichment scan seams + fire-once guard. The scanner and the
// dispatcher are injectable so tests never touch the real event log or the threadpool.
private readonly IAppxDeploymentFailureScanner _appxScanner;
@@ -285,6 +294,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
_lastSubcategoryStates = new Dictionary<string, Dictionary<string, string>>(StringComparer.OrdinalIgnoreCase);
_provisioningFailureSettleTimers = new Dictionary<string, Timer>(StringComparer.OrdinalIgnoreCase);
_provisioningFailureSettleArgs = new Dictionary<string, EspFailureDetectedEventArgs>(StringComparer.OrdinalIgnoreCase);
_provisioningFailureTerminalArgs = new Dictionary<string, EspFailureDetectedEventArgs>(StringComparer.OrdinalIgnoreCase);
_provisioningFailureTerminalUtc = new Dictionary<string, DateTime>(StringComparer.OrdinalIgnoreCase);
_postFailureRetryEmitted = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
_postFailureRecoveredEmitted = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
_deviceSetupProvisioningCompleteFired = false;
_deviceSetupFallbackTimer = null;
_accountSetupProvisioningCompleteFired = false;
@@ -665,6 +678,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// null-ing here is correctness-neutral on the start-condition side.
ResetAccountSetupFallbackTimer();
_accountSetupProvisioningCompleteFired = true;
MaybeEmitPostFailureRecovered("AccountSetupCategory.Status", "AccountSetup");
try { AccountSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); }
catch (Exception ex) { _logger.Error("AccountSetupProvisioningComplete handler failed (fallback path)", ex); }
}
@@ -833,6 +847,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// null-ing here is correctness-neutral on the start-condition side.
ResetDeviceSetupFallbackTimer();
_deviceSetupProvisioningCompleteFired = true;
MaybeEmitPostFailureRecovered("DeviceSetupCategory.Status", "DeviceSetup");
try { DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); }
catch (Exception ex) { _logger.Error("DeviceSetupProvisioningComplete handler failed (fallback path)", ex); }
}
@@ -946,12 +961,25 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
var severity = categorySucceeded == false ? EventSeverity.Warning : EventSeverity.Info;
EmitProvisioningEvent(categoryLabel, categorySucceeded, statusText, subcategories, severity);
EmitRawRegistryDump(categoryLabel, jsonValue, $"category_resolved_{(categorySucceeded == true ? "success" : "failed")}");
// Session 4910a5a5: category resolving to success after a terminally
// fired failure = the failure recovered (fallback-path successes call
// this from their own timer handlers).
if (categorySucceeded == true)
{
MaybeEmitPostFailureRecovered(categoryName, categoryLabel);
}
}
else
{
var transitions = DetectSubcategoryTransitions(categoryName, subcategories);
StoreSubcategoryStates(categoryName, subcategories);
// Session 4910a5a5: after a terminally fired failure, the failed
// subcategory leaving "failed" is the ESP re-running the step —
// consistent with the user pressing "Try again" on the failure page.
MaybeEmitPostFailureRetry(categoryName, categoryLabel, transitions);
var failureTransitions = transitions.Where(t => t.IsFailure).ToList();
if (transitions.Count > 0)
{
@@ -1025,6 +1053,21 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
$"escalating as {failureTypeName} (errorCode={errorCode ?? "n/a"})");
_logger.Warning($"Provisioning failure detected: {failureTypeName}");
// Session 4910a5a5: name the likely culprit app(s) directly on the failure args so
// the DecisionEngine's advisory/terminal events carry them — never-started apps
// first (they starve ESP's app gate without ever producing an IME install event),
// capped at 3 names.
IReadOnlyList<string> likelyCulpritApps = null;
if (string.Equals(failedSubcategoryName, "Apps", StringComparison.OrdinalIgnoreCase))
{
likelyCulpritApps = SnapshotTrackedAppsNotCompleted()
.OrderBy(a => a["everStartedInstalling"] is bool started && started ? 1 : 0)
.Select(a => a["appName"]?.ToString())
.Where(n => !string.IsNullOrEmpty(n))
.Take(3)
.ToList();
}
// Caller already holds _stateLock.
ArmFailureSettleTimer(
categoryName: categoryName,
@@ -1032,7 +1075,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
failureType: failureTypeName,
errorCode: errorCode,
failedSubcategory: failedSubcategoryName,
category: categoryLabel));
category: categoryLabel,
likelyCulpritApps: likelyCulpritApps));
// Settle-window owns the actual EspFailureDetected fire. The legacy "fire-after-emit"
// path in CheckProvisioningStatus is now a no-op for this code-path; it stays in place
@@ -1292,6 +1336,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
_provisioningCategoriesResolved.Remove(categoryName);
}
}
else
{
// Session 4910a5a5: remember the terminally fired failure so a LATE
// recovery (outside the settle window — e.g. user pressing "Try again"
// minutes later) can be told as esp_failure_retry_detected /
// esp_failure_recovered instead of hiding in a generic state-change.
_provisioningFailureTerminalArgs[categoryName] = args;
_provisioningFailureTerminalUtc[categoryName] = DateTime.UtcNow;
}
}
if (recovered)
@@ -1382,6 +1435,133 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
});
}
/// <summary>
/// Session 4910a5a5: after a terminally fired failure (settle window expired,
/// EspFailureDetected raised), the failed subcategory leaving the <c>failed</c> state
/// means the ESP re-ran the step — consistent with the user pressing "Try again" on
/// the ESP failure page (the agent cannot observe the click itself). Emits
/// <c>esp_failure_retry_detected</c> once per terminally fired category. Caller holds
/// <see cref="_stateLock"/>.
/// </summary>
private void MaybeEmitPostFailureRetry(string categoryName, string categoryLabel, List<SubcategoryTransition> transitions)
{
if (transitions == null || transitions.Count == 0) return;
if (_postFailureRetryEmitted.Contains(categoryName)) return;
if (_provisioningFailureTerminalArgs == null
|| !_provisioningFailureTerminalArgs.TryGetValue(categoryName, out var terminalArgs))
{
return; // No terminal fire on record — in-window recovery is settle_recovered's job.
}
SubcategoryTransition? retryTransition = null;
foreach (var t in transitions)
{
if (string.Equals(t.OldState, "failed", StringComparison.OrdinalIgnoreCase)
&& !string.Equals(t.NewState, "failed", StringComparison.OrdinalIgnoreCase))
{
retryTransition = t;
break;
}
}
if (retryTransition == null) return;
var retry = retryTransition.Value;
_postFailureRetryEmitted.Add(categoryName);
var minutesSinceFailure = MinutesSinceTerminalFailure(categoryName);
var data = new Dictionary<string, object>
{
{ "category", categoryLabel },
{ "subcategory", retry.SubcategoryName },
{ "previousState", retry.OldState },
{ "newState", retry.NewState },
{ "failureType", terminalArgs.FailureType },
{ "minutesSinceFailure", minutesSinceFailure },
};
if (!string.IsNullOrEmpty(terminalArgs.ErrorCode))
data["errorCode"] = terminalArgs.ErrorCode;
_post.Emit(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
EventType = Constants.EventTypes.EspFailureRetryDetected,
Severity = EventSeverity.Info,
Source = "EspAndHelloTracker",
Phase = EnrollmentPhase.Unknown,
Message = $"ESP retry detected — {categoryLabel}/{retry.SubcategoryName} left the failed state " +
$"({retry.OldState} → {retry.NewState}) {minutesSinceFailure} min after the failure — " +
"consistent with the user pressing 'Try again' on the ESP failure page.",
Data = data,
ImmediateUpload = true
});
}
/// <summary>
/// Session 4910a5a5: the category behind a terminally fired failure reached success
/// (categorySucceeded=true or the all-subcategories-succeeded fallback) — the failure
/// demonstrably recovered. Emits <c>esp_failure_recovered</c> once per terminally
/// fired category so the timeline tells "failed → retried → recovered" instead of
/// leaving the stale failure as the last word. Caller holds <see cref="_stateLock"/>.
/// </summary>
private void MaybeEmitPostFailureRecovered(string categoryName, string categoryLabel)
{
if (_postFailureRecoveredEmitted == null || _postFailureRecoveredEmitted.Contains(categoryName)) return;
if (_provisioningFailureTerminalArgs == null
|| !_provisioningFailureTerminalArgs.TryGetValue(categoryName, out var terminalArgs))
{
return;
}
_postFailureRecoveredEmitted.Add(categoryName);
var minutesSinceFailure = MinutesSinceTerminalFailure(categoryName);
string subcategoryStatus = null;
if (terminalArgs.FailedSubcategory != null
&& _lastSubcategoryStates != null
&& _lastSubcategoryStates.TryGetValue(categoryName, out var subs)
&& subs.TryGetValue(terminalArgs.FailedSubcategory, out var currentState))
{
subcategoryStatus = currentState;
}
var data = new Dictionary<string, object>
{
{ "category", categoryLabel },
{ "failedSubcategory", terminalArgs.FailedSubcategory ?? "category-level" },
{ "failureType", terminalArgs.FailureType },
{ "minutesSinceFailure", minutesSinceFailure },
};
if (!string.IsNullOrEmpty(terminalArgs.ErrorCode))
data["errorCode"] = terminalArgs.ErrorCode;
if (subcategoryStatus != null)
data["subcategoryState"] = subcategoryStatus;
_post.Emit(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
EventType = Constants.EventTypes.EspFailureRecovered,
Severity = EventSeverity.Info,
Source = "EspAndHelloTracker",
Phase = EnrollmentPhase.Unknown,
Message = $"ESP failure recovered — {categoryLabel}/{terminalArgs.FailedSubcategory ?? "category-level"} " +
$"completed successfully {minutesSinceFailure} min after the failure; the earlier ESP failure no longer applies.",
Data = data,
ImmediateUpload = true
});
}
private int MinutesSinceTerminalFailure(string categoryName)
{
if (_provisioningFailureTerminalUtc != null
&& _provisioningFailureTerminalUtc.TryGetValue(categoryName, out var firedAt))
{
return Math.Max(0, (int)Math.Round((DateTime.UtcNow - firedAt).TotalMinutes));
}
return 0;
}
private void EmitFailureSettleStarted(EspFailureDetectedEventArgs args)
{
var data = new Dictionary<string, object>
@@ -1863,6 +2043,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
_provisioningFailureSettleTimers = new Dictionary<string, Timer>(StringComparer.OrdinalIgnoreCase);
if (_provisioningFailureSettleArgs == null)
_provisioningFailureSettleArgs = new Dictionary<string, EspFailureDetectedEventArgs>(StringComparer.OrdinalIgnoreCase);
if (_provisioningFailureTerminalArgs == null)
_provisioningFailureTerminalArgs = new Dictionary<string, EspFailureDetectedEventArgs>(StringComparer.OrdinalIgnoreCase);
if (_provisioningFailureTerminalUtc == null)
_provisioningFailureTerminalUtc = new Dictionary<string, DateTime>(StringComparer.OrdinalIgnoreCase);
if (_postFailureRetryEmitted == null)
_postFailureRetryEmitted = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
if (_postFailureRecoveredEmitted == null)
_postFailureRecoveredEmitted = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
}
}
@@ -37,8 +37,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
/// <see cref="StallProbeCollectorAdapter"/>. Owns its 60-s idle-check timer (the
/// collector itself has no timer — it's a pure probe invoked from outside).</item>
/// <item><b>EspPolicyProviderStallHost</b> — always-on 60-s wall-clock tick for the
/// <c>esp_policy_provider_stalled</c> tripwire (registered EnrollmentStatusTracking CSP
/// provider continuously incomplete ≥ 15 min — the no-timeout ESP wait).</item>
/// two-arm <c>esp_policy_provider_stalled</c> tripwire (EnrollmentStatusTracking CSP
/// provider continuously incomplete ≥ 15 min, OR Setup\Apps providers registered
/// without the expected <c>Sidecar</c>/IME provider — the no-timeout ESP wait).</item>
/// </list>
/// Optional peripheral hosts (driven by <see cref="CollectorConfiguration"/> toggles):
/// <list type="bullet">
@@ -307,11 +308,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
}
// ESP policy-provider stall tripwire — always-on kernel host (no config gate, like
// disk_space_low): a registered EnrollmentStatusTracking CSP provider that never
// completes (e.g. co-management "ConfigMgr" without "Sidecar" on a pre-provisioned
// device) parks the user ESP at "Apps (Identifying)" WITHOUT any OS timeout. Wall-clock
// dwell, deliberately outside the StallProbe gate: the idle clock there resets on any
// session activity, and the stall must accrue regardless of it.
// disk_space_low): a provider that never completes, or co-management "ConfigMgr"
// registered without the expected "Sidecar"/IME provider (issue #106 — even with
// TrackingPoliciesCreated=1 the ESP ignores foreign provider names), parks the user
// ESP at "Apps (Identifying)" WITHOUT any OS timeout. Wall-clock dwell, deliberately
// outside the StallProbe gate: the idle clock there resets on any session activity,
// and the stall must accrue regardless of it.
hosts.Add(new EspPolicyProviderStallHost(
sessionId: sessionId,
tenantId: tenantId,
@@ -111,6 +111,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
logger: logger,
matchLogPath: expandedMatchLogPath,
stateDirectory: stateDirectory);
// Historic-replay guard runs against the agent clock, not the raw system clock —
// keeps the tracker's staleness verdicts consistent with the adapter's clamp.
_tracker.UtcNowProvider = () => clock.UtcNow;
if (simulationMode)
{
@@ -1,6 +1,7 @@
#nullable enable
using System;
using System.Collections.Generic;
using System.Globalization;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.DecisionCore.Engine;
@@ -267,6 +268,14 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
payload["failedSubcategory"] = failedSubcategory!;
if (!string.IsNullOrEmpty(category))
payload["category"] = category!;
// Session 4910a5a5: culprit-app names ride the signal so the DecisionEngine's
// esp_failure_advisory / enrollment_failed events can name them directly.
var culprits = args?.LikelyCulpritApps;
if (culprits != null && culprits.Count > 0)
{
payload["likelyCulpritApps"] = string.Join(", ", culprits);
payload["likelyCulpritAppCount"] = culprits.Count.ToString(CultureInfo.InvariantCulture);
}
_ingress.Post(
kind: DecisionSignalKind.EspTerminalFailure,
@@ -97,12 +97,24 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
// bootstrap marker line. Lets MCP report "which device runs which bootstrap version".
private bool _bootstrapDetectedPosted;
// One-shot: historic script replay detected (a previous enrollment's IME log content
// surviving on disk) — its script events are suppressed, and a single
// historic_ime_replay_detected Info event explains the gap in the timeline.
private bool _historicReplayNoted;
private int _suppressedHistoricReplayEvents; // forensic count for the log line
// A platform script whose observed run duration reaches this is treated as having hit the
// IME script-execution timeout (default ~30 min). 25 min leaves headroom below 30 so clock
// jitter / the agent's late replay window can't miss it, while staying well above any
// legitimately long install wrapper that completes on its own.
private static readonly TimeSpan ScriptTimeoutSuspectedThreshold = TimeSpan.FromMinutes(25);
// Source log lines older than this relative to the clock are pathological — shared by
// ResolveOccurredAt's staleness clamp, the historic-replay suppression, the duration
// plausibility backstop AND the tracker's app-mutation guard (single source of truth
// in ImeLogTracker so the layers can never drift apart).
private static readonly TimeSpan StaleSourceThreshold = ImeLogTracker.HistoricReplayThreshold;
// Matches the deterministic marker line the bootstrap script writes via Write-Log,
// e.g. "Bootstrap script version: v2.0" — see scripts/Bootstrap/Install-AutopilotMonitor.ps1.
// Same shape as the web-side regex in utils/bootstrapVersion.ts; kept in sync intentionally.
@@ -289,17 +301,11 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
rawSourceTimestamp = sourceTsOverride ?? _tracker.LastMatchedLogTimestamp;
if (rawSourceTimestamp.HasValue)
{
// CMTrace log timestamps from IME are emitted in UTC, but DateTimeKind may
// arrive as Unspecified depending on the parser path. Normalize via
// SpecifyKind=Utc rather than ToUniversalTime() to avoid double-conversion
// when Kind is already UTC.
var asUtc = rawSourceTimestamp.Value.Kind == DateTimeKind.Utc
? rawSourceTimestamp.Value
: DateTime.SpecifyKind(rawSourceTimestamp.Value, DateTimeKind.Utc);
var asUtc = NormalizeUtc(rawSourceTimestamp.Value);
var clockNow = _clock.UtcNow;
var ageHours = (clockNow - asUtc).TotalHours;
if (ageHours > 24.0 || ageHours < -1.0)
if (ageHours > StaleSourceThreshold.TotalHours || ageHours < -1.0)
{
// Pathologically stale (>24h old) or in the future (>1h skew) — log,
// fall back, and let the caller flag the event.
@@ -325,6 +331,67 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
data["rejectedSourceTimestamp"] = rawSourceTs.Value.ToString("o", System.Globalization.CultureInfo.InvariantCulture);
}
// CMTrace Kind normalization — shared implementation lives on the tracker (used by its
// historic-replay guard too).
private static DateTime NormalizeUtc(DateTime value) => ImeLogTracker.NormalizeUtc(value);
/// <summary>
/// True when an event's source log line is a historic replay: the source timestamp
/// was rejected as stale (> <see cref="StaleSourceThreshold"/> in the PAST). Those lines
/// are script runs and app installs from a previous enrollment whose IME log survived on
/// disk (session eaf3d8c4: 156 replayed script completions + 147 replayed app events
/// shown as current activity, immediate-upload flood → ingress_backpressure). Future-skew
/// rejections (negative age — mid-enrollment clock jump) and clock-only fallbacks (no
/// source timestamp at all) are NOT replay and must still emit. Emits the one-shot
/// <c>historic_ime_replay_detected</c> summary on the first suppression; replay is
/// chronological, so that first suppressed line carries the earliest rejected source
/// timestamp. Bypassed in <see cref="ImeLogTracker.SimulationMode"/> — the
/// --replay-log-dir dev tool feeds historic lines on purpose.
/// </summary>
private bool SuppressIfHistoricReplay(
bool derivedFromClock, DateTime? rawSourceTs, string eventLabel, string entityId)
{
if (_tracker.SimulationMode) return false;
if (!derivedFromClock || !rawSourceTs.HasValue) return false;
var asUtc = NormalizeUtc(rawSourceTs.Value);
var clockNow = _clock.UtcNow;
var age = clockNow - asUtc;
if (age <= StaleSourceThreshold) return false; // future-skew or fresh → emit
bool emitSummary;
int suppressedSoFar;
lock (_lock)
{
suppressedSoFar = ++_suppressedHistoricReplayEvents;
emitSummary = !_historicReplayNoted;
_historicReplayNoted = true;
}
if (emitSummary)
{
var culture = System.Globalization.CultureInfo.InvariantCulture;
// Standard batch upload on purpose — no immediateUpload; the whole point of the
// suppression is to stop the replayed batch from flooding the ingest.
_post.Emit(
eventType: SharedEventTypes.HistoricImeReplayDetected,
source: SourceLabel,
message: "Historic IME activity from a previous enrollment detected in the log "
+ $"(earliest source timestamp {asUtc:o}) — its script and app events are suppressed for this session.",
severity: EventSeverity.Info,
data: new Dictionary<string, string>(StringComparer.Ordinal)
{
["decision"] = "historic_ime_replay_suppressed",
["earliestRejectedSourceTimestamp"] = asUtc.ToString("o", culture),
["staleThresholdHours"] = StaleSourceThreshold.TotalHours.ToString("F0", culture),
});
}
_logger?.Debug(
$"ImeAdapter: suppressed historic {eventLabel} for {entityId} "
+ $"(source ts {asUtc:o}, age {age.TotalHours:F1}h, suppressed so far: {suppressedSoFar})");
return true;
}
private void EmitEspPhase(string phase)
{
if (string.IsNullOrEmpty(phase)) return;
@@ -504,6 +571,14 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
var now = ResolveOccurredAt(out var derivedFromClock, out var rawSourceTs);
// Historic replay (a previous enrollment's log) — do not emit at all. Placed BEFORE
// the sub-phase declaration, the timing bookkeeping and the terminal-signal dedup so
// a replayed app neither consumes the fire-once flags nor poisons _appTimings (which
// feeds FinalStatusBuilder) nor posts a phantom DecisionSignal. The early return also
// covers the shadow download_progress and the app_tracking_summary snapshot below.
if (SuppressIfHistoricReplay(derivedFromClock, rawSourceTs, $"app-state {oldState}->{newState}", app.Id))
return;
// Plan §5 Fix 2: first app activity in a given ESP phase opens the sub-phase on
// the UI timeline via a `phase_transition` declaration event. Fire-once per ESP
// phase; emission happens BEFORE the actual app_* event so the UI sees the phase
@@ -819,6 +894,11 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
if (!string.IsNullOrEmpty(patternId)) data["patternId"] = patternId!;
var now = ResolveOccurredAt(out var derivedFromClock, out var rawSourceTs);
// Historic replay — a week-old DO summary is not this enrollment's download.
if (SuppressIfHistoricReplay(derivedFromClock, rawSourceTs, SharedEventTypes.DoTelemetry, app.Id))
return;
TagDerivedTimestamp(data, derivedFromClock, rawSourceTs);
var label = string.IsNullOrEmpty(app.Name) ? app.Id : app.Name;
@@ -910,13 +990,27 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
now = ResolveOccurredAt(script.ExitObservedAtUtc, out derivedFromClock, out rawSourceTs);
else
now = ResolveOccurredAt(out derivedFromClock, out rawSourceTs);
// Historic replay (a previous enrollment's log) — do not emit at all. The early
// return also skips MaybeEmitBootstrapDetected / MaybeEmitScriptTimeoutSuspected,
// which would otherwise fire on week-old evidence.
if (SuppressIfHistoricReplay(derivedFromClock, rawSourceTs, eventType, script.PolicyId))
return;
TagDerivedTimestamp(data, derivedFromClock, rawSourceTs);
// Per-script run duration (start line → this completion, `now`). Surfaced on every
// Per-script run duration (start line → this completion). Surfaced on every
// script completion so the UI can flag slow / inefficient scripts, not just timed-out
// ones. Omitted when the start line was never observed (StartedAtUtc null); clamped at 0
// against clock skew between the (possibly clock-derived) completion stamp and start.
//
// When the completion timestamp was clock-derived because the source line's timestamp
// was rejected (future-skew CMTrace clock jump — the stale case never reaches here),
// `now` lives on the clock's timeline while StartedAtUtc was captured RAW from the
// source log. Mixing the two produced absurd durations (session eaf3d8c4: 170 h), so
// the duration uses the raw source pair — both ends on the same timeline, the
// difference is the true runtime. The event stamp stays `now` (timeline position).
//
// L19 (delta review 2026-07-02): the same field name carries two different semantics —
// start→own-end-signal (≈ script runtime) vs HS-SCRIPT-START→HS-NEW-RESULT (the whole
// cycle INCLUDING IME's 30 s–3 min batched reporting latency, i.e. systematically
@@ -924,10 +1018,16 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
// consumers never compare the two as equals. The emitting handler stamps the basis on
// the state (health-script early-signal completions are script_runtime too); the
// scriptType fallback covers states from paths that predate the field.
var completionForDuration = derivedFromClock && rawSourceTs.HasValue
? NormalizeUtc(rawSourceTs.Value)
: now;
if (script.StartedAtUtc.HasValue)
{
var durationSeconds = (now - script.StartedAtUtc.Value).TotalSeconds;
if (durationSeconds >= 0)
var durationSeconds = (completionForDuration - script.StartedAtUtc.Value).TotalSeconds;
// Plausibility backstop: IME's script execution timeout is ~30 min; anything above
// 24 h is a cross-run artifact (e.g. a stale pending start slot from a previous
// enrollment paired with a fresh completion) — omit rather than lie.
if (durationSeconds >= 0 && durationSeconds <= StaleSourceThreshold.TotalSeconds)
{
data["durationSeconds"] = durationSeconds.ToString("F2", culture);
data["durationBasis"] = script.DurationBasis
@@ -979,7 +1079,7 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
$"ImeAdapter: script completed policyId={shortId} type={script.ScriptType ?? "?"} result={script.Result ?? "?"} exit={(script.ExitCode.HasValue ? script.ExitCode.Value.ToString() : "n/a")}");
MaybeEmitBootstrapDetected(script, now);
MaybeEmitScriptTimeoutSuspected(script, now);
MaybeEmitScriptTimeoutSuspected(script, now, completionForDuration);
}
/// <summary>
@@ -991,15 +1091,19 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
/// late start / pre-failed ESP. Advisory only: no state mutation, the underlying
/// <c>script_failed</c> is still emitted separately. Health (remediation) scripts are
/// excluded — they re-run on their own cadence and have a different timeout regime.
/// <paramref name="durationEndUtc"/> is the timeline-consistent completion for duration
/// math (raw source ts on rejected-timestamp emissions); <paramref name="occurredAtUtc"/>
/// stamps the emitted event.
/// </summary>
private void MaybeEmitScriptTimeoutSuspected(ScriptExecutionState script, DateTime completionUtc)
private void MaybeEmitScriptTimeoutSuspected(ScriptExecutionState script, DateTime occurredAtUtc, DateTime durationEndUtc)
{
if (IsRemediation(script.ScriptType)) return; // platform scripts only
if (!script.StartedAtUtc.HasValue) return; // no start ⇒ no duration
if (!string.Equals(script.Result, "Failed", StringComparison.OrdinalIgnoreCase)) return;
var duration = completionUtc - script.StartedAtUtc.Value;
var duration = durationEndUtc - script.StartedAtUtc.Value;
if (duration < ScriptTimeoutSuspectedThreshold) return;
if (duration > StaleSourceThreshold) return; // implausible — cross-run artifact, not a hung script
if (!_tracker.TryClaimScriptTimeoutSuspected(script.PolicyId)) return; // restart-safe dedup per policyId (persisted tracker state)
@@ -1026,7 +1130,7 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
message: $"Platform script {shortId} ran {durationMinutes:F0} min and was marked Failed — suspected IME script timeout blocking the enrollment.",
severity: EventSeverity.Warning,
data: data,
occurredAtUtc: completionUtc);
occurredAtUtc: occurredAtUtc);
_logger?.Info(
$"ImeAdapter: script_timeout_suspected policyId={shortId} duration={durationMinutes:F1}min result={script.Result} espPhase={espPhase ?? "(none)"}");
@@ -1081,6 +1185,12 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
if (!string.IsNullOrEmpty(patternId)) data["patternId"] = patternId!;
var now = ResolveOccurredAt(out var derivedFromClock, out var rawSourceTs);
// Historic replay — suppressing here also kills the immediateUpload flood the
// replayed batch caused (session eaf3d8c4: 3× ingress_backpressure).
if (SuppressIfHistoricReplay(derivedFromClock, rawSourceTs, SharedEventTypes.ScriptStarted, info.PolicyId))
return;
TagDerivedTimestamp(data, derivedFromClock, rawSourceTs);
var label = IsRemediation(info.ScriptType) ? "Health script" : "Platform script";
@@ -0,0 +1,382 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.DecisionCore.Serialization;
using AutopilotMonitor.DecisionCore.Signals;
using AutopilotMonitor.DecisionCore.State;
using Xunit;
namespace AutopilotMonitor.DecisionCore.Tests
{
/// <summary>
/// Session 4910a5a5 (2026-07-23) — advisory recovery. Field failure: DeviceSetup/Apps
/// failed (culprit app never started installing), the advisory defang armed the
/// <c>advisory_completion</c> window, the user pressed "Try again" ~23 min later, the apps
/// re-ran to 10/10 and <c>DeviceSetupProvisioningComplete</c> arrived — yet the window
/// fired 30 min after the advisory and un-defanged the stale failure
/// (<c>enrollment_failed: esp_terminal_failure</c>) on a live enrollment mid-AccountSetup,
/// because the advisory variant was exempt from ALL re-arm/rebase guards. Coverage:
/// <list type="bullet">
/// <item>The advisory records the failed category + culprit apps.</item>
/// <item>A ProvisioningComplete of the SAME category sets the resolved fact + emits
/// <c>esp_failure_advisory_resolved</c>; a different category does not.</item>
/// <item>Deadline fire after recovery + enforcement progress → re-arm, not Failed.</item>
/// <item>Deadline fire after recovery without progress → Failed with the truthful
/// <c>esp_recovered_without_completion_evidence</c> reason and
/// LastFailureTrigger=DeadlineFired (likely-stuck promotion off).</item>
/// <item>Unrecovered advisory keeps the legacy un-defang exactly (regression guard).</item>
/// <item>Reboot re-bases a recovered-advisory window (and still does NOT touch an
/// unrecovered one).</item>
/// <item>Snapshot round-trip + census surfacing of the new facts.</item>
/// </list>
/// </summary>
public sealed class AdvisoryRecoveryTests
{
private static readonly DateTime T0 = new DateTime(2026, 7, 23, 3, 30, 0, DateTimeKind.Utc);
private static DecisionSignal MakeSignal(
long ordinal,
DecisionSignalKind kind,
DateTime occurredAtUtc,
IReadOnlyDictionary<string, string>? payload = null)
{
return new DecisionSignal(
sessionSignalOrdinal: ordinal,
sessionTraceOrdinal: ordinal,
kind: kind,
kindSchemaVersion: 1,
occurredAtUtc: occurredAtUtc,
sourceOrigin: "test",
evidence: new Evidence(EvidenceKind.Synthetic, $"{kind}-{ordinal}", "test"),
payload: payload);
}
private static DecisionSignal DeadlineFired(long ordinal, DateTime occurredAtUtc) =>
MakeSignal(ordinal, DecisionSignalKind.DeadlineFired, occurredAtUtc,
new Dictionary<string, string> { [SignalPayloadKeys.Deadline] = DeadlineNames.AdvisoryCompletion });
private static DecisionEffect? FindTimelineEffect(DecisionStep step, string eventType) =>
step.Effects.FirstOrDefault(e =>
e.Kind == DecisionEffectKind.EmitEventTimelineEntry
&& e.Parameters != null
&& e.Parameters.TryGetValue("eventType", out var et)
&& et == eventType);
private static ActiveDeadline? FindDeadline(DecisionState state, string name) =>
state.Deadlines.FirstOrDefault(d => d.Name == name);
/// <summary>
/// Replays the session-4910a5a5 shape up to (but excluding) the ESP terminal failure:
/// Classic UserDriven, ContinueAnyway profile, Hello disabled, DeviceSetup entered,
/// AccountSetup entered (04:18, BEFORE the 04:34 DeviceSetup/Apps failure — the IME
/// phase line landed while device apps were still at 9/10).
/// </summary>
private static DecisionState SetupSession(DecisionEngine engine)
{
var state = DecisionState.CreateInitial("sess-4910a5a5", "tenant-e46bc88e", T0);
state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0)).NewState;
state = engine.Reduce(state, MakeSignal(
5, DecisionSignalKind.EspConfigDetected, T0.AddMinutes(1),
new Dictionary<string, string>
{
[SignalPayloadKeys.SkipUserEsp] = "false",
[SignalPayloadKeys.SkipDeviceEsp] = "false",
[SignalPayloadKeys.EspSyncFailureTimeoutMinutes] = "60",
[SignalPayloadKeys.EspAllowContinueAnyway] = "true",
})).NewState;
state = engine.Reduce(state, MakeSignal(
8, DecisionSignalKind.HelloPolicyDetected, T0.AddMinutes(2),
new Dictionary<string, string> { [SignalPayloadKeys.HelloEnabled] = "false" })).NewState;
state = engine.Reduce(state, MakeSignal(
10, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(6),
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "DeviceSetup" })).NewState;
state = engine.Reduce(state, MakeSignal(
20, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(48),
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
return state;
}
private static DecisionStep ApplyDeviceSetupAppsFailure(DecisionEngine engine, DecisionState state, long ordinal = 50) =>
engine.Reduce(state, MakeSignal(
ordinal, DecisionSignalKind.EspTerminalFailure, T0.AddMinutes(64),
new Dictionary<string, string>
{
["failureType"] = "Provisioning_DeviceSetup_Apps_Failed",
["failedSubcategory"] = "Apps",
["category"] = "DeviceSetup",
["likelyCulpritApps"] = "Oriflame Cosmectics - Teams Backgroundsv v2",
["likelyCulpritAppCount"] = "1",
}));
private static DecisionStep ApplyDeviceSetupResolved(DecisionEngine engine, DecisionState state, long ordinal = 60) =>
engine.Reduce(state, MakeSignal(
ordinal, DecisionSignalKind.DeviceSetupProvisioningComplete, T0.AddMinutes(87)));
// ================================================== advisory arming context ====
[Fact]
public void Advisory_RecordsFailedCategory_AndCulpritApps()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
var step = ApplyDeviceSetupAppsFailure(engine, state);
Assert.NotNull(step.NewState.EspAdvisoryFailureRecordedUtc);
Assert.Equal("DeviceSetup", step.NewState.EspAdvisoryFailureCategory?.Value);
Assert.Null(step.NewState.EspAdvisoryFailureResolvedUtc);
var advisory = FindTimelineEffect(step, "esp_failure_advisory");
Assert.NotNull(advisory);
Assert.Equal("Oriflame Cosmectics - Teams Backgroundsv v2", advisory!.Parameters!["likelyCulpritApps"]);
}
// ===================================================== recovery hook ====
[Fact]
public void DeviceSetupComplete_SameCategory_ResolvesAdvisory_AndEmitsStoryEvent()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
var step = ApplyDeviceSetupResolved(engine, state);
Assert.NotNull(step.NewState.EspAdvisoryFailureResolvedUtc);
Assert.Equal(60, step.NewState.EspAdvisoryFailureResolvedUtc!.SourceSignalOrdinal);
// The anchor itself stays — the advisory happened; it just no longer blocks.
Assert.NotNull(step.NewState.EspAdvisoryFailureRecordedUtc);
var resolved = FindTimelineEffect(step, "esp_failure_advisory_resolved");
Assert.NotNull(resolved);
Assert.Equal("DeviceSetup", resolved!.Parameters!["category"]);
Assert.Equal("23", resolved.Parameters["minutesSinceAdvisory"]);
}
[Fact]
public void DeviceSetupComplete_DifferentCategory_DoesNotResolve()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
// Advisory for AccountSetup — DeviceSetup resolving must not defuse it.
state = engine.Reduce(state, MakeSignal(
50, DecisionSignalKind.EspTerminalFailure, T0.AddMinutes(64),
new Dictionary<string, string>
{
["failureType"] = "Provisioning_AccountSetup_Apps_Failed",
["failedSubcategory"] = "Apps",
["category"] = "AccountSetup",
})).NewState;
var step = ApplyDeviceSetupResolved(engine, state);
Assert.Null(step.NewState.EspAdvisoryFailureResolvedUtc);
Assert.Null(FindTimelineEffect(step, "esp_failure_advisory_resolved"));
}
[Fact]
public void DeviceSetupComplete_Duplicate_ResolvesOnlyOnce()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
// Post-reboot duplicate (AnchorAlreadySet passthrough branch).
var duplicate = engine.Reduce(state, MakeSignal(
65, DecisionSignalKind.DeviceSetupProvisioningComplete, T0.AddMinutes(92)));
Assert.Equal(60, duplicate.NewState.EspAdvisoryFailureResolvedUtc!.SourceSignalOrdinal);
Assert.Null(FindTimelineEffect(duplicate, "esp_failure_advisory_resolved"));
}
// ================================================ deadline fire semantics ====
[Fact]
public void DeadlineFire_AfterRecovery_WithEnforcementProgress_ReArmsInsteadOfFailing()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
// Post-reboot IME re-assert of AccountSetup (session shape: 05:02:59, ordinal 654)
// — user-phase enforcement demonstrably progressed since the arming at ordinal 50.
state = engine.Reduce(state, MakeSignal(
70, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(92),
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
var step = engine.Reduce(state, DeadlineFired(80, T0.AddMinutes(94)));
// Not failed — the window re-arms with fresh baselines instead.
Assert.Null(step.NewState.Outcome);
Assert.NotEqual(SessionStage.Failed, step.NewState.Stage);
var rearmed = FindDeadline(step.NewState, DeadlineNames.AdvisoryCompletion);
Assert.NotNull(rearmed);
Assert.Equal(T0.AddMinutes(94).AddMinutes(30), rearmed!.DueAtUtc);
Assert.Contains(step.Effects, e => e.Kind == DecisionEffectKind.ScheduleDeadline);
}
[Fact]
public void DeadlineFire_AfterRecovery_NoProgress_FailsWithRecoveredReason()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
var step = engine.Reduce(state, DeadlineFired(80, T0.AddMinutes(94)));
Assert.Equal(SessionStage.Failed, step.NewState.Stage);
Assert.Equal(SessionOutcome.EnrollmentFailed, step.NewState.Outcome);
var failed = FindTimelineEffect(step, "enrollment_failed");
Assert.NotNull(failed);
// Truthful reason: the original failure recovered — do not blame it.
Assert.Equal("esp_recovered_without_completion_evidence", failed!.Parameters!["reason"]);
Assert.Equal("true", failed.Parameters["failureRecovered"]);
Assert.Equal("advisory_recovered_window_expired_without_completion_evidence", failed.Parameters["advisoryReason"]);
// Likely-stuck app promotion stays off: apps are not stuck, they succeeded.
Assert.Equal(nameof(DecisionSignalKind.DeadlineFired), step.NewState.LastFailureTrigger?.Value);
}
[Fact]
public void DeadlineFire_WithoutRecovery_KeepsLegacyUndefang()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
// No recovery — even with enforcement progress the advisory variant must
// un-defang exactly as before (its anchor failure never un-happened).
state = engine.Reduce(state, MakeSignal(
70, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(92),
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
var step = engine.Reduce(state, DeadlineFired(80, T0.AddMinutes(94)));
Assert.Equal(SessionStage.Failed, step.NewState.Stage);
var failed = FindTimelineEffect(step, "enrollment_failed");
Assert.NotNull(failed);
Assert.Equal("esp_terminal_failure", failed!.Parameters!["reason"]);
Assert.Equal(nameof(DecisionSignalKind.EspTerminalFailure), step.NewState.LastFailureTrigger?.Value);
}
// ======================================================= reboot rebase ====
[Fact]
public void Reboot_AfterRecovery_RebasesAdvisoryWindow()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
var step = engine.Reduce(state, MakeSignal(
70, DecisionSignalKind.SystemRebootObserved, T0.AddMinutes(92)));
Assert.Contains(step.Effects, e =>
e.Kind == DecisionEffectKind.CancelDeadline
&& e.CancelDeadlineName == DeadlineNames.AdvisoryCompletion);
var rebased = FindDeadline(step.NewState, DeadlineNames.AdvisoryCompletion);
Assert.NotNull(rebased);
Assert.Equal(T0.AddMinutes(92).AddMinutes(30), rebased!.DueAtUtc);
}
[Fact]
public void Reboot_WithoutRecovery_DoesNotTouchAdvisoryWindow()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
var originalDue = FindDeadline(state, DeadlineNames.AdvisoryCompletion)!.DueAtUtc;
var step = engine.Reduce(state, MakeSignal(
70, DecisionSignalKind.SystemRebootObserved, T0.AddMinutes(92)));
Assert.DoesNotContain(step.Effects, e => e.Kind == DecisionEffectKind.CancelDeadline);
Assert.Equal(originalDue, FindDeadline(step.NewState, DeadlineNames.AdvisoryCompletion)!.DueAtUtc);
}
// ============================================== full session-4910a5a5 replay ====
[Fact]
public void Session4910a5a5_FailureRecoveryRebootFire_DoesNotFailTheLiveEnrollment()
{
// Field ordinals: 527 EspTerminalFailure → 611 DeviceSetupProvisioningComplete
// (post "Try again", apps 10/10) → 635 SystemRebootObserved → 654 AccountSetup
// re-assert → 671 DeadlineFired. Pre-fix outcome: enrollment_failed at the fire.
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state, ordinal: 527).NewState;
state = ApplyDeviceSetupResolved(engine, state, ordinal: 611).NewState;
state = engine.Reduce(state, MakeSignal(
635, DecisionSignalKind.SystemRebootObserved, T0.AddMinutes(92))).NewState;
state = engine.Reduce(state, MakeSignal(
654, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(93),
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
var step = engine.Reduce(state, DeadlineFired(671, T0.AddMinutes(94)));
Assert.Null(step.NewState.Outcome);
Assert.NotEqual(SessionStage.Failed, step.NewState.Stage);
Assert.NotNull(FindDeadline(step.NewState, DeadlineNames.AdvisoryCompletion));
}
// =============================================== serialization + census ====
[Fact]
public void SnapshotRoundTrip_PreservesRecoveryFacts()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
var roundtripped = StateSerializer.Deserialize(StateSerializer.Serialize(state));
Assert.Equal("DeviceSetup", roundtripped.EspAdvisoryFailureCategory?.Value);
Assert.Equal(state.EspAdvisoryFailureResolvedUtc!.Value, roundtripped.EspAdvisoryFailureResolvedUtc?.Value);
Assert.Equal(state.EspAdvisoryFailureResolvedUtc.SourceSignalOrdinal, roundtripped.EspAdvisoryFailureResolvedUtc?.SourceSignalOrdinal);
}
[Fact]
public void LegacySnapshot_WithoutRecoveryFacts_DeserializesToNull()
{
// Simulate a snapshot written by a pre-fix agent: strip the new properties from
// the JSON entirely — deserialization must default them to null (additive compat).
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
var legacy = Newtonsoft.Json.Linq.JObject.Parse(StateSerializer.Serialize(state));
foreach (var prop in legacy.Properties()
.Where(p => p.Name.IndexOf("EspAdvisoryFailureResolved", StringComparison.OrdinalIgnoreCase) >= 0
|| p.Name.IndexOf("EspAdvisoryFailureCategory", StringComparison.OrdinalIgnoreCase) >= 0)
.ToList())
{
prop.Remove();
}
var roundtripped = StateSerializer.Deserialize(legacy.ToString());
Assert.Null(roundtripped.EspAdvisoryFailureResolvedUtc);
Assert.Null(roundtripped.EspAdvisoryFailureCategory);
// The pre-existing advisory anchor still round-trips.
Assert.NotNull(roundtripped.EspAdvisoryFailureRecordedUtc);
}
[Fact]
public void Census_SurfacesAdvisoryResolved()
{
var engine = new DecisionEngine();
var state = SetupSession(engine);
state = ApplyDeviceSetupAppsFailure(engine, state).NewState;
state = ApplyDeviceSetupResolved(engine, state).NewState;
var census = DecisionStateSignalCensus.Build(state);
Assert.Contains("esp_advisory_failure_resolved", census.SignalsSeen);
Assert.True(census.SignalTimestamps.ContainsKey("espAdvisoryFailureResolved"));
}
}
}
@@ -114,7 +114,10 @@ namespace AutopilotMonitor.DecisionCore.Tests
// state-change-only dedupe anchor for the completion_waiting event → 17.
// Session 772fe502 (2026-07-13) added `helloWizardStartedUtc` — genuine
// Shell-Core 62404 wizard launch; vetoes the policy-disabled Hello skip → 18.
Assert.Equal(18, facts.Count);
// Session 4910a5a5 (2026-07-23) added `espAdvisoryFailureResolvedUtc` (the failed
// category recovered — lifts the advisory's re-arm/rebase guard exemption) and
// `espAdvisoryFailureCategory` (which category the advisory was for) → 20.
Assert.Equal(20, facts.Count);
Assert.All(facts.Values, v => Assert.Null(v));
}
@@ -236,10 +239,12 @@ namespace AutopilotMonitor.DecisionCore.Tests
// `completionWaitingFingerprint` as the state-change-only dedupe anchor for
// the completion_waiting event → 17. Session 772fe502 (2026-07-13) added
// `helloWizardStartedUtc` — the genuine Shell-Core 62404 wizard-launch fact
// that vetoes/retracts the policy-disabled Hello skip → 18. If this number
// ever changes, both the count expectation AND the actual snapshot output
// need to evolve in lockstep.
Assert.Equal(18, expectedFactKeys.Count);
// that vetoes/retracts the policy-disabled Hello skip → 18. Session 4910a5a5
// (2026-07-23) added `espAdvisoryFailureResolvedUtc` + `espAdvisoryFailureCategory`
// — advisory-recovery facts that lift the AdvisoryCompletion guard exemption → 20.
// If this number ever changes, both the count expectation AND the actual snapshot
// output need to evolve in lockstep.
Assert.Equal(20, expectedFactKeys.Count);
var snapshot = DecisionStateSnapshotBuilder.Build(DecisionState.CreateInitial("s", "t"));
var facts = (Dictionary<string, object?>)snapshot["facts"]!;
@@ -0,0 +1,195 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text.Json;
using System.Threading.Tasks;
using AutopilotMonitor.Functions.Functions.Apps;
using AutopilotMonitor.Shared.DataAccess;
using AutopilotMonitor.Shared.Models;
using Moq;
using Xunit;
namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Pins the terminal-only failure-rate convention on the Apps dashboard aggregations
/// (<see cref="AppsAnalyticsHelper"/>): every failureRate is Failed / (Failed + Succeeded) —
/// finished installs only. "InProgress" rows (still installing, or orphaned by a session that
/// died mid-install) sit in the install counts but never dilute a rate, matching the enrollment
/// success-rate convention. Responses are anonymous projections, so tests assert on the
/// JSON wire shape like the sibling suites.
/// </summary>
public class AppsAnalyticsFailureRateTests
{
private const string TenantId = "00000000-0000-0000-0000-000000000fa1";
private static AppInstallSummary A(
string status,
string appName = "Contoso App",
DateTime? startedAt = null,
string sessionId = "s-1",
string appVersion = "")
=> new()
{
TenantId = TenantId,
SessionId = sessionId,
AppName = appName,
AppVersion = appVersion,
Status = status,
StartedAt = startedAt ?? DateTime.UtcNow.AddHours(-2),
DurationSeconds = status == "Succeeded" ? 30 : 0,
};
// ── /apps/list ──────────────────────────────────────────────────────────
[Fact]
public void List_FailureRate_IsOverFinishedInstalls_InProgressExcluded()
{
var summaries = new List<AppInstallSummary>
{
A("Failed"),
A("Succeeded"),
A("InProgress"),
A("InProgress"),
};
var root = JsonSerializer.SerializeToElement(
AppsAnalyticsHelper.BuildAppsListResponse(summaries, days: 30));
var app = root.GetProperty("apps")[0];
Assert.Equal(4, app.GetProperty("totalInstalls").GetInt32());
// 1 / (1 + 1) = 50% (over finished), NOT 1 / 4 = 25% (over all installs).
Assert.Equal(50d, app.GetProperty("failureRate").GetDouble());
}
[Fact]
public void List_FailureRate_IsZero_WhenNothingFinishedYet()
{
var summaries = new List<AppInstallSummary> { A("InProgress"), A("InProgress") };
var root = JsonSerializer.SerializeToElement(
AppsAnalyticsHelper.BuildAppsListResponse(summaries, days: 30));
Assert.Equal(0d, root.GetProperty("apps")[0].GetProperty("failureRate").GetDouble());
}
[Fact]
public void List_Trend_UsesFinishedRates_AndGatesOnFinishedSamples()
{
var now = DateTime.UtcNow;
var firstHalf = now.AddDays(-20); // days: 30 → midpoint at now - 15d
var secondHalf = now.AddDays(-5);
var summaries = new List<AppInstallSummary>();
// First half: 1 failed / 5 finished = 20%.
summaries.Add(A("Failed", startedAt: firstHalf));
for (var i = 0; i < 4; i++) summaries.Add(A("Succeeded", startedAt: firstHalf));
// Second half: 3 failed / 5 finished = 60% — plus 10 in-flight installs that
// previously dragged the half's rate down to 20% and masked the regression.
for (var i = 0; i < 3; i++) summaries.Add(A("Failed", startedAt: secondHalf));
for (var i = 0; i < 2; i++) summaries.Add(A("Succeeded", startedAt: secondHalf));
for (var i = 0; i < 10; i++) summaries.Add(A("InProgress", startedAt: secondHalf));
var root = JsonSerializer.SerializeToElement(
AppsAnalyticsHelper.BuildAppsListResponse(summaries, days: 30));
var app = root.GetProperty("apps")[0];
Assert.Equal("worsening", app.GetProperty("trend").GetString());
Assert.Equal(40d, app.GetProperty("trendDelta").GetDouble());
}
[Fact]
public void List_Trend_StaysStable_WhenAHalfLacksFiveFinishedInstalls()
{
var now = DateTime.UtcNow;
var summaries = new List<AppInstallSummary>();
// First half: 5 finished. Second half: 4 finished + many in-flight — the old
// install-count gate would have passed; the finished-sample gate must not.
for (var i = 0; i < 5; i++) summaries.Add(A("Succeeded", startedAt: now.AddDays(-20)));
for (var i = 0; i < 4; i++) summaries.Add(A("Failed", startedAt: now.AddDays(-5)));
for (var i = 0; i < 10; i++) summaries.Add(A("InProgress", startedAt: now.AddDays(-5)));
var root = JsonSerializer.SerializeToElement(
AppsAnalyticsHelper.BuildAppsListResponse(summaries, days: 30));
var app = root.GetProperty("apps")[0];
Assert.Equal("stable", app.GetProperty("trend").GetString());
Assert.Equal(JsonValueKind.Null, app.GetProperty("trendDelta").ValueKind);
}
// ── /apps/{appName}/analytics ───────────────────────────────────────────
private static async Task<JsonElement> BuildAnalyticsAsync(
List<AppInstallSummary> summaries, ISessionRepository? sessionRepo = null)
{
if (sessionRepo == null)
{
var mock = new Mock<ISessionRepository>();
mock.Setup(r => r.GetSessionAsync(It.IsAny<string>(), It.IsAny<string>()))
.ReturnsAsync((SessionSummary?)null);
sessionRepo = mock.Object;
}
var result = await AppsAnalyticsHelper.BuildAnalyticsResponseAsync(
summaries, sessionRepo, "Contoso App", days: 30);
return JsonSerializer.SerializeToElement(result);
}
[Fact]
public async Task Analytics_SummaryVersionAndTimeSeriesRates_AreOverFinishedInstalls()
{
var summaries = new List<AppInstallSummary>
{
A("Failed", appVersion: "1.0"),
A("Succeeded", appVersion: "1.0"),
A("InProgress", appVersion: "1.0"),
A("InProgress", appVersion: "1.0"),
};
var root = await BuildAnalyticsAsync(summaries);
// Summary: 1 / (1 + 1) = 50%, NOT 1 / 4 = 25%.
var summary = root.GetProperty("summary");
Assert.Equal(4, summary.GetProperty("totalInstalls").GetInt32());
Assert.Equal(50d, summary.GetProperty("failureRate").GetDouble());
var version = root.GetProperty("versionBreakdown")[0];
Assert.Equal(4, version.GetProperty("installs").GetInt32());
Assert.Equal(50d, version.GetProperty("failureRate").GetDouble());
// All four installs land in today's bucket → same terminal-only rate there.
var buckets = root.GetProperty("timeSeries").EnumerateArray().ToList();
var todayBucket = buckets.Single(b => b.GetProperty("installs").GetInt32() > 0);
Assert.Equal(50d, todayBucket.GetProperty("failureRate").GetDouble());
}
[Fact]
public async Task Analytics_DeviceModelBreakdown_RatesAndSampleFloor_UseFinishedInstalls()
{
var sessionRepo = new Mock<ISessionRepository>();
sessionRepo.Setup(r => r.GetSessionAsync(TenantId, It.IsAny<string>()))
.ReturnsAsync((string _, string sessionId) => new SessionSummary
{
TenantId = TenantId,
SessionId = sessionId,
Manufacturer = "Contoso",
Model = sessionId.StartsWith("s-a") ? "ModelA" : "ModelB",
});
var summaries = new List<AppInstallSummary>();
// ModelA: 5 finished (1 failed → 20%) + 3 in-flight → ranked, rate undiluted.
summaries.Add(A("Failed", sessionId: "s-a-0"));
for (var i = 1; i <= 4; i++) summaries.Add(A("Succeeded", sessionId: $"s-a-{i}"));
for (var i = 5; i <= 7; i++) summaries.Add(A("InProgress", sessionId: $"s-a-{i}"));
// ModelB: 4 finished + 6 in-flight — 10 installs, but below the 5-finished floor.
for (var i = 0; i <= 3; i++) summaries.Add(A("Failed", sessionId: $"s-b-{i}"));
for (var i = 4; i <= 9; i++) summaries.Add(A("InProgress", sessionId: $"s-b-{i}"));
var root = await BuildAnalyticsAsync(summaries, sessionRepo.Object);
var breakdown = root.GetProperty("deviceModelBreakdown");
var model = Assert.Single(breakdown.EnumerateArray());
Assert.Equal("ModelA", model.GetProperty("model").GetString());
Assert.Equal(8, model.GetProperty("installs").GetInt32());
Assert.Equal(20d, model.GetProperty("failureRate").GetDouble());
}
}
@@ -10,9 +10,10 @@ namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Covers the server-side Fleet Health aggregation in
/// <see cref="MetricsMath.BuildFleetHealthPayload"/>, the single source of truth shared by the
/// tenant (metrics/fleet-health) and global (global/metrics/fleet-health) functions. These assert
/// the semantics ported verbatim from the previous client-side aggregation — notably success rate
/// over ALL sessions and average duration over non-in-progress sessions (failures included).
/// tenant (metrics/fleet-health) and global (global/metrics/fleet-health) functions. Success and
/// failure rates follow the SLA convention — over finished enrollments (Succeeded + Failed) only,
/// so in-flight sessions never dilute them. Average duration stays over non-in-progress sessions
/// that carry a duration (failures included).
/// </summary>
public class FleetHealthPayloadTests
{
@@ -55,7 +56,7 @@ public class FleetHealthPayloadTests
}
[Fact]
public void SuccessRate_IsOverAllSessions_NotJustTerminal()
public void SuccessRate_IsOverFinishedSessions_InFlightAndIncompleteExcluded()
{
var sessions = new List<SessionSummary>
{
@@ -63,16 +64,34 @@ public class FleetHealthPayloadTests
S(SessionStatus.Succeeded),
S(SessionStatus.Failed),
S(SessionStatus.InProgress),
S(SessionStatus.Pending),
S(SessionStatus.Incomplete), // terminal but non-failure — stays out of the rate
};
var payload = MetricsMath.BuildFleetHealthPayload(sessions, days: 7);
Assert.Equal(4, payload.Stats.Total);
Assert.Equal(6, payload.Stats.Total);
Assert.Equal(2, payload.Stats.Succeeded);
Assert.Equal(1, payload.Stats.Failed);
Assert.Equal(1, payload.Stats.InProgress);
// 2 / 4 = 50% (over total), NOT 2 / 3 = 66.7% (over terminal).
Assert.Equal(50d, payload.Stats.SuccessRate);
Assert.Equal(1, payload.Stats.Incomplete);
// 2 / (2 + 1) = 66.7% (over finished), NOT 2 / 6 = 33.3% (over total).
Assert.Equal(66.7d, payload.Stats.SuccessRate);
}
[Fact]
public void SuccessRate_IsZero_WhenNothingFinishedYet()
{
var sessions = new List<SessionSummary>
{
S(SessionStatus.InProgress),
S(SessionStatus.Pending),
};
var payload = MetricsMath.BuildFleetHealthPayload(sessions, days: 7);
// No finished enrollments → no rate; clients render "—" off Succeeded + Failed == 0.
Assert.Equal(0d, payload.Stats.SuccessRate);
}
[Fact]
@@ -111,6 +130,27 @@ public class FleetHealthPayloadTests
Assert.DoesNotContain(payload.ModelHealth, m => m.Model == "Contoso Model1");
}
[Fact]
public void ModelHealth_CountsFailedSeparately_InFlightInTotalOnly()
{
var sessions = new List<SessionSummary>
{
S(SessionStatus.Succeeded, model: "X"),
S(SessionStatus.Failed, model: "X"),
S(SessionStatus.InProgress, model: "X"),
};
var payload = MetricsMath.BuildFleetHealthPayload(sessions, days: 7);
var m = Assert.Single(payload.ModelHealth);
// Total keeps the full device count; the client derives the rate from
// Succeeded / (Succeeded + Failed), so the in-flight session must land
// in Total but in neither outcome bucket.
Assert.Equal(3, m.Total);
Assert.Equal(1, m.Succeeded);
Assert.Equal(1, m.Failed);
}
[Fact]
public void ModelKey_FallsBackToUnknown_WhenManufacturerAndModelBlank()
{
@@ -147,10 +187,13 @@ public class FleetHealthPayloadTests
{
var sessions = new List<SessionSummary>
{
// Model A: 1 failed of 2 → 50%
// Model A: 1 failed / 2 finished → 50%; the 2 in-flight sessions widen Total
// but must not dilute the rate (over-total it would read 25%).
S(SessionStatus.Failed, model: "A"),
S(SessionStatus.Succeeded, model: "A"),
// Model B: 2 failed of 2 → 100%
S(SessionStatus.InProgress, model: "A"),
S(SessionStatus.Pending, model: "A"),
// Model B: 2 failed of 2 finished → 100%
S(SessionStatus.Failed, model: "B"),
S(SessionStatus.Failed, model: "B"),
// Model C: no failures → excluded entirely
@@ -164,35 +207,37 @@ public class FleetHealthPayloadTests
Assert.Equal(2, payload.TopFailingModels[0].Failed);
Assert.Equal(100, payload.TopFailingModels[0].FailureRate);
Assert.Equal("Contoso A", payload.TopFailingModels[1].Model);
Assert.Equal(4, payload.TopFailingModels[1].Total);
Assert.Equal(50, payload.TopFailingModels[1].FailureRate);
Assert.DoesNotContain(payload.TopFailingModels, m => m.Model == "Contoso C");
}
[Fact]
public void FailureReasons_TruncateLongReasons_AndTakeTopFive()
public void FailureReasons_GroupByPrefix_KeepFullestText_AndTakeTopFive()
{
var sessions = new List<SessionSummary>();
// 6 distinct reasons with descending frequency 6..1 → only top 5 kept.
for (int freq = 6; freq >= 1; freq--)
// 5 distinct short reasons with descending frequency 5..1.
for (int freq = 5; freq >= 1; freq--)
for (int i = 0; i < freq; i++)
sessions.Add(S(SessionStatus.Failed, failureReason: $"Reason {freq}"));
// A null reason folds into "Unknown".
sessions.Add(S(SessionStatus.Failed, failureReason: null));
// An over-long reason is collapsed to a 50-char prefix + ellipsis.
var longReason = new string('x', 60);
sessions.Add(S(SessionStatus.Failed, failureReason: longReason));
// Two variants that share the first 50 characters collapse into one group;
// the longest variant is kept for display so the UI can show the full text.
var prefix = new string('x', 50);
var shortVariant = prefix + " short";
var longVariant = prefix + " a much longer tail that must survive intact";
for (int i = 0; i < 6; i++)
sessions.Add(S(SessionStatus.Failed, failureReason: shortVariant));
sessions.Add(S(SessionStatus.Failed, failureReason: longVariant));
var payload = MetricsMath.BuildFleetHealthPayload(sessions, days: 30);
Assert.Equal(5, payload.FailureReasons.Count);
Assert.Equal("Reason 6", payload.FailureReasons[0].Reason);
Assert.Equal(6, payload.FailureReasons[0].Count);
// The collapsed long reason exists in the tally (50 chars + "...").
var collapsed = new string('x', 50) + "...";
Assert.True(
sessions.Count(s => s.FailureReason == longReason) == 1,
"sanity: exactly one long-reason session");
Assert.Equal(53, collapsed.Length);
// The grouped cluster (6 + 1 = 7) outranks every "Reason N".
Assert.Equal(7, payload.FailureReasons[0].Count);
// The full, longest text survives end-to-end — no 50-char truncation.
Assert.Equal(longVariant, payload.FailureReasons[0].Reason);
Assert.DoesNotContain("...", payload.FailureReasons[0].Reason);
}
[Fact]
@@ -0,0 +1,99 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Functions.Functions.Metrics;
using AutopilotMonitor.Shared.Models;
using Xunit;
namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Pins the success-rate semantics of the geographic aggregation
/// (<see cref="GetGeographicMetricsFunction.ComputeGeographicMetrics"/>): the rate is an outcome
/// quota over finished enrollments (Succeeded + Failed) following the SLA convention. In-flight
/// sessions (InProgress/Pending/Stalled/AwaitingUser) and Incomplete (terminal, non-failure) sit
/// in SessionCount but never dilute the rate — the customer-visible symptom this pins against was
/// a site mid-rollout showing a poor rate despite zero actual failures.
/// </summary>
public class GeographicMetricsSuccessRateTests
{
private static SessionSummary S(SessionStatus status, string city = "Frankfurt")
=> new()
{
TenantId = "00000000-0000-0000-0000-000000000fe0",
SessionId = Guid.NewGuid().ToString(),
Status = status,
StartedAt = DateTime.UtcNow.AddHours(-2),
GeoCountry = "DE",
GeoRegion = "Hessen",
GeoCity = city,
GeoLoc = "50.11,8.68",
};
[Fact]
public void SuccessRate_IsOverFinishedSessions_InFlightAndIncompleteExcluded()
{
var sessions = new List<SessionSummary>
{
S(SessionStatus.Succeeded),
S(SessionStatus.Succeeded),
S(SessionStatus.Succeeded),
S(SessionStatus.Failed),
S(SessionStatus.InProgress),
S(SessionStatus.Pending),
S(SessionStatus.AwaitingUser),
S(SessionStatus.Incomplete), // terminal but non-failure — stays out of the rate
};
var result = GetGeographicMetricsFunction.ComputeGeographicMetrics(
sessions, new List<AppInstallSummary>(), "city");
var loc = Assert.Single(result.Locations);
Assert.Equal(8, loc.SessionCount);
Assert.Equal(3, loc.Succeeded);
Assert.Equal(1, loc.Failed);
// 3 / (3 + 1) = 75% (over finished), NOT 3 / 8 = 37.5% (over all sessions).
Assert.Equal(75d, loc.SuccessRate);
}
[Fact]
public void SuccessRate_IsZero_WhenNothingFinishedYet()
{
var sessions = new List<SessionSummary>
{
S(SessionStatus.InProgress),
S(SessionStatus.Pending),
};
var result = GetGeographicMetricsFunction.ComputeGeographicMetrics(
sessions, new List<AppInstallSummary>(), "city");
var loc = Assert.Single(result.Locations);
// No finished enrollments → no rate; the frontend renders "—" off Succeeded + Failed == 0.
Assert.Equal(0d, loc.SuccessRate);
Assert.Equal(0, loc.Succeeded + loc.Failed);
Assert.Equal(2, loc.SessionCount);
}
[Fact]
public void SuccessRate_IsPerLocation_NotGlobal()
{
var sessions = new List<SessionSummary>
{
// Frankfurt: 1 / 1 finished → 100% despite the in-flight session.
S(SessionStatus.Succeeded, city: "Frankfurt"),
S(SessionStatus.InProgress, city: "Frankfurt"),
// Berlin: 1 / 2 finished → 50%.
S(SessionStatus.Succeeded, city: "Berlin"),
S(SessionStatus.Failed, city: "Berlin"),
};
var result = GetGeographicMetricsFunction.ComputeGeographicMetrics(
sessions, new List<AppInstallSummary>(), "city");
var frankfurt = result.Locations.Single(l => l.City == "Frankfurt");
var berlin = result.Locations.Single(l => l.City == "Berlin");
Assert.Equal(100d, frankfurt.SuccessRate);
Assert.Equal(50d, berlin.SuccessRate);
}
}
@@ -0,0 +1,107 @@
using AutopilotMonitor.Functions.Services;
using AutopilotMonitor.Shared.Models;
using Xunit;
namespace AutopilotMonitor.Functions.Tests;
/// <summary>
/// Session eaf3d8c4 (2026-07-23): a previous enrollment's IME log surviving on disk made the
/// agent replay a week-old script history — 156 replayed <c>script_completed</c> events
/// inflated the session's RemediationScriptCount. Newer agents suppress the replay at the
/// source; this predicate covers the fleet of not-yet-updated agents by skipping the script
/// counter increment for events whose <c>rejectedSourceTimestamp</c> (the source log line's
/// own time, preserved by the agent's staleness clamp) is more than 24 h older than the
/// event's clock-clamped stamp.
/// </summary>
public class IngestHistoricImeReplayTests
{
private static readonly DateTime EventStamp = new(2026, 7, 23, 15, 42, 0, DateTimeKind.Utc);
private static EnrollmentEvent ScriptEvent(object? rejectedSourceTimestamp, bool includeKey = true)
{
var evt = new EnrollmentEvent
{
EventType = "script_completed",
Timestamp = EventStamp,
Data = new Dictionary<string, object> { ["scriptType"] = "remediation" },
};
if (includeKey)
evt.Data["rejectedSourceTimestamp"] = rejectedSourceTimestamp!;
return evt;
}
[Fact]
public void StaleRejectedSourceTimestamp_IsHistoricReplay()
{
var evt = ScriptEvent(EventStamp.AddDays(-7).ToString("o"));
Assert.True(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Fact]
public void StaleAppInstallEvent_IsHistoricReplay()
{
// The predicate is event-type-agnostic — it also guards AggregateAppInstallEvent
// (AppInstallSummaries would otherwise be overwritten with week-old runs).
var evt = new EnrollmentEvent
{
EventType = "app_install_completed",
Timestamp = EventStamp,
Data = new Dictionary<string, object>
{
["appName"] = "Contoso App",
["rejectedSourceTimestamp"] = EventStamp.AddDays(-7).ToString("o"),
},
};
Assert.True(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Fact]
public void JustOver24h_IsHistoricReplay()
{
var evt = ScriptEvent(EventStamp.AddHours(-25).ToString("o"));
Assert.True(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Fact]
public void Within24h_IsNotHistoricReplay()
{
var evt = ScriptEvent(EventStamp.AddHours(-23).ToString("o"));
Assert.False(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Fact]
public void FutureSkewRejection_IsNotHistoricReplay()
{
// A rejected source timestamp AHEAD of the event stamp is a mid-enrollment clock
// jump (WhiteGlove +1h CMTrace skew), not replayed history.
var evt = ScriptEvent(EventStamp.AddHours(2).ToString("o"));
Assert.False(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Fact]
public void MissingKey_IsNotHistoricReplay()
{
Assert.False(EventIngestProcessor.IsHistoricImeReplay(ScriptEvent(null, includeKey: false)));
}
[Fact]
public void NullData_IsNotHistoricReplay()
{
var evt = new EnrollmentEvent { EventType = "script_completed", Timestamp = EventStamp, Data = null! };
Assert.False(EventIngestProcessor.IsHistoricImeReplay(evt));
}
[Theory]
[InlineData("")]
[InlineData("not-a-date")]
public void UnparseableValue_IsNotHistoricReplay(string raw)
{
Assert.False(EventIngestProcessor.IsHistoricImeReplay(ScriptEvent(raw)));
}
[Fact]
public void NullEvent_IsNotHistoricReplay()
{
Assert.False(EventIngestProcessor.IsHistoricImeReplay(null));
}
}
@@ -119,6 +119,24 @@ public class MetricsMathAppPayloadTests
Assert.Equal(2, topCode.GetProperty("count").GetInt32());
}
[Fact]
public void FailureRate_IsOverFinishedInstalls_InProgressExcluded()
{
var summaries = new List<AppInstallSummary>
{
new() { AppName = "App A", Status = "Failed" },
new() { AppName = "App A", Status = "Succeeded", DurationSeconds = 10 },
new() { AppName = "App A", Status = "InProgress" },
new() { AppName = "App A", Status = "InProgress" },
};
var app = Build(summaries).GetProperty("topFailingApps")[0];
Assert.Equal(4, app.GetProperty("totalInstalls").GetInt32());
// 1 / (1 + 1) = 50% (over finished), NOT 1 / 4 = 25% (over all installs).
Assert.Equal(50d, app.GetProperty("failureRate").GetDouble());
}
[Fact]
public void SlowestApps_DropsAppsBelowSampleFloor()
{
@@ -62,7 +62,7 @@ public class SessionDeletionWorkerTests
};
harness.EnqueueMessage(JsonConvert.SerializeObject(envelope), dequeueCount: QueuePollingWorkerBase.DefaultMaxDequeueCount + 1);
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
// Poison queue received the body and main queue deleted the original.
harness.PoisonQueue.Verify(q => q.SendMessageAsync(
@@ -121,7 +121,7 @@ public class SessionDeletionWorkerTests
},
"etag-mock"));
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
var poisoned = Assert.Single(harness.OpsEventCalls, e => e.EventType == "SessionDeletionPoisoned");
Assert.Contains($"\"observedResidualCount\":{capObservation}", poisoned.RawDetails);
@@ -168,7 +168,7 @@ public class SessionDeletionWorkerTests
},
"etag-mock"));
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
var poisoned = Assert.Single(harness.OpsEventCalls, e => e.EventType == "SessionDeletionPoisoned");
Assert.Contains("\"observedResidualCount\":3", poisoned.RawDetails);
@@ -307,7 +307,7 @@ public class SessionDeletionWorkerTests
},
"etag-mock"));
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
var poisoned = Assert.Single(harness.OpsEventCalls, e => e.EventType == "SessionDeletionPoisoned");
Assert.True(poisoned.RawDetails.Length < 4096,
@@ -357,7 +357,7 @@ public class SessionDeletionWorkerTests
return Task.FromResult(Response.FromValue(receipt, new Mock<Response>().Object));
});
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
var casIdx = callOrder.IndexOf("cas-running-to-poisoned");
var poisonIdx = callOrder.IndexOf("poison-queue-send");
@@ -402,7 +402,7 @@ public class SessionDeletionWorkerTests
CurrentState = SessionDeletionState.Poisoned,
});
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
// Both CAS attempts fired, and the poison-queue send still completed.
harness.StorageMock.Verify(s => s.CasSetSessionDeletionStateAsync(
@@ -444,7 +444,7 @@ public class SessionDeletionWorkerTests
CurrentState = "Unknown",
});
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.OpsEventRecorded());
harness.PoisonQueue.Verify(q => q.SendMessageAsync(It.IsAny<string>(), It.IsAny<CancellationToken>()),
Times.AtLeastOnce);
@@ -457,7 +457,7 @@ public class SessionDeletionWorkerTests
var harness = new Harness();
harness.EnqueueMessage("{ \"this is not valid JSON for an envelope: garbage", dequeueCount: 1);
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.MainQueueDeleted());
harness.HandlerMock.Verify(h => h.HandleAsync(
It.IsAny<SessionDeletionEnvelope>(), It.IsAny<CancellationToken>()),
@@ -491,7 +491,7 @@ public class SessionDeletionWorkerTests
await Task.Delay(TimeSpan.FromMilliseconds(350), ct);
});
await harness.RunForAsync(TimeSpan.FromMilliseconds(800));
await harness.RunUntilAsync(() => harness.HeartbeatCount() >= 3);
// Heartbeat called at least 3× while the handler was busy (350ms / 50ms ≈ 7, minus a few
// due to scheduling jitter). One call is enough to prove the heartbeat task is wired.
@@ -512,7 +512,7 @@ public class SessionDeletionWorkerTests
};
harness.EnqueueMessage(JsonConvert.SerializeObject(envelope), dequeueCount: 1);
await harness.RunForAsync(TimeSpan.FromMilliseconds(500));
await harness.RunUntilAsync(() => harness.MainQueueDeleted());
harness.HandlerMock.Verify(h => h.HandleAsync(
It.IsAny<SessionDeletionEnvelope>(), It.IsAny<CancellationToken>()),
@@ -663,7 +663,9 @@ public class SessionDeletionWorkerTests
opsRepo.Setup(r => r.SaveOpsEventAsync(It.IsAny<OpsEventEntry>()))
.Returns<OpsEventEntry>(e =>
{
OpsEventCalls.Add(CapturedOpsEvent.From(e));
// Locked so RunUntilAsync's condition poll can read Count from the test
// thread while the worker thread appends.
lock (OpsEventCalls) OpsEventCalls.Add(CapturedOpsEvent.From(e));
return Task.CompletedTask;
});
var alertDispatch = new OpsAlertDispatchService(
@@ -721,6 +723,41 @@ public class SessionDeletionWorkerTests
try { await Sut.StopAsync(CancellationToken.None); }
catch (OperationCanceledException) { /* expected */ }
}
/// <summary>
/// De-flake (CI run 30047512186): <see cref="RunForAsync"/>'s fixed wall-clock window
/// raced the worker's background poll loop on loaded CI runners — positive assertions
/// (delete issued, ops event recorded) could fire before the loop ever processed the
/// message. Runs the worker until <paramref name="condition"/> observes the awaited
/// side effect (polled every 25 ms); the ceiling only bounds a genuinely broken worker,
/// the asserts after this call remain the source of truth. Same pattern as the watchdog
/// event-gate de-flake. Only for POSITIVE expectations — Times.Never-style tests keep
/// the fixed window (there is no event to wait for).
/// </summary>
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) { /* expected */ }
while (!condition() && DateTime.UtcNow < deadline)
await Task.Delay(25);
cts.Cancel();
try { await Sut.StopAsync(CancellationToken.None); }
catch (OperationCanceledException) { /* expected */ }
}
// Condition probes for RunUntilAsync. Moq's Invocations list snapshots under its
// internal lock, so polling it from the test thread while the worker invokes the
// mock is safe. OpsEventCalls is guarded by its own lock (see the repo callback).
public bool MainQueueDeleted() =>
MainQueue.Invocations.Any(i => i.Method.Name == nameof(QueueClient.DeleteMessageAsync));
public int HeartbeatCount() =>
MainQueue.Invocations.Count(i => i.Method.Name == nameof(QueueClient.UpdateMessageAsync));
public bool OpsEventRecorded()
{
lock (OpsEventCalls) return OpsEventCalls.Count > 0;
}
}
private sealed record AuditEntry(
@@ -1,5 +1,6 @@
using System.Collections.Specialized;
using System.Threading;
using AutopilotMonitor.Functions.Helpers;
using AutopilotMonitor.Shared.DataAccess;
using AutopilotMonitor.Shared.Models;
@@ -146,24 +147,11 @@ namespace AutopilotMonitor.Functions.Functions.Apps
var succeeded = g.Count(s => s.Status == "Succeeded");
var failed = g.Count(s => s.Status == "Failed");
var completed = g.Where(s => s.Status == "Succeeded").ToList();
var failureRate = total > 0 ? Math.Round((double)failed / total * 100, 1) : 0;
var failureRate = MetricsMath.TerminalFailureRatePct(failed, succeeded);
// Trend: compare failure rate in first half vs second half of window.
// Only emit non-stable trend if BOTH halves have >= 5 installs (too noisy otherwise).
var firstHalf = g.Where(s => s.StartedAt < midpoint).ToList();
var secondHalf = g.Where(s => s.StartedAt >= midpoint).ToList();
double? trendDelta = null;
string trend = "stable";
if (firstHalf.Count >= 5 && secondHalf.Count >= 5)
{
var fhRate = (double)firstHalf.Count(s => s.Status == "Failed") / firstHalf.Count * 100;
var shRate = (double)secondHalf.Count(s => s.Status == "Failed") / secondHalf.Count * 100;
var delta = Math.Round(shRate - fhRate, 1);
trendDelta = delta;
if (delta < -1) trend = "improving";
else if (delta > 1) trend = "worsening";
}
var (trend, trendDelta) = ComputeFailureTrend(firstHalf, secondHalf);
return new
{
@@ -275,7 +263,7 @@ namespace AutopilotMonitor.Functions.Functions.Apps
var succeeded = summaries.Count(s => s.Status == "Succeeded");
var failed = summaries.Count(s => s.Status == "Failed");
var completed = summaries.Where(s => s.Status == "Succeeded").ToList();
var failureRate = Math.Round((double)failed / total * 100, 1);
var failureRate = MetricsMath.TerminalFailureRatePct(failed, succeeded);
var avgDurationSeconds = completed.Count > 0 ? Math.Round(completed.Average(s => s.DurationSeconds), 0) : 0;
var p95DurationSeconds = Percentile(completed.Select(s => s.DurationSeconds).ToList(), 0.95);
var avgDownloadBytes = completed.Count > 0 ? (long)completed.Average(s => s.DownloadBytes) : 0;
@@ -283,16 +271,7 @@ namespace AutopilotMonitor.Functions.Functions.Apps
// Trend (same rule as list endpoint).
var firstHalf = summaries.Where(s => s.StartedAt < midpoint).ToList();
var secondHalf = summaries.Where(s => s.StartedAt >= midpoint).ToList();
double? trendDelta = null;
string trend = "stable";
if (firstHalf.Count >= 5 && secondHalf.Count >= 5)
{
var fhRate = (double)firstHalf.Count(s => s.Status == "Failed") / firstHalf.Count * 100;
var shRate = (double)secondHalf.Count(s => s.Status == "Failed") / secondHalf.Count * 100;
trendDelta = Math.Round(shRate - fhRate, 1);
if (trendDelta < -1) trend = "improving";
else if (trendDelta > 1) trend = "worsening";
}
var (trend, trendDelta) = ComputeFailureTrend(firstHalf, secondHalf);
var flakinessScore = total > 0
? Math.Round((double)summaries.Count(s => s.AttemptNumber > 1) / total, 3)
@@ -308,12 +287,13 @@ namespace AutopilotMonitor.Functions.Functions.Apps
{
var vTotal = g.Count();
var vFailed = g.Count(s => s.Status == "Failed");
var vSucceeded = g.Count(s => s.Status == "Succeeded");
return new
{
appVersion = g.Key,
installs = vTotal,
failed = vFailed,
failureRate = vTotal > 0 ? Math.Round((double)vFailed / vTotal * 100, 1) : 0
failureRate = MetricsMath.TerminalFailureRatePct(vFailed, vSucceeded)
};
})
.OrderByDescending(v => v.installs)
@@ -359,12 +339,16 @@ namespace AutopilotMonitor.Functions.Functions.Apps
Model = sessionLookup[$"{s.TenantId}|{s.SessionId}"].Model ?? "Unknown"
})
.GroupBy(x => new { x.Manufacturer, x.Model })
.Where(g => g.Count() >= 5)
// Sample floor on FINISHED installs — the displayed metric is the terminal-only
// failure rate, so a model with many in-flight installs but few outcomes is still
// too noisy to rank.
.Where(g => g.Count(x => x.Summary.Status == "Failed" || x.Summary.Status == "Succeeded") >= 5)
.Select(g =>
{
var modelTotal = g.Count();
var modelFailed = g.Count(x => x.Summary.Status == "Failed");
var modelFailureRate = Math.Round((double)modelFailed / modelTotal * 100, 1);
var modelSucceeded = g.Count(x => x.Summary.Status == "Succeeded");
var modelFailureRate = MetricsMath.TerminalFailureRatePct(modelFailed, modelSucceeded);
var lift = failureRate > 0
? Math.Round(modelFailureRate / failureRate, 2)
: 0;
@@ -496,6 +480,30 @@ namespace AutopilotMonitor.Functions.Functions.Apps
// ── Helpers ─────────────────────────────────────────────────────────
/// <summary>
/// Failure-rate trend between the two halves of the window, shared by the list and
/// analytics endpoints. Rates follow the terminal-only convention
/// (<see cref="MetricsMath.TerminalFailureRatePct"/>), and a non-stable trend requires
/// at least 5 FINISHED installs in BOTH halves — too noisy otherwise, and a half made
/// up of in-flight installs has no outcome to trend on.
/// </summary>
private static (string Trend, double? TrendDelta) ComputeFailureTrend(
List<AppInstallSummary> firstHalf, List<AppInstallSummary> secondHalf)
{
var fhFailed = firstHalf.Count(s => s.Status == "Failed");
var fhSucceeded = firstHalf.Count(s => s.Status == "Succeeded");
var shFailed = secondHalf.Count(s => s.Status == "Failed");
var shSucceeded = secondHalf.Count(s => s.Status == "Succeeded");
if (fhFailed + fhSucceeded < 5 || shFailed + shSucceeded < 5)
return ("stable", null);
var delta = Math.Round(
MetricsMath.TerminalFailureRatePct(shFailed, shSucceeded)
- MetricsMath.TerminalFailureRatePct(fhFailed, fhSucceeded), 1);
var trend = delta < -1 ? "improving" : delta > 1 ? "worsening" : "stable";
return (trend, delta);
}
private static List<object> BuildTimeSeries(List<AppInstallSummary> summaries, DateTime cutoff, DateTime now, string bucket)
{
var start = bucket == "week" ? StartOfWeek(cutoff) : cutoff.Date;
@@ -531,7 +539,7 @@ namespace AutopilotMonitor.Functions.Functions.Apps
installs = bTotal,
succeeded = bSucceeded,
failed = bFailed,
failureRate = bTotal > 0 ? Math.Round((double)bFailed / bTotal * 100, 1) : 0,
failureRate = MetricsMath.TerminalFailureRatePct(bFailed, bSucceeded),
avgDurationSeconds = bCompleted.Count > 0 ? Math.Round(bCompleted.Average(s => s.DurationSeconds), 0) : 0
};
})
@@ -106,6 +106,13 @@ namespace AutopilotMonitor.Functions.Functions.Metrics
var first = group.First();
var succeeded = group.Where(s => s.Status == SessionStatus.Succeeded).ToList();
var failed = group.Where(s => s.Status == SessionStatus.Failed).ToList();
// Success rate is an outcome quota over finished enrollments only
// (Succeeded + Failed), matching the SLA convention. In-flight sessions
// (InProgress/Pending/Stalled/AwaitingUser) and Incomplete (terminal,
// non-failure) must not dilute it — a site mid-rollout would otherwise
// show a poor rate despite zero actual failures. 0 finished → 0; the
// frontend renders "—" off Succeeded+Failed instead of a 0% badge.
var finished = succeeded.Count + failed.Count;
// Duration stats from succeeded sessions with valid duration
var durations = succeeded
@@ -156,7 +163,7 @@ namespace AutopilotMonitor.Functions.Functions.Metrics
SessionCount = group.Count(),
Succeeded = succeeded.Count,
Failed = failed.Count,
SuccessRate = group.Count() > 0 ? Math.Round((double)succeeded.Count / group.Count() * 100, 1) : 0,
SuccessRate = finished > 0 ? Math.Round((double)succeeded.Count / finished * 100, 1) : 0,
AvgDurationMinutes = Math.Round(avgDuration, 1),
MedianDurationMinutes = Math.Round(medianDuration, 1),
P95DurationMinutes = Math.Round(p95Duration, 1),
@@ -7,6 +7,19 @@ namespace AutopilotMonitor.Functions.Helpers;
/// </summary>
public static class MetricsMath
{
/// <summary>
/// App-install failure rate over finished installs only: Failed / (Failed + Succeeded), one
/// decimal, 0 when nothing finished. The same outcome-quota convention as the enrollment
/// success rate — "InProgress" rows (still installing, or orphaned by a session that died
/// mid-install) never dilute the rate. Shared by the app-metrics payload and the Apps
/// dashboard aggregations so the definition can't drift between panes.
/// </summary>
public static double TerminalFailureRatePct(int failed, int succeeded)
{
var finished = failed + succeeded;
return finished > 0 ? Math.Round((double)failed / finished * 100, 1) : 0;
}
/// <summary>
/// Builds the complete app-metrics response object from a (pre-time-filtered) set of app
/// install summaries. Single source of truth for both the tenant (<c>metrics/app</c>) and
@@ -40,7 +53,7 @@ public static class MetricsMath
totalInstalls = total,
succeeded = completed.Count,
failed = failed.Count,
failureRate = total > 0 ? Math.Round((double)failed.Count / total * 100, 1) : 0,
failureRate = TerminalFailureRatePct(failed.Count, completed.Count),
avgDurationSeconds = completed.Count > 0 ? Math.Round(completed.Average(s => s.DurationSeconds), 0) : 0,
maxDurationSeconds = completed.Count > 0 ? completed.Max(s => s.DurationSeconds) : 0,
avgDownloadBytes = completed.Count > 0 ? (long)completed.Average(s => s.DownloadBytes) : 0,
@@ -93,9 +106,10 @@ public static class MetricsMath
/// Single source of truth for the tenant (<c>metrics/fleet-health</c>) and global
/// (<c>global/metrics/fleet-health</c>) functions. Replaces the previous client-side path that
/// drained up to 200k raw sessions into the browser and ran these aggregations on the main
/// thread. Semantics are preserved verbatim from that client code, notably: success rate is
/// over ALL sessions (not just terminal ones), and average duration counts every
/// non-in-progress session that carries a positive duration (failures included).
/// thread. Success rate follows the SLA convention: Succeeded / (Succeeded + Failed) — finished
/// enrollments only, so in-flight sessions and Incomplete (terminal, non-failure) never dilute
/// it. Average duration counts every non-in-progress session that carries a positive duration
/// (failures included).
/// </summary>
public static FleetHealthMetrics BuildFleetHealthPayload(IReadOnlyList<SessionSummary> sessions, int days)
{
@@ -121,6 +135,7 @@ public static class MetricsMath
}
int total = sessions.Count;
int finished = succeeded + failed;
var stats = new FleetHealthStats
{
Total = total,
@@ -128,7 +143,7 @@ public static class MetricsMath
Failed = failed,
InProgress = inProgress,
Incomplete = incomplete,
SuccessRate = total > 0 ? Math.Round((double)succeeded / total * 100, 1) : 0,
SuccessRate = finished > 0 ? Math.Round((double)succeeded / finished * 100, 1) : 0,
AvgDurationMinutes = completedWithDurationCount > 0
? (int)Math.Round((double)completedDurationSeconds / completedWithDurationCount / 60.0, MidpointRounding.AwayFromZero)
: 0,
@@ -179,19 +194,29 @@ public static class MetricsMath
private static List<FleetFailureReason> BuildFleetFailureReasons(IReadOnlyList<SessionSummary> sessions)
{
var reasons = new Dictionary<string, int>();
// Group near-identical messages by a 50-char prefix so variants collapse
// into one row, but keep the longest full reason as the display value. The
// UI truncates and expands it on demand, so the complete text must survive.
var groups = new Dictionary<string, (string Display, int Count)>();
foreach (var s in sessions)
{
if (s.Status != SessionStatus.Failed) continue;
var reason = string.IsNullOrEmpty(s.FailureReason) ? "Unknown" : s.FailureReason;
// Collapse very long reasons to a 50-char prefix so near-identical messages group.
if (reason.Length > 50) reason = reason.Substring(0, 50) + "...";
reasons[reason] = reasons.GetValueOrDefault(reason) + 1;
var key = reason.Length > 50 ? reason.Substring(0, 50) : reason;
if (groups.TryGetValue(key, out var g))
{
var display = reason.Length > g.Display.Length ? reason : g.Display;
groups[key] = (display, g.Count + 1);
}
else
{
groups[key] = (reason, 1);
}
}
return reasons
.OrderByDescending(kv => kv.Value)
return groups
.OrderByDescending(kv => kv.Value.Count)
.Take(5)
.Select(kv => new FleetFailureReason { Reason = kv.Key, Count = kv.Value })
.Select(kv => new FleetFailureReason { Reason = kv.Value.Display, Count = kv.Value.Count })
.ToList();
}
@@ -208,6 +233,7 @@ public static class MetricsMath
}
m.Total++;
if (s.Status == SessionStatus.Succeeded) m.Succeeded++;
else if (s.Status == SessionStatus.Failed) m.Failed++;
}
return models.Values
.OrderByDescending(m => m.Total)
@@ -240,15 +266,18 @@ public static class MetricsMath
private static List<FleetFailingModel> BuildFleetTopFailingModels(IReadOnlyList<SessionSummary> sessions)
{
var acc = new Dictionary<string, (int Failed, int Total)>();
var acc = new Dictionary<string, (int Failed, int Succeeded, int Total)>();
foreach (var s in sessions)
{
var key = FleetModelKey(s);
acc.TryGetValue(key, out var cur);
cur.Total++;
if (s.Status == SessionStatus.Failed) cur.Failed++;
else if (s.Status == SessionStatus.Succeeded) cur.Succeeded++;
acc[key] = cur;
}
// FailureRate over finished enrollments only (mirror of the success-rate convention);
// the Where(Failed > 0) guard also keeps the denominator non-zero.
return acc
.Where(kv => kv.Value.Failed > 0)
.Select(kv => new FleetFailingModel
@@ -256,7 +285,8 @@ public static class MetricsMath
Model = kv.Key,
Failed = kv.Value.Failed,
Total = kv.Value.Total,
FailureRate = (int)Math.Round((double)kv.Value.Failed / kv.Value.Total * 100, MidpointRounding.AwayFromZero),
FailureRate = (int)Math.Round(
(double)kv.Value.Failed / (kv.Value.Failed + kv.Value.Succeeded) * 100, MidpointRounding.AwayFromZero),
})
.OrderByDescending(m => m.Failed)
.Take(5)
@@ -22,6 +22,13 @@ namespace AutopilotMonitor.Functions.Services
if (!isRelevant) return;
// Legacy-agent stale-replay guard (session eaf3d8c4): app events replayed from a
// previous enrollment's IME log carry a rejectedSourceTimestamp > 24 h older than
// the event stamp. They would create/overwrite this session's AppInstallSummaries
// rows with week-old runs. The fixed agent suppresses them at the source; this
// covers agents not yet rolled out.
if (IsHistoricImeReplay(evt)) return;
var appName = evt.Data?.ContainsKey("appName") == true ? evt.Data["appName"]?.ToString()?.Trim() : null;
if (string.IsNullOrEmpty(appName)) return;
@@ -82,6 +82,13 @@ namespace AutopilotMonitor.Functions.Services
break;
case "script_completed":
case "script_failed":
// Legacy-agent stale-replay guard: events flagged with a
// rejectedSourceTimestamp > 24 h older than the event stamp are replayed
// history from a previous enrollment (session eaf3d8c4 inflated
// RemediationScriptCount to 156 in a 7-min session). The fixed agent
// suppresses them at the source; this covers agents not yet rolled out.
if (IsHistoricImeReplay(evt))
break;
var scriptType = evt.Data?.ContainsKey("scriptType") == true
? evt.Data["scriptType"]?.ToString() : null;
if (string.Equals(scriptType, "platform", StringComparison.OrdinalIgnoreCase))
@@ -119,6 +126,28 @@ namespace AutopilotMonitor.Functions.Services
return string.Equals(reason, "max_lifetime", StringComparison.OrdinalIgnoreCase);
}
/// <summary>
/// True for an agent event whose <c>Data.rejectedSourceTimestamp</c> is more than 24 h
/// older than the event's own (clock-clamped) timestamp: the agent replayed IME log
/// content from a previous enrollment that survived on disk. Such runs happened days ago
/// and must not count as this session's script executions. A rejected source timestamp
/// in the FUTURE (negative difference) is a mid-enrollment clock jump, not a replay.
/// The 24 h bound mirrors the agent's source-timestamp staleness clamp.
/// </summary>
internal static bool IsHistoricImeReplay(EnrollmentEvent? evt)
{
if (evt?.Data == null || !evt.Data.ContainsKey("rejectedSourceTimestamp"))
return false;
var raw = evt.Data["rejectedSourceTimestamp"]?.ToString();
if (string.IsNullOrEmpty(raw))
return false;
if (!DateTime.TryParse(raw, System.Globalization.CultureInfo.InvariantCulture,
System.Globalization.DateTimeStyles.AssumeUniversal | System.Globalization.DateTimeStyles.AdjustToUniversal,
out var rejected))
return false;
return evt.Timestamp - rejected > TimeSpan.FromHours(24);
}
/// <summary>
/// True for an <c>enrollment_failed</c> event whose <c>Data.failureType</c> is
/// <c>agent_timeout</c> — the V1-parity companion of the max-lifetime watchdog shutdown
@@ -3,6 +3,9 @@
"version": "1.5.1",
"description": "MCP server for Autopilot-Monitor — enables AI agents to query enrollment sessions, device properties, events and vulnerabilities",
"type": "module",
"engines": {
"node": ">=22"
},
"bin": {
"autopilot-monitor-mcp": "./dist/index.js"
},
@@ -0,0 +1,53 @@
/**
* Historic-replay predicate (session eaf3d8c4): legacy agents replay IME log content from a
* previous enrollment; the replayed events carry `data.rejectedSourceTimestamp` > 24 h older
* than the event stamp. `get_session_summary` filters them out so appInstalls counts,
* errorCount (replayed app_install_failed are Error-severity) and the keyEvents triage
* timeline reflect only this enrollment's activity.
*/
import { describe, it, expect } from 'vitest';
import { isHistoricImeReplay } from '../tools/sessions.js';
const BASE = Date.UTC(2026, 6, 23, 15, 42, 0);
const DAY_MS = 24 * 60 * 60 * 1000;
const evt = (rejected?: unknown, timestamp: string = new Date(BASE).toISOString()): Record<string, unknown> => ({
timestamp,
eventType: 'app_install_completed',
data: rejected === undefined ? {} : { rejectedSourceTimestamp: rejected },
});
describe('isHistoricImeReplay', () => {
it('detects a rejected source timestamp > 24h older than the event stamp', () => {
expect(isHistoricImeReplay(evt(new Date(BASE - 7 * DAY_MS).toISOString()))).toBe(true);
expect(isHistoricImeReplay(evt(new Date(BASE - 25 * 60 * 60 * 1000).toISOString()))).toBe(true);
});
it('keeps within-24h rejections', () => {
expect(isHistoricImeReplay(evt(new Date(BASE - 23 * 60 * 60 * 1000).toISOString()))).toBe(false);
});
it('keeps future-skew rejections (clock jump, not replay)', () => {
expect(isHistoricImeReplay(evt(new Date(BASE + 2 * 60 * 60 * 1000).toISOString()))).toBe(false);
});
it('keeps events without or with malformed rejectedSourceTimestamp', () => {
expect(isHistoricImeReplay(evt())).toBe(false);
expect(isHistoricImeReplay(evt(''))).toBe(false);
expect(isHistoricImeReplay(evt('not-a-date'))).toBe(false);
expect(isHistoricImeReplay(evt(12345))).toBe(false);
expect(isHistoricImeReplay({ timestamp: new Date(BASE).toISOString() })).toBe(false);
});
it('keeps events with an unparseable event timestamp', () => {
expect(isHistoricImeReplay(evt(new Date(BASE - 7 * DAY_MS).toISOString(), 'garbage'))).toBe(false);
});
it('reads the snake_case wire variant', () => {
const e = {
timestamp: new Date(BASE).toISOString(),
data: { rejected_source_timestamp: new Date(BASE - 7 * DAY_MS).toISOString() },
};
expect(isHistoricImeReplay(e)).toBe(true);
});
});
@@ -23,6 +23,9 @@ export const EVENT_TYPES_CATALOG = {
'esp_failure_advisory',
'esp_failure_settle_started',
'esp_failure_settle_recovered',
'esp_failure_retry_detected',
'esp_failure_recovered',
'esp_failure_advisory_resolved',
'esp_exiting',
'mdm_policy_reboot_required',
'esp_config_detected',
@@ -77,7 +80,7 @@ export const EVENT_TYPES_CATALOG = {
'office_install_failed',
'office_preinstalled_detected',
],
script_events: ['script_started', 'script_completed', 'script_failed', 'script_timeout_suspected'],
script_events: ['script_started', 'script_completed', 'script_failed', 'script_timeout_suspected', 'historic_ime_replay_detected'],
network_events: [
'network_state_change',
'network_connectivity_check',
@@ -28,7 +28,8 @@ export const KEY_EVENT_TYPES = new Set([
'enrollment_complete', 'enrollment_failed', 'completion_check',
'desktop_arrived', 'hello_policy_detected', 'waiting_for_hello', 'hello_completion_timeout',
'agent_started', 'agent_shutdown', 'agent_shutting_down', 'agent_trace',
'script_started', 'script_completed', 'script_failed', 'vulnerability_report',
'script_started', 'script_completed', 'script_failed', 'historic_ime_replay_detected',
'vulnerability_report',
]);
// Phase-defining events promoted to the top of the triage timeline. Module-level
// (not handler-local) so the same drift test can validate it.
@@ -36,6 +37,27 @@ export const PHASE_EVENT_TYPES = new Set([
'phase_transition', 'esp_phase_changed', 'enrollment_type_detected',
'enrollment_complete', 'enrollment_failed', 'desktop_arrived',
]);
// Mirrors the agent's 24 h source-timestamp staleness clamp (session eaf3d8c4).
const HISTORIC_REPLAY_THRESHOLD_MS = 24 * 60 * 60 * 1000;
/**
* True when an event is replayed history from a previous enrollment: legacy agents replay
* IME log content surviving a re-enrollment, stamping the rejected source-line time as
* `data.rejectedSourceTimestamp` — more than 24 h older than the event stamp means the
* activity happened during a previous enrollment. Newer agents suppress these at the
* source; this filter covers sessions recorded by older agents. A rejected timestamp in
* the FUTURE (clock jump) is genuine current activity and passes through. Exported so the
* unit tests can pin the predicate.
*/
export function isHistoricImeReplay(e: Record<string, unknown>): boolean {
const data = e.data as Record<string, unknown> | undefined;
const rejected = data?.rejectedSourceTimestamp ?? data?.rejected_source_timestamp;
if (typeof rejected !== 'string' || rejected.length === 0) return false;
const rej = Date.parse(rejected);
const ts = Date.parse(String(e.timestamp ?? ''));
return Number.isFinite(rej) && Number.isFinite(ts) && ts - rej > HISTORIC_REPLAY_THRESHOLD_MS;
}
// Permissive ISO-8601 guard: rejects unparseable junk (which the backend would
// silently treat as no filter) while still accepting the date-only and
// timezone-offset forms the backend honors.
@@ -482,7 +504,12 @@ export function registerSessionTools(server: McpServer, ga: boolean, delegated:
: null,
};
const allEvents = (eventsData?.events ?? []) as Array<Record<string, unknown>>;
// Historic-replay filter: replayed app_install_failed events are Error-severity and
// would inflate errorCount; replayed app_install_* would inflate the appInstalls
// stats; replayed events would pollute the keyEvents triage timeline. One filter
// cleans all three. stats.totalEvents therefore counts non-replayed events.
const allEvents = ((eventsData?.events ?? []) as Array<Record<string, unknown>>)
.filter((e) => !isHistoricImeReplay(e));
let errorCount = 0;
let warningCount = 0;
@@ -73,6 +73,11 @@ namespace AutopilotMonitor.DecisionCore.Engine
/// The advisory variant (<see cref="DecisionState.EspAdvisoryFailureRecordedUtc"/>
/// set) is deliberately NOT touched: its anchor is a real ESP terminal failure and
/// a reboot does not un-happen that failure — the window must still un-defang it.
/// EXCEPTION (session 4910a5a5, 2026-07-23): when
/// <see cref="DecisionState.EspAdvisoryFailureResolvedUtc"/> is set the failed
/// category demonstrably recovered to success — the failure DID un-happen, and a
/// reboot mid-recovery (ESP continuing into AccountSetup) must re-base the window
/// exactly like the esp-exit variant instead of letting it fail a live enrollment.
/// </para>
/// Returns the effects (cancel + schedule + a fingerprint-bypassing
/// <c>completion_waiting</c> carrying the re-based due-time, mirroring the
@@ -84,7 +89,9 @@ namespace AutopilotMonitor.DecisionCore.Engine
DecisionStateBuilder builder,
DecisionSignal signal)
{
if (state.EspAdvisoryFailureRecordedUtc != null || !HasAdvisoryCompletionDeadline(state))
var unresolvedAdvisoryAnchored = state.EspAdvisoryFailureRecordedUtc != null
&& state.EspAdvisoryFailureResolvedUtc == null;
if (unresolvedAdvisoryAnchored || !HasAdvisoryCompletionDeadline(state))
{
return Array.Empty<DecisionEffect>();
}
@@ -139,6 +146,10 @@ namespace AutopilotMonitor.DecisionCore.Engine
"mayHaveContinuedAnyway",
"continueAnywayHint",
"advisoryReason",
// Session 4910a5a5 — recovery story context.
"failureRecovered",
"likelyCulpritApps",
"likelyCulpritAppCount",
};
/// <summary>
@@ -408,10 +419,17 @@ namespace AutopilotMonitor.DecisionCore.Engine
string reason,
Dictionary<string, string> parameters)
{
// Session 4910a5a5: remember WHICH category failed so the recovery hook
// (TryResolveAdvisoryOnCategoryRecovery) can later match a ProvisioningComplete
// signal of the same category against this advisory. Absent on event-log-derived
// failures — the hook then never matches.
string? failedCategory = null;
signal.Payload?.TryGetValue("category", out failedCategory);
var builder = state.ToBuilder()
.WithStepIndex(nextStep)
.WithLastAppliedSignalOrdinal(signal.SessionSignalOrdinal)
.WithEspAdvisoryFailureRecorded(signal.OccurredAtUtc, signal.SessionSignalOrdinal);
.WithEspAdvisoryFailureRecorded(signal.OccurredAtUtc, signal.SessionSignalOrdinal, failedCategory);
// Stage / Outcome deliberately untouched — monitoring continues. The session's
// normal completion paths (Hello/Desktop, IME pattern, AccountSetup provisioning
@@ -454,6 +472,63 @@ namespace AutopilotMonitor.DecisionCore.Engine
return new DecisionStep(newState, transition, effects);
}
/// <summary>
/// Session 4910a5a5 (2026-07-23) — recovery hook for a defanged ESP failure. When a
/// <c>DeviceSetupProvisioningComplete</c> / <c>AccountSetupProvisioningComplete</c>
/// signal reports the SAME category the advisory failure was recorded for, the failure
/// demonstrably un-happened (DeviceSetup/Apps failed → user pressed "Try again" ~23 min
/// later → apps re-ran to 10/10 → category resolved). Sets the set-once
/// <see cref="DecisionState.EspAdvisoryFailureResolvedUtc"/> fact on
/// <paramref name="builder"/> and returns an <c>esp_failure_advisory_resolved</c>
/// timeline effect telling the recovery story; returns null (builder untouched) when
/// there is no advisory, it is already resolved, or the category does not match.
/// <para>
/// The fact lifts the advisory variant's exemption from the AdvisoryCompletion
/// re-arm/rebase guards (see <see cref="HandleAdvisoryCompletionDeadlineFired"/> and
/// <see cref="RebaseEspExitVariantAdvisoryWindowOnReboot"/>) — without it the window
/// un-defangs the stale failure and fails a live enrollment mid-AccountSetup.
/// </para>
/// </summary>
private static DecisionEffect? TryResolveAdvisoryOnCategoryRecovery(
DecisionState state,
DecisionStateBuilder builder,
DecisionSignal signal,
string resolvedCategory)
{
if (state.EspAdvisoryFailureRecordedUtc == null) return null;
if (state.EspAdvisoryFailureResolvedUtc != null) return null;
var advisoryCategory = state.EspAdvisoryFailureCategory?.Value;
if (!string.Equals(advisoryCategory, resolvedCategory, StringComparison.OrdinalIgnoreCase))
{
return null;
}
builder.WithEspAdvisoryFailureResolved(signal.OccurredAtUtc, signal.SessionSignalOrdinal);
var minutesSinceAdvisory = Math.Max(0,
(int)Math.Round((signal.OccurredAtUtc - state.EspAdvisoryFailureRecordedUtc.Value).TotalMinutes));
var continueAnywayAllowed = state.ScenarioObservations?.EspAllowContinueAnyway?.Value == true;
var parameters = new Dictionary<string, string>
{
["eventType"] = SharedConstants.EventTypes.EspFailureAdvisoryResolved,
["source"] = "DecisionEngine",
["severity"] = "Info",
["immediateUpload"] = "false",
["message"] = $"ESP failure advisory resolved: {resolvedCategory} completed successfully "
+ $"{minutesSinceAdvisory} min after the advisory — the ESP re-ran the failed step "
+ "(consistent with a user-initiated retry on the ESP failure page"
+ (continueAnywayAllowed ? "; the profile allows Try again / Continue anyway" : "")
+ "). The earlier failure no longer blocks completion.",
["category"] = resolvedCategory,
["minutesSinceAdvisory"] = minutesSinceAdvisory.ToString(CultureInfo.InvariantCulture),
["espAllowContinueAnyway"] = continueAnywayAllowed ? "true" : "false",
};
return new DecisionEffect(DecisionEffectKind.EmitEventTimelineEntry, parameters: parameters);
}
/// <summary>
/// <see cref="DeadlineNames.AdvisoryCompletion"/> fired — the resolution window after a
/// completion dead-end expired without one of the normal completion paths terminating
@@ -511,6 +586,12 @@ namespace AutopilotMonitor.DecisionCore.Engine
var deadlineStillArmed = armedDeadline != null;
var hasAdvisoryAnchor = state.EspAdvisoryFailureRecordedUtc != null;
// Session 4910a5a5: once the failed category demonstrably recovered
// (TryResolveAdvisoryOnCategoryRecovery set the fact), the advisory variant's
// "a real ESP terminal failure does not un-happen" premise is disproven — the
// guards below that protect live enrollments (enforcement-progress re-arm,
// hello-never-observed promote) apply to it again.
var advisoryResolved = state.EspAdvisoryFailureResolvedUtc != null;
// Presence-only anchor (L5, delta review 2026-07-02). The esp-exit arming site only
// runs when AccountSetupEnteredUtc is already set, so both facts being present is
// the anchor; `deadlineStillArmed` below is what rejects stray timer fires. The old
@@ -635,8 +716,13 @@ namespace AutopilotMonitor.DecisionCore.Engine
// When user-phase enforcement demonstrably progressed since arming, the dead-end
// shape is disproven: re-arm a fresh window with updated baselines instead of
// failing a live enrollment mid-install. The advisory variant is exempt — its
// anchor is a real ESP terminal failure that a busy IME does not un-happen.
if (!hasAdvisoryAnchor && HasEnforcementProgressSinceArming(state, armedDeadline!))
// anchor is a real ESP terminal failure that a busy IME does not un-happen —
// UNLESS the failed category later resolved to success (session 4910a5a5:
// DeviceSetup/Apps failed, user retried, apps reached 10/10, DeviceSetup resolved
// — the failure DID un-happen, so a live AccountSetup must not be failed on the
// stale advisory). Convergent either way: each re-arm renews the baselines, so a
// session that stalls after the recovery still fails one window later.
if ((!hasAdvisoryAnchor || advisoryResolved) && HasEnforcementProgressSinceArming(state, armedDeadline!))
{
var rearmedDeadline = BuildAdvisoryCompletionDeadline(state, signal);
builder.AddDeadline(rearmedDeadline);
@@ -692,7 +778,7 @@ namespace AutopilotMonitor.DecisionCore.Engine
// through Finalizing. Deliberately does NOT require the IME user-session gate —
// the FP sessions never saw an IME user-session completion (that gate guards
// completion evidence, not user presence; presence is the DAD-validated desktop).
if (!hasAdvisoryAnchor
if ((!hasAdvisoryAnchor || advisoryResolved)
&& desktopArrived
&& state.HelloResolvedUtc == null
&& state.HelloPolicyEnabled == null
@@ -741,7 +827,30 @@ namespace AutopilotMonitor.DecisionCore.Engine
// stays the deadline, not EspTerminalFailure).
string reason;
Dictionary<string, string> parameters;
if (hasAdvisoryAnchor)
if (hasAdvisoryAnchor && advisoryResolved)
{
// Session 4910a5a5: the original ESP failure demonstrably recovered (failed
// category resolved to success after the advisory), so claiming
// `esp_terminal_failure` would blame a failure that un-happened. The device
// recovered its device phase but then produced no completion evidence for a
// whole (re-armed, progress-gated) window. LastFailureTrigger stays the
// deadline so the EnrollmentTerminationHandler's likely-stuck app promotion
// stays OFF — the apps are not stuck, they succeeded.
reason = "esp_recovered_without_completion_evidence";
parameters = BuildEspFailureParameters(
signal: signal,
reason: reason,
advisoryPath: false,
observations: state.ScenarioObservations);
parameters["advisoryReason"] = "advisory_recovered_window_expired_without_completion_evidence";
parameters["failureRecovered"] = "true";
if (state.EspAdvisoryFailureCategory != null)
{
parameters["category"] = state.EspAdvisoryFailureCategory.Value;
}
builder.WithLastFailureTrigger(nameof(DecisionSignalKind.DeadlineFired), signal.SessionSignalOrdinal);
}
else if (hasAdvisoryAnchor)
{
// Registry-derived failure context (failureType/errorCode/...) lived on the
// original signal and is already on the wire via the esp_failure_advisory
@@ -885,6 +994,12 @@ namespace AutopilotMonitor.DecisionCore.Engine
parameters["failedSubcategory"] = failedSubcategory;
if (signal.Payload.TryGetValue("category", out var category) && !string.IsNullOrEmpty(category))
parameters["category"] = category;
// Session 4910a5a5 — tracker-snapshotted culprit-app names for Apps failures,
// so the advisory/terminal event tells WHICH app ESP most likely failed on.
if (signal.Payload.TryGetValue("likelyCulpritApps", out var culpritApps) && !string.IsNullOrEmpty(culpritApps))
parameters["likelyCulpritApps"] = culpritApps;
if (signal.Payload.TryGetValue("likelyCulpritAppCount", out var culpritCount) && !string.IsNullOrEmpty(culpritCount))
parameters["likelyCulpritAppCount"] = culpritCount;
}
// FirstSync-derived ESP failure-handling settings — observable hint that
@@ -98,17 +98,28 @@ namespace AutopilotMonitor.DecisionCore.Engine
// was already armed (or already cancelled by AccountSetup). Pass-through.
if (state.DeviceSetupResolvedUtc != null)
{
var passthroughState = state.ToBuilder()
var passthroughBuilder = state.ToBuilder()
.WithStepIndex(nextStep)
.WithLastAppliedSignalOrdinal(signal.SessionSignalOrdinal)
.Build();
.WithLastAppliedSignalOrdinal(signal.SessionSignalOrdinal);
// Session 4910a5a5 recovery hook: a duplicate arrival (e.g. the post-reboot
// registry re-read) can still be the first evidence that the advisory's failed
// category recovered — set-once + category-match inside the helper keep this
// a no-op everywhere else.
var passthroughResolveEffect = TryResolveAdvisoryOnCategoryRecovery(
state, passthroughBuilder, signal, resolvedCategory: "DeviceSetup");
var passthroughState = passthroughBuilder.Build();
var passthroughTransition = BuildTakenTransition(
before: state,
signal: signal,
toStage: state.Stage,
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.DeviceSetupProvisioningComplete) + ":AnchorAlreadySet");
return new DecisionStep(passthroughState, passthroughTransition, Array.Empty<DecisionEffect>());
return new DecisionStep(
passthroughState,
passthroughTransition,
passthroughResolveEffect != null
? new[] { passthroughResolveEffect }
: Array.Empty<DecisionEffect>());
}
// Step 2 — Set the DeviceSetupResolvedUtc anchor UNCONDITIONALLY. Even when Classic
@@ -119,6 +130,13 @@ namespace AutopilotMonitor.DecisionCore.Engine
.WithLastAppliedSignalOrdinal(signal.SessionSignalOrdinal);
builder.DeviceSetupResolvedUtc = new SignalFact<DateTime>(signal.OccurredAtUtc, signal.SessionSignalOrdinal);
// Session 4910a5a5 recovery hook: DeviceSetup resolving to success while a
// DeviceSetup advisory failure is on record means the failure un-happened (user
// "Try again" retry). Sets the set-once resolved fact + emits the
// esp_failure_advisory_resolved story event; no-op otherwise.
var advisoryResolveEffect = TryResolveAdvisoryOnCategoryRecovery(
state, builder, signal, resolvedCategory: "DeviceSetup");
// Step 3 — Classic-path short-circuit: AccountSetup already started. The DeviceOnly
// deadline is moot (already cancelled by HandleEspPhaseChangedV1's AccountSetup branch,
// or never armed under the new code). No deadline arm here.
@@ -136,7 +154,12 @@ namespace AutopilotMonitor.DecisionCore.Engine
toStage: state.Stage,
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.DeviceSetupProvisioningComplete) + ":AccountSetupAlreadyEntered");
return new DecisionStep(classicState, classicTransition, Array.Empty<DecisionEffect>());
return new DecisionStep(
classicState,
classicTransition,
advisoryResolveEffect != null
? new[] { advisoryResolveEffect }
: Array.Empty<DecisionEffect>());
}
// Step 4 — Arm the deadline. Cancel any existing DeviceOnlyEspDetection first
@@ -156,13 +179,14 @@ namespace AutopilotMonitor.DecisionCore.Engine
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.DeviceSetupProvisioningComplete) + ":DeadlineArmed");
var effects = new[]
var effects = new List<DecisionEffect>(3)
{
new DecisionEffect(DecisionEffectKind.CancelDeadline, cancelDeadlineName: DeadlineNames.DeviceOnlyEspDetection),
new DecisionEffect(DecisionEffectKind.ScheduleDeadline, deadline: deadline),
};
if (advisoryResolveEffect != null) effects.Add(advisoryResolveEffect);
return new DecisionStep(newState, transition, effects);
return new DecisionStep(newState, transition, effects.ToArray());
}
/// <summary>
@@ -836,6 +836,13 @@ namespace AutopilotMonitor.DecisionCore.Engine
.WithStepIndex(nextStep)
.WithLastAppliedSignalOrdinal(signal.SessionSignalOrdinal);
// Session 4910a5a5 recovery hook (AccountSetup counterpart): the user-phase
// category resolving to success while an AccountSetup advisory failure is on
// record means that failure un-happened. Sets the set-once resolved fact + emits
// the esp_failure_advisory_resolved story event; no-op otherwise.
var advisoryResolveEffect = TryResolveAdvisoryOnCategoryRecovery(
state, builder, signal, resolvedCategory: "AccountSetup");
var alreadyRecorded = state.AccountSetupProvisioningSucceededUtc != null;
if (!alreadyRecorded)
{
@@ -876,10 +883,10 @@ namespace AutopilotMonitor.DecisionCore.Engine
toStage: state.Stage,
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.AccountSetupProvisioningComplete));
return new DecisionStep(
newState,
transition,
waitingEffect != null ? new[] { waitingEffect } : Array.Empty<DecisionEffect>());
var noPromoteEffects = new List<DecisionEffect>(2);
if (advisoryResolveEffect != null) noPromoteEffects.Add(advisoryResolveEffect);
if (waitingEffect != null) noPromoteEffects.Add(waitingEffect);
return new DecisionStep(newState, transition, noPromoteEffects.ToArray());
}
// Deferred-completion parity (session caa6cf50 fix, 2026-06-11): when the strong gate
@@ -910,14 +917,18 @@ namespace AutopilotMonitor.DecisionCore.Engine
builder.CancelDeadline(DeadlineNames.HelloSafety);
}
var deferredLeadingEffects = new List<DecisionEffect>(2);
if (advisoryResolveEffect != null) deferredLeadingEffects.Add(advisoryResolveEffect);
if (helloSafetyCancelEffect != null) deferredLeadingEffects.Add(helloSafetyCancelEffect);
return CompleteThroughFinalizingOrDefer(
state: state,
signal: signal,
preparedBuilder: builder,
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.AccountSetupProvisioningComplete) + ":DeferredCompletion",
leadingEffects: helloSafetyCancelEffect != null
? new[] { helloSafetyCancelEffect }
leadingEffects: deferredLeadingEffects.Count > 0
? deferredLeadingEffects.ToArray()
: null);
}
@@ -946,12 +957,13 @@ namespace AutopilotMonitor.DecisionCore.Engine
nextStepIndex: nextStep,
trigger: nameof(DecisionSignalKind.AccountSetupProvisioningComplete) + ":DeferredPromote");
var promotedEffects = new[]
var promotedEffects = new List<DecisionEffect>(2)
{
new DecisionEffect(DecisionEffectKind.ScheduleDeadline, deadline: helloSafety),
};
if (advisoryResolveEffect != null) promotedEffects.Add(advisoryResolveEffect);
return new DecisionStep(promotedState, promotedTransition, promotedEffects);
return new DecisionStep(promotedState, promotedTransition, promotedEffects.ToArray());
}
/// <summary>
@@ -110,6 +110,17 @@ namespace AutopilotMonitor.DecisionCore.Engine
timestamps["imeUserSessionCompleted"] = FormatUtc(state.ImeUserSessionCompletedUtc.Value);
evidence["imeUserSessionCompleted"] = TimestampedEvidence(state.ImeUserSessionCompletedUtc);
}
// Session 4910a5a5 — the ESP category behind a defanged advisory failure later
// resolved to success (user "Try again" recovery). Surfaced so terminal audit
// trails show that the original failure demonstrably un-happened — the
// discriminant between "failed and stayed failed" and "failed, recovered, but
// produced no completion evidence".
if (state.EspAdvisoryFailureResolvedUtc != null)
{
seen.Add("esp_advisory_failure_resolved");
timestamps["espAdvisoryFailureResolved"] = FormatUtc(state.EspAdvisoryFailureResolvedUtc.Value);
evidence["espAdvisoryFailureResolved"] = TimestampedEvidence(state.EspAdvisoryFailureResolvedUtc);
}
// Session 772fe502 — genuine Hello-wizard launch (Shell-Core 62404, CXID AADHello/
// NGC). Surfaced in the census so terminal audit trails show whether a wizard was
// observed — the discriminant between "Hello skipped by policy" and "Hello skipped
@@ -63,6 +63,8 @@ namespace AutopilotMonitor.DecisionCore.Engine
["helloPolicyEnabled"] = SerializeFact(state.HelloPolicyEnabled, v => (object)v),
["lastFailureTrigger"] = SerializeFact(state.LastFailureTrigger, v => v),
["espAdvisoryFailureRecordedUtc"] = SerializeFact(state.EspAdvisoryFailureRecordedUtc, FormatUtc),
["espAdvisoryFailureResolvedUtc"] = SerializeFact(state.EspAdvisoryFailureResolvedUtc, FormatUtc),
["espAdvisoryFailureCategory"] = SerializeFact(state.EspAdvisoryFailureCategory, v => v),
["imeUserSessionCompletedUtc"] = SerializeFact(state.ImeUserSessionCompletedUtc, FormatUtc),
["completionWaitingFingerprint"] = SerializeFact(state.CompletionWaitingFingerprint, v => v),
["helloWizardStartedUtc"] = SerializeFact(state.HelloWizardStartedUtc, FormatUtc),
@@ -64,7 +64,9 @@ namespace AutopilotMonitor.DecisionCore.State
SignalFact<DateTime>? espAdvisoryFailureRecordedUtc = null,
SignalFact<DateTime>? imeUserSessionCompletedUtc = null,
SignalFact<string>? completionWaitingFingerprint = null,
SignalFact<DateTime>? helloWizardStartedUtc = null)
SignalFact<DateTime>? helloWizardStartedUtc = null,
SignalFact<DateTime>? espAdvisoryFailureResolvedUtc = null,
SignalFact<string>? espAdvisoryFailureCategory = null)
{
if (string.IsNullOrEmpty(sessionId))
{
@@ -108,6 +110,8 @@ namespace AutopilotMonitor.DecisionCore.State
ImeUserSessionCompletedUtc = imeUserSessionCompletedUtc;
CompletionWaitingFingerprint = completionWaitingFingerprint;
HelloWizardStartedUtc = helloWizardStartedUtc;
EspAdvisoryFailureResolvedUtc = espAdvisoryFailureResolvedUtc;
EspAdvisoryFailureCategory = espAdvisoryFailureCategory;
}
public string SessionId { get; }
@@ -320,6 +324,36 @@ namespace AutopilotMonitor.DecisionCore.State
/// </summary>
public SignalFact<DateTime>? HelloWizardStartedUtc { get; }
/// <summary>
/// Set when the ESP category behind a recorded advisory failure
/// (<see cref="EspAdvisoryFailureRecordedUtc"/>) later resolves to success — i.e. the
/// failure demonstrably un-happened. Session 4910a5a5 (2026-07-23): DeviceSetup/Apps
/// failed, the user pressed "Try again" ~23 min later, the apps re-ran to 10/10 and
/// <c>DeviceSetupProvisioningComplete</c> arrived — yet the <c>AdvisoryCompletion</c>
/// window still un-defanged the stale failure and failed the live enrollment.
/// <para>
/// Set-once by the shared recovery hook in the ProvisioningComplete handlers when the
/// resolved category matches the <c>armFailedCategory</c> carried on the armed
/// <c>AdvisoryCompletion</c> deadline. Once set, the advisory variant loses its
/// exemption from the enforcement-progress re-arm, the reboot rebase and the Hello
/// promotes — those guards exist to protect live enrollments, and with this fact the
/// "a real ESP terminal failure does not un-happen" premise is disproven for this
/// session. Additive-nullable, no snapshot-schema bump.
/// </para>
/// </summary>
public SignalFact<DateTime>? EspAdvisoryFailureResolvedUtc { get; }
/// <summary>
/// The ESP category (<c>DeviceSetup</c> / <c>AccountSetup</c>) named by the advisory
/// failure's signal payload, recorded alongside <see cref="EspAdvisoryFailureRecordedUtc"/>.
/// Lives on state — not on the <c>AdvisoryCompletion</c> deadline payload — because
/// re-arm and reboot-rebase sites rebuild that deadline and would silently drop a
/// payload-carried category. Null when the arming signal carried no category (e.g.
/// event-log-derived failures); the recovery hook then never matches and behavior is
/// unchanged. Additive-nullable, no snapshot-schema bump.
/// </summary>
public SignalFact<string>? EspAdvisoryFailureCategory { get; }
public string SchemaVersion { get; }
/// <summary>
@@ -51,6 +51,8 @@ namespace AutopilotMonitor.DecisionCore.State
ImeUserSessionCompletedUtc = source.ImeUserSessionCompletedUtc;
CompletionWaitingFingerprint = source.CompletionWaitingFingerprint;
HelloWizardStartedUtc = source.HelloWizardStartedUtc;
EspAdvisoryFailureResolvedUtc = source.EspAdvisoryFailureResolvedUtc;
EspAdvisoryFailureCategory = source.EspAdvisoryFailureCategory;
}
public string SessionId { get; set; }
@@ -84,6 +86,8 @@ namespace AutopilotMonitor.DecisionCore.State
public SignalFact<DateTime>? ImeUserSessionCompletedUtc { get; set; }
public SignalFact<string>? CompletionWaitingFingerprint { get; set; }
public SignalFact<DateTime>? HelloWizardStartedUtc { get; set; }
public SignalFact<DateTime>? EspAdvisoryFailureResolvedUtc { get; set; }
public SignalFact<string>? EspAdvisoryFailureCategory { get; set; }
public string SchemaVersion { get; set; }
// ---------- fluent helpers for the most common reducer operations ----------
@@ -197,9 +201,25 @@ namespace AutopilotMonitor.DecisionCore.State
/// Fire-once gate: subsequent <c>EspTerminalFailure</c> signals see this fact set and
/// dead-end without further effect.
/// </summary>
public DecisionStateBuilder WithEspAdvisoryFailureRecorded(DateTime utc, long sourceSignalOrdinal)
public DecisionStateBuilder WithEspAdvisoryFailureRecorded(
DateTime utc, long sourceSignalOrdinal, string? failedCategory = null)
{
EspAdvisoryFailureRecordedUtc = new SignalFact<DateTime>(utc, sourceSignalOrdinal);
if (!string.IsNullOrEmpty(failedCategory))
{
EspAdvisoryFailureCategory = new SignalFact<string>(failedCategory!, sourceSignalOrdinal);
}
return this;
}
/// <summary>
/// Record that the ESP category behind the recorded advisory failure later resolved to
/// success (session 4910a5a5 — "Try again" recovery). Set-once; lifts the advisory
/// variant's exemption from the AdvisoryCompletion re-arm/rebase guards.
/// </summary>
public DecisionStateBuilder WithEspAdvisoryFailureResolved(DateTime utc, long sourceSignalOrdinal)
{
EspAdvisoryFailureResolvedUtc = new SignalFact<DateTime>(utc, sourceSignalOrdinal);
return this;
}
@@ -236,6 +256,8 @@ namespace AutopilotMonitor.DecisionCore.State
espAdvisoryFailureRecordedUtc: EspAdvisoryFailureRecordedUtc,
imeUserSessionCompletedUtc: ImeUserSessionCompletedUtc,
completionWaitingFingerprint: CompletionWaitingFingerprint,
helloWizardStartedUtc: HelloWizardStartedUtc);
helloWizardStartedUtc: HelloWizardStartedUtc,
espAdvisoryFailureResolvedUtc: EspAdvisoryFailureResolvedUtc,
espAdvisoryFailureCategory: EspAdvisoryFailureCategory);
}
}
@@ -340,6 +340,13 @@ namespace AutopilotMonitor.Shared
// start→completion duration (works on replay since start carries the source log
// timestamp). Warning, advisory ("suspected"); no state mutation.
public const string ScriptTimeoutSuspected = "script_timeout_suspected";
// One-shot per agent run: the IME adapter detected replayed log content from a
// previous enrollment (source lines > 24 h stale, e.g. IME logs surviving a
// re-enrollment) and suppressed the historic script (script_started/completed/
// failed) and app (app_install_*/download_progress/do_telemetry) events.
// Data.earliestRejectedSourceTimestamp dates the replayed content so operators
// know why those events are missing (session eaf3d8c4).
public const string HistoricImeReplayDetected = "historic_ime_replay_detected";
public const string EspProvisioningStatus = "esp_provisioning_status";
public const string SoftwareInventoryAnalysis = "software_inventory_analysis";
public const string VulnerabilityReport = "vulnerability_report";
@@ -539,6 +546,17 @@ namespace AutopilotMonitor.Shared
public const string EspFailureSettleRecovered = "esp_failure_settle_recovered"; // The failed subcategory left the "failed" state during the settle window (e.g. ESP "Try again" retry, session c071e92b) — the terminal EspFailureDetected fire is suppressed and monitoring continues; a subsequent failure re-arms a fresh settle window.
public const string EspAppxFailureAnalysis = "esp_appx_failure_analysis"; // One-shot AppXDeploymentServer/Operational scan during the ESP failure settle window: candidate MSIX/Store packages behind an "Apps (0x…)" subcategory failure invisible to ImeLogTracker (session 2bc884b6). Assessment, not a confirmed root cause.
public const string EspProvisioningRaw = "esp_provisioning_raw";
// Recovery story AFTER a terminally fired ESP failure (session 4910a5a5, 2026-07-23 —
// DeviceSetup/Apps failed, user pressed "Try again" ~23 min later, apps re-ran to
// 10/10). Distinct from EspFailureSettleRecovered, which covers recovery INSIDE the
// 30s settle window (terminal fire suppressed); these fire when the failure already
// went terminal (advisory/enrollment_failed) and the registry later disproves it.
public const string EspFailureRetryDetected = "esp_failure_retry_detected"; // failed subcategory left "failed" post-terminal — consistent with the user pressing "Try again"
public const string EspFailureRecovered = "esp_failure_recovered"; // previously failed category reached all-subcategories-succeeded post-terminal
// DecisionEngine counterpart (survives reboots via snapshot, unlike the in-run tracker
// pair above): the category behind a defanged esp_failure_advisory later resolved to
// success — the advisory no longer blocks; re-arm/rebase guards apply again.
public const string EspFailureAdvisoryResolved = "esp_failure_advisory_resolved";
public const string EspFailure = "esp_failure";
public const string EspExiting = "esp_exiting";
@@ -36,7 +36,8 @@ namespace AutopilotMonitor.Shared.Models
public int InProgress { get; set; }
/// <summary>Terminal, non-failure sessions (timeout reclassification). Surfaced as its own count; not a failure.</summary>
public int Incomplete { get; set; }
/// <summary>Succeeded / total * 100 (one decimal). Note: over all sessions, not just terminal.</summary>
/// <summary>Succeeded / (Succeeded + Failed) * 100 (one decimal) — finished enrollments only,
/// matching the SLA convention. 0 when nothing has finished yet (clients render "—").</summary>
public double SuccessRate { get; set; }
/// <summary>Average duration in minutes over non-in-progress sessions that carry a duration.</summary>
public int AvgDurationMinutes { get; set; }
@@ -58,8 +59,11 @@ namespace AutopilotMonitor.Shared.Models
public sealed class FleetModelHealth
{
public string Model { get; set; } = default!;
/// <summary>All sessions on this model in the window, including in-flight ones.</summary>
public int Total { get; set; }
public int Succeeded { get; set; }
/// <summary>Clients derive the per-model rate as Succeeded / (Succeeded + Failed).</summary>
public int Failed { get; set; }
}
public sealed class FleetSlowModel
@@ -73,7 +77,9 @@ namespace AutopilotMonitor.Shared.Models
{
public string Model { get; set; } = default!;
public int Failed { get; set; }
/// <summary>All sessions on this model in the window, including in-flight ones.</summary>
public int Total { get; set; }
/// <summary>Failed / (Failed + Succeeded) * 100, rounded — finished enrollments only.</summary>
public int FailureRate { get; set; }
}
}
@@ -3,6 +3,7 @@
import { useCallback, useEffect, useState } from "react";
import { api } from "@/lib/api";
import { authenticatedFetch } from "@/lib/authenticatedFetch";
import TruncatedLabel from "@/components/TruncatedLabel";
import { trackEvent } from "@/lib/appInsights";
import type { AutoResolveResult, IgnoredSoftwareEntry } from "./SoftwareMappingTypes";
@@ -211,8 +212,8 @@ export function IgnoredSoftwareTab({
return (
<tr key={key} className="hover:bg-gray-50 dark:hover:bg-gray-700/30 transition-colors">
<td className="px-3 py-3 text-sm text-gray-900 dark:text-gray-100 truncate">
{entry.softwareName}
<td className="px-3 py-3">
<TruncatedLabel text={entry.softwareName} className="block text-sm text-gray-900 dark:text-gray-100" />
</td>
<td className="px-3 py-3 text-sm text-gray-600 dark:text-gray-400 truncate">
{entry.publisher || <span className="text-gray-300 dark:text-gray-600 italic">unknown</span>}
@@ -3,6 +3,7 @@
import { useCallback, useEffect, useState } from "react";
import Link from "next/link";
import { api } from "@/lib/api";
import TruncatedLabel from "@/components/TruncatedLabel";
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
import { extractContinuation } from "@/lib/paginationLink";
import { extractSessionId, buildAutoReason } from "./opsEventSessionHelpers";
@@ -445,8 +446,8 @@ export function OpsEventsSection({
<td className="px-3 py-2.5 text-sm font-mono text-gray-700 dark:text-gray-300 whitespace-nowrap">
{evt.eventType}
</td>
<td className="px-3 py-2.5 text-sm text-gray-700 dark:text-gray-300 max-w-[300px] truncate">
{evt.message}
<td className="px-3 py-2.5 max-w-[300px]">
<TruncatedLabel interactive={false} text={evt.message ?? ""} className="block text-sm text-gray-700 dark:text-gray-300" />
</td>
<td className="px-3 py-2.5 text-sm font-mono text-gray-700 dark:text-gray-300">
{evt.tenantId ? (evt.tenantId.length > 8 ? `${evt.tenantId.slice(0, 8)}...` : evt.tenantId) : <span className="text-gray-300 dark:text-gray-600">-</span>}
@@ -3,6 +3,7 @@
import { useCallback, useEffect, useState } from "react";
import { api } from "@/lib/api";
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
import TruncatedLabel from "@/components/TruncatedLabel";
import { extractContinuation } from "@/lib/paginationLink";
import { isGuid } from "@/utils/inputValidation";
import { trackEvent } from "@/lib/appInsights";
@@ -355,8 +356,10 @@ export function SessionReportsSection({
<td className="px-4 py-3 text-sm text-gray-700 dark:text-gray-300">
{r.submittedBy}
</td>
<td className="px-4 py-3 text-sm text-gray-700 dark:text-gray-300 truncate max-w-xs">
{r.comment || <span className="text-gray-400 italic">no comment</span>}
<td className="px-4 py-3 max-w-xs">
{r.comment
? <TruncatedLabel interactive={false} text={r.comment} className="block text-sm text-gray-700 dark:text-gray-300" />
: <span className="text-sm text-gray-400 italic">no comment</span>}
</td>
<td className="px-4 py-3 text-sm text-gray-700 dark:text-gray-300">
{r.adminNote ? (
@@ -364,7 +367,7 @@ export function SessionReportsSection({
<svg className="w-4 h-4 text-indigo-500 dark:text-indigo-400 shrink-0" fill="currentColor" viewBox="0 0 24 24">
<path d="M3 17.25V21h3.75L17.81 9.94l-3.75-3.75L3 17.25zM20.71 7.04a1 1 0 000-1.41l-2.34-2.34a1 1 0 00-1.41 0l-1.83 1.83 3.75 3.75 1.83-1.83z" />
</svg>
<span className="truncate max-w-[140px]">{r.adminNote}</span>
<TruncatedLabel interactive={false} text={r.adminNote} className="max-w-[140px]" />
</div>
) : (
<span className="text-gray-300 dark:text-gray-600">—</span>
@@ -3,6 +3,7 @@
import { useCallback, useEffect, useState } from "react";
import { api } from "@/lib/api";
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
import TruncatedLabel from "@/components/TruncatedLabel";
import { trackEvent } from "@/lib/appInsights";
import type { UnmatchedSoftwareEntry, AutoResolveResult } from "./SoftwareMappingTypes";
@@ -564,9 +565,7 @@ export function UnmappedSoftwareTab({
/>
)}
</div>
<div className="px-3 py-3 text-sm text-gray-900 dark:text-gray-100 flex-1 min-w-0 truncate">
{entry.softwareName}
</div>
<TruncatedLabel text={entry.softwareName} className="px-3 py-3 text-sm text-gray-900 dark:text-gray-100 flex-1" />
<div className="px-3 py-3 text-sm text-gray-600 dark:text-gray-400 truncate" style={{ width: "18%", flexShrink: 0 }}>
{entry.publisher || <span className="text-gray-300 dark:text-gray-600 italic">unknown</span>}
</div>
@@ -3,6 +3,7 @@
import { useEffect, useState, useMemo, useCallback } from 'react';
import { useRouter } from 'next/navigation';
import { api } from '@/lib/api';
import TruncatedLabel from '@/components/TruncatedLabel';
import { useAuth } from '../../../../contexts/AuthContext';
import { useNotifications } from '../../../../contexts/NotificationContext';
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
@@ -705,7 +706,7 @@ export function SectionAgentMetrics() {
<p className="text-xs text-gray-500 mb-1">Top exceptions:</p>
{crashRate.topExceptions.map((e) => (
<div key={e.exceptionType} className="flex justify-between text-xs">
<span className="text-red-600 font-mono truncate mr-2">{e.exceptionType}</span>
<TruncatedLabel text={e.exceptionType} className="text-red-600 font-mono mr-2" />
<span className="text-gray-500">{e.count}x</span>
</div>
))}
@@ -170,11 +170,14 @@ export default function InstallsTab({ scope, timeRange }: InstallsTabProps) {
if (!data) return { totalApps: 0, totalInstalls: 0, avgFailureRate: 0 };
const apps = data.apps ?? [];
const totalFailed = apps.reduce((acc, a) => acc + a.failed, 0);
const totalInstalls = data.totalInstalls;
// Terminal-only convention: rate over finished installs (succeeded + failed), so
// in-flight/orphaned InProgress rows don't dilute it. Matches the per-app failureRate.
const totalSucceeded = apps.reduce((acc, a) => acc + a.succeeded, 0);
const totalFinished = totalFailed + totalSucceeded;
return {
totalApps: data.totalApps,
totalInstalls,
avgFailureRate: totalInstalls > 0 ? Math.round((totalFailed / totalInstalls) * 1000) / 10 : 0,
totalInstalls: data.totalInstalls,
avgFailureRate: totalFinished > 0 ? Math.round((totalFailed / totalFinished) * 1000) / 10 : 0,
};
}, [data]);
@@ -16,6 +16,7 @@ export interface FleetHealthStats {
inProgress: number;
/** Terminal, non-failure (timeout reclassification). Surfaced separately; not counted as a failure. */
incomplete: number;
/** Succeeded / (succeeded + failed) — finished enrollments only. 0 when nothing finished yet. */
successRate: number;
avgDurationMinutes: number;
}
@@ -30,8 +31,10 @@ export interface FleetFailureReason {
}
export interface FleetModelHealth {
model: string;
/** All sessions on this model in the window, including in-flight ones. */
total: number;
succeeded: number;
failed: number;
}
export interface FleetSlowModel {
model: string;
@@ -10,6 +10,7 @@ import { useNotifications } from "../../contexts/NotificationContext";
import { api } from "@/lib/api";
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
import FleetStatCard from "./components/FleetStatCard";
import TruncatedLabel from "../../components/TruncatedLabel";
import { useFleetHealth } from "./hooks/useFleetHealth";
import { useAggregatedAdminScope } from "@/hooks";
import { GlobalAdminBanner, globalAdminSubtitle } from "@/components/GlobalAdminBanner";
@@ -129,6 +130,9 @@ export default function FleetHealthPage() {
successRate: s?.successRate ?? 0,
avgDuration: s?.avgDurationMinutes ?? 0,
};
// Success rate is an outcome quota over finished enrollments (succeeded + failed);
// with none finished there is no rate to show — the card renders "—" instead of 0%.
const finishedCount = stats.succeeded + stats.failed;
const modelHealth = data?.modelHealth ?? [];
const slowestModels = data?.slowestModels ?? [];
@@ -238,10 +242,16 @@ export default function FleetHealthPage() {
<div className="grid grid-cols-1 sm:grid-cols-2 lg:grid-cols-5 gap-5 mb-8">
<FleetStatCard
title="Success Rate"
value={`${stats.successRate.toFixed(1)}%`}
subtitle={`${stats.succeeded} of ${stats.total} enrollments`}
value={finishedCount > 0 ? `${stats.successRate.toFixed(1)}%` : "—"}
subtitle={
finishedCount > 0
? `${stats.succeeded} of ${finishedCount} finished enrollments`
: "No finished enrollments yet"
}
color={
stats.successRate >= 95
finishedCount === 0
? "slate"
: stats.successRate >= 95
? "green"
: stats.successRate >= 80
? "yellow"
@@ -395,9 +405,10 @@ export default function FleetHealthPage() {
</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 truncate pr-2">
{fr.reason}
</span>
<TruncatedLabel
text={fr.reason}
className="text-sm text-gray-700 pr-2"
/>
<span className="text-sm font-medium text-gray-900 flex-shrink-0">
({fr.count})
</span>
@@ -435,9 +446,10 @@ export default function FleetHealthPage() {
</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 truncate pr-2">
{m.model}
</span>
<TruncatedLabel
text={m.model}
className="text-sm text-gray-700 pr-2"
/>
<span className="text-sm font-medium text-gray-900 flex-shrink-0">
{m.avgMinutes} min
</span>
@@ -470,9 +482,10 @@ export default function FleetHealthPage() {
</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 truncate pr-2">
{m.model}
</span>
<TruncatedLabel
text={m.model}
className="text-sm text-gray-700 pr-2"
/>
<span className="text-sm font-medium text-red-600 flex-shrink-0">
{m.failed} failed
</span>
@@ -536,9 +549,10 @@ export default function FleetHealthPage() {
</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 truncate pr-2">
{app.appName}
</span>
<TruncatedLabel
text={app.appName}
className="text-sm text-gray-700 pr-2"
/>
<span className="text-sm font-medium text-gray-900 flex-shrink-0">
{avgLabel} avg
</span>
@@ -586,9 +600,10 @@ export default function FleetHealthPage() {
</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 truncate pr-2">
{app.appName}
</span>
<TruncatedLabel
text={app.appName}
className="text-sm text-gray-700 pr-2"
/>
<span className="text-sm font-medium text-red-600 flex-shrink-0">
{app.failed} failed
</span>
@@ -601,7 +616,7 @@ export default function FleetHealthPage() {
/>
</div>
<span className="text-xs text-gray-400 flex-shrink-0">
{app.failureRate}% of {app.totalInstalls}
{app.failureRate}% of {app.succeeded + app.failed} finished
</span>
</div>
{app.topFailureCodes.length > 0 && (
@@ -631,10 +646,13 @@ export default function FleetHealthPage() {
) : (
<div className="space-y-3">
{modelHealth.map((m) => {
// Rate over finished enrollments only; devices still enrolling don't count
// against the model. No finished enrollments → no rate ("—", neutral bar).
const finished = m.succeeded + m.failed;
const successRate =
m.total > 0
? Math.round((m.succeeded / m.total) * 100)
: 0;
finished > 0
? Math.round((m.succeeded / finished) * 100)
: null;
return (
<Link
key={m.model}
@@ -645,19 +663,21 @@ export default function FleetHealthPage() {
<div className="flex items-baseline justify-between mb-1">
<span className="text-sm text-gray-700 group-hover:text-blue-600 break-words leading-snug">{m.model}</span>
<span className="ml-3 flex-shrink-0 text-sm font-medium text-gray-900">
{successRate}% <span className="text-xs font-normal text-gray-400">({m.total} devices)</span>
{successRate !== null ? `${successRate}%` : "—"} <span className="text-xs font-normal text-gray-400">({m.total} devices)</span>
</span>
</div>
<div className="w-full h-2 bg-gray-100 rounded-full overflow-hidden">
<div
className={`h-full rounded-full transition-all ${
successRate >= 95
successRate === null
? "bg-gray-300"
: successRate >= 95
? "bg-green-500"
: successRate >= 80
? "bg-yellow-500"
: "bg-red-500"
}`}
style={{ width: `${successRate}%` }}
style={{ width: `${successRate ?? 0}%` }}
/>
</div>
</Link>
@@ -59,7 +59,7 @@ export const KNOWN_EVENT_TYPES: EventTypeEntry[] = [
{ value: "stall_probe_check", label: "stall_probe_check", category: "stall",
description: "Trace-level heartbeat from a stall probe — proves the logic ran (default: only the 15 min probe)." },
{ value: "esp_policy_provider_stalled", label: "esp_policy_provider_stalled", category: "stall",
description: "A registered ESP policy provider (EnrollmentStatusTracking CSP) stayed incomplete for 15+ minutes — e.g. co-management leaves only ConfigMgr registered without the Intune Sidecar provider, which parks the user ESP at 'Apps (Identifying)' with no OS timeout. One-shot Warning; payload carries the full provider table, per-provider state, and sidecarRegistered." },
description: "The ESP's app-tracking wait (EnrollmentStatusTracking CSP) made no progress for 15+ minutes: a registered policy provider stayed incomplete (reason=provider_incomplete), or Setup/Apps providers exist without the expected Intune 'Sidecar' provider (reason=sidecar_provider_missing) — the co-management signature where only ConfigMgr is registered (even with TrackingPoliciesCreated=1) and the user ESP parks at 'Apps (Identifying)' with no OS timeout. One-shot Warning; payload carries reason, the full provider table, per-provider state, and sidecarRegistered." },
{ value: "agent_late_start", label: "agent_late_start", category: "stall",
description: "Low observation coverage: the agent started long after device boot (≥10 min) AND lived only briefly (≤5 min) before a terminal outcome — it arrived after the enrollment had already decided, so its diagnosis is a post-mortem of the end-state, not a live observation. Carries bootToAgentStartSeconds, agentUptimeSeconds and outcome. Often paired with script_timeout_suspected (a script that hung ahead of the agent bootstrap)." },
@@ -98,6 +98,12 @@ export const KNOWN_EVENT_TYPES: EventTypeEntry[] = [
description: "ESP reported a subcategory failure but the device had already progressed to AccountSetup with ContinueAnyway enabled — non-terminal advisory, the agent continues monitoring." },
{ value: "esp_appx_failure_analysis", label: "esp_appx_failure_analysis", category: "esp",
description: "AppX deployment log scan during the ESP failure settle window: suspected MSIX/Store package candidates behind an Apps-subcategory failure (assessment, not a confirmed root cause)." },
{ value: "esp_failure_retry_detected", label: "esp_failure_retry_detected", category: "esp",
description: "After a terminally reported ESP failure, the failed subcategory left the failed state — consistent with the user pressing 'Try again' on the ESP failure page." },
{ value: "esp_failure_recovered", label: "esp_failure_recovered", category: "esp",
description: "The ESP category behind a terminally reported failure later completed successfully — the earlier failure recovered (e.g. after a user retry)." },
{ value: "esp_failure_advisory_resolved", label: "esp_failure_advisory_resolved", category: "esp",
description: "DecisionEngine: the category behind a defanged esp_failure_advisory resolved to success — the advisory no longer blocks completion." },
// -------- App installs --------
{ value: "app_install_started", label: "app_install_started", category: "app",
@@ -136,6 +142,8 @@ export const KNOWN_EVENT_TYPES: EventTypeEntry[] = [
description: "A platform script crashed (exit code != 0), or the remediation phase of a health script crashed. Health-script detection / post-detection phases use exit code as a compliance verdict (non-zero = non-compliant) and emit script_completed even on non-zero exit; only a true script crash in those phases would surface here." },
{ value: "script_timeout_suspected", label: "script_timeout_suspected", category: "script",
description: "A platform script ran to the IME script-execution timeout (~30 min; threshold 25 min) and was marked Failed while the enrollment was in progress. IME runs platform scripts serially, so a hung script starves app installs and the Autopilot-Monitor bootstrap — the prime suspect behind a late agent start / pre-failed ESP. Advisory (one per policyId); carries durationSeconds, exitCode and espPhase." },
{ value: "historic_ime_replay_detected", label: "historic_ime_replay_detected", category: "diagnostics",
description: "One-shot per agent run: the IME log contained replayed script and app activity from a previous enrollment (source lines more than 24 h stale, e.g. IME logs surviving a re-enrollment). The historic script_* and app_install_*/download_progress/do_telemetry events were suppressed for this session; carries earliestRejectedSourceTimestamp so the replayed window is datable." },
// -------- Diagnostics / misc --------
{ value: "error_detected", label: "error_detected", category: "diagnostics",
@@ -11,8 +11,11 @@ interface LocationMetric {
city: string;
loc: string;
sessionCount: number;
succeeded: number;
failed: number;
avgDurationMinutes: number;
appLoadScore: number;
/** Over finished enrollments (succeeded + failed) only; 0 when nothing finished yet. */
successRate: number;
avgThroughputBytesPerSec: number;
isOutlier: boolean;
@@ -160,7 +163,10 @@ export default function GeoMap({ locations, globalAvgDuration, selectedLocation,
<Tooltip direction="top" offset={[0, -10]} opacity={0.95}>
<div className="text-xs">
<div className="font-bold text-sm mb-1">{loc.locationKey}</div>
<div><strong>Sessions:</strong> {loc.sessionCount} ({loc.successRate}% success)</div>
<div>
<strong>Sessions:</strong> {loc.sessionCount}
{loc.succeeded + loc.failed > 0 ? ` (${loc.successRate}% success)` : " (none finished yet)"}
</div>
<div><strong>Avg Duration:</strong> {Math.round(loc.avgDurationMinutes)} min</div>
{loc.appLoadScore > 0 && (
<div><strong>App-Load-Score:</strong> {Math.round(loc.appLoadScore)}</div>
@@ -4,6 +4,7 @@ import { useEffect, useState, useRef, useMemo, useCallback } from "react";
import { useRouter } from "next/navigation";
import dynamic from "next/dynamic";
import { ProtectedRoute } from "../../components/ProtectedRoute";
import TruncatedLabel from "@/components/TruncatedLabel";
import { useTenant } from "../../contexts/TenantContext";
import { useAuth } from "../../contexts/AuthContext";
import { api } from "@/lib/api";
@@ -323,18 +324,14 @@ export default function GeographicPerformancePage() {
</div>
<div className="bg-white rounded-lg shadow p-4">
<div className="text-sm font-medium text-gray-500">Fastest Location</div>
<div className="text-lg font-bold text-green-600 truncate" title={stats.fastest?.locationKey}>
{stats.fastest?.locationKey || "—"}
</div>
<TruncatedLabel text={stats.fastest?.locationKey || "—"} className="block text-lg font-bold text-green-600" />
<div className="text-xs text-gray-400">
{stats.fastest ? `${Math.round(stats.fastest.avgDurationMinutes)} min avg` : "No data"}
</div>
</div>
<div className="bg-white rounded-lg shadow p-4">
<div className="text-sm font-medium text-gray-500">Slowest Location</div>
<div className="text-lg font-bold text-red-600 truncate" title={stats.slowest?.locationKey}>
{stats.slowest?.locationKey || "—"}
</div>
<TruncatedLabel text={stats.slowest?.locationKey || "—"} className="block text-lg font-bold text-red-600" />
<div className="text-xs text-gray-400">
{stats.slowest ? `${Math.round(stats.slowest.avgDurationMinutes)} min avg` : "No data"}
</div>
@@ -507,17 +504,28 @@ export default function GeographicPerformancePage() {
</td>
<td className="px-4 py-3 text-sm text-gray-700 font-medium">{loc.sessionCount}</td>
<td className="px-4 py-3 text-sm">
<span
className={`inline-flex items-center px-2 py-0.5 rounded text-xs font-medium ${
loc.successRate >= 90
? "bg-green-100 text-green-800"
: loc.successRate >= 70
? "bg-yellow-100 text-yellow-800"
: "bg-red-100 text-red-800"
}`}
>
{loc.successRate}%
</span>
{/* Rate is over finished enrollments (succeeded + failed) only; a
location where everything is still in flight has no rate yet. */}
{loc.succeeded + loc.failed > 0 ? (
<span
className={`inline-flex items-center px-2 py-0.5 rounded text-xs font-medium ${
loc.successRate >= 90
? "bg-green-100 text-green-800"
: loc.successRate >= 70
? "bg-yellow-100 text-yellow-800"
: "bg-red-100 text-red-800"
}`}
>
{loc.successRate}%
</span>
) : (
<span
className="inline-flex items-center px-2 py-0.5 rounded text-xs font-medium bg-gray-100 text-gray-500"
title="No finished enrollments yet"
>
—
</span>
)}
</td>
<td className="px-4 py-3 text-sm">
<span
@@ -3,6 +3,7 @@
import { useTenant } from "../../contexts/TenantContext";
import { useAuth } from "../../contexts/AuthContext";
import { useNotifications } from "../../contexts/NotificationContext";
import TruncatedLabel from "@/components/TruncatedLabel";
import { useSignalR } from "../../contexts/SignalRContext";
import { ProtectedRoute } from "../../components/ProtectedRoute";
import { useProgressSearch } from "./hooks/useProgressSearch";
@@ -374,13 +375,16 @@ export default function ProgressPortalPage() {
{isCurrent && (step.id === 3 || step.id === 5) && (
<div className="flex items-center space-x-1.5 mt-0.5">
<div className="w-1.5 h-1.5 bg-blue-400 rounded-full animate-pulse flex-shrink-0" />
<span className="text-xs text-blue-500 truncate">
{currentDownload?.active && currentDownload.appName
? `Downloading ${currentDownload.appName}...`
: currentInstall?.active && currentInstall.appName
? `Installing ${currentInstall.appName}...`
: "Processing..."}
</span>
<TruncatedLabel
className="text-xs text-blue-500"
text={
currentDownload?.active && currentDownload.appName
? `Downloading ${currentDownload.appName}...`
: currentInstall?.active && currentInstall.appName
? `Installing ${currentInstall.appName}...`
: "Processing..."
}
/>
</div>
)}
</div>
@@ -398,9 +402,7 @@ export default function ProgressPortalPage() {
<div>
<p className="text-xs text-blue-500 mb-1 font-medium">Downloading</p>
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-blue-700 font-medium truncate pr-2">
{currentDownload.appName}
</span>
<TruncatedLabel text={currentDownload.appName} className="text-sm text-blue-700 font-medium pr-2" />
{currentDownload.downloadRateBps > 0 && (
<span className="text-xs text-blue-500 flex-shrink-0">
{currentDownload.downloadRateBps >= 1024 * 1024
@@ -443,9 +445,7 @@ export default function ProgressPortalPage() {
<div className="flex items-center justify-between">
<div className="flex items-center space-x-1.5 min-w-0">
<div className="w-1.5 h-1.5 bg-blue-500 rounded-full animate-pulse flex-shrink-0" />
<span className="text-sm text-blue-700 font-medium truncate">
{currentInstall.appName}
</span>
<TruncatedLabel text={currentInstall.appName} className="text-sm text-blue-700 font-medium" />
</div>
{installElapsedMs != null && installElapsedMs > 0 && (
<span className="text-xs text-blue-600 font-medium tabular-nums flex-shrink-0 ml-2">
@@ -521,6 +521,46 @@ function EventRow({ event, showScriptOutput }: { event: EnrollmentEvent; showScr
subcategory: <span className="font-mono">{String(sub)}</span>
</span>
)}
{event.data?.likelyCulpritApps && (
<span
className="px-1.5 py-0.5 rounded bg-orange-100 text-orange-800 font-medium"
title="Tracked app(s) ESP most likely failed on — never-started apps ranked first (snapshot at failure time)."
>
Likely app: {String(event.data.likelyCulpritApps)}
</span>
)}
</div>
);
})()}
{/* Recovery-story badges (session 4910a5a5): a terminally reported ESP failure that
later un-happened — the user retried ("Try again"), the failed step re-ran and
recovered. Green/teal palette so the timeline visually closes the earlier red/amber
failure arc. */}
{(event.eventType === "esp_failure_retry_detected" || event.eventType === "esp_failure_recovered" || event.eventType === "esp_failure_advisory_resolved") && (() => {
const isRetry = event.eventType === "esp_failure_retry_detected";
const label = isRetry ? "User retry" : "Recovered";
const badgeCls = isRetry ? "bg-sky-100 text-sky-800" : "bg-emerald-100 text-emerald-800";
const cat = event.data?.category;
const sub = event.data?.subcategory ?? event.data?.failedSubcategory;
const mins = event.data?.minutesSinceFailure ?? event.data?.minutesSinceAdvisory;
return (
<div className="mt-1 flex flex-wrap items-center gap-2 text-xs">
<span
className={`px-1.5 py-0.5 rounded ${badgeCls} font-medium`}
title={isRetry
? "The failed ESP step left the failed state — consistent with the user pressing 'Try again' on the ESP failure page."
: "The previously failed ESP category completed successfully — the earlier failure no longer applies."}
>
{label}
</span>
{cat && (
<span className="text-gray-500">
{String(cat)}{sub ? <> / <span className="font-mono">{String(sub)}</span></> : null}
</span>
)}
{mins !== undefined && mins !== null && (
<span className="text-gray-500">{String(mins)} min after the failure</span>
)}
</div>
);
})()}
@@ -62,6 +62,10 @@ export function useSessionDerivedData(
// Extract latest app_tracking_summary state-breakdown for progress headers.
// Schema is the flat V1 shape — see AppTrackingSummaryBuilder.cs for the contract.
// Known legacy limitation: on sessions recorded by agents without the tracker-level
// historic-replay guard, the snapshot may count apps replayed from a previous
// enrollment's IME log — accepted; fixed agents keep replayed apps out of the summary
// at the source (ImeLogTracker AppMutatingActions guard).
const appSummaryStats = useMemo(() => {
const summaryEvents = events.filter(e => e.eventType === "app_tracking_summary");
if (summaryEvents.length === 0) return null;
@@ -4,6 +4,7 @@ import { useEffect, useState, useCallback } from 'react';
import { useTenant } from '../../contexts/TenantContext';
import { useAuth } from '../../contexts/AuthContext';
import { useNotifications } from '../../contexts/NotificationContext';
import TruncatedLabel from '@/components/TruncatedLabel';
import { ProtectedRoute } from '../../components/ProtectedRoute';
import { api } from "@/lib/api";
import { authenticatedFetch, TokenExpiredError } from "@/lib/authenticatedFetch";
@@ -333,7 +334,7 @@ export default function SlaPage() {
<span className="text-xs text-gray-400 w-4">{i + 1}</span>
<div className="flex-1 min-w-0">
<div className="flex items-center justify-between mb-1">
<span className="text-sm text-gray-700 dark:text-gray-300 truncate pr-2">{app.appName}</span>
<TruncatedLabel text={app.appName} className="text-sm text-gray-700 dark:text-gray-300 pr-2" />
<span className="text-sm font-medium text-red-600 dark:text-red-400 flex-shrink-0">{app.failCount} failed</span>
</div>
<div className="w-full h-2 bg-gray-100 dark:bg-gray-700 rounded-full overflow-hidden">
@@ -429,7 +430,9 @@ export default function SlaPage() {
{v.violationType}
</span>
</td>
<td className="px-6 py-4 text-sm text-gray-500 dark:text-gray-400 max-w-xs truncate">{v.failureReason || "-"}</td>
<td className="px-6 py-4 max-w-xs">
<TruncatedLabel text={v.failureReason || "-"} className="block text-sm text-gray-500 dark:text-gray-400" />
</td>
</tr>
))}
</tbody>
@@ -1,6 +1,8 @@
"use client";
import { useMemo, useState } from "react";
import { partitionHistoricReplayEvents } from "@/lib/historicReplay";
import TruncatedLabel from "@/components/TruncatedLabel";
import { shouldSkipLowBytesTotal, shouldSkipNoActivity } from "@/lib/downloadProgressFilters";
import { formatBytes, formatThroughput, formatDuration } from "@/lib/formatting";
import DoBreakdownBar from "./DoBreakdownBar";
@@ -84,10 +86,18 @@ function formatDoDuration(duration: string): string {
}
export default function DownloadProgress({ events, summaryStats }: DownloadProgressProps) {
const downloads = useMemo(() => {
if (events.length === 0) return [];
// Legacy-agent guard: drop download events replayed from a previous enrollment's IME log.
// Silent (empty finals set) — the InstallProgress panel already reports the hidden count
// for the same apps; a second note here would double-report them.
const current = useMemo(
() => partitionHistoricReplayEvents(events, new Set<string>()).current,
[events]
);
const sortedEvents = [...events].sort(
const downloads = useMemo(() => {
if (current.length === 0) return [];
const sortedEvents = [...current].sort(
(a, b) => new Date(a.timestamp).getTime() - new Date(b.timestamp).getTime()
);
@@ -185,7 +195,7 @@ export default function DownloadProgress({ events, summaryStats }: DownloadProgr
// This avoids active items jumping when completion status changes.
return a.firstSeenIndex - b.firstSeenIndex;
});
}, [events]);
}, [current]);
const [expanded, setExpanded] = useState(true);
const [showSkipped, setShowSkipped] = useState(false);
@@ -344,7 +354,7 @@ function DownloadItem({ download: dl, progressPercent }: { download: DownloadIte
<path strokeLinecap="round" strokeLinejoin="round" strokeWidth={2} d="M4 16v1a3 3 0 003 3h10a3 3 0 003-3v-1m-4-4l-4 4m0 0l-4-4m4 4V4" />
</svg>
)}
<span className={`text-sm font-medium truncate ${dl.isSkipped ? "text-gray-500" : "text-gray-900"}`}>{dl.appName}</span>
<TruncatedLabel text={dl.appName} className={`text-sm font-medium ${dl.isSkipped ? "text-gray-500" : "text-gray-900"}`} />
{dl.isSkipped && (
<span className="text-xs px-2 py-0.5 rounded-full bg-gray-200 text-gray-600 font-medium">Skipped</span>
)}
@@ -2,6 +2,8 @@
import { useEffect, useMemo, useState } from "react";
import { getErrorCodeEntry, formatErrorCode } from "@/utils/errorCodeMap";
import { partitionHistoricReplayEvents } from "@/lib/historicReplay";
import TruncatedLabel from "@/components/TruncatedLabel";
interface InstallEvent {
timestamp: string;
@@ -29,6 +31,10 @@ const ESP_APPS_TIMEOUT = "esp_apps_timeout";
const ESP_APPS_DETECTION_FAILURE = "esp_apps_detection_failure";
const ESP_APPS_INSTALL_FAILURE = "esp_apps_install_failure";
// Finals counted by the historic-replay partition — one per hidden install, so the note
// is not inflated by started/progress events of the same app.
const APP_FINAL_TYPES: ReadonlySet<string> = new Set(["app_install_completed", "app_install_failed"]);
interface InstallItem {
appName: string;
appId: string;
@@ -76,10 +82,18 @@ function formatDuration(ms: number): string {
}
export default function InstallProgress({ events, summaryStats }: InstallProgressProps) {
const installs = useMemo(() => {
if (events.length === 0) return [];
// Legacy-agent guard: split off app events replayed from a previous enrollment's IME log
// (newer agents suppress them at the source) so week-old installs never render as current.
// office_*/realmjoin_* events never carry rejectedSourceTimestamp and pass through untouched.
const { current, historicCount } = useMemo(
() => partitionHistoricReplayEvents(events, APP_FINAL_TYPES),
[events]
);
const sortedEvents = [...events].sort(
const installs = useMemo(() => {
if (current.length === 0) return [];
const sortedEvents = [...current].sort(
(a, b) => new Date(a.timestamp).getTime() - new Date(b.timestamp).getTime()
);
@@ -265,7 +279,7 @@ export default function InstallProgress({ events, summaryStats }: InstallProgres
}
return Array.from(installMap.values()).sort((a, b) => a.firstSeenIndex - b.firstSeenIndex);
}, [events]);
}, [current]);
const [expanded, setExpanded] = useState(true);
const [showSkipped, setShowSkipped] = useState(false);
@@ -288,7 +302,7 @@ export default function InstallProgress({ events, summaryStats }: InstallProgres
return showSkipped ? installs : installs.filter(d => d.state !== "Skipped");
}, [installs, showSkipped]);
if (installs.length === 0) return null;
if (installs.length === 0 && historicCount === 0) return null;
const activeCount = installs.filter(d => d.state === "Installing").length;
const completedCount = installs.filter(d => d.state === "Installed").length;
@@ -376,6 +390,14 @@ export default function InstallProgress({ events, summaryStats }: InstallProgres
{filteredInstalls.map((item) => (
<InstallItemRow key={item.appName} item={item} />
))}
{historicCount > 0 && (
<div
className="text-xs text-gray-400 italic"
title="These installs were replayed from IME log content that predates this enrollment by more than 24 hours — they ran during a previous enrollment on this device"
>
{historicCount} historic app install{historicCount === 1 ? "" : "s"} from a previous enrollment hidden
</div>
)}
</div>}
</div>
);
@@ -444,9 +466,7 @@ function InstallItemRow({ item }: { item: InstallItem }) {
<path strokeLinecap="round" strokeLinejoin="round" strokeWidth={2} d="M9 3v2m6-2v2M9 19v2m6-2v2M5 9H3m2 6H3m18-6h-2m2 6h-2M7 19h10a2 2 0 002-2V7a2 2 0 00-2-2H7a2 2 0 00-2 2v10a2 2 0 002 2zM9 9h6v6H9V9z" />
</svg>
)}
<span className={`text-sm font-medium truncate ${item.state === "Skipped" ? "text-gray-500" : "text-gray-900"}`}>
{item.appName}
</span>
<TruncatedLabel text={item.appName} className={`text-sm font-medium ${item.state === "Skipped" ? "text-gray-500" : "text-gray-900"}`} />
{item.state === "Skipped" && (
<span className="text-xs px-2 py-0.5 rounded-full bg-gray-200 text-gray-600 font-medium">Skipped</span>
)}
@@ -10,6 +10,7 @@ import {
isDetectOnlyRow,
isNonCompliantReport,
mapRemediationStatus,
partitionHistoricScriptEvents,
reduceScriptEvents,
scriptCardKey,
scriptItemKey,
@@ -38,11 +39,15 @@ interface ScriptExecutionsProps {
}
export default function ScriptExecutions({ events, showScriptOutput, latestBootstrapVersion, displayNamesByRefKey }: ScriptExecutionsProps) {
const cards = useMemo(() => groupScriptItems(reduceScriptEvents(events)), [events]);
// Legacy-agent guard: split off script events replayed from a previous enrollment's IME
// log (newer agents suppress them at the source) so week-old runs never render as current
// executions. The muted note below keeps the gap explainable.
const { current, historicCount } = useMemo(() => partitionHistoricScriptEvents(events), [events]);
const cards = useMemo(() => groupScriptItems(reduceScriptEvents(current)), [current]);
const [expanded, setExpanded] = useState(true);
if (cards.length === 0) return null;
if (cards.length === 0 && historicCount === 0) return null;
// Header counters work on cards (one per policy), so a remediated cycle reads as
// "1 succeeded" rather than "1 succeeded + 2 non-compliant" when its detection /
@@ -114,6 +119,14 @@ export default function ScriptExecutions({ events, showScriptOutput, latestBoots
displayNamesByRefKey={displayNamesByRefKey}
/>
))}
{historicCount > 0 && (
<div
className="text-xs text-gray-400 italic"
title="These executions were replayed from IME log content that predates this enrollment by more than 24 hours — they ran during a previous enrollment on this device"
>
{historicCount} historic script execution{historicCount === 1 ? "" : "s"} from a previous enrollment hidden
</div>
)}
</div>
)}
</div>
@@ -0,0 +1,67 @@
"use client";
import { useState } from "react";
interface TruncatedLabelProps {
/** The full text to display. Also used verbatim as the hover tooltip. */
text: string;
/** Extra classes for the text styling (font size, colour, padding). */
className?: string;
/**
* When false, only the hover tooltip is provided — no click-to-expand and no
* button semantics. Use this inside an already-clickable row/link/button,
* where an inner onClick would hijack the outer navigation.
*/
interactive?: boolean;
}
/**
* A single-line label that truncates with an ellipsis by default.
*
* - Hovering always shows the full text in a native browser tooltip (standard
* tooltip, no special cursor).
* - When `interactive` (the default), clicking — or pressing Enter/Space when
* focused — toggles a fully expanded view that wraps the entire text over as
* many lines as needed. This keeps long values readable on touch devices
* where hover is unavailable.
* - When `interactive={false}`, it is a plain truncated span with only the
* tooltip, safe to nest inside a clickable row or link.
*/
export default function TruncatedLabel({
text,
className = "",
interactive = true,
}: TruncatedLabelProps) {
const [expanded, setExpanded] = useState(false);
if (!interactive) {
return (
<span title={text} className={`${className} min-w-0 truncate`}>
{text}
</span>
);
}
const toggle = () => setExpanded((v) => !v);
return (
<span
title={text}
role="button"
tabIndex={0}
aria-expanded={expanded}
onClick={toggle}
onKeyDown={(e) => {
if (e.key === "Enter" || e.key === " ") {
e.preventDefault();
toggle();
}
}}
className={`${className} min-w-0 cursor-pointer ${
expanded ? "whitespace-normal break-words" : "truncate"
}`}
>
{text}
</span>
);
}
@@ -1,6 +1,7 @@
"use client";
import { severityChipClass, KEV_BADGE_CLASS } from "@/lib/vulnerabilitySeverity";
import TruncatedLabel from "@/components/TruncatedLabel";
export interface VulnerabilityTopCve {
cveId: string;
@@ -136,7 +137,7 @@ export default function VulnerabilityExposurePanel({
)}
</div>
{c.sampleSoftware.length > 0 && (
<div className="text-[11px] text-gray-500 dark:text-gray-400 truncate mt-0.5">{c.sampleSoftware.join(", ")}</div>
<TruncatedLabel text={c.sampleSoftware.join(", ")} className="block text-[11px] text-gray-500 dark:text-gray-400 mt-0.5" />
)}
</div>
<div className="text-right flex-shrink-0">
@@ -0,0 +1,77 @@
import { describe, it, expect } from "vitest";
import {
HISTORIC_REPLAY_THRESHOLD_MS,
partitionHistoricReplayEvents,
type ReplayInputEvent,
} from "../historicReplay";
const BASE = 1700000000000;
const DAY_MS = 24 * 60 * 60 * 1000;
const evt = (overrides: Partial<ReplayInputEvent> = {}): ReplayInputEvent => ({
timestamp: new Date(BASE).toISOString(),
eventType: "app_install_completed",
data: {},
...overrides,
});
const APP_FINALS = new Set(["app_install_completed", "app_install_failed"]);
describe("partitionHistoricReplayEvents", () => {
it("drops events whose rejectedSourceTimestamp is > 24h older than the event stamp", () => {
const historic = evt({ data: { rejectedSourceTimestamp: new Date(BASE - 7 * DAY_MS).toISOString() } });
const fresh = evt({ data: {} });
const { current, historicCount } = partitionHistoricReplayEvents([historic, fresh], APP_FINALS);
expect(current).toEqual([fresh]);
expect(historicCount).toBe(1);
});
it("counts only finals — dropped non-final events are removed uncounted", () => {
const staleTs = new Date(BASE - 7 * DAY_MS).toISOString();
const events = [
evt({ eventType: "app_download_started", data: { rejectedSourceTimestamp: staleTs } }),
evt({ eventType: "download_progress", data: { rejectedSourceTimestamp: staleTs } }),
evt({ eventType: "app_install_started", data: { rejectedSourceTimestamp: staleTs } }),
evt({ eventType: "app_install_completed", data: { rejectedSourceTimestamp: staleTs } }),
evt({ eventType: "app_install_failed", data: { rejectedSourceTimestamp: staleTs } }),
];
const { current, historicCount } = partitionHistoricReplayEvents(events, APP_FINALS);
expect(current).toEqual([]);
expect(historicCount).toBe(2);
});
it("keeps future-skew rejections (source timestamp ahead of the event stamp)", () => {
const skewed = evt({ data: { rejectedSourceTimestamp: new Date(BASE + 2 * 60 * 60 * 1000).toISOString() } });
const { current, historicCount } = partitionHistoricReplayEvents([skewed], APP_FINALS);
expect(current).toEqual([skewed]);
expect(historicCount).toBe(0);
});
it("keeps within-24h rejections, missing and malformed rejectedSourceTimestamp", () => {
const within = evt({ data: { rejectedSourceTimestamp: new Date(BASE - 23 * 60 * 60 * 1000).toISOString() } });
const none = evt({ data: {} });
const noData = evt({ data: undefined });
const malformed = evt({ data: { rejectedSourceTimestamp: "not-a-date" } });
const { current, historicCount } = partitionHistoricReplayEvents([within, none, noData, malformed], APP_FINALS);
expect(current).toHaveLength(4);
expect(historicCount).toBe(0);
});
it("reads the snake_case wire variant", () => {
const historic = evt({ data: { rejected_source_timestamp: new Date(BASE - 7 * DAY_MS).toISOString() } });
const { current, historicCount } = partitionHistoricReplayEvents([historic], APP_FINALS);
expect(current).toEqual([]);
expect(historicCount).toBe(1);
});
it("empty finals set filters silently (DownloadProgress mode)", () => {
const historic = evt({ data: { rejectedSourceTimestamp: new Date(BASE - 7 * DAY_MS).toISOString() } });
const { current, historicCount } = partitionHistoricReplayEvents([historic], new Set<string>());
expect(current).toEqual([]);
expect(historicCount).toBe(0);
});
it("exposes the 24h threshold constant", () => {
expect(HISTORIC_REPLAY_THRESHOLD_MS).toBe(DAY_MS);
});
});
@@ -7,6 +7,7 @@ import {
isDetectOnlyRow,
isNonCompliantReport,
mapRemediationStatus,
partitionHistoricScriptEvents,
reduceScriptEvents,
scriptItemKey,
toNumber,
@@ -905,3 +906,82 @@ describe("groupScriptItems — card durationSeconds is the max phase run time",
expect(cards[0].durationSeconds).toBeUndefined();
});
});
describe("partitionHistoricScriptEvents", () => {
// Agent-side clamp evidence: rejectedSourceTimestamp = the source log line's own time,
// timestamp = the clock-clamped event stamp. > 24 h older ⇒ replayed history from a
// previous enrollment (session eaf3d8c4).
const DAY_MS = 24 * 60 * 60 * 1000;
it("drops events whose rejectedSourceTimestamp is > 24 h older than the event stamp and counts finals", () => {
const historicFinal = finalEvent({
ts: 0,
data: { policyId: "p1", scriptType: "remediation", rejectedSourceTimestamp: new Date(1700000000000 - 7 * DAY_MS).toISOString() },
});
const historicStart = finalEvent({
eventType: "script_started",
ts: 1,
data: { policyId: "p1", scriptType: "remediation", rejectedSourceTimestamp: new Date(1700000000000 - 7 * DAY_MS).toISOString() },
});
const fresh = finalEvent({ ts: 2, data: { policyId: "p2", scriptType: "platform" } });
const { current, historicCount } = partitionHistoricScriptEvents([historicFinal, historicStart, fresh]);
expect(current).toEqual([fresh]);
// Only finals count toward the "hidden executions" note — dropped starts would
// double-count the same run.
expect(historicCount).toBe(1);
});
it("keeps future-skew rejections (source timestamp ahead of the event stamp)", () => {
const skewed = finalEvent({
ts: 0,
data: { policyId: "p1", scriptType: "platform", rejectedSourceTimestamp: new Date(1700000000000 + 2 * 60 * 60 * 1000).toISOString() },
});
const { current, historicCount } = partitionHistoricScriptEvents([skewed]);
expect(current).toEqual([skewed]);
expect(historicCount).toBe(0);
});
it("keeps within-24h rejections and events without or with malformed rejectedSourceTimestamp", () => {
const within = finalEvent({
ts: 0,
data: { policyId: "p1", scriptType: "platform", rejectedSourceTimestamp: new Date(1700000000000 - 23 * 60 * 60 * 1000).toISOString() },
});
const none = finalEvent({ ts: 1, data: { policyId: "p2", scriptType: "platform" } });
const malformed = finalEvent({ ts: 2, data: { policyId: "p3", scriptType: "platform", rejectedSourceTimestamp: "not-a-date" } });
const { current, historicCount } = partitionHistoricScriptEvents([within, none, malformed]);
expect(current).toHaveLength(3);
expect(historicCount).toBe(0);
});
it("reads the snake_case wire variant too", () => {
const historic = finalEvent({
ts: 0,
data: { policyId: "p1", scriptType: "platform", rejected_source_timestamp: new Date(1700000000000 - 7 * DAY_MS).toISOString() },
});
const { current, historicCount } = partitionHistoricScriptEvents([historic]);
expect(current).toEqual([]);
expect(historicCount).toBe(1);
});
});
describe("reduceScriptEvents — implausible duration blanking", () => {
it("blanks durations above 24 h (mixed-timeline artifacts from legacy agents)", () => {
// Session eaf3d8c4: clock-clamped completion minus raw week-old start = 612225 s ≈ 170 h.
const items = reduceScriptEvents([
finalEvent({ data: { policyId: "p1", scriptType: "remediation", scriptPart: "detection", exitCode: "0", complianceResult: "True", durationSeconds: "612225.00", durationBasis: "script_runtime" } }),
]);
expect(items[0].durationSeconds).toBeUndefined();
expect(items[0].reportedAfterSeconds).toBeUndefined();
});
it("keeps the 24 h boundary value and blanks cycle-basis values the same way", () => {
const items = reduceScriptEvents([
finalEvent({ data: { policyId: "p1", scriptType: "platform", exitCode: "0", result: "Success", durationSeconds: "86400", durationBasis: "script_runtime" } }),
finalEvent({ ts: 1, data: { policyId: "p2", scriptType: "remediation", scriptPart: "detection", exitCode: "0", complianceResult: "True", durationSeconds: "90000", durationBasis: "cycle_including_reporting_latency" } }),
]);
expect(items[0].durationSeconds).toBe(86400);
expect(items[1].reportedAfterSeconds).toBeUndefined();
});
});
@@ -0,0 +1,55 @@
/**
* Client-side guard against historic IME-log replay (session eaf3d8c4): when a previous
* enrollment's IME log survives a re-enrollment, legacy agents replay its content and emit
* week-old script runs and app installs as if they were current activity. The agent's
* timestamp clamp preserves the evidence as `rejectedSourceTimestamp` on the event data —
* a source timestamp more than 24 h OLDER than the event stamp marks the event as replayed
* history. Newer agents suppress those events at the source (historic_ime_replay_detected);
* this partition covers sessions recorded by older agents.
*/
/** Mirrors the agent's 24 h source-timestamp staleness clamp. */
export const HISTORIC_REPLAY_THRESHOLD_MS = 24 * 60 * 60 * 1000;
export interface ReplayInputEvent {
timestamp: string;
eventType?: string;
data?: Record<string, any>;
}
export interface HistoricPartition<T extends ReplayInputEvent> {
current: T[];
/**
* Count of dropped events whose eventType is in `countedFinalTypes` — the number the UI
* reports as "hidden". Dropped non-final events (starts, progress ticks) are removed but
* not counted, so the note is not inflated by multiple events of the same run.
*/
historicCount: number;
}
/**
* Splits off events that are replayed history from a previous enrollment. Future-skew
* rejections (source timestamp AHEAD of the event stamp — mid-enrollment clock jump) are
* genuine current activity and stay in `current`, as do events without (or with malformed)
* `rejectedSourceTimestamp`.
*/
export function partitionHistoricReplayEvents<T extends ReplayInputEvent>(
events: T[],
countedFinalTypes: ReadonlySet<string>,
): HistoricPartition<T> {
const current: T[] = [];
let historicCount = 0;
for (const evt of events) {
const rejected = evt.data?.rejectedSourceTimestamp ?? evt.data?.rejected_source_timestamp;
if (typeof rejected === "string" && rejected.length > 0) {
const rej = Date.parse(rejected);
const ts = Date.parse(evt.timestamp);
if (Number.isFinite(rej) && Number.isFinite(ts) && ts - rej > HISTORIC_REPLAY_THRESHOLD_MS) {
if (evt.eventType && countedFinalTypes.has(evt.eventType)) historicCount++;
continue;
}
}
current.push(evt);
}
return { current, historicCount };
}
@@ -5,6 +5,7 @@
* mapping can be unit-tested without React Testing Library.
*/
import { extractBootstrapVersion } from "@/utils/bootstrapVersion";
import { HISTORIC_REPLAY_THRESHOLD_MS, partitionHistoricReplayEvents } from "./historicReplay";
export interface ScriptInputEvent {
timestamp: string;
@@ -119,6 +120,30 @@ export function scriptCardKey(card: Pick<ScriptCard, "policyId" | "scriptType" |
/** Threshold above which a Running placeholder is rendered as "stuck?" rather than animated. */
export const STALE_RUNNING_THRESHOLD_SECONDS = 600;
export { HISTORIC_REPLAY_THRESHOLD_MS };
const SCRIPT_FINAL_TYPES: ReadonlySet<string> = new Set(["script_completed", "script_failed"]);
export interface HistoricPartition {
current: ScriptInputEvent[];
/**
* Count of dropped FINAL events (script_completed / script_failed) — what the user reads
* as "hidden executions". Dropped script_started events are removed but not counted, so
* the note is not inflated by start/end pairs of the same run.
*/
historicCount: number;
}
/**
* Script-specific wrapper over `partitionHistoricReplayEvents` (see lib/historicReplay.ts
* for the replay semantics): drops script events replayed from a previous enrollment
* (session eaf3d8c4: 156 replayed runs shown with ~170 h durations) and counts the finals
* for the "N hidden" note.
*/
export function partitionHistoricScriptEvents(events: ScriptInputEvent[]): HistoricPartition {
return partitionHistoricReplayEvents(events, SCRIPT_FINAL_TYPES);
}
/**
* Score how complete a script item's data is (higher = better). Used by the reducer to
* pick the best entry when re-emissions of the same script collapse into one row.
@@ -261,7 +286,13 @@ export function reduceScriptEvents(events: ScriptInputEvent[]): ScriptItem[] {
// the script's own result line (runtime), remediation durations to HS-NEW-RESULT
// (cycle) — infer accordingly so old data is never displayed as run time when it
// isn't one.
const rawDuration = toNumber(d.durationSeconds ?? d.duration_seconds);
// Scripts cannot run > 24 h inside an enrollment (IME's execution timeout is ~30 min);
// larger values are mixed-timeline artifacts from legacy agents (raw stale start paired
// with a clock-clamped completion — session eaf3d8c4 showed 170 h). Hide, don't lie.
const rawDurationUnchecked = toNumber(d.durationSeconds ?? d.duration_seconds);
const rawDuration = rawDurationUnchecked != null && rawDurationUnchecked <= HISTORIC_REPLAY_THRESHOLD_MS / 1000
? rawDurationUnchecked
: undefined;
const rawBasis = d.durationBasis ?? d.duration_basis;
const isCycleBasis = typeof rawBasis === "string"
? rawBasis === "cycle_including_reporting_latency"
@@ -2,6 +2,9 @@
"name": "autopilot-monitor-web",
"version": "1.0.0",
"private": true,
"engines": {
"node": "22.x"
},
"scripts": {
"dev": "next dev",
"prebuild": "node scripts/sync-error-codes.js && node scripts/generate-lastmod.js",