Compare commits

..

71 Commits

Author SHA1 Message Date
Oliver Kieselbach fec4bcc6c5 bump pointer: internal (B-gkg, B-g22 built; ships with the D-394 agent release B-ztz)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-30 01:23:39 +01:00
Oliver Kieselbach 6ce2176aa0 Agent logs the TenantId miss block once and no longer swallows handler faults silently
- TenantIdAwaiter re-checks silently. The bootstrap's own probe has already written
  the resolver's miss block, which used to appear twice in a row whenever the
  TenantId was missing at start (the wait is on by default). A hit re-probes with
  the logger for the source line; an internal overload makes this testable.
- Handler and callback faults are logged at Warning: HelloCompleted (it carries the
  Hello resolution to the decision engine), the upload orchestrator's five events
  (one RaiseSafely helper), the AAD user-joined callback and ConsoleBypassWatcher's
  WatcherArmFailed.
- Faults on per-signal and per-event paths are logged at Debug with a repeatKey:
  the hand-off of signals and transitions to the upload spool, the SignalPosted and
  back-pressure observers, and timeline subscribers.
- Comments that still named a level from before D-394 are corrected; two German
  comments in SignalIngress are replaced.

D-394

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-30 01:23:28 +01:00
Oliver Kieselbach 1fe4e6711e bump pointer: internal, .claude/commands (D-394 built; agent release and count B-ztz)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-30 00:54:17 +01:00
Oliver Kieselbach 61947c416c Agent log levels follow one contract: Info is the flow, Debug the why, Verbose every detail, Trace the mechanics
- AgentLogger documents the four levels and takes an optional repeatKey on
  Info/Debug/Verbose: an identical repeat under the same key goes to Trace.
- To Trace: the IME registry watcher's arm/fire cycle (the only watcher wired
  to Debug), spool enqueue and ingress per item, informational pass-through,
  classifier-tick and no-op decision steps, idle DO polls, the Hello policy
  poll and the upload send.
- Decision-stage changes are Info; other effect-bearing steps and dead ends
  stay Debug.
- To Verbose: the upload success record (now with firstId, lastId, bytes),
  adapter mappings, download progress, per-file diagnostics entries and raw
  provisioning JSON.
- To Debug: "how" lines of start and end loops, duplicate Info lines, the
  OOBE update registry snapshot, caught exceptions that were logged below
  Debug, and IME lines read from a previous enrollment's log.
- Repeats at Info (re-collections, interval gather rules, recurring health
  scripts, IME policy and session lines) carry a repeatKey.
- Stop followed by Dispose logs "Stopped" once, Hello COMPLETED is logged only
  when it completed, and the await-enrollment poll no longer warns every 5 s.
- The Shared LogLevel doc and the portal hint describe the levels the same
  way; manifests and wire types regenerated.

D-394

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-30 00:53:57 +01:00
Oliver Kieselbach 25c65f1837 bump pointer: internal (D-393 live; field verify B-8v3)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-30 00:04:36 +01:00
Oliver Kieselbach eb287248c6 bump pointer: internal (D-392 VM check clean; D-393 built, backend deploy after go)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 23:57:53 +01:00
Oliver Kieselbach 738a349710 Failed app rows without a code take IME's code from the registry (D-393)
When the IME log line that first marks a failure carries no code (installer
timeout and similar), the agent reports the failure without one. IME's code
follows seconds later, but the app is already Error, so no second event goes
out and FailureCode stays empty; "Top Failure Codes" skipped such rows.

At session end the backend now fills an empty FailureCode on failed IME rows
from the latest registry_app_state error of the same AppId (canonical through
ErrorCodeCatalog.NormalizeCode). Fill only: a code or failureType from the
event stays, and a registry error older than the row's last attempt start is
never used. It runs at the terminal seam, after the agent's shutdown batch and
from the sweep, next to the ESP-blocking resolution; idempotent and fail-soft.

The session row-range filter, now used three times in the file, moves into
SessionAppRowsFilter.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 23:57:31 +01:00
Oliver Kieselbach 73525f1d34 bump pointer: internal (D-392 live; field verify B-wpr, VM check B-qfy)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 22:41:10 +01:00
Oliver Kieselbach b7c6b11909 bump pointer: internal (D-392 phase 2 built; release and VM check B-qfy)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 22:16:13 +01:00
Oliver Kieselbach 74d489b51e Agent reports IME's detection check after the install as app_post_install_detection
IME checks an app right after its installer; only that check's verdict reaches the ESP and
Intune. The agent now reports its result as its own informational event (D-392):

- IME-POST-INSTALL-DETECTION marks the check ("expected to have enforcement state:
  Detected", logged only for the app just installed); the app's next detection result line
  becomes app_post_install_detection (postInstallDetection, afterReboot) and detectionResult
  stays the check before the install.
- After an exit code mapped to SoftReboot/HardReboot the check right after the install is not
  reported; IME-POST-REBOOT-DETECTION (InProgressPendingReboot -> Success) marks the check
  after the restart instead.
- The mark is transient and the marker action app-mutating, so a marker from a previous
  enrollment's log or without its result line never turns a later check into this one. No
  state transition, no decision signal; historic replay is suppressed like DO telemetry.
- Install Progress, the timeline, the diagnosis tile (DiagnosisCulprit.PostInstallDetection)
  and the MCP event catalog show the check.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 22:16:00 +01:00
Oliver Kieselbach dff69b4d73 bump pointer: internal (D-392 app detection, phase 1 built; deploy and verify B-wpr)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 21:55:12 +01:00
Oliver Kieselbach 9c654983d1 App detection follows IME's two checks: 0x87D1041C is the verdict after the install, detectionResult the check before it
IME checks every app before the install (NotDetected starts it) and right after the
installer; only the second check's verdict reaches the ESP and Intune. app_install_completed
comes at IME's provisional "Success", so detectionResult on app events is the check before
the install. The apps banner, ANALYZE-APP-001 and the diagnosis read it as the result after
the install and flagged healthy installs (D-392).

- IME-ERROR-REPORT captures EnforcementErrorCode as errorCode (-2016345060 = 0x87D1041C).
- AppInstallSummaries.FailureCode is stored canonical (ErrorCodeCatalog.NormalizeCode); one
  HRESULT parser serves the catalog lookup, the diagnosis and the ingest.
- The apps banner counts failed installs IME did not detect after the installer
  (DetectionFailureCount, renamed from DetectionLiesCount), with its own advice for Store
  apps; the app page uses the generated AppAnalyticsResponse.
- ANALYZE-APP-001 v2 matches the code in any enrollment outcome; ANALYZE-APP-013 picks its
  app by the code; ANALYZE-APP-010 is retired (APP-001 reports the same event).
- Diagnosis, Install Progress and the timeline read the code: IME's verdict turns an
  installed row into a detection failure, error codes read as hex, and the timeline shows the
  check before the install.
- The summary column DetectionResult and DiagnosisCulprit.DetectionResult are gone.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 21:54:40 +01:00
Oliver Kieselbach 0bc82fd719 bump pointer: internal (D-390/D-391 released: backend 1.5.1306, MCP 1.6.569 @ 783b390; field verify B-w7y, alert rule B-5q5)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 20:17:29 +01:00
Oliver Kieselbach 783b390448 bump pointer: internal (lesson from the D-390/D-391 request-body work)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 18:00:39 +01:00
Oliver Kieselbach 5c75155293 bump pointer: internal, .claude/commands (D-390/D-391 counted body cap and report upload limit built; deploy and verify B-w7y, alert rule B-5q5)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 17:58:50 +01:00
Oliver Kieselbach 7588286787 Request bodies are capped on the bytes actually read, and report uploads run three at a time per instance
RequestBody checked its byte cap only against the Content-Length header and then buffered the
whole body. A chunked body carries no Content-Length and a gzip body's header names the compressed
size, so a route with an 8 KB cap read whatever Kestrel's unpinned default allowed once inflated.
Every read now counts the bytes the handler receives, after request decompression, and stops one
byte past the cap; a site that names no cap reads under 1 MiB, and the error stays the 400
"Request body too large". The agent routes that parse with their own reader (session
registration, error report, distress, upload URL) and the Azure Monitor alert webhook read through
the same counted buffer and keep their responses. The telemetry ingest shares the counting, so a
body refused at the worker limit gets its 413 instead of a 500.

The worker's request body limit is pinned at 20 MiB, the largest route cap. Kestrel and the
decompression stream both enforce it, and a PostConfigure keeps registration order and app
settings from lifting it. A guard test keeps every body read inside the counted reader.

Session report and diagnostic-file uploads (up to 20 MiB each) run at most three at a time per
instance. A fourth gets 429 with Retry-After, and the portal dialogs keep their input. The first
refusal per instance and hour raises the new ReportUploadLimitReached ops event, which an alert
rule can route.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 17:58:24 +01:00
Oliver Kieselbach 0d6797275c bump pointer: internal (B-xg7 done, B-vu8 trimmed, D-389 changelog entry)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 16:14:48 +01:00
Oliver Kieselbach 17f98f5c56 bump pointer: internal (D-389 usage hardware device count released, B-xg7)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 16:06:20 +01:00
Oliver Kieselbach f53fdf86f6 Fleet Health counts read "1 enrollment" and "1 install" in the singular
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 16:00:46 +01:00
Oliver Kieselbach b57f9312ce bump pointer: internal (D-389 usage hardware device count built, B-xg7)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 15:42:21 +01:00
Oliver Kieselbach 5136d33c2c Usage Metrics hardware lists show the devices behind their sessions; Fleet Health counts enrollments
Top Manufacturers and Top Models counted enrollment sessions without saying so, so a device
reset and enrolled again read like several devices. The lists still rank and share by sessions;
every row now also carries the distinct devices behind them (HardwareCount.DeviceCount), keyed
like device journeys: the normalized serial number per tenant, and a session without a usable
serial counts as its own device. The page groups both lists under a Hardware heading that says
so. Fleet Health's Health by Device Model labelled its session count "devices"; it now says
"enrollments". The get_usage_metrics description names the unit.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 15:41:45 +01:00
Oliver Kieselbach 5589ca42c7 bump pointer: internal (D-388 feedback id released: backend 1.5.1304, B-cfz)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 13:39:38 +01:00
Oliver Kieselbach 8f9cf6e153 bump pointer: internal (lesson: browser checks are always possible)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 13:13:42 +01:00
Oliver Kieselbach eebbc895c8 bump pointer: internal, infra (D-388 feedback id built; deploy, backfill and verify B-cfz)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 13:06:28 +01:00
Oliver Kieselbach 7d19a71230 Every feedback entry gets a 12-character id, shown on User Feedback and linked from the bell and alerts
Help-menu feedback, ratings and farewell comments each carry a FeedbackId: 12 lowercase hex
characters, the shape of a session report id. The feedback repository mints it when a row is first
written and keeps it on every later write (the rating and farewell rows are rewritten whole); a
help-menu row's RowKey ends in it. It is stored as a column in every kind, so one filter finds an
entry across all partitions.

FeedbackEntryWire.FeedbackId is that id for every kind (it was the help-menu RowKey).
FeedbackReceived, FeedbackRatingReceived and OffboardingFeedbackReceived carry feedbackId and a
portal path to the single entry, and the "New Feedback" / "New Rating" bells link it too.

The User Feedback page shows the id with a copy button on every card and follows ?feedbackId= to
the entry's tab and page, highlighting the card; an unknown id is named in the error banner.

Rows written before get their id from a one-time backfill after this backend is live.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 13:05:41 +01:00
Oliver Kieselbach 77569e0dfb bump pointer: internal (D-387 push telemetry released: backend 1.5.1303, B-6qk)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 11:52:35 +01:00
Oliver Kieselbach 7a457b5d63 bump pointer: internal, .claude/commands (D-387 push telemetry built; deploy and verify B-6qk)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 11:17:01 +01:00
Oliver Kieselbach 1ea366c419 Push app usage telemetry: opens, pairing steps, actions and device type per pairing scope
The push receiver reports push_app_opened (per page load, per return after a minute in
the background, per notification tap), push_device_checked, push_pair_step and
push_action. Each event carries the platform, display mode, notification permission and
screen class and, where the browser gives Client Hints, the model and OS version. Every
receiver item is attributed to the scope its device token names; only the token's first
segment is read, and a platform-scope receiver counts as a Global Admin. Nothing from the
history, no id and no token leaves the device.

The 2-hourly maintenance run reports the paired-device inventory (counts only), and
PushPairing and PushDelivery carry the tenant. Notify me when done reports
session_watch_toggled.

A notification tapped while the receiver shows its status or pairing page now opens the
entry. The CSP no longer allows js.monitor.azure.com: the SDK is bundled and its only
request there is switched off.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-29 11:16:15 +01:00
Oliver Kieselbach bba8a0d6b4 bump pointer: internal, .claude/commands (B-s8j: own tenant out of the growth figures)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 19:45:53 +01:00
Oliver Kieselbach 6abe450388 Growth figures can leave the operator's own and test tenants out
GET global/metrics/growth and get_growth_metrics take excludeTenantIds (at
most 20 tenant ids, normalized; anything else is a 400) and drop those
tenants before any figure is computed: signups, cohorts, activation,
segments, plans and the tenant rows. excludedTenants counts the
configuration rows that matched, so a mistyped or offboarded id shows up
instead of being counted silently. The ids stay with the operator, never
in code.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 19:45:32 +01:00
Oliver Kieselbach fe193268ea bump pointer: internal, .claude/commands (D-386 growth report built; deploy and verify B-ddq)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 17:28:35 +01:00
Oliver Kieselbach ef6cf8e3f4 Growth figures for operators: one server-side join of signups, counters and daily usage
GET global/metrics/growth (GlobalReadOrAdmin) and the MCP tool
get_growth_metrics return the signups of the last N UTC days with peak days
and hour/weekday counts in an IANA time zone, weekly cohorts with enrollment,
success and the days to the first day with sessions, segments of all tenants
and plan counts; rows per signup only on request, ids and dates without
domains. The per-tenant counters are read with their tenant id, and the
unused UsageMetrics snapshot reader gives way to a range reader that throws
instead of reporting no activity.

query_table projects fields server-side and keeps the projection across
pages, as the server instructions promise; the raw table route no longer
copies the entity flattening.

The dashboard welcome card sends welcome_link_clicked and the OOBE code copy
buttons send bootstrap_session_copied (through useCopy, so a failed clipboard
write no longer rejects unhandled), which makes the step between signup and
the first enrollment measurable.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 17:28:22 +01:00
Oliver Kieselbach e06a687ddd bump pointer: internal (aborted-body 400 released: backend 1.5.1301, B-usk)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 16:32:00 +01:00
Oliver Kieselbach 1ee13de7a8 bump pointer: internal, .claude/commands (B-9zh; platform-health baselines 2026-10-28)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 16:27:10 +01:00
Oliver Kieselbach 8cb061784e Backend: a request body the client stopped sending is a 400, not a 500
When the browser cancels a request mid-body (tab closed, navigation,
network drop), Kestrel throws BadHttpRequestException "Unexpected end of
request content" while the body is read. The function's catch turned that
into a 500 and an exception row: 39 x POST AddToGroup and 1 x
GetScriptDisplayNames in 30 days, all client aborts.

RequestBody, the one body reader, now answers that case with the same 400
envelope as an empty or malformed body ("Request body incomplete"). Agent
routes are untouched: they read req.Body themselves, and ingest keeps its
503 so the agent replays the batch.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 16:27:08 +01:00
Oliver Kieselbach 7fd4a4fe62 MCP + rules tooling: qs 6.16.1, body-parser 2.4.0, fast-uri 3.1.9 close the open Dependabot alerts
Lockfile-only bumps of transitive dependencies, all inside the ranges their
parents already declare (express ^2.3.0 / ^6.16.0, ajv ^3.0.1):

- body-parser 2.3.0 -> 2.4.0 (mcp via express), GHSA-27r3-jxmh-p828;
  pulls iconv-lite 0.7.2 -> 0.7.3 with it
- qs 6.16.0 -> 6.16.1 (mcp via express/body-parser), GHSA-6pq8-jhm2-2vcw
- fast-uri 3.1.8 -> 3.1.9 (mcp and rules/scripts via ajv),
  GHSA-w74x-v6f9-j3xg, GHSA-xhq7-xmqj-769h, GHSA-wjr9-j795-jxcr,
  GHSA-333x-w4r6-6crp

The MCP fast-uri override is a security floor (7df208fa), so it moves from
^3.1.4 to ^3.1.9. qs stays on 6.16.1 rather than 6.17.0, which is a day old
and inside the 7-day cooldown. The MCP lockfile was written with npm 11.21.1
so the libc fields Dependabot added in #192 survive.

npm audit: 0 vulnerabilities in mcp, web, rules/scripts and tools/quality.
MCP: tsc, build, lint (0 warnings), knip clean; 1057 tests pass.
rules/scripts/validate.js passes.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-28 13:10:38 +01:00
dependabot[bot] 8929f1c5b4 chore(deps): bump the mcp group (#192)
Bumps the mcp group in /src/McpServer/autopilot-monitor-mcp with 3 updates: [undici](https://github.com/nodejs/undici), [knip](https://github.com/webpro-nl/knip/tree/HEAD/packages/knip) and [typescript-eslint](https://github.com/typescript-eslint/typescript-eslint/tree/HEAD/packages/typescript-eslint).


Updates `undici` from 8.11.2 to 8.12.3
- [Release notes](https://github.com/nodejs/undici/releases)
- [Commits](https://github.com/nodejs/undici/compare/v8.11.2...v8.12.3)

Updates `knip` from 6.41.0 to 6.42.1
- [Release notes](https://github.com/webpro-nl/knip/releases)
- [Commits](https://github.com/webpro-nl/knip/commits/knip@6.42.1/packages/knip)

Updates `typescript-eslint` from 8.71.2 to 8.72.0
- [Release notes](https://github.com/typescript-eslint/typescript-eslint/releases)
- [Changelog](https://github.com/typescript-eslint/typescript-eslint/blob/main/packages/typescript-eslint/CHANGELOG.md)
- [Commits](https://github.com/typescript-eslint/typescript-eslint/commits/v8.72.0/packages/typescript-eslint)

---
updated-dependencies:
- dependency-name: undici
  dependency-version: 8.12.3
  dependency-type: direct:production
  update-type: version-update:semver-minor
  dependency-group: mcp
- dependency-name: knip
  dependency-version: 6.42.1
  dependency-type: direct:development
  update-type: version-update:semver-minor
  dependency-group: mcp
- dependency-name: typescript-eslint
  dependency-version: 8.72.0
  dependency-type: direct:development
  update-type: version-update:semver-minor
  dependency-group: mcp
...

Signed-off-by: dependabot[bot] <support@github.com>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
2026-10-28 12:45:05 +01:00
dependabot[bot] ff04137d0a chore(deps): bump the web group (#193)
Bumps the web group in /src/Web/autopilot-monitor-web with 6 updates:

| Package | From | To |
| --- | --- | --- |
| [next](https://github.com/vercel/next.js) | `16.4.1` | `16.4.2` |
| [react](https://github.com/react/react/tree/HEAD/packages/react) | `19.3.0` | `19.3.1` |
| [react-dom](https://github.com/react/react/tree/HEAD/packages/react-dom) | `19.3.0` | `19.3.1` |
| [@next/bundle-analyzer](https://github.com/vercel/next.js/tree/HEAD/packages/next-bundle-analyzer) | `16.4.0` | `16.4.2` |
| [eslint-config-next](https://github.com/vercel/next.js/tree/HEAD/packages/eslint-config-next) | `16.4.0` | `16.4.2` |
| [knip](https://github.com/webpro-nl/knip/tree/HEAD/packages/knip) | `6.41.0` | `6.42.1` |


Updates `next` from 16.4.1 to 16.4.2
- [Release notes](https://github.com/vercel/next.js/releases)
- [Commits](https://github.com/vercel/next.js/compare/v16.4.1...v16.4.2)

Updates `react` from 19.3.0 to 19.3.1
- [Release notes](https://github.com/react/react/releases)
- [Changelog](https://github.com/react/react/blob/main/CHANGELOG.md)
- [Commits](https://github.com/react/react/commits/v19.3.1/packages/react)

Updates `react-dom` from 19.3.0 to 19.3.1
- [Release notes](https://github.com/react/react/releases)
- [Changelog](https://github.com/react/react/blob/main/CHANGELOG.md)
- [Commits](https://github.com/react/react/commits/v19.3.1/packages/react-dom)

Updates `@next/bundle-analyzer` from 16.4.0 to 16.4.2
- [Release notes](https://github.com/vercel/next.js/releases)
- [Commits](https://github.com/vercel/next.js/commits/v16.4.2/packages/next-bundle-analyzer)

Updates `eslint-config-next` from 16.4.0 to 16.4.2
- [Release notes](https://github.com/vercel/next.js/releases)
- [Commits](https://github.com/vercel/next.js/commits/v16.4.2/packages/eslint-config-next)

Updates `knip` from 6.41.0 to 6.42.1
- [Release notes](https://github.com/webpro-nl/knip/releases)
- [Commits](https://github.com/webpro-nl/knip/commits/knip@6.42.1/packages/knip)

---
updated-dependencies:
- dependency-name: next
  dependency-version: 16.4.2
  dependency-type: direct:production
  update-type: version-update:semver-patch
  dependency-group: web
- dependency-name: react
  dependency-version: 19.3.1
  dependency-type: direct:production
  update-type: version-update:semver-patch
  dependency-group: web
- dependency-name: react-dom
  dependency-version: 19.3.1
  dependency-type: direct:production
  update-type: version-update:semver-patch
  dependency-group: web
- dependency-name: "@next/bundle-analyzer"
  dependency-version: 16.4.2
  dependency-type: direct:development
  update-type: version-update:semver-patch
  dependency-group: web
- dependency-name: eslint-config-next
  dependency-version: 16.4.2
  dependency-type: direct:development
  update-type: version-update:semver-patch
  dependency-group: web
- dependency-name: knip
  dependency-version: 6.42.1
  dependency-type: direct:development
  update-type: version-update:semver-minor
  dependency-group: web
...

Signed-off-by: dependabot[bot] <support@github.com>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
2026-10-28 12:44:47 +01:00
Oliver Kieselbach ff8bc7927f bump pointer: internal (D-385 addendum released: one gate workflow)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 12:18:08 +02:00
Oliver Kieselbach 8a53c6233f Web + MCP: vitest 4.1.12 closes the @vitest/mocker advisories (GHSA-qxg6-89mg-rqv8, GHSA-xp26-3454-mjgp)
Dev-only. Resolved with --before=2026-10-16 so the bump honours the 7-day
cooldown of dependabot.yml: vite stays 8.3.4 and rolldown 1.2.14, only the
vitest chain moves (plus chai 6.3.0, tinyrainbow 3.2.0, and in MCP
@jridgewell/sourcemap-codec 1.6.0). The libc fields Dependabot wrote for the
@next/swc-linux-* entries in #191 are kept; a local npm 11.8 drops them.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 12:09:29 +02:00
Oliver Kieselbach f3a4ce6ed8 bump pointer: internal (D-385 amended: one gate workflow)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 12:00:02 +02:00
Oliver Kieselbach 42dae1b38c Bootstrap script gates: one workflow instead of a caller plus a reusable copy (D-385)
The gate workflow carries its own push, pull-request and dispatch triggers
next to workflow_call, so the workflow list shows it once and its page lists
its runs. pester.yml, which only called it, is gone, and so are its entries in
the paths-ignore of ci.yml and codeql.yml. The workflow has no concurrency
group, because a workflow-level group would also bind the runs the publishers
call.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 11:59:41 +02:00
dependabot[bot] b58830ddcb chore(deps): bump the web-security group across 1 directory with 2 updates (#191)
Bumps the web-security group with 2 updates in the /src/Web/autopilot-monitor-web directory: [next](https://github.com/vercel/next.js) and [dompurify](https://github.com/cure53/DOMPurify).


Updates `next` from 16.4.0 to 16.4.1
- [Release notes](https://github.com/vercel/next.js/releases)
- [Commits](https://github.com/vercel/next.js/compare/v16.4.0...v16.4.1)

Updates `dompurify` from 3.4.16 to 3.4.17
- [Release notes](https://github.com/cure53/DOMPurify/releases)
- [Commits](https://github.com/cure53/DOMPurify/compare/3.4.16...3.4.17)

---
updated-dependencies:
- dependency-name: next
  dependency-version: 16.4.1
  dependency-type: direct:production
  dependency-group: web-security
- dependency-name: dompurify
  dependency-version: 3.4.17
  dependency-type: indirect
  dependency-group: web-security
...

Signed-off-by: dependabot[bot] <support@github.com>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
2026-10-23 11:45:54 +02:00
Oliver Kieselbach caac165172 bump pointer: internal (D-385 released: bootstrap gates run on every change)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 11:42:03 +02:00
Oliver Kieselbach d25f2286b4 bump pointer: internal (D-385 bootstrap gates on every change and before every signing or upload)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 11:30:53 +02:00
Oliver Kieselbach 1dd4a477c5 Bootstrap gates run on every change and before every signing or upload (D-385)
The gates were attached to publishing: they ran only as the first job of the
script publish. Holding that publish back with GitHub's skip-actions marker
dropped them together with CI, CodeQL and zizmor. The stable agent release
published the same scripts without them, the MSI build signed the loader
without them, and no gate page ever showed a run.

- pester.yml, shown as "Bootstrap script gates", runs on pushes to main as
  well as pull requests, with one list of every input of the checks.
- publish-scripts.yml: a push whose commit message carries the skip-publish
  marker (spelled out in the workflow) runs neither job and uploads nothing;
  every check of the push still runs.
- build-agent.yml: a publish_as_stable release waits for the gates, which run
  next to the build and are skipped otherwise.
- build-msi.yml: nothing is signed before the gates pass. The loader's own
  parse/ASCII step goes, since the gates cover it.
- The reusable workflow is named "Bootstrap script gates (reusable)", since
  its runs show under the caller only.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 11:29:19 +02:00
Oliver Kieselbach b8312ee0c6 bump pointer: internal (D-384 released: installer 2.9, bootstrap MSI 1.4.0, docs, web, MCP)
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-23 02:49:58 +02:00
Oliver Kieselbach d639d9dda9 Bootstrap MSI 1.4: the action runs only the exact loader the package embeds (SHA-256 baked in at build time)
The automated security review of the previous commit found that a publisher pin alone
would run any validly signed script of ours placed at the copy's path, such as an older
loader without the held handle. The build now bakes the SHA-256 of the signed loader into
the action (wix build -d LoaderSha256=...; the package refuses to build without it), and
the action compares the bytes it read against it before the signature check.

- Package.wxs: hash check, preprocessor guard, comment
- build-msi.yml: the build step hashes the signed loader and passes it to wix
- Bootstrap.Integration.Tests.ps1: the harness substitutes the hash of the loader it serves;
  a copy that is not the embedded loader, however validly signed, runs nothing
- BootstrapContractTests: the hash condition, the guard and the build step are pinned
- internal: D-384, footprint doc and plan updated

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-23 02:09:56 +02:00
Oliver Kieselbach f44e8aadb0 Bootstrap MSI 1.4 keeps its loader copy under ProgramData and runs only what it checked; installer 2.9 removes the copy (D-384)
MSI 1.3 (D-377) installed the loader under Program Files, where nothing removed it: a
customer found the file on every device. Everything of ours lives under ProgramData.

- Package.wxs 1.4.0: the loader copy goes back to <base>\Msi (new component GUID); the
  deferred SYSTEM action, started in System32, reads the copy once, checks our signature
  and the publisher pin on those bytes and runs those bytes from memory, so a file a user
  planted at that path leads to nothing and no handle keeps the installer from removing
  the copy. Every bracket and brace is escaped for the Windows Installer formatter.
- Install-AutopilotMonitor.ps1 2.9: Remove-MsiTransportFolder removes the copy in the
  agent-present branch (install and skip clear the base already) and an agent folder that
  is then empty; Remove-LegacyMsiLoaderFolder removes MSI 1.3's folder under Program Files
  in every outcome while devices still enroll with 1.3.
- Tests: installer unit tests for both functions; the loader's MSI contract; the harness
  asserts after every run that nothing exists outside ProgramData, runs the MSI 1.4 action
  read from Package.wxs (valid, foreign, unsigned, changed; install, skip, marker only,
  agent present) and expects MSI 1.3's folder gone; BootstrapContractTests pin the
  directory chain, the publisher pin, the escapes and the working directory.
- build-msi.yml: smoke job installs the built MSI on windows-2022/2025 with the deployment
  marker set and expects nothing under ProgramData or Program Files, then uninstalls.
- internal: D-384, footprint doc, plan, lessons, backlog.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-23 02:01:15 +02:00
Oliver Kieselbach e5b7003799 bump pointer: internal (ConfigMgr Watcher opt-in, D-382 updated)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 01:45:59 +02:00
Oliver Kieselbach 6db3cb9741 ConfigMgr Watcher: the ConfigMgr client check is opt-in per tenant (D-382)
The check from d4e67cdb now runs only for tenants that enable it, like the
RealmJoin Watcher: TenantConfiguration.EnableConfigMgrWatcher feeds
AnalyzerConfiguration.EnableConfigMgrWatcher (default off, ConfigVersion
42). With the setting off, DefaultComponentFactory does not create the
ConfigMgrClientHost, so other tenants' devices run no check at all.

- Portal: toggle "ConfigMgr Watcher" in Agent Settings, section field map,
  tenant config report.
- Privacy page: the check is named as optional.
- Shared manifest and the web and MCP wire types regenerated.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 01:45:22 +02:00
Oliver Kieselbach a213290eb6 bump pointer: internal (D-382 V1-style ConfigMgr detection, D-384 dropped, B-b2u, lesson)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 00:45:12 +02:00
Oliver Kieselbach d4e67cdbb5 ConfigMgr client detection is back in the V2 agent (D-382)
The V1 agent reported whether the Configuration Manager client is
installed; the check was lost when the V2 agent replaced the V1 enrollment
tracker. ConfigMgrClientProbe reads what V1 read (the CCM key, CCMSetup
LastValidVersion, the assigned site code, the %windir%\CCM folder, the
CcmExec service state) and keeps the V1 confidence score.
ConfigMgrClientDetector, polled by ConfigMgrClientHost every minute, emits
configmgr_client_detected with the V1 payload when the client is first seen
and again when its reported state changes, at most 10 times per run; a
restart into the same state stays silent.

- Session Info shows the latest detection; the V1 sentence about disturbed
  event sequences is gone.
- Privacy page: device context names the Configuration Manager client.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-23 00:44:16 +02:00
Oliver Kieselbach e4d3e8ed30 bump pointer: internal (D-382 to D-384, provider-stall concept doc, configmgr-client-status plan phase 1a)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 23:55:23 +02:00
Oliver Kieselbach d4774ed043 Provider-stall tripwire counts device-preparation providers only while device preparation is open (D-383)
A ConfigMgr client installed as a Win32 app registers its device-preparation
policy provider after its own install, with InstallationState=1, and nothing
completes it. The tripwire then reported a stall long after device
preparation had ended.

- EspPhaseSnapshot.DevicePreparationOpen decides whether device preparation
  can still hold the ESP (it runs or failed, or the phase is unknown).
  EvaluateStallTransition takes it as a parameter; the detector reads the
  phase through an injectable reader.
- The cross-restart fingerprint applies the same filter, so a restart does
  not report the same stall again.
- The message names the wait: Setup/Apps providers hold the ESP without any
  timeout, device-preparation providers until their timeout.
- The diagnosis names a stalled provider only for a failure in its ESP
  category; the waiting list of an unfinished session stays unfiltered.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 23:55:00 +02:00
Oliver Kieselbach b9cc515258 bump pointer: internal (deploy of D-379, D-380, D-381 recorded)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 23:14:11 +02:00
Oliver Kieselbach fef1f54c09 bump pointer: internal (configmgr-client-status plan draft)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:59:25 +02:00
Oliver Kieselbach 60dc850317 web: AGENTS.md heading level, page lastmod regenerated for /about and /privacy
Both were left uncommitted in the working tree; committed as they stand.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:59:25 +02:00
Oliver Kieselbach da58ac0a27 bump pointer: internal (B-ne6 join volume)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:51:57 +02:00
Oliver Kieselbach d1d15db4fe bump pointer: internal (backlog B-ne6 from the security review of D-381)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:49:30 +02:00
Oliver Kieselbach a3810b74a7 bump pointer: internal (SignalR revoke bound to the sign-in tenant, D-381)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:40:47 +02:00
Oliver Kieselbach 80d50a6d92 A live SignalR connection is addressed by its sign-in tenant; a revoke reaches only the tenant whose grant it ends (D-381)
Security finding (CWE-863): the SignalR user id was the bare UPN and every revoke cut that UPN across the
hub. A tenant admin could add any UPN (a Global Admin, another customer's operator) and remove, disable or
demote it in a loop, restarting that person's live connections in every tenant.

- Negotiate binds the user id to the sign-in tenant plus principal key from the validated request context
  (SignalRGroupHelper.UserId); a caller without a principal key negotiates without a user id, since every
  revocable join gate needs the key.
- ISignalRNotificationService.DisconnectUserAsync takes the tenant and the key. LiveStreamRevoker is its
  only caller and names the tenant each grant resolved under: member routes the route's tenant,
  self-service routes the managing tenant, Global Admin routes the tenant of the UPN's identity binding.
  Replacing or deleting a binding now cuts the streams signed in under the previous one.
- A self-service assignment confers scope only while its assignee is bound to the owning tenant, so a
  self-service grant resolves under the owner alone and the owner's revokes never need another tenant.
- Remove, disable and enable of a UPN without a row in the tenant answer 404 and change nothing: no audit,
  no push revoke, no end of an assignment, no cut.
- GlobalAdminService.DisableGlobalAdminAsync and its repository method had no caller and are removed.
- Tests pin the finding's attack, the 404s, the self-service gate, the binding routes and the call sites;
  each part was mutated back to the old behaviour and failed its tests.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 22:39:26 +02:00
Oliver Kieselbach 5371de3856 bump pointer: internal (D-380 verify items in B-pxg)
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 22:24:55 +02:00
Oliver Kieselbach 483dc3de94 The onboarding seat belongs to the first activation and to the recorded member alone (D-380)
Two follow-up findings of the security scan against D-378.

- IsPromotableUpn is a shape test (contains '@', no whitespace, no #EXT#); the "System" prefix
  test is gone. It rejected real members such as systemadmin@… although every sentinel already
  fails the '@' test, so such a tenant got no seat and fell back to first-caller-wins.
- BuildAuthResult keys the first-user guard off a recorded OnboardedBy, not off its promotability:
  a recorded value nobody can seat still blocks every other roleless caller.
- RevokeAsync records the revoke (PreviewWhitelist row "revoked") before it deletes the activation,
  fail-loud; a re-approve never clears it, and activation seats nobody while it exists. A member
  the tenant removed stays removed whatever a Global Admin's revoke + re-approve does.
- Every successful first-admin seat (activation and first sign-in) writes the tenant's audit entry
  CREATE TenantAdmin, fail-soft, through a new longest TenantAdminsService constructor.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 22:22:57 +02:00
Oliver Kieselbach 06b69aa0d8 The logparser pattern test ends at the first timeout or a 2 s budget, honours cancellation, caps the pattern at 2,000 characters, runs interpreted and admits two tests per instance (D-379)
Security finding (ReDoS / CWE-1333): a Tenant Admin of any tenant or a Global Reader could send a catastrophic pattern with 200 non-matching lines to POST rules/gather/test-pattern and cost ~200 s of a worker thread per request (one swallowed 1 s timeout per line), repeat it up to the portal budget and disconnect at once — nothing cancelled the work, nothing limited concurrency, the pattern length was bounded only by the body cap, and RegexOptions.Compiled emitted IL for every caller pattern.

- TestLogPatternFunction: the first RegexMatchTimeoutException ends the test, a 2 s EvaluationBudget ends it when every line is merely slow, and the invocation CancellationToken (client disconnect, host shutdown) ends it between two lines — without throwing. Lines after the stop get no row; LogPatternTestResult.StopReason (regex_timeout | time_budget | cancelled) and a note name the stop and the unevaluated range. A timeout on the last line is a complete test.
- ValidateRequest rejects patterns over 2,000 characters (the MCP schema's cap) before any Regex is built.
- BuildAgentRegex keeps the agent's semantic options and its 1 s match timeout but drops Compiled: the flag changes speed only, never a match result.
- TestLogPatternGate (singleton, limit 2) is entered before the regex is built; without a free slot the function answers 429 RateLimited with Retry-After: 3 and never queues. Stops and refusals log at Warning.
- Shared: LogPatternTestResult.StopReason (additive); manifests and wire types regenerated. MCP: the tool description says that the first timeout ends the test.
- Tests: pattern cap, interpreted construction with the agent's timeout, catastrophic pattern stops after one timeout (was ~200 s), last-line timeout is no stop, budget and cancellation stops, gate slots.

Submodule pointers: internal (plan, D-379, backlog B-66p/B-j42), .claude/commands (platform-health marker).

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 21:35:14 +02:00
Oliver Kieselbach 351c8d4b3a bump pointer: internal (activation race fix live, D-378)
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 21:01:23 +02:00
Oliver Kieselbach e704aa7359 Activation seats the onboarding admin before it activates the tenant; the first-user seat belongs to that member alone (D-378)
Security finding (CWE-367): the activation wrote the approved row first and the OnboardedBy
admin row a few storage round-trips later. In between the tenant was activated with no
members, and auth/me seated any roleless caller of that moment as Admin; every member of the
customer's Entra tenant could poll auth/me across the auto-approve moment.

- TenantApprovalService: uncached pre-check, then the OnboardedBy Admin row (conditional
  insert, best-effort, fresh config read), then the activation row (still the arbiter), then
  the welcome mail. The two tables cannot share a batch, so "before" is the guarantee.
- AuthFunction.BuildAuthResult: with a promotable OnboardedBy the first-user auto-admin goes
  to that UPN only; other roleless callers stay roleless. Without one (rows from before the
  field existed) the first sign-in still becomes the admin. The grant logs at Warning.
- Both first-admin writers use IAdminRepository.TryAddTenantMemberAsync (AddEntityAsync,
  409 = left untouched) instead of an upsert; TenantAdminsService.TryAddTenantAdminAsync
  replaces AddTenantAdminAsync. PreviewWhitelistService.IsApprovedFreshAsync is the pre-check.
- Dead after this: IsTenantAdminAsync on the service, the repository interface and the table
  repository, plus its test.
- Tests pin the write order, the designated-member guard (unit and auth/me end to end) and the
  conditional write; each part was mutated back to the old code and failed its tests.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 20:47:53 +02:00
Oliver Kieselbach 622a2437a0 bump pointer: internal (plan note on the customer wording correction, D-377)
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 19:01:17 +02:00
Oliver Kieselbach 5ceab7e611 bump pointer: internal (bootstrap security findings released, D-377)
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
2026-10-22 18:52:47 +02:00
Oliver Kieselbach 8a7cd5ed98 bump pointer: internal (MSI field check and lab name both MSI paths)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 18:51:18 +02:00
Oliver Kieselbach 15804e2817 bump pointer: internal (bootstrap MSI agent start report closed)
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-22 18:20:39 +02:00
324 changed files with 10687 additions and 2342 deletions
+43 -6
View File
@@ -1,13 +1,50 @@
name: Bootstrap script gates
# Quality gate for the customer-facing PowerShell scripts, factored out so it exists
# once and both callers run the identical checks:
# * pester.yml -- pull requests (reports, does not block the merge button)
# * publish-scripts.yml -- pushes to main, where it BLOCKS the upload to the
# download alias. Devices execute these scripts as SYSTEM
# during enrollment, so a red suite must never ship.
# Quality gate for the customer-facing PowerShell scripts. Devices execute them as SYSTEM
# during enrollment, so a red suite must never ship. It runs in two roles:
# * on its own, on every pull request and push to main that changes an input of these
# checks (reports, does not block the merge button);
# * called as the gates job that BLOCKS every signing or upload of bootstrap code:
# publish-scripts.yml, build-agent.yml (stable releases), build-msi.yml. Those runs
# show under the caller.
#
# Both path lists are the checks' complete inputs and stay identical. They cover every
# push path of publish-scripts.yml, which leaves the check of a [skip publish] push to
# this workflow.
#
# No concurrency group: it would also bind the runs called by the publishers, and a
# cancel there would block a publish.
on:
push:
branches: [main]
paths:
- 'scripts/Bootstrap/**'
- 'scripts/CustomerSetup/**'
- '.github/scripts/Publish-BootstrapScripts.ps1'
- '.github/scripts/Get-Endpoints.ps1'
- '.github/scripts/Invoke-BootstrapSystemPass.ps1'
- '.github/scripts/Test-BootstrapAttacker.ps1'
- '.github/workflows/bootstrap-script-gates.yml'
# The integration tests run the generated OOBE script and the MSI's custom action; the
# contract tests also read the MSI build.
- 'src/Backend/AutopilotMonitor.Functions.Tests/TestData/oobe-bootstrap-golden.ps1'
- 'src/Agent/AutopilotMonitor.BootstrapMsi/Package.wxs'
- '.github/workflows/build-msi.yml'
pull_request:
branches: [main]
paths:
- 'scripts/Bootstrap/**'
- 'scripts/CustomerSetup/**'
- '.github/scripts/Publish-BootstrapScripts.ps1'
- '.github/scripts/Get-Endpoints.ps1'
- '.github/scripts/Invoke-BootstrapSystemPass.ps1'
- '.github/scripts/Test-BootstrapAttacker.ps1'
- '.github/workflows/bootstrap-script-gates.yml'
- 'src/Backend/AutopilotMonitor.Functions.Tests/TestData/oobe-bootstrap-golden.ps1'
- 'src/Agent/AutopilotMonitor.BootstrapMsi/Package.wxs'
- '.github/workflows/build-msi.yml'
workflow_dispatch:
workflow_call:
permissions:
+12 -4
View File
@@ -254,6 +254,12 @@ jobs:
if-no-files-found: error
retention-days: 1
# A stable release publishes the customer scripts as well, so it waits for the gates their
# own publish waits for. Next to the build; skipped when nothing goes out as stable.
gates:
if: inputs.publish_as_stable
uses: $/.github/workflows/bootstrap-script-gates.yml
# Trust zone: only this repository's scripts, pinned actions and the pinned signing tool
# run here -- never a restore or build. The build output arrives as data. The runner
# image's Windows SDK signtool is used read-only, to verify third-party signatures.
@@ -263,7 +269,9 @@ jobs:
# sign nor write storage, whatever its permissions say.
release:
name: Sign and publish
needs: [reserve, build]
needs: [reserve, build, gates]
# A skipped gates job (no stable publish) lets the release run; a failed or cancelled one stops it.
if: ${{ !cancelled() && needs.build.result == 'success' && (needs.gates.result == 'success' || needs.gates.result == 'skipped') }}
runs-on: windows-latest
environment: release
permissions:
@@ -726,9 +734,9 @@ jobs:
Send-Blob -Local $env:VERSIONED_ZIP -BlobName $env:STABLE_ZIP -ContentType "application/zip"
Send-Blob -Local $env:MANIFEST_NAME -BlobName $env:STABLE_MANIFEST -ContentType "application/json"
# Customer-facing scripts: same publisher publish-scripts.yml runs on every push
# to main, so a release lands a set that is consistent with what is already live
# (dev render, version-bump guard, bootstrapVersion oracles, alias verification).
# Customer-facing scripts: same publisher and same gates (the gates job) as
# publish-scripts.yml, so a release lands a set that is consistent with what is
# already live (dev render, version-bump guard, bootstrapVersion oracles, alias verification).
# Runs AFTER version.json so its bootstrapVersion read sees this build's manifest.
# Signed with the same identity: the device-side loader verifies the publisher
# of what it downloads, and the publisher refuses to upload unsigned scripts.
+93 -18
View File
@@ -34,6 +34,12 @@ env:
CODE_SIGN_EXPECTED_SUBJECT: ${{ vars.CODE_SIGN_EXPECTED_SUBJECT }}
jobs:
# The loader executes as SYSTEM on every enrolling device, and the MSI's custom action runs
# it: nothing is signed before the bootstrap gates pass on this commit, since a signed copy
# of ours is trusted wherever it lands.
gates:
uses: $/.github/workflows/bootstrap-script-gates.yml
# Signs the loader BEFORE the build: wix embeds the file as it finds it, so a loader signed
# afterwards would leave the copy inside the MSI unsigned. Devices under an AllSigned policy
# need the embedded loader to carry a signature of its own.
@@ -42,6 +48,7 @@ jobs:
# here. The `release` environment is the only subject the code-signing identity trusts.
sign-loader:
name: Sign bootstrap loader
needs: gates
runs-on: windows-latest
environment: release
permissions:
@@ -59,22 +66,6 @@ jobs:
shell: pwsh
run: ./.github/scripts/Get-Endpoints.ps1 -ExportToGitHubEnv
# The loader executes as SYSTEM on every enrolling device — a parse error or
# non-ASCII mojibake (PS 5.1 codepage roulette) must fail the build, not the fleet.
# bootstrap-script-gates.yml runs the same checks plus Pester on pushes; this job
# stands on its own because it can be dispatched at any time.
- name: Validate runner script (parse + ASCII-only)
shell: pwsh
run: |
$errs = $null
[System.Management.Automation.Language.Parser]::ParseFile((Resolve-Path $env:RUNNER_SCRIPT), [ref]$null, [ref]$errs) | Out-Null
if ($errs) { $errs | ForEach-Object { Write-Error $_.ToString() }; exit 1 }
if ((Get-Content $env:RUNNER_SCRIPT -Raw) -match '[^\x00-\x7F]') {
Write-Error "Runner script contains non-ASCII characters"
exit 1
}
Write-Host "Runner script parse + ASCII check passed"
# Every published MSI is signed; a missing variable stops the run before the build.
- name: Check code-signing configuration
shell: pwsh
@@ -181,11 +172,16 @@ jobs:
- name: Build MSI
shell: pwsh
run: |
# The MSI's action runs only the exact bytes the package embeds: the hash of the
# signed loader goes into the command here, so no other signed script of ours runs
# in its place on a device.
$loaderSha256 = (Get-FileHash -LiteralPath $env:RUNNER_SCRIPT -Algorithm SHA256).Hash.ToLowerInvariant()
Write-Host "Embedded loader SHA-256: $loaderSha256"
# wix resolves File/@Source relative to the working directory, not the wxs —
# build from inside the project dir (same as the local build documented in the wxs).
$out = Join-Path (Get-Location) $env:STABLE_MSI
Push-Location $env:MSI_PROJECT_DIR
wix build Package.wxs -arch x64 -o $out
wix build Package.wxs -arch x64 -d LoaderSha256=$loaderSha256 -o $out
Pop-Location
if (-not (Test-Path $env:STABLE_MSI)) { Write-Error "wix build produced no MSI"; exit 1 }
Write-Host "Built $env:STABLE_MSI ($([math]::Round((Get-Item $env:STABLE_MSI).Length / 1KB)) KB)"
@@ -198,11 +194,90 @@ jobs:
if-no-files-found: error
retention-days: 1
# The real chain on a runner, before anything is signed or published: msiexec installs the
# MSI from the build, its action checks the loader copy and runs it, the loader fetches the
# published installer, which finds the deployment marker set here and removes the copy. The
# marker is the installer's first guard, so no agent is ever installed on the runner. Needs
# the published installer to be 2.9 or later, which removes the copy in every outcome.
smoke:
name: Install on a runner (${{ matrix.os }})
needs: build
strategy:
fail-fast: false
matrix:
os: [windows-2022, windows-2025]
runs-on: ${{ matrix.os }}
steps:
- name: Checkout repository
uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1
with:
persist-credentials: false
- name: Download unsigned MSI
uses: actions/download-artifact@3e5f45b2cfb9172054b4087a40e8e0b5a5461e7c # v8.0.1
with:
name: bootstrap-msi-unsigned
path: ${{ runner.temp }}/msi
- name: Install with the deployment marker set, check the footprint, uninstall
shell: pwsh
run: |
$ErrorActionPreference = 'Stop'
$msi = Join-Path $env:RUNNER_TEMP "msi/$env:STABLE_MSI"
$wxs = Get-Content "$env:MSI_PROJECT_DIR/Package.wxs" -Raw
if ($wxs -notmatch 'Version="(\d+\.\d+\.\d+)"') { throw 'Could not parse Version from Package.wxs' }
$version = $Matches[1]
New-Item -Path 'HKLM:\SOFTWARE\AutopilotMonitor' -Force | Out-Null
Set-ItemProperty -Path 'HKLM:\SOFTWARE\AutopilotMonitor' -Name 'Deployed' -Value ((Get-Date).ToUniversalTime().ToString('o'))
function Invoke-Msiexec {
param([string]$Verb, [string]$Log)
$p = Start-Process -FilePath msiexec.exe -ArgumentList "/$Verb `"$msi`" /qn /l*v `"$Log`"" -Wait -PassThru
if ($p.ExitCode -ne 0) { Get-Content $Log | Select-Object -Last 60; throw "msiexec /$Verb exited with $($p.ExitCode)" }
}
function Get-Registration {
Get-ChildItem 'HKLM:\SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall' | Get-ItemProperty | Where-Object { $_.DisplayName -eq 'Autopilot Monitor Bootstrap' }
}
function Show-Tree {
param([string]$Path)
Get-ChildItem -LiteralPath $Path -Recurse -Force | ForEach-Object { Write-Host " $($_.FullName)" }
}
$installLog = Join-Path $env:RUNNER_TEMP 'msi-install.log'
Invoke-Msiexec -Verb i -Log $installLog
$registered = Get-Registration
if (-not $registered) { throw 'The product is not registered after the install.' }
if ($registered.DisplayVersion -ne $version) { throw "Registered version $($registered.DisplayVersion), Package.wxs says $version." }
if ((Get-Content $installLog -Raw) -notmatch 'RunBootstrap') { throw 'The install log does not show the action.' }
Write-Host "Registered: $($registered.DisplayName) $($registered.DisplayVersion)"
# Only the installer removes the copy the MSI put under ProgramData: its absence
# proves the action ran the loader and the loader ran the installer.
foreach ($path in @("$env:ProgramW6432\AutopilotMonitor", "$env:ProgramData\AutopilotMonitor")) {
if (Test-Path -LiteralPath $path) { Show-Tree $path; throw "$path exists after the run." }
}
$runFolders = @(Get-ChildItem -LiteralPath $env:ProgramData -Directory -Filter 'AutopilotMonitor-Loader-*' -Force)
if ($runFolders.Count -ne 0) {
foreach ($folder in $runFolders) {
Show-Tree $folder.FullName
Get-ChildItem -LiteralPath $folder.FullName -Filter '*.log' | ForEach-Object { Get-Content -LiteralPath $_.FullName }
}
throw 'A loader run folder stays: the loader did not end with exit 0.'
}
Write-Host 'After the install: nothing under ProgramData or Program Files.'
Invoke-Msiexec -Verb x -Log (Join-Path $env:RUNNER_TEMP 'msi-uninstall.log')
if (Get-Registration) { throw 'The product is still registered after the uninstall.' }
Remove-Item -Path 'HKLM:\SOFTWARE\AutopilotMonitor' -Recurse -Force
Write-Host 'Uninstalled; the registration is gone.'
# Trust zone: signs, verifies and publishes the MSI as data; never builds. Environment
# `release`, like sign-loader.
release:
name: Sign and publish MSI
needs: build
needs: smoke
runs-on: windows-latest
environment: release
permissions:
-2
View File
@@ -46,7 +46,6 @@ on:
- '.github/workflows/deploy-mcp.yml'
- '.github/workflows/deploy-web.yml'
- '.github/workflows/indexnow-notify.yml'
- '.github/workflows/pester.yml'
- '.github/workflows/publish-scripts.yml'
pull_request:
branches: [main]
@@ -79,7 +78,6 @@ on:
- '.github/workflows/deploy-mcp.yml'
- '.github/workflows/deploy-web.yml'
- '.github/workflows/indexnow-notify.yml'
- '.github/workflows/pester.yml'
- '.github/workflows/publish-scripts.yml'
workflow_dispatch:
-2
View File
@@ -38,7 +38,6 @@ on:
- '.github/workflows/deploy-mcp.yml'
- '.github/workflows/deploy-web.yml'
- '.github/workflows/indexnow-notify.yml'
- '.github/workflows/pester.yml'
- '.github/workflows/publish-scripts.yml'
pull_request:
branches: [main]
@@ -70,7 +69,6 @@ on:
- '.github/workflows/deploy-mcp.yml'
- '.github/workflows/deploy-web.yml'
- '.github/workflows/indexnow-notify.yml'
- '.github/workflows/pester.yml'
- '.github/workflows/publish-scripts.yml'
schedule:
# Weekly, so advisories published after a merge still surface. Deliberately
-35
View File
@@ -1,35 +0,0 @@
name: Pester (Bootstrap scripts)
# Pull-request view of the bootstrap script gates. Like ci.yml it reports rather than
# blocks the merge button.
#
# There is deliberately no push trigger: publish-scripts.yml runs the very same
# reusable gate workflow on every push to main and blocks the upload to the download
# alias on it. A push trigger here would only duplicate that run, with no consequence.
on:
pull_request:
branches: [main]
paths:
- 'scripts/Bootstrap/**'
- 'scripts/CustomerSetup/**'
- '.github/scripts/Publish-BootstrapScripts.ps1'
- '.github/scripts/Invoke-BootstrapSystemPass.ps1'
- '.github/scripts/Test-BootstrapAttacker.ps1'
- '.github/workflows/bootstrap-script-gates.yml'
# The integration tests run the generated OOBE script and the MSI's command line.
- 'src/Backend/AutopilotMonitor.Functions.Tests/TestData/oobe-bootstrap-golden.ps1'
- 'src/Agent/AutopilotMonitor.BootstrapMsi/Package.wxs'
workflow_dispatch:
permissions:
contents: read
concurrency:
group: pester-${{ github.ref }}
cancel-in-progress: true
jobs:
# $/ is the self-repository form: this repository at the running commit.
gates:
uses: $/.github/workflows/bootstrap-script-gates.yml
+5
View File
@@ -55,7 +55,12 @@ env:
jobs:
# $/ is the self-repository form: this repository at the running commit, never a
# path some earlier step could have written to the workspace.
#
# A push with [skip publish] in one of its commit messages runs neither job and uploads
# nothing; the gates' own push trigger, whose paths cover these, still checks it. Never
# [skip actions] for that: it drops every check of the push, CI and these gates included.
gates:
if: github.event_name != 'push' || !contains(join(github.event.commits.*.message, ' '), '[skip publish]')
uses: $/.github/workflows/bootstrap-script-gates.yml
publish:
+1 -1
Submodule infra updated: 0085deab45...7589909f54
+32 -23
View File
@@ -1,56 +1,63 @@
{
"$schema": "../schema/analyze-rule.schema.json",
"ruleId": "ANALYZE-APP-001",
"title": "Win32 App Detection Script Failure",
"description": "Detects when a Win32 app detection script fails or returns unexpected results.",
"title": "App Not Detected After Install (0x87D1041C)",
"description": "Detects when Intune's detection check right after an app's installer finished did not find the app, so Intune reports the install as failed (0x87D1041C).",
"severity": "warning",
"category": "apps",
"version": "1.3.0",
"version": "2.0.0",
"enabled": true,
"evaluateOn": [
"enrollment_end",
"whiteglove_sealed"
],
"baseConfidence": 60,
"baseConfidence": 90,
"conditions": [
{
"signal": "detection_failure",
"source": "event_type",
"eventType": "app_install_failed",
"dataField": "detectionResult",
"operator": "equals",
"value": "NotDetected",
"required": true,
"suppressByEvent": {
"eventType": "app_install_completed",
"joinField": "appId"
}
"dataField": "errorCode",
"operator": "regex",
"value": "^(-2016345060|0x87d1041c)$",
"required": true
}
],
"explanation": "A Win32 app detection script failed or did not detect the app after installation. This causes the app to appear as 'not installed' despite successful installation. Detection failures that were later resolved by a successful install of the same app are suppressed and do not raise this finding.",
"explanation": "The Intune Management Extension runs an app's detection twice: before the install, to decide whether the install is needed, and right after the installer finishes. Here the installer finished, but the check afterwards did not find the app. Intune therefore reports the install as failed with **0x87D1041C** (*application not detected after installation completed successfully*), even though the installer itself succeeded.\n\nFor Win32 apps the detection rule does not match what the installer left on the device. Common causes:\n\n- The rule checks a path or registry key the installer does not create (wrong path, version folder or bitness, e.g. HKLM\\SOFTWARE\\... versus HKLM\\SOFTWARE\\WOW6432Node\\...).\n- The installer finishes its work later (an async task, a service, or a restart it needs but does not request with a restart return code), after the check has run.\n- A detection script exits 0 without writing to stdout, which Intune treats as not detected.\n- The installer writes to the user profile while the rule looks in system scope, or the other way round.\n\nMicrosoft Store (WinGet) apps have no detection rule to edit: Intune asks WinGet whether the package is installed in the app's install context.\n\nWhen the installer requests a restart with its return code, Intune checks again after the restart; this finding then means the app was still missing afterwards.",
"remediation": [
{
"title": "Fix detection rules",
"title": "Check the detection rule against an installed device",
"steps": [
"Review the app's detection rules in Intune",
"Verify file/registry paths are correct",
"Test detection script manually on a device"
"Open the app in Intune → Properties → Detection rules and note exactly what the rule checks",
"Install the app on a test device outside Autopilot and confirm that the file, registry key or script result exists right after the installer exits",
"For registry rules, check both HKLM\\SOFTWARE\\... and HKLM\\SOFTWARE\\WOW6432Node\\... depending on the installer's bitness",
"For script rules, run the script as SYSTEM: it must write at least one line to stdout and exit 0 when the app is present",
"If the installer completes its work later, detect something it writes synchronously, such as the MSI product code under HKLM\\SOFTWARE\\Microsoft\\Windows\\CurrentVersion\\Uninstall\\"
]
},
{
"title": "Microsoft Store (WinGet) apps",
"steps": [
"Check the package identifier and the install behavior (System or User) of the app in Intune",
"Install the package manually in the same context on a test device and confirm it is reported as installed"
]
}
],
"relatedDocs": [
{
"title": "Win32 app detection rules in Intune",
"url": "https://learn.microsoft.com/en-us/mem/intune/apps/apps-win32-add#step-4-detection-rules"
}
],
"presentation": {
"role": "cause",
"summary": "{{detection_failure.appName}} was not detected after its install",
"summary": "{{detection_failure.appName}} was not detected after its installer finished",
"subject": {
"kind": "app",
"key": "{{detection_failure.appId}}",
"name": "{{detection_failure.appName}}"
},
"facts": [
{
"label": "Detection",
"value": "{{detection_failure.value}}"
},
{
"label": "Error",
"value": "{{detection_failure.errorCode}}",
@@ -61,6 +68,8 @@
"tags": [
"apps",
"detection",
"win32"
"win32",
"winget",
"0x87d1041c"
]
}
-87
View File
@@ -1,87 +0,0 @@
{
"$schema": "../schema/analyze-rule.schema.json",
"ruleId": "ANALYZE-APP-010",
"version": "1.1.0",
"title": "App Reverted to Error After Successful Install",
"description": "Detects when a specific app (matched by appId) was first reported as successfully installed but subsequently reported an IME enforcement error — while enrollment completed successfully. The app may be broken post-enrollment.",
"severity": "warning",
"category": "apps",
"enabled": true,
"trigger": "correlation",
"baseConfidence": 75,
"conditions": [
{
"signal": "app_regression",
"source": "event_correlation",
"eventType": "app_install_completed",
"correlateEventType": "app_install_failed",
"joinField": "appId",
"dataField": "errorPatternId",
"operator": "equals",
"value": "IME-ERROR-REPORT",
"required": true
},
{
"signal": "enrollment_succeeded",
"source": "event_type",
"eventType": "enrollment_complete",
"operator": "exists",
"value": "",
"required": true
}
],
"confidenceThreshold": 70,
"explanation": "An app was initially reported as **successfully installed** (`app_install_completed`) but the IME (Intune Management Extension) subsequently reported an **Error** state for the same app via an `IME-ERROR-REPORT` event — while the overall enrollment completed successfully.\n\nThis pattern occurs when the IME re-evaluates enforcement state after the initial install report and detects a failure, e.g. `EnforcementState` transitions from `Success` → `Error`. The affected app and its details are captured in the matched evidence.\n\nCommon causes:\n- A post-install detection check fails (detection rule mismatch)\n- The enforcement error code `-2016345060` (0x87D13B9C) indicates the app state diverged from expected\n- The app may appear installed in the ESP summary but is in an error state on the device\n\n**The enrollment succeeded, but the affected app requires attention.**",
"remediation": [
{
"title": "Investigate the app's post-install enforcement state",
"steps": [
"Note the appId and appName from the rule finding — these identify the exact affected app",
"Check the Intune portal: Devices > [Device] > Apps — confirm the current enforcement state of the app",
"Review IME logs on the device: C:\\ProgramData\\Microsoft\\IntuneManagementExtension\\Logs\\IntuneManagementExtension.log",
"Search the log for the appId and look for 'EnforcementState' transitions (Success → Error) near the enrollment time",
"Error -2016345060 (0x87D13B9C) typically indicates a detection failure after install — verify the app's detection rule in Intune",
"Trigger a manual sync (Company Portal or Settings > Accounts > Access work or school > Sync) to force re-evaluation"
]
},
{
"title": "Fix detection or installation issues",
"steps": [
"If detection fails: correct the detection rule (file path, registry key, or PowerShell script) in the Intune app configuration",
"If the app itself is broken: redeploy or reassign the app to trigger a fresh install",
"Consider adding a post-install validation script to catch this scenario proactively"
]
}
],
"relatedDocs": [
{ "title": "Troubleshoot Win32 app installations", "url": "https://learn.microsoft.com/en-us/troubleshoot/mem/intune/app-management/troubleshoot-win32-app-install" },
{ "title": "Intune Management Extension logs", "url": "https://learn.microsoft.com/en-us/mem/intune/apps/intune-management-extension" }
],
"presentation": {
"role": "cause",
"summary": "{{app_regression.eventA_appName}} installed, then reported an error",
"subject": {
"kind": "app",
"key": "{{app_regression.joinValue}}",
"name": "{{app_regression.eventA_appName}}"
},
"facts": [
{
"label": "Installed",
"value": "{{app_regression.eventA_timestamp}}",
"format": "timestamp"
},
{
"label": "Error after",
"value": "{{app_regression.timeDeltaSeconds}}",
"format": "duration"
},
{
"label": "Error",
"value": "{{app_regression.eventB_errorCode}}",
"format": "errorCode"
}
]
},
"tags": ["apps", "win32", "enforcement", "post-install", "correlation"]
}
+6 -10
View File
@@ -5,7 +5,7 @@
"description": "Detects when the Enrollment Status Page failed because Intune could not verify an app was installed (HRESULT 0x87D1041C). The installer ran but the detection rule did not match afterwards.",
"severity": "critical",
"category": "apps",
"version": "1.3.0",
"version": "1.4.0",
"enabled": true,
"evaluateOn": [
"enrollment_end",
@@ -27,9 +27,9 @@
"signal": "app_with_detection_failure",
"source": "event_type",
"eventType": "app_install_failed",
"dataField": "detectionResult",
"operator": "equals",
"value": "NotDetected",
"dataField": "errorCode",
"operator": "regex",
"value": "^(-2016345060|0x87d1041c)$",
"required": true
},
{
@@ -42,7 +42,7 @@
"required": false
}
],
"explanation": "App **{{appName}}** failed during the Enrollment Status Page with HRESULT **{{errorCode}}** — *Application not detected after installation completed successfully*. The installer reported success but the Intune detection rule (file/registry/script) did not find the app afterwards, so the ESP Apps subcategory failed and the device's enrollment terminated.\n\nThis is a confirmed detection-rule mismatch, NOT an install timeout — the install itself most likely completed (or the installer exited 0). Common root causes:\n\n- The detection rule looks for a registry/file path that the installer doesn't create (wrong path, wrong bitness — e.g. checking HKLM\\SOFTWARE\\... on a 32-bit installer that lands under WOW6432Node).\n- The installer writes the detection artefact AFTER the ESP's detection probe runs (e.g. async post-install task, requires reboot).\n- The detection script returns 0 with no stdout (Intune treats empty stdout as \"not detected\").\n- The installer wrote files to a user profile but the rule looks in System scope (or vice-versa).",
"explanation": "App **{{app_with_detection_failure.appName}}** failed during the Enrollment Status Page with HRESULT **0x87D1041C** — *Application not detected after installation completed successfully*. The installer reported success but the Intune detection rule (file/registry/script) did not find the app afterwards, so the ESP Apps subcategory failed and the device's enrollment terminated.\n\nThis is a confirmed detection-rule mismatch, NOT an install timeout — the install itself most likely completed (or the installer exited 0). Common root causes:\n\n- The detection rule looks for a registry/file path that the installer doesn't create (wrong path, wrong bitness — e.g. checking HKLM\\SOFTWARE\\... on a 32-bit installer that lands under WOW6432Node).\n- The installer finishes its work later (an async task, a service, or a restart it needs but does not request with a restart return code), after Intune's check has run.\n- The detection script returns 0 with no stdout (Intune treats empty stdout as \"not detected\").\n- The installer wrote files to a user profile but the rule looks in System scope (or vice-versa).",
"remediation": [
{
"title": "Validate the detection rule against an installed device",
@@ -66,7 +66,7 @@
{
"title": "Cross-check the agent's per-app event",
"steps": [
"Look at the app_install_failed event in this session for DataJson.detectionResult — NotDetected confirms Intune's detection probe ran and returned negative",
"Look at the app_install_failed event of this app: errorCode 0x87D1041C (the IME log writes it as -2016345060) is Intune's own verdict that its check right after the installer did not find the app",
"Look at app_install_failed.bytesDownloaded vs bytesTotal — if they match, the package downloaded fully (install error vs. download error)",
"Cross-reference DataJson.exitCode and hresultFromWin32 — these come from the installer itself and may explain why the detection artefact was not written"
]
@@ -95,10 +95,6 @@
"label": "ESP error",
"value": "{{esp_failure_errorcode.value}}",
"format": "errorCode"
},
{
"label": "Detection",
"value": "{{app_with_detection_failure.value}}"
}
]
},
+38 -131
View File
@@ -3,56 +3,63 @@
"rules": [
{
"ruleId": "ANALYZE-APP-001",
"title": "Win32 App Detection Script Failure",
"description": "Detects when a Win32 app detection script fails or returns unexpected results.",
"title": "App Not Detected After Install (0x87D1041C)",
"description": "Detects when Intune's detection check right after an app's installer finished did not find the app, so Intune reports the install as failed (0x87D1041C).",
"severity": "warning",
"category": "apps",
"version": "1.3.0",
"version": "2.0.0",
"enabled": true,
"evaluateOn": [
"enrollment_end",
"whiteglove_sealed"
],
"baseConfidence": 60,
"baseConfidence": 90,
"conditions": [
{
"signal": "detection_failure",
"source": "event_type",
"eventType": "app_install_failed",
"dataField": "detectionResult",
"operator": "equals",
"value": "NotDetected",
"required": true,
"suppressByEvent": {
"eventType": "app_install_completed",
"joinField": "appId"
}
"dataField": "errorCode",
"operator": "regex",
"value": "^(-2016345060|0x87d1041c)$",
"required": true
}
],
"explanation": "A Win32 app detection script failed or did not detect the app after installation. This causes the app to appear as 'not installed' despite successful installation. Detection failures that were later resolved by a successful install of the same app are suppressed and do not raise this finding.",
"explanation": "The Intune Management Extension runs an app's detection twice: before the install, to decide whether the install is needed, and right after the installer finishes. Here the installer finished, but the check afterwards did not find the app. Intune therefore reports the install as failed with **0x87D1041C** (*application not detected after installation completed successfully*), even though the installer itself succeeded.\n\nFor Win32 apps the detection rule does not match what the installer left on the device. Common causes:\n\n- The rule checks a path or registry key the installer does not create (wrong path, version folder or bitness, e.g. HKLM\\SOFTWARE\\... versus HKLM\\SOFTWARE\\WOW6432Node\\...).\n- The installer finishes its work later (an async task, a service, or a restart it needs but does not request with a restart return code), after the check has run.\n- A detection script exits 0 without writing to stdout, which Intune treats as not detected.\n- The installer writes to the user profile while the rule looks in system scope, or the other way round.\n\nMicrosoft Store (WinGet) apps have no detection rule to edit: Intune asks WinGet whether the package is installed in the app's install context.\n\nWhen the installer requests a restart with its return code, Intune checks again after the restart; this finding then means the app was still missing afterwards.",
"remediation": [
{
"title": "Fix detection rules",
"title": "Check the detection rule against an installed device",
"steps": [
"Review the app's detection rules in Intune",
"Verify file/registry paths are correct",
"Test detection script manually on a device"
"Open the app in Intune → Properties → Detection rules and note exactly what the rule checks",
"Install the app on a test device outside Autopilot and confirm that the file, registry key or script result exists right after the installer exits",
"For registry rules, check both HKLM\\SOFTWARE\\... and HKLM\\SOFTWARE\\WOW6432Node\\... depending on the installer's bitness",
"For script rules, run the script as SYSTEM: it must write at least one line to stdout and exit 0 when the app is present",
"If the installer completes its work later, detect something it writes synchronously, such as the MSI product code under HKLM\\SOFTWARE\\Microsoft\\Windows\\CurrentVersion\\Uninstall\\"
]
},
{
"title": "Microsoft Store (WinGet) apps",
"steps": [
"Check the package identifier and the install behavior (System or User) of the app in Intune",
"Install the package manually in the same context on a test device and confirm it is reported as installed"
]
}
],
"relatedDocs": [
{
"title": "Win32 app detection rules in Intune",
"url": "https://learn.microsoft.com/en-us/mem/intune/apps/apps-win32-add#step-4-detection-rules"
}
],
"presentation": {
"role": "cause",
"summary": "{{detection_failure.appName}} was not detected after its install",
"summary": "{{detection_failure.appName}} was not detected after its installer finished",
"subject": {
"kind": "app",
"key": "{{detection_failure.appId}}",
"name": "{{detection_failure.appName}}"
},
"facts": [
{
"label": "Detection",
"value": "{{detection_failure.value}}"
},
{
"label": "Error",
"value": "{{detection_failure.errorCode}}",
@@ -63,7 +70,9 @@
"tags": [
"apps",
"detection",
"win32"
"win32",
"winget",
"0x87d1041c"
]
},
{
@@ -541,104 +550,6 @@
],
"version": "1.2.0"
},
{
"ruleId": "ANALYZE-APP-010",
"version": "1.1.0",
"title": "App Reverted to Error After Successful Install",
"description": "Detects when a specific app (matched by appId) was first reported as successfully installed but subsequently reported an IME enforcement error — while enrollment completed successfully. The app may be broken post-enrollment.",
"severity": "warning",
"category": "apps",
"enabled": true,
"trigger": "correlation",
"baseConfidence": 75,
"conditions": [
{
"signal": "app_regression",
"source": "event_correlation",
"eventType": "app_install_completed",
"correlateEventType": "app_install_failed",
"joinField": "appId",
"dataField": "errorPatternId",
"operator": "equals",
"value": "IME-ERROR-REPORT",
"required": true
},
{
"signal": "enrollment_succeeded",
"source": "event_type",
"eventType": "enrollment_complete",
"operator": "exists",
"value": "",
"required": true
}
],
"confidenceThreshold": 70,
"explanation": "An app was initially reported as **successfully installed** (`app_install_completed`) but the IME (Intune Management Extension) subsequently reported an **Error** state for the same app via an `IME-ERROR-REPORT` event — while the overall enrollment completed successfully.\n\nThis pattern occurs when the IME re-evaluates enforcement state after the initial install report and detects a failure, e.g. `EnforcementState` transitions from `Success` → `Error`. The affected app and its details are captured in the matched evidence.\n\nCommon causes:\n- A post-install detection check fails (detection rule mismatch)\n- The enforcement error code `-2016345060` (0x87D13B9C) indicates the app state diverged from expected\n- The app may appear installed in the ESP summary but is in an error state on the device\n\n**The enrollment succeeded, but the affected app requires attention.**",
"remediation": [
{
"title": "Investigate the app's post-install enforcement state",
"steps": [
"Note the appId and appName from the rule finding — these identify the exact affected app",
"Check the Intune portal: Devices > [Device] > Apps — confirm the current enforcement state of the app",
"Review IME logs on the device: C:\\ProgramData\\Microsoft\\IntuneManagementExtension\\Logs\\IntuneManagementExtension.log",
"Search the log for the appId and look for 'EnforcementState' transitions (Success → Error) near the enrollment time",
"Error -2016345060 (0x87D13B9C) typically indicates a detection failure after install — verify the app's detection rule in Intune",
"Trigger a manual sync (Company Portal or Settings > Accounts > Access work or school > Sync) to force re-evaluation"
]
},
{
"title": "Fix detection or installation issues",
"steps": [
"If detection fails: correct the detection rule (file path, registry key, or PowerShell script) in the Intune app configuration",
"If the app itself is broken: redeploy or reassign the app to trigger a fresh install",
"Consider adding a post-install validation script to catch this scenario proactively"
]
}
],
"relatedDocs": [
{
"title": "Troubleshoot Win32 app installations",
"url": "https://learn.microsoft.com/en-us/troubleshoot/mem/intune/app-management/troubleshoot-win32-app-install"
},
{
"title": "Intune Management Extension logs",
"url": "https://learn.microsoft.com/en-us/mem/intune/apps/intune-management-extension"
}
],
"presentation": {
"role": "cause",
"summary": "{{app_regression.eventA_appName}} installed, then reported an error",
"subject": {
"kind": "app",
"key": "{{app_regression.joinValue}}",
"name": "{{app_regression.eventA_appName}}"
},
"facts": [
{
"label": "Installed",
"value": "{{app_regression.eventA_timestamp}}",
"format": "timestamp"
},
{
"label": "Error after",
"value": "{{app_regression.timeDeltaSeconds}}",
"format": "duration"
},
{
"label": "Error",
"value": "{{app_regression.eventB_errorCode}}",
"format": "errorCode"
}
]
},
"tags": [
"apps",
"win32",
"enforcement",
"post-install",
"correlation"
]
},
{
"ruleId": "ANALYZE-APP-012",
"title": "Enforcement Error Resolved by Successful Detection",
@@ -724,7 +635,7 @@
"description": "Detects when the Enrollment Status Page failed because Intune could not verify an app was installed (HRESULT 0x87D1041C). The installer ran but the detection rule did not match afterwards.",
"severity": "critical",
"category": "apps",
"version": "1.3.0",
"version": "1.4.0",
"enabled": true,
"evaluateOn": [
"enrollment_end",
@@ -746,9 +657,9 @@
"signal": "app_with_detection_failure",
"source": "event_type",
"eventType": "app_install_failed",
"dataField": "detectionResult",
"operator": "equals",
"value": "NotDetected",
"dataField": "errorCode",
"operator": "regex",
"value": "^(-2016345060|0x87d1041c)$",
"required": true
},
{
@@ -761,7 +672,7 @@
"required": false
}
],
"explanation": "App **{{appName}}** failed during the Enrollment Status Page with HRESULT **{{errorCode}}** — *Application not detected after installation completed successfully*. The installer reported success but the Intune detection rule (file/registry/script) did not find the app afterwards, so the ESP Apps subcategory failed and the device's enrollment terminated.\n\nThis is a confirmed detection-rule mismatch, NOT an install timeout — the install itself most likely completed (or the installer exited 0). Common root causes:\n\n- The detection rule looks for a registry/file path that the installer doesn't create (wrong path, wrong bitness — e.g. checking HKLM\\SOFTWARE\\... on a 32-bit installer that lands under WOW6432Node).\n- The installer writes the detection artefact AFTER the ESP's detection probe runs (e.g. async post-install task, requires reboot).\n- The detection script returns 0 with no stdout (Intune treats empty stdout as \"not detected\").\n- The installer wrote files to a user profile but the rule looks in System scope (or vice-versa).",
"explanation": "App **{{app_with_detection_failure.appName}}** failed during the Enrollment Status Page with HRESULT **0x87D1041C** — *Application not detected after installation completed successfully*. The installer reported success but the Intune detection rule (file/registry/script) did not find the app afterwards, so the ESP Apps subcategory failed and the device's enrollment terminated.\n\nThis is a confirmed detection-rule mismatch, NOT an install timeout — the install itself most likely completed (or the installer exited 0). Common root causes:\n\n- The detection rule looks for a registry/file path that the installer doesn't create (wrong path, wrong bitness — e.g. checking HKLM\\SOFTWARE\\... on a 32-bit installer that lands under WOW6432Node).\n- The installer finishes its work later (an async task, a service, or a restart it needs but does not request with a restart return code), after Intune's check has run.\n- The detection script returns 0 with no stdout (Intune treats empty stdout as \"not detected\").\n- The installer wrote files to a user profile but the rule looks in System scope (or vice-versa).",
"remediation": [
{
"title": "Validate the detection rule against an installed device",
@@ -785,7 +696,7 @@
{
"title": "Cross-check the agent's per-app event",
"steps": [
"Look at the app_install_failed event in this session for DataJson.detectionResult — NotDetected confirms Intune's detection probe ran and returned negative",
"Look at the app_install_failed event of this app: errorCode 0x87D1041C (the IME log writes it as -2016345060) is Intune's own verdict that its check right after the installer did not find the app",
"Look at app_install_failed.bytesDownloaded vs bytesTotal — if they match, the package downloaded fully (install error vs. download error)",
"Cross-reference DataJson.exitCode and hresultFromWin32 — these come from the installer itself and may explain why the detection artefact was not written"
]
@@ -814,10 +725,6 @@
"label": "ESP error",
"value": "{{esp_failure_errorcode.value}}",
"format": "errorCode"
},
{
"label": "Detection",
"value": "{{app_with_detection_failure.value}}"
}
]
},
+22 -3
View File
@@ -195,7 +195,7 @@
"category": "always",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: (?<id>{GUID}) resulted in action status: Success and detection state: (?<detection>DetectedDifferentVersion|NotDetected|Detected)",
"action": "captureDetectionResult",
"description": "Captures the detection rule result after IME runs detection for an app. 'Detected' means the detection rule matched (app is installed), 'NotDetected' means it did not, 'DetectedDifferentVersion' means a different version was found (supersedence / WinGet version mismatch). DetectedDifferentVersion must come first in the alternation so the unanchored regex does not mis-capture its 'Detected' prefix. Excludes [SimulatedDetectionActionHandler] which fires during applicability pre-checks.",
"description": "Captures the result of every IME detection run for an app: the check before the install (NotDetected is what starts the install) and the check right after it. App events therefore carry the check before the install; IME's verdict after the install is the enforcement error 0x87D1041C on failure. 'Detected' means the detection rule matched (app is installed), 'NotDetected' means it did not, 'DetectedDifferentVersion' means a different version was found (supersedence / WinGet version mismatch). DetectedDifferentVersion must come first in the alternation so the unanchored regex does not mis-capture its 'Detected' prefix. Excludes [SimulatedDetectionActionHandler] which fires during applicability pre-checks.",
"enabled": true
},
{
@@ -285,12 +285,12 @@
{
"patternId": "IME-ERROR-REPORT",
"category": "currentPhase",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:\"{1,2}(?<from>\\w+)\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}(?<to>\\w+)\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:\"{1,2}(?<from>\\w+)\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}(?<to>\\w+)\"{1,2}(?:\\},\"{1,2}EnforcementErrorCode\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:-?\\d+|null),\"{1,2}NewValue\"{1,2}:(?<errorCode>-?\\d+))?",
"action": "updateStateError",
"parameters": {
"checkTo": "true"
},
"description": "Captures enforcement state transitions via ReportingManager. Only triggers error when 'to' value indicates an error state. OldValue may be the unquoted JSON literal null on the first-ever write of a reporting state — transitions straight from the initial state (e.g. first write directly to an error state) would otherwise be invisible (IME 1.97 audit 2026-08-17). Quote-flexible since 2026-08-17: IME 1.104 serializes the report-delta JSON with single quotes ({\"Key\":...) where older versions logged doubled quotes ({\"\"Key\"\":...) - every literal quote in the delta is matched as \"{1,2} to cover both.",
"description": "Captures enforcement state transitions via ReportingManager. Only triggers error when 'to' value indicates an error state. OldValue may be the unquoted JSON literal null on the first-ever write of a reporting state — transitions straight from the initial state (e.g. first write directly to an error state) would otherwise be invisible (IME 1.97 audit 2026-08-17). Quote-flexible since 2026-08-17: IME 1.104 serializes the report-delta JSON with single quotes ({\"Key\":...) where older versions logged doubled quotes ({\"\"Key\"\":...) - every literal quote in the delta is matched as \"{1,2} to cover both. The optional errorCode group takes EnforcementErrorCode.NewValue, which IME logs as a signed decimal right after the state object (e.g. -2016345060 = 0x87D1041C: IME's check after the install did not find the app); the code reaches app_install_failed only when this line is the app's first move to Error.",
"enabled": true
},
{
@@ -487,6 +487,25 @@
"description": "Captures the JSON policies list discovered by IME, used to build the app inventory.",
"enabled": true
},
{
"patternId": "IME-POST-INSTALL-DETECTION",
"category": "always",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Policy with id: {GUID} is expected to have enforcement state: Detected\\.",
"action": "markPostInstallDetection",
"description": "Marks IME's check right after an install. IME logs this line only for the app it has just installed, before that check's result line; the agent reports that result (IME-DETECTION-RESULT) as app_post_install_detection and keeps detectionResult as the check before the install. Other apps of the same dependency chain are checked in the same run without this line. A failed check is IME's error 0x87D1041C (IME-ERROR-REPORT).",
"enabled": true
},
{
"patternId": "IME-POST-REBOOT-DETECTION",
"category": "always",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgressPendingReboot\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{1,2}",
"action": "markPostInstallDetection",
"parameters": {
"afterReboot": "true"
},
"description": "Marks IME's check after the restart an installer requested. After an exit code mapped to SoftReboot or HardReboot the check right after the install decides nothing; after the restart IME moves the app from InProgressPendingReboot to Success (held back like after a clean install) and checks again without the IME-POST-INSTALL-DETECTION line. That check's result is reported as app_post_install_detection with afterReboot=true. Quote-flexible like IME-ENFORCEMENT-SUCCESS.",
"enabled": true
},
{
"patternId": "IME-RESTART-STOP-PROCESSING",
"category": "currentPhase",
+1
View File
@@ -292,6 +292,7 @@
"app_install_completed",
"app_install_failed",
"app_install_skipped",
"app_post_install_detection",
"app_download_started",
"app_tracking_summary",
"download_progress",
@@ -4,6 +4,6 @@
"category": "always",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: (?<id>{GUID}) resulted in action status: Success and detection state: (?<detection>DetectedDifferentVersion|NotDetected|Detected)",
"action": "captureDetectionResult",
"description": "Captures the detection rule result after IME runs detection for an app. 'Detected' means the detection rule matched (app is installed), 'NotDetected' means it did not, 'DetectedDifferentVersion' means a different version was found (supersedence / WinGet version mismatch). DetectedDifferentVersion must come first in the alternation so the unanchored regex does not mis-capture its 'Detected' prefix. Excludes [SimulatedDetectionActionHandler] which fires during applicability pre-checks.",
"description": "Captures the result of every IME detection run for an app: the check before the install (NotDetected is what starts the install) and the check right after it. App events therefore carry the check before the install; IME's verdict after the install is the enforcement error 0x87D1041C on failure. 'Detected' means the detection rule matched (app is installed), 'NotDetected' means it did not, 'DetectedDifferentVersion' means a different version was found (supersedence / WinGet version mismatch). DetectedDifferentVersion must come first in the alternation so the unanchored regex does not mis-capture its 'Detected' prefix. Excludes [SimulatedDetectionActionHandler] which fires during applicability pre-checks.",
"enabled": true
}
+2 -2
View File
@@ -2,11 +2,11 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-REPORT",
"category": "currentPhase",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:\"{1,2}(?<from>\\w+)\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}(?<to>\\w+)\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:\"{1,2}(?<from>\\w+)\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}(?<to>\\w+)\"{1,2}(?:\\},\"{1,2}EnforcementErrorCode\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:(?:-?\\d+|null),\"{1,2}NewValue\"{1,2}:(?<errorCode>-?\\d+))?",
"action": "updateStateError",
"parameters": {
"checkTo": "true"
},
"description": "Captures enforcement state transitions via ReportingManager. Only triggers error when 'to' value indicates an error state. OldValue may be the unquoted JSON literal null on the first-ever write of a reporting state — transitions straight from the initial state (e.g. first write directly to an error state) would otherwise be invisible (IME 1.97 audit 2026-08-17). Quote-flexible since 2026-08-17: IME 1.104 serializes the report-delta JSON with single quotes ({\"Key\":...) where older versions logged doubled quotes ({\"\"Key\"\":...) - every literal quote in the delta is matched as \"{1,2} to cover both.",
"description": "Captures enforcement state transitions via ReportingManager. Only triggers error when 'to' value indicates an error state. OldValue may be the unquoted JSON literal null on the first-ever write of a reporting state — transitions straight from the initial state (e.g. first write directly to an error state) would otherwise be invisible (IME 1.97 audit 2026-08-17). Quote-flexible since 2026-08-17: IME 1.104 serializes the report-delta JSON with single quotes ({\"Key\":...) where older versions logged doubled quotes ({\"\"Key\"\":...) - every literal quote in the delta is matched as \"{1,2} to cover both. The optional errorCode group takes EnforcementErrorCode.NewValue, which IME logs as a signed decimal right after the state object (e.g. -2016345060 = 0x87D1041C: IME's check after the install did not find the app); the code reaches app_install_failed only when this line is the app's first move to Error.",
"enabled": true
}
@@ -0,0 +1,9 @@
{
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-POST-INSTALL-DETECTION",
"category": "always",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Policy with id: {GUID} is expected to have enforcement state: Detected\\.",
"action": "markPostInstallDetection",
"description": "Marks IME's check right after an install. IME logs this line only for the app it has just installed, before that check's result line; the agent reports that result (IME-DETECTION-RESULT) as app_post_install_detection and keeps detectionResult as the check before the install. Other apps of the same dependency chain are checked in the same run without this line. A failed check is IME's error 0x87D1041C (IME-ERROR-REPORT).",
"enabled": true
}
@@ -0,0 +1,12 @@
{
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-POST-REBOOT-DETECTION",
"category": "always",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Execution state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgressPendingReboot\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{1,2}",
"action": "markPostInstallDetection",
"parameters": {
"afterReboot": "true"
},
"description": "Marks IME's check after the restart an installer requested. After an exit code mapped to SoftReboot or HardReboot the check right after the install decides nothing; after the restart IME moves the app from InProgressPendingReboot to Success (held back like after a clean install) and checks again without the IME-POST-INSTALL-DETECTION line. That check's result is reported as app_post_install_detection with afterReboot=true. Quote-flexible like IME-ENFORCEMENT-SUCCESS.",
"enabled": true
}
+2 -1
View File
@@ -82,7 +82,8 @@
"captureAppTypeMsi",
"captureAttemptNumber",
"captureDetectionResult",
"captureExitCodeClass"
"captureExitCodeClass",
"markPostInstallDetection"
]
},
"parameters": {
+3 -3
View File
@@ -53,9 +53,9 @@
"license": "MIT"
},
"node_modules/fast-uri": {
"version": "3.1.8",
"resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.8.tgz",
"integrity": "sha512-GZMtZUTNRpOVIECoXwLNZS5xUGE+mVNbTB8h/7Rwh2TFWcBQiPzTgyZi05BF9UMZKkLJv8XBRJTlU7zg8+ZfMg==",
"version": "3.1.9",
"resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.9.tgz",
"integrity": "sha512-hS/0Wt3Ya043oKXs0sIxrMpKQITXhMLIrVAKKXi4gozGC9v7YRWVnXIZzjNPTO02M9BdxLCWqK1yRXgNziVyJQ==",
"dev": true,
"funding": [
{
@@ -70,8 +70,8 @@ function global:HarnessInvokeRestMethod {
function global:HarnessGetAuthenticodeSignature {
[CmdletBinding()]
param([string]$FilePath)
Write-HarnessTrace 'Get-AuthenticodeSignature' $FilePath
param([string]$FilePath, [byte[]]$Content, [string[]]$SourcePathOrExtension)
Write-HarnessTrace 'Get-AuthenticodeSignature' $(if ($Content) { "content:$($Content.Length)" } else { $FilePath })
return [pscustomobject]@{
Status = $global:HarnessOptions.SignatureStatus
SignerCertificate = [pscustomobject]@{ Subject = $global:HarnessOptions.SignerSubject; Thumbprint = 'HARNESS' }
@@ -188,8 +188,11 @@ if ($global:HarnessOptions.SwapElevation) { $swaps['Test-IsElevated'] = 'Harness
if ($global:HarnessOptions.SwapDacl) { $swaps['New-ProtectedDirectorySecurity'] = 'HarnessNewProtectedDirectorySecurity' }
foreach ($name in $swaps.Keys) { Set-Alias -Name $name -Value $swaps[$name] -Scope Global -Force }
# The OOBE script arrives as irm | iex, which ignores #Requires.
if ($global:HarnessOptions.Iex) {
# The bootstrap MSI's action is a -Command line; the OOBE script arrives as irm | iex, which
# ignores #Requires.
if ($global:HarnessOptions.CommandText) {
Invoke-Expression $global:HarnessOptions.CommandText
} elseif ($global:HarnessOptions.Iex) {
Invoke-Expression ([System.IO.File]::ReadAllText($global:HarnessOptions.Script))
} else {
& $global:HarnessOptions.Script @args
@@ -228,6 +231,7 @@ exit $LASTEXITCODE
Root = $root
ProgramData = Join-Path $root 'ProgramData'
Base = Join-Path $root 'ProgramData\AutopilotMonitor'
ProgramFiles = Join-Path $root 'ProgramFiles'
Temp = Join-Path $root 'Temp'
Server = Join-Path $root 'Server'
Outside = Join-Path $root 'Outside'
@@ -262,9 +266,11 @@ exit $LASTEXITCODE
CatalogValid = $true
Elevated = $true
Iex = $false
CommandText = $null
AgentStartFails = $false
}
foreach ($key in $Options.Keys) { $settings[$key] = $Options[$key] }
$script:promiseScenario = $Scenario
$settings.SwapElevation = ([bool]$settings.Elevated -ne $script:isElevated)
$settings.SwapDacl = -not $script:isElevated
@@ -287,6 +293,7 @@ exit $LASTEXITCODE
$psi.EnvironmentVariables['ALLUSERSPROFILE'] = $Scenario.ProgramData
$psi.EnvironmentVariables['TEMP'] = $Scenario.Temp
$psi.EnvironmentVariables['TMP'] = $Scenario.Temp
$psi.EnvironmentVariables['ProgramW6432'] = $Scenario.ProgramFiles
$process = [System.Diagnostics.Process]::Start($psi)
$stdout = $process.StandardOutput.ReadToEndAsync()
$stderr = $process.StandardError.ReadToEndAsync()
@@ -328,6 +335,25 @@ exit $LASTEXITCODE
return ($sorted -join "`n")
}
# The promise every run keeps, whatever the scenario asserts about ProgramData: nothing of
# ours anywhere else. The scenario's own fixture folders are the only other entries.
function Assert-NothingOutsideProgramData {
param($Scenario)
$fixtures = @('ProgramData', 'ProgramFiles', 'Temp', 'Server', 'Outside', 'Ime', 'Harness')
$others = @([System.IO.Directory]::GetFileSystemEntries($Scenario.Root) | ForEach-Object { [System.IO.Path]::GetFileName($_) } | Where-Object { $_ -notin $fixtures })
$others | Should -BeNullOrEmpty -Because 'the scripts write nowhere but ProgramData'
Get-Tree $Scenario.ProgramFiles | Should -BeNullOrEmpty -Because 'nothing of ours stays under Program Files'
Get-Tree $Scenario.Temp | Should -BeNullOrEmpty -Because 'the scripts never stage in the shared temp folder'
}
# Every Describe runs this after each test: the last run of the test kept the promise.
function Assert-PromiseOfLastRun {
if (-not $script:promiseScenario) { return }
$scenario = $script:promiseScenario
$script:promiseScenario = $null
Assert-NothingOutsideProgramData $scenario
}
function Get-StdErrLines {
param($Run)
return @($Run.StdErr -split "`r?`n" | Where-Object { $_ })
@@ -369,6 +395,7 @@ exit $LASTEXITCODE
}
Describe 'loader 1.4' {
AfterEach { Assert-PromiseOfLastRun }
It 'installs and leaves only the agent folder, with its log carried over' {
$s = New-Scenario
$run = Invoke-Scenario $s -Script $script:loaderPath -Arguments @('-MaxBootstrapWindowHours', '24')
@@ -471,7 +498,7 @@ Describe 'loader 1.4' {
It 'runs nothing it cannot verify: <Case>' -TestCases @(
@{ Case = 'unsigned'; Options = @{ SignatureStatus = 'NotSigned' }; Edit = $null }
@{ Case = 'another publisher'; Options = @{ SignerSubject = 'CN=Somebody Else, O=Somebody Else Ltd, C=US' }; Edit = $null }
@{ Case = 'an installer below 2.8'; Options = @{}; Edit = @('$ScriptVersion = "2.8"', '$ScriptVersion = "2.7"') }
@{ Case = 'an installer below 2.8'; Options = @{}; Edit = @('$ScriptVersion = "2.9"', '$ScriptVersion = "2.7"') }
@{ Case = 'not the installer'; Options = @{}; Edit = @('$ScriptRole = "AutopilotMonitor-Installer"', '$ScriptRole = "AutopilotMonitor-Other"') }
) {
$s = New-Scenario
@@ -502,6 +529,7 @@ Describe 'loader 1.4' {
}
Describe 'installer assigned directly' {
AfterEach { Assert-PromiseOfLastRun }
BeforeEach {
$s = New-Scenario
$imeCopy = Join-Path $s.Ime '0f1e2d3c-4b5a-6978-8796-a5b4c3d2e1f0.ps1'
@@ -605,6 +633,7 @@ Describe 'installer assigned directly' {
}
Describe 'loader 1.2, frozen' {
AfterEach { Assert-PromiseOfLastRun }
It 'installs with the current installer, which removes its copy and keeps the loader start line' {
$s = New-Scenario
$run = Invoke-Scenario $s -Script $script:loader12Path
@@ -644,6 +673,7 @@ Describe 'loader 1.2, frozen' {
}
Describe 'bootstrap MSI layouts, started in the folder the MSI installed' {
AfterEach { Assert-PromiseOfLastRun }
It '<Name> skips and leaves <Left>' -TestCases @(
@{ Name = 'MSI 1.3 (loader in Program Files)'; File = 'Start-AutopilotMonitor.ps1'; Source = 'loader'; Location = 'program-files'; Arguments = @('-LogFileName', 'bootstrap-msi.log'); Left = 'nothing'; Tree = @() }
@{ Name = 'MSI 1.2 (loader 1.3)'; File = 'Start-AutopilotMonitor.ps1'; Source = 'loader'; Arguments = @('-LogFileName', 'bootstrap-msi.log'); Left = 'nothing'; Tree = @() }
@@ -660,6 +690,26 @@ Describe 'bootstrap MSI layouts, started in the folder the MSI installed' {
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -Be (Join-Tree $Tree)
if ($Location -eq 'program-files') { $run.StdOut | Should -Match 'Bootstrap removed, and with it the empty' }
}
# MSI 1.3 installed its loader under Program Files, where nothing of ours belongs; the
# installer takes it away in every outcome, also when an agent is present.
It 'MSI 1.3 leaves nothing under Program Files when an agent is present' {
$s = New-Scenario
$msi = Join-Path $s.ProgramFiles 'AutopilotMonitor\Bootstrap'
New-Item -ItemType Directory -Path $msi -Force | Out-Null
Copy-Item -LiteralPath $script:loaderPath -Destination (Join-Path $msi 'Start-AutopilotMonitor.ps1')
Add-File (Join-Path $s.Base 'Logs\agent.log') 'kept log'
$before = Get-Tree $s.ProgramData -Content
$run = Invoke-Scenario $s -Script (Join-Path $msi 'Start-AutopilotMonitor.ps1') -Arguments @('-LogFileName', 'bootstrap-msi.log') -WorkingDirectory $msi -Options @{ Marker = '2026-10-01T08:00:00Z' }
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData -Content | Should -Be $before
Test-Path -LiteralPath (Join-Path $s.ProgramFiles 'AutopilotMonitor') | Should -BeFalse
$run.StdOut | Should -Match 'Agent present \(deployment marker\): .* is left as it is\.'
$run.StdOut | Should -Match 'Bootstrap removed, and with it the empty'
}
It '<Name> installs' -TestCases @(
@@ -678,10 +728,127 @@ Describe 'bootstrap MSI layouts, started in the folder the MSI installed' {
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -Be (Join-Tree ($script:installedTree + 'AutopilotMonitor\Logs\bootstrap-msi.log' + 'AutopilotMonitor\Logs\bootstrap-script.log'))
if ($Location -eq 'program-files') { $run.StdOut | Should -Match 'Bootstrap removed, and with it the empty' }
}
}
# MSI 1.4 installs the loader copy under <base>\Msi and runs this command as SYSTEM from
# System32: read the copy once, check our signature on those bytes, run those bytes. The
# command is taken from Package.wxs and formatted as Windows Installer formats it (measured
# on the built MSI, 2026-10-23); the wrapper runs it where the stubs apply.
Describe 'bootstrap MSI 1.4: the action checks the loader copy and runs what it read' {
AfterEach { Assert-PromiseOfLastRun }
BeforeAll {
$wxs = [xml][System.IO.File]::ReadAllText((Join-Path $script:repoRoot 'src\Agent\AutopilotMonitor.BootstrapMsi\Package.wxs'))
$action = @($wxs.Wix.Package.CustomAction) | Where-Object { $_.Id -eq 'RunBootstrap' }
if ($action.ExeCommand -notmatch ' -Command "(.*)"$') { throw 'Package.wxs: the action has no -Command argument.' }
$script:actionCommand = $Matches[1]
# What the build bakes in: the hash of the loader the package embeds, here the one served.
$script:loaderSha256 = (Get-FileHash -LiteralPath $script:loaderPath -Algorithm SHA256).Hash.ToLowerInvariant()
function Format-MsiAction {
param([string]$Text, [string]$InstallFolder)
return $Text.Replace('$(var.LoaderSha256)', $script:loaderSha256).Replace('[\[]', '[').Replace('[\]]', ']').Replace('[\{]', '{').Replace('[\}]', '}').Replace('[INSTALLFOLDER]', $InstallFolder)
}
function Add-MsiCopy {
param($Scenario)
$msi = Join-Path $Scenario.Base 'Msi'
New-Item -ItemType Directory -Path $msi -Force | Out-Null
Copy-Item -LiteralPath $script:loaderPath -Destination (Join-Path $msi 'Start-AutopilotMonitor.ps1')
}
function Invoke-MsiAction {
param($Scenario, [hashtable]$Options = @{})
$command = Format-MsiAction -Text $script:actionCommand -InstallFolder ((Join-Path $Scenario.Base 'Msi') + '\')
return Invoke-Scenario $Scenario -WorkingDirectory "$env:SystemRoot\System32" -Options ($Options + @{ CommandText = $command })
}
$script:copyOnlyTree = @('AutopilotMonitor\', 'AutopilotMonitor\Msi\', 'AutopilotMonitor\Msi\Start-AutopilotMonitor.ps1')
}
It 'is PowerShell that parses, with every bracket and brace escaped for Windows Installer' {
# Without the [\x] escapes, the only bracket left is the one property reference.
($script:actionCommand -replace '\[\\.\]', '').Replace('[INSTALLFOLDER]', '') | Should -Not -Match '[{}\[\]]'
@([regex]::Matches($script:actionCommand, '\[[A-Za-z0-9_.]+\]') | ForEach-Object { $_.Value } | Sort-Object -Unique) | Should -Be @('[INSTALLFOLDER]')
$errors = $null
[System.Management.Automation.Language.Parser]::ParseInput((Format-MsiAction -Text $script:actionCommand -InstallFolder 'C:\ProgramData\AutopilotMonitor\Msi\'), [ref]$null, [ref]$errors) | Out-Null
@($errors) | Should -BeNullOrEmpty
}
It 'installs, and the copy goes with the emptied agent folder' {
$s = New-Scenario
Add-MsiCopy $s
$run = Invoke-MsiAction $s
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -Be (Join-Tree ($script:installedTree + 'AutopilotMonitor\Logs\bootstrap-msi.log' + 'AutopilotMonitor\Logs\bootstrap-script.log'))
@($run.Trace | Where-Object { $_ -like 'Get-AuthenticodeSignature|content:*' }).Count | Should -Be 1
@($run.Trace | Where-Object { $_ -like 'Get-BootstrapDecision|*' }).Count | Should -Be 1
$run.StdOut | Should -Match 'Bootstrap Completed Successfully'
Get-Content -LiteralPath (Join-Path $s.Base 'Logs\bootstrap-msi.log') -Raw | Should -Match '=== Autopilot Monitor bootstrap loader v1\.4 started'
}
It 'skips and leaves nothing behind' {
$s = New-Scenario
Add-MsiCopy $s
$run = Invoke-MsiAction $s -Options @{ Install = $false }
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -BeNullOrEmpty
$run.StdOut | Should -Match 'No agent on this device: .* removed\.'
}
It 'leaves nothing behind when only the deployment marker is there' {
$s = New-Scenario
Add-MsiCopy $s
$run = Invoke-MsiAction $s -Options @{ Marker = '2026-10-01T08:00:00Z' }
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -BeNullOrEmpty
$run.StdOut | Should -Match 'Agent present \(deployment marker\): .*\\Msi removed, and with it the empty'
@($run.Trace | Where-Object { $_ -like 'Invoke-WebRequest|*Agent.zip' }).Count | Should -Be 0
}
It 'removes the copy and leaves the folder of an agent as it is' {
$s = New-Scenario
Add-File (Join-Path $s.Base 'Agent\AutopilotMonitor.Agent.exe') 'running agent'
Add-File (Join-Path $s.Base 'Logs\agent.log') 'agent log'
Add-MsiCopy $s
$run = Invoke-MsiAction $s
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -Be (Join-Tree @('AutopilotMonitor\', 'AutopilotMonitor\Agent\', 'AutopilotMonitor\Agent\AutopilotMonitor.Agent.exe', 'AutopilotMonitor\Logs\', 'AutopilotMonitor\Logs\agent.log'))
$run.StdOut | Should -Match 'Agent present \(agent executable\): .*\\Msi removed\.'
@($run.Trace | Where-Object { $_ -like 'Invoke-AgentInstallMode|*' }).Count | Should -Be 0
}
It 'runs nothing it cannot verify: <Case>' -TestCases @(
@{ Case = 'unsigned'; Options = @{ SignatureStatus = 'NotSigned' }; Append = $null }
@{ Case = 'changed after signing'; Options = @{ SignatureStatus = 'HashMismatch' }; Append = $null }
@{ Case = 'another publisher'; Options = @{ SignerSubject = 'CN=Somebody Else, O=Somebody Else Ltd, C=US' }; Append = $null }
@{ Case = 'not the loader the package embeds, however validly signed'; Options = @{}; Append = "`r`n# one more line" }
) {
$s = New-Scenario
Add-MsiCopy $s
if ($Append) { [System.IO.File]::AppendAllText((Join-Path $s.Base 'Msi\Start-AutopilotMonitor.ps1'), $Append) }
$run = Invoke-MsiAction $s -Options $Options
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
Get-Tree $s.ProgramData | Should -Be (Join-Tree $script:copyOnlyTree)
@($run.Trace | Where-Object { $_ -like 'Get-AuthenticodeSignature|content:*' }).Count | Should -Be 1
@($run.Trace | Where-Object { $_ -like 'Invoke-WebRequest|*' }).Count | Should -Be 0
@($run.Trace | Where-Object { $_ -like 'Get-BootstrapDecision|*' }).Count | Should -Be 0
}
}
Describe 'OOBE script, as the backend generates it' {
AfterEach { Assert-PromiseOfLastRun }
It 'installs the agent with the bootstrap token and leaves only the agent folder' {
$s = New-Scenario
Add-Leftovers $s
@@ -733,6 +900,7 @@ Describe 'OOBE script, as the backend generates it' {
}
Describe 'publish pipeline and dev channel' {
AfterEach { Assert-PromiseOfLastRun }
BeforeAll {
$script:rendered = Join-Path $TestDrive 'rendered'
$script:pwsh = (Get-Command pwsh -CommandType Application -ErrorAction Stop | Select-Object -First 1).Source
@@ -768,9 +936,9 @@ Describe 'publish pipeline and dev channel' {
}
It 'refuses to publish an installer the loader would refuse: <Case>' -TestCases @(
@{ Case = 'below the minimum version'; Old = '$ScriptVersion = "2.8"'; New = '$ScriptVersion = "2.7"' }
@{ Case = 'below the minimum version'; Old = '$ScriptVersion = "2.9"'; New = '$ScriptVersion = "2.7"' }
@{ Case = 'without its role line'; Old = '$ScriptRole = "AutopilotMonitor-Installer"'; New = '# no role' }
@{ Case = 'with a second version line'; Old = '$ScriptVersion = "2.8"'; New = "`$ScriptVersion = `"2.8`"`n`$ScriptVersion = `"2.9`"" }
@{ Case = 'with a second version line'; Old = '$ScriptVersion = "2.9"'; New = "`$ScriptVersion = `"2.9`"`n`$ScriptVersion = `"3.0`"" }
) {
$root = Join-Path $TestDrive ('repo' + [guid]::NewGuid().ToString('N').Substring(0, 6))
New-Item -ItemType Directory -Path (Join-Path $root 'scripts\Bootstrap') -Force | Out-Null
@@ -817,7 +985,7 @@ Describe 'publish pipeline and dev channel' {
$run.ExitCode | Should -Be 0
$run.StdErr | Should -BeNullOrEmpty
$run.StdOut | Should -Match 'Installer accepted: AutopilotMonitor-Installer v2\.8'
$run.StdOut | Should -Match 'Installer accepted: AutopilotMonitor-Installer v2\.9'
$run.StdOut | Should -Match 'Bootstrap Completed Successfully'
}
}
@@ -800,6 +800,153 @@ Describe 'Remove-AgentBaseOnSkip' {
}
}
Describe 'Remove-MsiTransportFolder' {
BeforeEach {
Mock Start-Sleep { }
Mock New-ProtectedDirectorySecurity { New-TestDirectorySecurity }
Mock Test-IsOwnedByUs { $true }
$AgentBasePath = Join-Path $TestDrive "AutopilotMonitor-$([guid]::NewGuid().ToString('N').Substring(0, 8))"
$MsiTransportPath = Join-Path $AgentBasePath 'Msi'
}
It 'has nothing to do without an agent folder or without the copy' {
Remove-MsiTransportFolder | Should -BeNullOrEmpty
New-Item -ItemType Directory -Path (Join-Path $AgentBasePath 'Logs') -Force | Out-Null
Remove-MsiTransportFolder | Should -BeNullOrEmpty
Test-Path (Join-Path $AgentBasePath 'Logs') | Should -BeTrue
}
It 'removes the copy and keeps an agent folder that holds anything else' {
New-Item -ItemType File -Path (Join-Path $AgentBasePath 'Logs\agent.log') -Value 'kept' -Force | Out-Null
New-Item -ItemType Directory -Path $MsiTransportPath -Force | Out-Null
Set-Content -Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') -Value 'x'
Remove-MsiTransportFolder | Should -Be "$MsiTransportPath removed."
Test-Path $MsiTransportPath | Should -BeFalse
Get-Content (Join-Path $AgentBasePath 'Logs\agent.log') | Should -Be 'kept'
}
It 'removes the copy and with it an agent folder that is then empty' {
New-Item -ItemType Directory -Path $MsiTransportPath -Force | Out-Null
Set-Content -Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') -Value 'x'
Remove-MsiTransportFolder | Should -Be "$MsiTransportPath removed, and with it the empty $AgentBasePath."
Test-Path $AgentBasePath | Should -BeFalse
}
It 'leaves a copy that is not ours, and says so' {
New-Item -ItemType Directory -Path $MsiTransportPath -Force | Out-Null
Set-Content -Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') -Value 'x'
Mock Test-IsOwnedByUs { $Path -notlike '*\Msi' }
Remove-MsiTransportFolder | Should -Be "$MsiTransportPath left as it is (Foreign)."
Test-Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') | Should -BeTrue
}
It 'touches nothing below an agent folder that is not ours' {
New-Item -ItemType Directory -Path $MsiTransportPath -Force | Out-Null
Set-Content -Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') -Value 'x'
Mock Test-IsOwnedByUs { $false }
Remove-MsiTransportFolder | Should -BeNullOrEmpty
Test-Path (Join-Path $MsiTransportPath 'Start-AutopilotMonitor.ps1') | Should -BeTrue
}
It 'never follows a link planted as the copy' {
New-Item -ItemType Directory -Path $AgentBasePath -Force | Out-Null
$target = New-SentinelJunction -Link $MsiTransportPath
Remove-MsiTransportFolder | Should -Be "$MsiTransportPath left as it is (Link)."
Test-Path (Join-Path $target 'sentinel.txt') | Should -BeTrue
}
It 'never throws' {
Mock Get-FolderState { throw 'unexpected' }
{ Remove-MsiTransportFolder } | Should -Not -Throw
}
}
Describe 'Remove-LegacyMsiLoaderFolder' {
BeforeEach {
Mock Start-Sleep { }
Mock New-ProtectedDirectorySecurity { New-TestDirectorySecurity }
Mock Test-IsOwnedByUs { $true }
$script:realProgramW6432 = $env:ProgramW6432
$script:realProgramFiles = $env:ProgramFiles
$env:ProgramW6432 = New-TestFolder 'ProgramFiles64'
$env:ProgramFiles = New-TestFolder 'ProgramFiles32'
$script:company = Join-Path $env:ProgramW6432 'AutopilotMonitor'
$script:loader = Join-Path $script:company 'Bootstrap\Start-AutopilotMonitor.ps1'
}
AfterEach {
$env:ProgramW6432 = $script:realProgramW6432
$env:ProgramFiles = $script:realProgramFiles
}
It 'has nothing to do where MSI 1.3 never ran' {
Remove-LegacyMsiLoaderFolder | Should -BeNullOrEmpty
New-Item -ItemType Directory -Path $script:company -Force | Out-Null
Remove-LegacyMsiLoaderFolder | Should -BeNullOrEmpty
Test-Path $script:company | Should -BeTrue
}
It 'removes what MSI 1.3 installed, and the company folder with it' {
New-Item -ItemType File -Path $script:loader -Force | Out-Null
Remove-LegacyMsiLoaderFolder | Should -Be "$(Split-Path $script:loader) removed, and with it the empty $script:company."
Test-Path $script:company | Should -BeFalse
}
It 'keeps the company folder when anything else is in it' {
New-Item -ItemType File -Path $script:loader -Force | Out-Null
Set-Content -Path (Join-Path $script:company 'other.txt') -Value 'x'
Remove-LegacyMsiLoaderFolder | Should -Be "$(Split-Path $script:loader) removed."
Test-Path (Split-Path $script:loader) | Should -BeFalse
Test-Path (Join-Path $script:company 'other.txt') | Should -BeTrue
}
It 'reads the 64-bit Program Files, also from the 32-bit host' {
$other = Join-Path $env:ProgramFiles 'AutopilotMonitor\Bootstrap\Start-AutopilotMonitor.ps1'
New-Item -ItemType File -Path $script:loader -Force | Out-Null
New-Item -ItemType File -Path $other -Force | Out-Null
Remove-LegacyMsiLoaderFolder | Should -BeLike '*removed*'
Test-Path $script:company | Should -BeFalse
Test-Path $other | Should -BeTrue
}
It 'leaves a folder that is not ours' {
New-Item -ItemType File -Path $script:loader -Force | Out-Null
Mock Test-IsOwnedByUs { $false }
Remove-LegacyMsiLoaderFolder | Should -Be "$script:company left as it is (Foreign)."
Test-Path $script:loader | Should -BeTrue
}
It 'never follows a link' {
$target = New-SentinelJunction -Link $script:company
Remove-LegacyMsiLoaderFolder | Should -Be "$script:company left as it is (Link)."
Test-Path (Join-Path $target 'sentinel.txt') | Should -BeTrue
}
It 'never throws' {
Mock Get-FolderState { throw 'unexpected' }
{ Remove-LegacyMsiLoaderFolder } | Should -Not -Throw
}
}
Describe 'Get-AgentPayloadRejections' {
# The payload catalog check, shared verbatim with the OOBE go-script. What matters is the
# DECISION: which payload is accepted and which is refused. Test-FileCatalog is mocked for
@@ -1122,7 +1269,7 @@ Describe 'script text' {
It 'declares the role and version the loader checks, one line each' {
([regex]::Matches($script:text, '(?m)^\$ScriptRole = "AutopilotMonitor-Installer"\s*$')).Count | Should -Be 1
([regex]::Matches($script:text, '(?m)^\$ScriptVersion = "2\.8"\s*$')).Count | Should -Be 1
([regex]::Matches($script:text, '(?m)^\$ScriptVersion = "2\.9"\s*$')).Count | Should -Be 1
}
It 'never stages anything in the shared temp folder' {
+65 -3
View File
@@ -13,7 +13,8 @@
The agent is installed only when its ZIP matches the SHA-256 in its manifest and every
file matches the catalog signed by glueckkanja AG. The agent removes itself when
enrollment completes; the registry value HKLM\SOFTWARE\AutopilotMonitor\Deployed stays so
that the device is not installed again. A skipped device without an agent keeps nothing.
that the device is not installed again. A skipped device without an agent keeps nothing,
and the loader copy the bootstrap MSI installs is removed in every outcome.
Log: %ProgramData%\AutopilotMonitor\Logs\bootstrap-script.log when the agent is installed
or the install fails; a skip is logged to the script output only. Exit code 0: installed
@@ -53,7 +54,7 @@ param(
)
# The loader checks these two lines before it runs this script.
$ScriptVersion = "2.8"
$ScriptVersion = "2.9"
$ScriptRole = "AutopilotMonitor-Installer"
# Signer of the agent's file catalog; a subject pattern, so certificate renewals keep working.
@@ -69,6 +70,9 @@ $LogFile = "$AgentLogPath\bootstrap-script.log"
$LegacyInstallerPath = "$AgentBasePath\Install-AutopilotMonitor.ps1"
$LoaderRunFolderPrefix = "AutopilotMonitor-Loader-"
# Where the bootstrap MSI installs its loader copy; this script removes it in every outcome.
$MsiTransportPath = "$AgentBasePath\Msi"
$AgentExeName = "AutopilotMonitor.Agent.exe"
$AgentTaskName = "AutopilotMonitor-Agent"
$DeploymentMarkerKey = "SOFTWARE\AutopilotMonitor"
@@ -608,6 +612,57 @@ function Remove-AgentBaseOnSkip {
}
}
# The loader copy the bootstrap MSI installs. It goes whatever the outcome; an agent folder
# that is then empty goes with it (a running agent, or logs kept after enrollment, keep it).
# Returns what was done, or $null when there was nothing to do; never throws.
function Remove-MsiTransportFolder {
try {
if ((Get-FolderState $AgentBasePath) -ne 'Ours') { return $null }
$state = Get-FolderState $MsiTransportPath
if ($state -eq 'Missing') { return $null }
if ($state -ne 'Ours') { return "$MsiTransportPath left as it is ($state)." }
$left = Remove-OwnTree -Path $MsiTransportPath
if ($left.Foreign.Count -gt 0 -or $left.Locked.Count -gt 0) {
return ("$MsiTransportPath kept: {0} entries of another account, {1} in use." -f $left.Foreign.Count, $left.Locked.Count)
}
if (@([System.IO.Directory]::EnumerateFileSystemEntries($AgentBasePath)).Count -eq 0) {
[System.IO.Directory]::Delete($AgentBasePath, $false)
return "$MsiTransportPath removed, and with it the empty $AgentBasePath."
}
return "$MsiTransportPath removed."
} catch {
return "$MsiTransportPath left as it is ($($_.Exception.Message))."
}
}
# What bootstrap MSI 1.3 installed under Program Files, on devices that still enroll with it.
# Returns what was done, or $null when there was nothing to do; never throws.
function Remove-LegacyMsiLoaderFolder {
try {
$programFiles = if ($env:ProgramW6432) { $env:ProgramW6432 } else { $env:ProgramFiles }
if (-not $programFiles) { return $null }
$company = Join-Path $programFiles 'AutopilotMonitor'
$companyState = Get-FolderState $company
if ($companyState -eq 'Missing') { return $null }
if ($companyState -ne 'Ours') { return "$company left as it is ($companyState)." }
$path = Join-Path $company 'Bootstrap'
$state = Get-FolderState $path
if ($state -eq 'Missing') { return $null }
if ($state -ne 'Ours') { return "$path left as it is ($state)." }
$left = Remove-OwnTree -Path $path
if ($left.Foreign.Count -gt 0 -or $left.Locked.Count -gt 0) {
return ("$path kept: {0} entries of another account, {1} in use." -f $left.Foreign.Count, $left.Locked.Count)
}
if (@([System.IO.Directory]::EnumerateFileSystemEntries($company)).Count -eq 0) {
[System.IO.Directory]::Delete($company, $false)
return "$path removed, and with it the empty $company."
}
return "$path removed."
} catch {
return "The loader folder of bootstrap MSI 1.3 is left as it is ($($_.Exception.Message))."
}
}
function Test-IsLoaderRunFolder {
param([string]$Folder)
if (-not $Folder) { return $false }
@@ -711,12 +766,17 @@ function Invoke-Bootstrap {
$decision = Get-BootstrapDecision -MaxBootstrapWindowHours $MaxBootstrapWindowHours -OobeProfileMaxAgeMinutes $OobeProfileMaxAgeMinutes
$agent = Get-AgentPresence
if ($agent) {
Write-Log "Agent present ($agent): $AgentBasePath is left as it is."
$transport = Remove-MsiTransportFolder
Write-Log "Agent present ($agent): $(if ($transport) { $transport } else { "$AgentBasePath is left as it is." })"
$legacy = Remove-LegacyMsiLoaderFolder
if ($legacy) { Write-Log $legacy }
Remove-StaleLoaderRunFolders -ScriptRoot $PSScriptRoot
exit 0
}
if (-not $decision.Install) {
Write-Log "No agent on this device: $(Remove-AgentBaseOnSkip -Path $AgentBasePath)"
$legacy = Remove-LegacyMsiLoaderFolder
if ($legacy) { Write-Log $legacy }
Remove-StaleLoaderRunFolders -ScriptRoot $PSScriptRoot
exit 0
}
@@ -729,6 +789,8 @@ function Invoke-Bootstrap {
Write-LoaderLogs $loaderLogs
Open-LogFile
Write-Log "Agent folder prepared: $AgentBasePath (protected, emptied)."
$legacy = Remove-LegacyMsiLoaderFolder
if ($legacy) { Write-Log $legacy }
Remove-StaleLoaderRunFolders -ScriptRoot $PSScriptRoot
$agentExePath = Join-Path $AgentBinPath $AgentExeName
@@ -467,11 +467,15 @@ Describe 'publish contract' {
$wxs.Contains('-LogFileName bootstrap-msi.log') | Should -BeTrue
}
# The file a SYSTEM custom action runs must not sit where a standard user could have
# created the folder first: Program Files, never ProgramData.
It 'is installed by the bootstrap MSI under Program Files' {
# Everything of ours lives under ProgramData, so the copy the MSI installs does too, where
# the installer removes it. A standard user could have created that folder first, so the
# action never runs the file as such: it checks the signature on the bytes it read and runs
# those bytes, from System32.
It 'is installed by the bootstrap MSI under ProgramData and run only after the check' {
$wxs = Get-Content (Join-Path $PSScriptRoot '..\..\src\Agent\AutopilotMonitor.BootstrapMsi\Package.wxs') -Raw
$wxs | Should -Match '<StandardDirectory Id="ProgramFiles64Folder">'
$wxs | Should -Not -Match 'CommonAppDataFolder'
$wxs | Should -Match '<StandardDirectory Id="CommonAppDataFolder">'
$wxs | Should -Not -Match 'ProgramFiles'
$wxs.Contains('Get-AuthenticodeSignature -Content $b -SourcePathOrExtension ''.ps1''') | Should -BeTrue
$wxs.Contains('Directory="System64Folder"') | Should -BeTrue
}
}
@@ -1,8 +1,10 @@
using System;
using System.IO;
using System.Linq;
using System.Reflection;
using System.Text;
using System.Text.RegularExpressions;
using System.Xml.Linq;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime;
using AutopilotMonitor.Agent.V2.Core.Security;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
@@ -26,6 +28,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Bootstrap
private static readonly string Loader = File.ReadAllText(Path.Combine(BootstrapDir, "Start-AutopilotMonitor.ps1"));
private static readonly string OobeScript = File.ReadAllText(Path.Combine(
RepoPaths.Root(), "src", "Backend", "AutopilotMonitor.Functions.Tests", "TestData", "oobe-bootstrap-golden.ps1"));
private static readonly string Wxs = File.ReadAllText(Path.Combine(
RepoPaths.Root(), "src", "Agent", "AutopilotMonitor.BootstrapMsi", "Package.wxs"));
private readonly string _logs = Path.Combine(Path.GetTempPath(), "apm-bootstrap-contract-" + Guid.NewGuid().ToString("N"));
@@ -80,8 +84,54 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Bootstrap
Assert.Matches(@"\[string\]\$LogFileName = """ + Regex.Escape(BootstrapProvenanceReader.LoaderLogName) + @"""", Loader);
Assert.Contains("$LogFile = \"$AgentLogPath\\" + BootstrapProvenanceReader.OobeLogName + "\"", OobeScript);
var wxs = File.ReadAllText(Path.Combine(RepoPaths.Root(), "src", "Agent", "AutopilotMonitor.BootstrapMsi", "Package.wxs"));
Assert.Contains("-LogFileName " + BootstrapProvenanceReader.MsiLoaderLogName, wxs);
Assert.Contains("-LogFileName " + BootstrapProvenanceReader.MsiLoaderLogName, Wxs);
}
// The bootstrap MSI installs its loader copy where the installer removes it, starts
// PowerShell in System32, and runs only bytes it has checked against the publisher pin
// the loader applies to the installer. Windows Installer formats the command, so every
// bracket and brace is escaped and the only property references are the two paths.
[Fact]
public void The_msi_puts_the_loader_copy_where_the_installer_removes_it_and_runs_only_what_it_checked()
{
XNamespace ns = "http://wixtoolset.org/schemas/v4/wxs";
var package = XDocument.Parse(Wxs).Root.Element(ns + "Package");
Assert.Equal("1fbe5515-d346-445c-b8b8-14ee79f97522", (string)package.Attribute("UpgradeCode"));
var root = package.Elements(ns + "StandardDirectory").Single();
Assert.Equal("CommonAppDataFolder", (string)root.Attribute("Id"));
var chain = root.Descendants(ns + "Directory").Select(d => (string)d.Attribute("Name")).ToArray();
Assert.Equal("INSTALLFOLDER", (string)root.Descendants(ns + "Directory").Last().Attribute("Id"));
var transport = Assignment(Installer, "MsiTransportPath").Replace("$AgentBasePath", Assignment(Installer, "AgentBasePath"));
Assert.Equal("$env:ProgramData\\" + string.Join("\\", chain), transport);
var action = package.Elements(ns + "CustomAction").Single(a => (string)a.Attribute("Id") == "RunBootstrap");
Assert.Equal("System64Folder", (string)action.Attribute("Directory"));
Assert.Equal("deferred", (string)action.Attribute("Execute"));
Assert.Equal("no", (string)action.Attribute("Impersonate"));
Assert.Equal("ignore", (string)action.Attribute("Return"));
var exeCommand = (string)action.Attribute("ExeCommand");
var command = exeCommand.Substring(exeCommand.IndexOf(" -Command ", StringComparison.Ordinal));
Assert.Contains("-NonInteractive", exeCommand);
Assert.Contains("[\\[]System.IO.File[\\]]::ReadAllBytes('[INSTALLFOLDER]Start-AutopilotMonitor.ps1')", command);
Assert.Contains("Get-AuthenticodeSignature -Content $b -SourcePathOrExtension '.ps1'", command);
Assert.Contains("$h -eq '$(var.LoaderSha256)' -and $s.Status -eq 'Valid' -and $s.SignerCertificate.Subject -like '" + Assignment(Loader, "ExpectedPublisher") + "'", command);
// The hash is baked in by the build from the loader it embeds; a package built without it must not exist.
Assert.Contains("<?ifndef var.LoaderSha256 ?>", Wxs);
var workflow = File.ReadAllText(Path.Combine(RepoPaths.Root(), ".github", "workflows", "build-msi.yml"));
Assert.Contains("wix build Package.wxs -arch x64 -d LoaderSha256=$loaderSha256", workflow);
Assert.Contains("Get-FileHash -LiteralPath $env:RUNNER_SCRIPT -Algorithm SHA256", workflow);
Assert.Contains("[\\[]scriptblock[\\]]::Create([\\[]System.Text.Encoding[\\]]::UTF8.GetString($b))", command);
Assert.DoesNotContain("-File", command);
// Without the [\x] escapes, the only bracket left is the one property reference.
var unescaped = Regex.Replace(command, @"\[\\.\]", "");
Assert.DoesNotMatch(@"[{}\[\]]", unescaped.Replace("[INSTALLFOLDER]", ""));
Assert.Equal(new[] { "[INSTALLFOLDER]" }, Regex.Matches(command, @"\[[A-Za-z0-9_.]+\]").Cast<Match>().Select(m => m.Value).Distinct().ToArray());
var custom = package.Element(ns + "InstallExecuteSequence").Elements(ns + "Custom").Single();
Assert.Equal("RunBootstrap", (string)custom.Attribute("Action"));
Assert.Equal("NOT Installed", (string)custom.Attribute("Condition"));
}
[Fact]
@@ -0,0 +1,80 @@
#nullable enable
using System;
using System.Collections.Generic;
using System.IO;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Shared.Models;
using Newtonsoft.Json;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Harness
{
/// <summary>
/// An <see cref="ImeLogTracker"/> fed the shipped IME pattern pack (<c>rules/ime-log-patterns</c>,
/// sorted as combine.js embeds it) and a CMTrace <c>IntuneManagementExtension.log</c> the test
/// appends to, so a test drives the real patterns end to end.
/// </summary>
internal sealed class ShippedImePackHarness : IDisposable
{
private readonly TempDirectory _tmp = new TempDirectory();
public ImeLogTracker Tracker { get; }
public string StateDir { get; }
public DateTime Now { get; } = new DateTime(2026, 9, 6, 12, 0, 0, DateTimeKind.Utc);
public ShippedImePackHarness()
{
StateDir = Path.Combine(_tmp.Path, "State");
Tracker = Build();
}
public static List<ImeLogPattern> Pack()
=> Directory.GetFiles(Path.Combine(RepoPaths.Root(), "rules", "ime-log-patterns"), "*.json")
.OrderBy(f => f, StringComparer.Ordinal)
.Select(f => JsonConvert.DeserializeObject<ImeLogPattern>(File.ReadAllText(f))!)
.ToList();
/// <summary>A second tracker on the same log and state folder (an agent restart).</summary>
public ImeLogTracker Build()
{
var tracker = new ImeLogTracker(
logFolder: _tmp.Path,
patterns: Pack(),
logger: new AgentLogger(_tmp.Path, AgentLogLevel.Info),
stateDirectory: StateDir);
// The historic-replay guard skips app-mutating actions for lines older than 24 h
// relative to "now": pin both so the appended entries are always fresh.
tracker.UtcNowProvider = () => Now;
return tracker;
}
public void Append(params string[] messages) => AppendAt(Now.AddSeconds(-60), messages);
/// <summary>Entries one second apart from <paramref name="firstUtc"/> (an older instant replays a previous enrollment).</summary>
public void AppendAt(DateTime firstUtc, params string[] messages)
{
var lines = messages.Select((m, i) => Entry(m, firstUtc.AddSeconds(i)));
File.AppendAllText(Path.Combine(_tmp.Path, "IntuneManagementExtension.log"),
string.Join(Environment.NewLine, lines) + Environment.NewLine);
}
public Task Pass() => Tracker.CheckLogFilesAsync(CancellationToken.None);
public void Dispose()
{
Tracker.Dispose();
_tmp.Dispose();
}
private static string Entry(string message, DateTime utcInstant)
{
// CMTrace line with a zero writer offset: the tracker reads the local time and
// resolves it against the reader zone; only freshness (< 24 h) matters here.
return $"<![LOG[{message}]LOG]!><time=\"{utcInstant:HH:mm:ss.fffffff}\" date=\"{utcInstant:M-d-yyyy}\" " +
"component=\"IntuneManagementExtension\" context=\"\" type=\"1\" thread=\"1\" file=\"\">";
}
}
}
@@ -125,5 +125,74 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Logging
// No assertion needed beyond "did not throw"; the regression we guard against is
// the original swallow-all behaviour, which the rotation refactor must preserve.
}
[Theory]
[InlineData(AgentLogLevel.Info, "INFO")]
[InlineData(AgentLogLevel.Debug, "INFO,DEBUG")]
[InlineData(AgentLogLevel.Verbose, "INFO,DEBUG,VERBOSE")]
[InlineData(AgentLogLevel.Trace, "INFO,DEBUG,VERBOSE,TRACE")]
public void Each_level_adds_to_the_one_before_it(AgentLogLevel level, string expectedTags)
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, level);
logger.Info("line");
logger.Debug("line");
logger.Verbose("line");
logger.Trace("line");
var tags = ReadLines(tmp.Path).Select(Tag);
Assert.Equal(expectedTags, string.Join(",", tags));
}
[Fact]
public void RepeatKey_sends_an_identical_repeat_to_trace_and_a_change_back_to_its_level()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Trace);
logger.Info("rule A ran", repeatKey: "rule:A");
logger.Info("rule A ran", repeatKey: "rule:A");
logger.Info("rule A ran again with new data", repeatKey: "rule:A");
logger.Info("rule A ran", repeatKey: "rule:A");
Assert.Equal(new[] { "INFO", "TRACE", "INFO", "INFO" }, ReadLines(tmp.Path).Select(Tag).ToArray());
}
[Fact]
public void RepeatKey_keeps_subjects_apart()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Trace);
logger.Debug("scan failed: access denied", repeatKey: "scan:System");
logger.Debug("scan failed: access denied", repeatKey: "scan:Application");
logger.Debug("scan failed: access denied", repeatKey: "scan:System");
Assert.Equal(new[] { "DEBUG", "DEBUG", "TRACE" }, ReadLines(tmp.Path).Select(Tag).ToArray());
}
[Fact]
public void RepeatKey_does_not_remember_a_line_its_level_did_not_write()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
logger.Debug("waiting for the policy", repeatKey: "hello.poll");
logger.SetLogLevel(AgentLogLevel.Debug);
logger.Debug("waiting for the policy", repeatKey: "hello.poll");
Assert.Equal(new[] { "DEBUG" }, ReadLines(tmp.Path).Select(Tag).ToArray());
}
private static string[] ReadLines(string dir) =>
File.ReadAllLines(Path.Combine(dir, BaseName + ".log"));
// "[2026-10-30 12:00:00.000] [INFO] message" -> "INFO"
private static string Tag(string line)
{
var open = line.IndexOf("] [", StringComparison.Ordinal) + 3;
return line.Substring(open, line.IndexOf(']', open) - open);
}
}
}
@@ -164,5 +164,36 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring
var info = f.InfoEvent("hello_pin_status");
Assert.Equal("false", info.Payload![SignalPayloadKeys.ImmediateUpload]);
}
[Fact]
public void A_throwing_HelloCompleted_handler_is_logged_and_the_completion_stands()
{
// The handler carries the Hello resolution to the decision engine; a fault there used
// to vanish without a trace.
using var f = new Fixture();
f.Tracker.HelloCompleted += (_, _) => throw new InvalidOperationException("handler bug");
f.Tracker.ProcessHelloEvent(300, Fixed, "Microsoft-Windows-User Device Registration", isBackfill: false);
Assert.True(f.Tracker.IsHelloCompleted);
f.InfoEvent("hello_provisioning_completed");
Assert.Contains("[WARN] HelloTracker: HelloCompleted handler threw: handler bug", ReadLog(f));
}
[Fact]
public void A_repeated_terminal_event_logs_COMPLETED_once()
{
// Live plus backfill deliver event 300 twice; only the first one completes Hello.
using var f = new Fixture();
f.Tracker.ProcessHelloEvent(300, Fixed, "Microsoft-Windows-User Device Registration", isBackfill: false);
f.Tracker.ProcessHelloEvent(300, Fixed, "Microsoft-Windows-User Device Registration", isBackfill: true);
var log = ReadLog(f);
Assert.Single(log.Split('\n'), l => l.Contains("Windows Hello provisioning COMPLETED successfully"));
}
private static string ReadLog(Fixture f) =>
System.IO.File.ReadAllText(System.IO.Path.Combine(f.Tmp.Path, "agent.log"));
}
}
@@ -270,6 +270,24 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
new[] { "id=" + Guid1, "to=InProgress" }
};
yield return new object[]
{
"IME-ERROR-REPORT",
"[Win32App][ReportingManager] Execution state for app with id: " + Guid1 + " has been updated. Report delta: {\"EnforcementState\":{\"OldValue\":\"Success\",\"NewValue\":\"Error\"},\"EnforcementErrorCode\":{\"OldValue\":null,\"NewValue\":-2016345060}}",
new[] { "id=" + Guid1, "from=Success", "to=Error", "errorCode=-2016345060" }
};
yield return new object[]
{
"IME-POST-INSTALL-DETECTION",
"[Win32App][DetectionActionHandler] Policy with id: " + Guid1 + " is expected to have enforcement state: Detected.",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-POST-REBOOT-DETECTION",
"[Win32App][ReportingManager] Execution state for app with id: " + Guid1 + " has been updated. Report delta: {\"EnforcementState\":{\"OldValue\":\"InProgressPendingReboot\",\"NewValue\":\"Success\"}}",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-TOKEN-FAILURE",
"Failed to get AAD token. len = 34 using client id fc0f3af4-6835-4174-b806-f7db311fd2f3 and resource id 26a4ae64-5862-427f-a9b0-044e62572a4f, errorCode = 3399548929",
@@ -0,0 +1,229 @@
#nullable enable
using System.Collections.Generic;
using System.Linq;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
/// <summary>
/// IME's sequence per app, driven through the shipped pattern pack: the check before the
/// install, the installer, "Execution state … Success", the check right after the install,
/// and the final state (D-392).
/// <list type="bullet">
/// <item>When the check after the install does not find the app, IME flips Success → Error
/// with EnforcementErrorCode -2016345060 (0x87D1041C) BEFORE it logs the check's
/// result line; that code is IME's verdict and must reach the error transition.</item>
/// <item>The check after the install is marked ("expected to have enforcement state:
/// Detected"); its result is reported through OnPostInstallDetection, and
/// detectionResult stays the check before the install.</item>
/// <item>After an exit code that asked for a restart, that check decides nothing; the check
/// after the restart (InProgressPendingReboot → Success) is the one reported.</item>
/// </list>
/// </summary>
public sealed class ImeLogTrackerDetectionAfterInstallTests
{
private const string AppId = "5c95bf94-1cf4-4629-88d1-3f616e7a405c";
private const string DependencyId = "9d2b8a71-4e0c-4f5a-a3c6-71b0e2d5c8f4";
private static string PhaseLine => "[Win32App] In EspPhase: DeviceSetup.";
private static string CurrentAppLine => @"[Win32App] SetCurrentDirectory: C:\Windows\IMECache\" + AppId + "_1";
private static string DetectionResult(string state, string appId = AppId)
=> "[Win32App][DetectionActionHandler] Detection for policy with id: " + appId +
" resulted in action status: Success and detection state: " + state + ".";
private static string[] CheckAfterInstallMarkers() => new[]
{
"[Win32App][DetectionActionHandler] Detection running for policy with id: " + AppId + ".",
"[Win32App][DetectionActionHandler] The last enforcement action was on policy with id: " + AppId + ".",
"[Win32App][DetectionActionHandler] Policy with id: " + AppId + " is expected to have enforcement state: Detected.",
};
private static string ExecutionDelta(string from, string to, string? errorCode = null)
=> "[Win32App][ReportingManager] Execution state for app with id: " + AppId + " has been updated. Report delta: " +
"{\"EnforcementState\":{\"OldValue\":\"" + from + "\",\"NewValue\":\"" + to + "\"}" +
(errorCode == null ? "" : ",\"EnforcementErrorCode\":{\"OldValue\":null,\"NewValue\":" + errorCode + "}") + "}";
private sealed class Run
{
public ShippedImePackHarness Harness { get; } = new ShippedImePackHarness();
public AppPackageState Package { get; } = new AppPackageState(AppId, 0);
public List<(AppInstallationState To, string? Code)> Transitions { get; } = new List<(AppInstallationState, string?)>();
public List<(string Detection, bool AfterReboot)> ChecksAfterInstall { get; } = new List<(string, bool)>();
public Run()
{
Package.UpdateState(AppInstallationState.Installing);
Harness.Tracker.PackageStates.Add(Package);
Harness.Tracker.OnAppStateChanged = (p, _, to) => { if (p.Id == AppId) Transitions.Add((to, p.ErrorCode)); };
Harness.Tracker.OnPostInstallDetection = (p, detection, afterReboot, _) => ChecksAfterInstall.Add((detection, afterReboot));
}
public void Lines(params string[] lines) => Harness.Append(lines);
}
private static string[] CleanInstallThen(params string[] tail)
{
var lines = new List<string>
{
PhaseLine,
DetectionResult("NotDetected"), // the check before the install
ExecutionDelta("InProgress", "Success"), // IME holds this back until its check
};
lines.AddRange(CheckAfterInstallMarkers());
lines.AddRange(tail);
return lines.ToArray();
}
[Fact]
public async Task Check_after_install_failing_carries_IMEs_code_on_the_error_transition()
{
var run = new Run();
using (run.Harness)
{
run.Lines(CleanInstallThen(
ExecutionDelta("Success", "Error", "-2016345060"),
DetectionResult("NotDetected"))); // the check's own result line comes last
await run.Harness.Pass();
Assert.Equal(new[] { AppInstallationState.Installed, AppInstallationState.Error }, run.Transitions.Select(t => t.To));
Assert.Equal("-2016345060", run.Transitions.Last().Code);
Assert.Equal(AppInstallationState.Error, run.Package.InstallationState);
Assert.Equal("IME-ERROR-REPORT", run.Package.ErrorPatternId);
Assert.Equal(new[] { ("NotDetected", false) }, run.ChecksAfterInstall);
Assert.Equal("NotDetected", run.Package.DetectionResult);
}
}
[Fact]
public async Task Check_after_a_clean_install_is_reported_and_detectionResult_stays_the_check_before()
{
var run = new Run();
using (run.Harness)
{
run.Lines(CleanInstallThen(DetectionResult("Detected")));
await run.Harness.Pass();
Assert.Equal(new[] { ("Detected", false) }, run.ChecksAfterInstall);
Assert.Equal("NotDetected", run.Package.DetectionResult);
Assert.Equal(AppInstallationState.Installed, run.Package.InstallationState);
}
}
[Fact]
public async Task A_different_version_found_after_the_install_is_reported_as_such()
{
var run = new Run();
using (run.Harness)
{
run.Lines(CleanInstallThen(DetectionResult("DetectedDifferentVersion")));
await run.Harness.Pass();
Assert.Equal(new[] { ("DetectedDifferentVersion", false) }, run.ChecksAfterInstall);
}
}
[Fact]
public async Task A_dependency_checked_in_the_same_run_is_no_check_after_its_install()
{
// IME checks every app of the dependency chain in the run after an install; only the
// installed app carries the markers.
var run = new Run();
using (run.Harness)
{
var dependency = new AppPackageState(DependencyId, 1);
run.Harness.Tracker.PackageStates.Add(dependency);
run.Lines(CleanInstallThen(
DetectionResult("Detected", DependencyId),
DetectionResult("Detected")));
await run.Harness.Pass();
Assert.Equal(new[] { ("Detected", false) }, run.ChecksAfterInstall);
Assert.Equal("Detected", dependency.DetectionResult);
}
}
[Fact]
public async Task The_check_before_a_requested_restart_is_not_reported_the_one_after_it_is()
{
var run = new Run();
using (run.Harness)
{
var beforeRestart = new List<string>
{
PhaseLine,
CurrentAppLine,
"[Win32App] lpExitCode 3010",
"[Win32App] lpExitCode is defined as SoftReboot",
ExecutionDelta("InProgress", "InProgressPendingReboot"),
};
beforeRestart.AddRange(CheckAfterInstallMarkers());
beforeRestart.Add(DetectionResult("NotDetected")); // provisional: IME sets no error
run.Lines(beforeRestart.ToArray());
await run.Harness.Pass();
Assert.Empty(run.ChecksAfterInstall);
run.Lines(
ExecutionDelta("InProgressPendingReboot", "Success"), // after the restart
DetectionResult("Detected"));
await run.Harness.Pass();
Assert.Equal(new[] { ("Detected", true) }, run.ChecksAfterInstall);
}
}
[Fact]
public async Task Lines_from_a_previous_enrollment_mark_nothing()
{
var run = new Run();
using (run.Harness)
{
run.Harness.AppendAt(run.Harness.Now.AddDays(-2), CleanInstallThen(DetectionResult("Detected")));
await run.Harness.Pass();
Assert.Empty(run.ChecksAfterInstall);
Assert.Null(run.Package.DetectionResult);
}
}
[Fact]
public async Task Other_IME_error_reports_carry_their_code_too()
{
// A download that fails is the app's first move to Error through the same line.
var run = new Run();
using (run.Harness)
{
run.Lines(PhaseLine, ExecutionDelta("InProgressDownloadCompleted", "Error", "-2145091577"));
await run.Harness.Pass();
Assert.Equal(AppInstallationState.Error, Assert.Single(run.Transitions).To);
Assert.Equal("-2145091577", run.Package.ErrorCode);
}
}
[Fact]
public async Task Error_report_without_a_code_leaves_the_code_empty()
{
var run = new Run();
using (run.Harness)
{
run.Lines(PhaseLine, ExecutionDelta("InProgress", "Error"));
await run.Harness.Pass();
Assert.Equal(AppInstallationState.Error, run.Package.InstallationState);
Assert.True(string.IsNullOrEmpty(run.Package.ErrorCode));
}
}
}
}
@@ -1,15 +1,10 @@
#nullable enable
using System;
using System.Collections.Generic;
using System.IO;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
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 Newtonsoft.Json;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
@@ -70,82 +65,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
// ---------------------------------------------------------------- shipped pack, end to end
private static string FindRulesPatternDir()
{
var dir = new DirectoryInfo(AppContext.BaseDirectory);
while (dir != null)
{
var candidate = Path.Combine(dir.FullName, "rules", "ime-log-patterns");
if (Directory.Exists(candidate)) return candidate;
dir = dir.Parent;
}
throw new DirectoryNotFoundException($"Could not locate rules/ime-log-patterns walking up from {AppContext.BaseDirectory}");
}
/// <summary>The shipped pack, exactly as combine.js embeds it (sorted by file name).</summary>
private static List<ImeLogPattern> ShippedPack()
=> Directory.GetFiles(FindRulesPatternDir(), "*.json")
.OrderBy(f => f, StringComparer.Ordinal)
.Select(f => JsonConvert.DeserializeObject<ImeLogPattern>(File.ReadAllText(f))!)
.ToList();
private static string Entry(string message, DateTime utcInstant)
{
// CMTrace line with a zero writer offset: the tracker reads the local time and
// resolves it against the reader zone; only freshness (< 24 h) matters here.
return $"<![LOG[{message}]LOG]!><time=\"{utcInstant:HH:mm:ss.fffffff}\" date=\"{utcInstant:M-d-yyyy}\" " +
"component=\"IntuneManagementExtension\" context=\"\" type=\"1\" thread=\"1\" file=\"\">";
}
private sealed class Harness : IDisposable
{
private readonly TempDirectory _tmp = new TempDirectory();
public ImeLogTracker Tracker { get; }
public string StateDir { get; }
public DateTime Now { get; } = new DateTime(2026, 9, 6, 12, 0, 0, DateTimeKind.Utc);
public Harness()
{
StateDir = Path.Combine(_tmp.Path, "State");
Tracker = Build();
}
public ImeLogTracker Build()
{
var tracker = new ImeLogTracker(
logFolder: _tmp.Path,
patterns: ShippedPack(),
logger: new AgentLogger(_tmp.Path, AgentLogLevel.Info),
stateDirectory: StateDir);
// The historic-replay guard skips app-mutating actions for lines older than 24 h
// relative to "now": pin both so the CMTrace entries below are always fresh.
tracker.UtcNowProvider = () => Now;
return tracker;
}
public void Append(params string[] messages)
{
var lines = messages.Select((m, i) => Entry(m, Now.AddSeconds(-60 + i)));
File.AppendAllText(Path.Combine(_tmp.Path, "IntuneManagementExtension.log"),
string.Join(Environment.NewLine, lines) + Environment.NewLine);
}
public Task Pass() => Tracker.CheckLogFilesAsync(CancellationToken.None);
public void Dispose()
{
Tracker.Dispose();
_tmp.Dispose();
}
}
private static string PhaseLine => "[Win32App] In EspPhase: DeviceSetup.";
private static string CurrentAppLine => @"[Win32App] SetCurrentDirectory: C:\Windows\IMECache\" + AppId + "_1";
[Fact]
public async Task Shipped_pattern_captures_the_class_for_the_current_app()
{
using var h = new Harness();
using var h = new ShippedImePackHarness();
h.Tracker.PackageStates.Add(new AppPackageState(AppId, 0));
h.Append(
PhaseLine, // activates the currentPhase pack (IME-EXITCODE, IME-EXITCODE-CLASS)
@@ -165,7 +91,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
[Fact]
public async Task Retry_loop_that_ends_in_success_reports_the_last_class()
{
using var h = new Harness();
using var h = new ShippedImePackHarness();
h.Tracker.PackageStates.Add(new AppPackageState(AppId, 0));
h.Append(
PhaseLine, CurrentAppLine,
@@ -188,7 +114,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
// IME-EXITCODE-CLASS and IME-EXITCODE-MAPPED-FAILED both match the Failed line: the
// class is captured and the existing error path stays intact.
using var h = new Harness();
using var h = new ShippedImePackHarness();
var pkg = new AppPackageState(AppId, 0);
pkg.UpdateState(AppInstallationState.Installing);
h.Tracker.PackageStates.Add(pkg);
@@ -207,7 +133,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
[Fact]
public async Task Default_branch_and_raw_numeric_types_leave_the_class_unset()
{
using var h = new Harness();
using var h = new ShippedImePackHarness();
h.Tracker.PackageStates.Add(new AppPackageState(AppId, 0));
h.Append(
PhaseLine, CurrentAppLine,
@@ -228,7 +154,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
// A SoftReboot/HardReboot app completes only after the reboot; the restarted agent
// must still know the class when the post-reboot Success line arrives.
using var h = new Harness();
using var h = new ShippedImePackHarness();
h.Tracker.PackageStates.Add(new AppPackageState(AppId, 0));
h.Append(
PhaseLine, CurrentAppLine,
@@ -0,0 +1,175 @@
#nullable enable
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Persistence;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.DecisionCore.Signals;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
{
/// <summary>The V1 confidence score of <see cref="ConfigMgrClientSnapshot"/>.</summary>
public sealed class ConfigMgrClientScoreTests
{
[Fact]
public void Nothing_found_scores_zero_and_is_not_detected()
{
Assert.Equal(0, ConfigMgrClientSnapshot.Empty.ConfidenceScore);
Assert.False(ConfigMgrClientSnapshot.Empty.Detected);
}
[Fact]
public void A_registered_running_client_scores_100()
{
var snapshot = new ConfigMgrClientSnapshot(true, true, "Running", "5.00.9999.1000", "ABC");
Assert.Equal(100, snapshot.ConfidenceScore);
}
[Fact]
public void The_folder_alone_is_a_weak_remnant_below_the_portal_threshold()
{
var snapshot = new ConfigMgrClientSnapshot(false, true, ConfigMgrClientProbe.ServiceNotFound, null, null);
Assert.True(snapshot.Detected);
Assert.Equal(10, snapshot.ConfidenceScore);
}
[Fact]
public void A_stopped_service_counts_without_the_running_bonus()
{
var snapshot = new ConfigMgrClientSnapshot(true, true, "Stopped", "5.00.9999.1000", "ABC");
Assert.Equal(80, snapshot.ConfidenceScore);
}
}
/// <summary>
/// Emission surface of <see cref="ConfigMgrClientDetector"/> via the real
/// <see cref="InformationalEventPost"/>. Static probe override → serial collection.
/// </summary>
[Collection("SerialThreading")]
public sealed class ConfigMgrClientDetectorEmissionTests : IDisposable
{
private static readonly DateTime At = new DateTime(2026, 10, 23, 8, 0, 0, DateTimeKind.Utc);
private readonly TempDirectory _tmp = new TempDirectory();
public void Dispose() => _tmp.Dispose();
private (ConfigMgrClientDetector sut, FakeSignalIngressSink sink) BuildDetector(StartupEventGate? gate = null)
{
var logger = new AgentLogger(_tmp.Path, AgentLogLevel.Info);
var sink = new FakeSignalIngressSink();
var clock = new VirtualClock(At);
var sut = new ConfigMgrClientDetector("S1", "T1", new InformationalEventPost(sink, clock), logger, clock, gate);
return (sut, sink);
}
private static IReadOnlyList<FakeSignalIngressSink.PostedSignal> Detected(FakeSignalIngressSink sink) =>
sink.Posted.Where(p =>
p.Payload != null
&& p.Payload.TryGetValue(SignalPayloadKeys.EventType, out var et)
&& et == "configmgr_client_detected").ToList();
private static ConfigMgrClientSnapshot Client(string serviceState, string? siteCode = "ABC") =>
new ConfigMgrClientSnapshot(true, true, serviceState, "5.00.9999.1000", siteCode);
[Fact]
public void No_client_never_emits()
{
using var _probe = new ConfigMgrClientProbe.ScopedOverride(() => ConfigMgrClientSnapshot.Empty);
var (sut, sink) = BuildDetector();
sut.Check();
sut.Check();
Assert.Empty(Detected(sink));
}
[Fact]
public void First_detection_emits_the_v1_payload()
{
using var _probe = new ConfigMgrClientProbe.ScopedOverride(() => Client("Running"));
var (sut, sink) = BuildDetector();
sut.Check();
var evt = Assert.Single(Detected(sink));
Assert.Equal(DecisionSignalKind.InformationalEvent, evt.Kind);
Assert.Equal("Info", evt.Payload![SignalPayloadKeys.Severity]);
Assert.Equal(ConfigMgrClientDetector.SourceLabel, evt.Payload[SignalPayloadKeys.Source]);
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(evt.TypedPayload);
Assert.Equal(true, data["ccmRegistryFound"]);
Assert.Equal(true, data["ccmDirectoryFound"]);
Assert.Equal("Running", data["ccmServiceState"]);
Assert.Equal("5.00.9999.1000", data["ccmVersion"]);
Assert.Equal("ABC", data["siteCode"]);
Assert.Equal(100, data["confidenceScore"]);
Assert.Equal("startup", data["detectedAt"]);
}
[Fact]
public void An_unchanged_state_emits_once_a_changed_state_again()
{
var current = Client("Stopped", siteCode: null);
using var _probe = new ConfigMgrClientProbe.ScopedOverride(() => current);
var (sut, sink) = BuildDetector();
sut.Check();
sut.Check();
Assert.Single(Detected(sink));
current = Client("Running");
sut.Check();
var events = Detected(sink);
Assert.Equal(2, events.Count);
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(events[0].TypedPayload);
Assert.Equal("unknown", data["siteCode"]); // missing values keep the V1 placeholder
var latest = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(events[1].TypedPayload);
Assert.Equal("Running", latest["ccmServiceState"]);
Assert.Equal("poll", latest["detectedAt"]);
}
[Fact]
public void A_restart_into_the_same_state_stays_silent()
{
var logger = new AgentLogger(_tmp.Path, AgentLogLevel.Info);
var current = Client("Running");
using var _probe = new ConfigMgrClientProbe.ScopedOverride(() => current);
var (run1, sink1) = BuildDetector(new StartupEventGate(_tmp.Path, logger));
run1.Check();
Assert.Single(Detected(sink1));
var (run2, sink2) = BuildDetector(new StartupEventGate(_tmp.Path, logger));
run2.Check();
Assert.Empty(Detected(sink2));
current = Client("Stopped");
run2.Check();
Assert.Single(Detected(sink2));
}
[Fact]
public void Emissions_are_capped_per_run()
{
var running = true;
using var _probe = new ConfigMgrClientProbe.ScopedOverride(() => Client(running ? "Running" : "Stopped"));
var (sut, sink) = BuildDetector();
for (var i = 0; i < ConfigMgrClientDetector.MaxEmissionsPerRun * 2; i++)
{
sut.Check();
running = !running;
}
Assert.Equal(ConfigMgrClientDetector.MaxEmissionsPerRun, Detected(sink).Count);
}
}
}
@@ -185,6 +185,46 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
Assert.False(EspPolicyProviderSnapshot.Empty.SidecarRegistered);
}
// ------------------------------------------------- phase gate for DevicePreparation providers
[Theory]
[InlineData("device_preparation", true)]
[InlineData("device_preparation_failed", true)] // a failed device preparation keeps its culprit
[InlineData("none", true)] // unknown phase → keep observing
[InlineData("unavailable", true)]
[InlineData("", true)]
[InlineData("device_preparation_done", false)]
[InlineData("device_setup", false)]
[InlineData("device_setup_failed", false)]
[InlineData("account_setup", false)]
[InlineData("esp_done", false)]
public void Device_preparation_counts_until_it_is_done(string phase, bool expected)
=> Assert.Equal(expected, EspPhaseSnapshot.DevicePreparationOpen(phase));
[Fact]
public void DevicePreparation_provider_past_its_phase_drops_out_while_setupApps_still_counts()
{
// Field shape (client installed as a Win32 app): the client registers its
// DevicePreparation provider after its own install with InstallationState=1, long
// after device preparation ended. Nothing ever completes it.
var snapshot = Snapshot(
DevicePrep("ConfigMgr", installState: 1),
SetupApps("Contoso", tracking: 0));
var seen = new Dictionary<string, DateTime>
{
["devicePreparation|device|ConfigMgr"] = T0,
["setupApps|device|Contoso"] = T0,
};
var eval = EspPolicyProviderStallDetector.EvaluateStallTransition(
snapshot, seen, new HashSet<string>(), null, false, T0.AddMinutes(30), Dwell,
devicePreparationOpen: false);
Assert.False(eval.UpdatedFirstSeenUtc.ContainsKey("devicePreparation|device|ConfigMgr")); // reset
var stalled = Assert.Single(eval.NewlyStalled);
Assert.Equal("Contoso", stalled.Provider.Name);
}
// ------------------------------------------------- arm 2: sidecar-missing transition
[Fact]
@@ -265,17 +305,27 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
public void Dispose() => _tmp.Dispose();
// The phase defaults to "none" so the tests never read the test machine's own ESP state.
private (EspPolicyProviderStallDetector sut, FakeSignalIngressSink sink, VirtualClock clock)
BuildDetector(StartupEventGate? gate = null)
BuildDetector(StartupEventGate? gate = null, Func<string>? phase = null)
{
var logger = new AgentLogger(_tmp.Path, AgentLogLevel.Info);
var sink = new FakeSignalIngressSink();
var clock = new VirtualClock(At);
var post = new InformationalEventPost(sink, clock);
var sut = new EspPolicyProviderStallDetector("S1", "T1", post, logger, clock, gate);
var sut = new EspPolicyProviderStallDetector("S1", "T1", post, logger, clock, gate,
espPhaseReader: phase ?? (() => EspPhaseSnapshot.None));
return (sut, sink, clock);
}
private static readonly TimeSpan DwellSpan = TimeSpan.FromMinutes(EspPolicyProviderStallDetector.DwellMinutes);
private static PolicyProviderState SidecarDone() =>
new PolicyProviderState("Sidecar", "device", EspPolicyProviderProbe.KindSetupApps, 1, null);
private static PolicyProviderState ConfigMgrDevicePrep(int? installationState) =>
new PolicyProviderState("ConfigMgr", "device", EspPolicyProviderProbe.KindDevicePreparation, null, installationState);
private static EspPolicyProviderSnapshot ConfigMgrOnly() => new EspPolicyProviderSnapshot(new[]
{
new PolicyProviderState("ConfigMgr", "device", EspPolicyProviderProbe.KindSetupApps,
@@ -435,6 +485,104 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
}
}
[Fact]
public void Provider_registered_after_device_preparation_never_emits()
{
// The ConfigMgr client as a Win32 app: its DevicePreparation provider shows up during
// device setup with InstallationState=1 and stays there.
var snapshot = new EspPolicyProviderSnapshot(new[] { SidecarDone(), ConfigMgrDevicePrep(1) });
using var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => snapshot);
var (sut, sink, clock) = BuildDetector(phase: () => "device_setup");
sut.Tick();
clock.Advance(TimeSpan.FromHours(2));
sut.Tick();
Assert.Empty(StalledEvents(sink));
}
[Fact]
public void A_real_device_preparation_hang_still_emits()
{
// Field shape: only ConfigMgr providers registered, the ESP never left device
// preparation and failed with 0x800705b4.
var snapshot = new EspPolicyProviderSnapshot(new[]
{
new PolicyProviderState("ConfigMgr", "device", EspPolicyProviderProbe.KindSetupApps, null, null),
ConfigMgrDevicePrep(1),
});
using var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => snapshot);
var (sut, sink, clock) = BuildDetector(phase: () => EspPhaseSnapshot.DevicePreparation);
sut.Tick();
clock.Advance(DwellSpan);
sut.Tick();
var evt = Assert.Single(StalledEvents(sink));
var data = Assert.IsAssignableFrom<IReadOnlyDictionary<string, object>>(evt.TypedPayload);
var stalled = Assert.IsAssignableFrom<IReadOnlyList<Dictionary<string, object>>>(data["stalledProviders"]);
Assert.Contains(stalled, s => (string)s["kind"] == EspPolicyProviderProbe.KindDevicePreparation);
}
[Fact]
public void Device_preparation_stall_message_names_the_provider_timeout()
{
var snapshot = new EspPolicyProviderSnapshot(new[] { SidecarDone(), ConfigMgrDevicePrep(1) });
using var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => snapshot);
var (sut, sink, clock) = BuildDetector(phase: () => EspPhaseSnapshot.DevicePreparation);
sut.Tick();
clock.Advance(DwellSpan);
sut.Tick();
var message = Assert.Single(StalledEvents(sink)).Payload![SignalPayloadKeys.Message];
Assert.Contains("until their timeout", message);
Assert.DoesNotContain("without any timeout", message);
}
[Fact]
public void Fingerprint_skips_device_preparation_providers_past_their_phase()
{
var logger = new AgentLogger(_tmp.Path, AgentLogLevel.Info);
var phase = EspPhaseSnapshot.DevicePreparation;
var devicePrepOnly = new EspPolicyProviderSnapshot(new[] { SidecarDone(), ConfigMgrDevicePrep(1) });
var withContoso = new EspPolicyProviderSnapshot(new[]
{
SidecarDone(),
ConfigMgrDevicePrep(1),
new PolicyProviderState("Contoso", "device", EspPolicyProviderProbe.KindSetupApps, 0, null),
});
var current = devicePrepOnly;
// Run 1: the DevicePreparation provider stalls during device preparation; later, in
// device setup, a Setup/Apps provider stalls as well.
using (var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => current))
{
var (sut, sink, clock) = BuildDetector(new StartupEventGate(_tmp.Path, logger), () => phase);
sut.Tick();
clock.Advance(DwellSpan);
sut.Tick();
phase = "device_setup";
current = withContoso;
sut.Tick();
clock.Advance(DwellSpan);
sut.Tick();
Assert.Equal(2, StalledEvents(sink).Count);
}
// Run 2 (restart in device setup): the same Contoso stall lands on the same
// fingerprint only if the stale DevicePreparation provider stayed out of it.
using (var _probe = new EspPolicyProviderProbe.ScopedOverride(_ => withContoso))
{
var (sut, sink, clock) = BuildDetector(new StartupEventGate(_tmp.Path, logger), () => "device_setup");
sut.Tick();
clock.Advance(DwellSpan);
sut.Tick();
Assert.Empty(StalledEvents(sink));
}
}
[Fact]
public void Healthy_or_absent_tracking_never_emits()
{
@@ -1,5 +1,6 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
@@ -304,6 +305,64 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
Assert.Same(step.NewState, sut.CurrentState);
}
// ========================================================================= Step log levels
[Fact]
public void ApplyStep_logs_a_stage_change_at_info()
{
using var rig = new Rig();
rig.Logger.SetLogLevel(AgentLogLevel.Trace);
var sut = rig.Build();
var (step, signal) = rig.ReduceAbort(); // SessionStarted -> Failed
sut.ApplyStep(step, signal);
Assert.Contains(StepLines(rig), l => l.Contains("[INFO] DecisionStep:") && l.Contains("stage=SessionStarted->Failed"));
}
[Fact]
public void ApplyStep_logs_informational_pass_through_and_no_op_at_trace()
{
using var rig = new Rig();
rig.Logger.SetLogLevel(AgentLogLevel.Trace);
var sut = rig.Build();
var (noOp, noOpSignal) = rig.ReduceSessionStarted(ordinal: 0);
sut.ApplyStep(noOp, noOpSignal);
var (info, infoSignal) = rig.ReduceInformational(sut, ordinal: 1);
sut.ApplyStep(info, infoSignal);
var lines = StepLines(rig);
Assert.Equal(2, lines.Length);
Assert.All(lines, l => Assert.Contains("[TRACE] DecisionStep:", l));
Assert.Contains("(no-op)", lines[0]);
Assert.Contains("kind=InformationalEvent", lines[1]);
}
[Fact]
public void ApplyStep_logs_informational_pass_through_with_failed_effect_at_debug()
{
using var rig = new Rig();
rig.Logger.SetLogLevel(AgentLogLevel.Trace);
rig.Effects.ScriptResult(new EffectRunResult(
sessionMustAbort: false,
abortReason: null,
failures: new[] { new EffectFailure(DecisionEffectKind.EmitEventTimelineEntry, "emit failed", isTransient: false, exhaustedRetries: true) },
classifierInvocations: 0,
classifierSkippedByAntiLoop: 0));
var sut = rig.Build();
var (step, signal) = rig.ReduceInformational(sut, ordinal: 0);
sut.ApplyStep(step, signal);
Assert.Contains(StepLines(rig), l => l.Contains("[DEBUG] DecisionStep:") && l.Contains("failures=1"));
}
private static string[] StepLines(Rig rig) =>
System.IO.File.ReadAllLines(System.IO.Path.Combine(rig.Tmp.Path, "agent.log"))
.Where(l => l.Contains("DecisionStep:"))
.ToArray();
// ========================================================================= Argument validation
[Fact]
@@ -40,7 +40,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
/// enabled by default) and system-boundary fakes only: temp state dir, fake ingress,
/// virtual clock, no network metrics, no telemetry spool.
/// </summary>
private CollectorSurfaces CreateSurfaces()
private CollectorSurfaces CreateSurfaces(AnalyzerConfiguration? analyzers = null)
{
var factory = new DefaultComponentFactory(
agentConfig: new AgentConfiguration
@@ -52,6 +52,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
remoteConfig: new AgentConfigResponse
{
Collectors = CollectorConfiguration.CreateDefault(),
Analyzers = analyzers ?? new AnalyzerConfiguration(),
},
networkMetrics: null,
agentVersion: "test",
@@ -142,6 +143,26 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
}
}
[Theory]
[InlineData(false, 0)]
[InlineData(true, 1)]
public void ConfigMgr_client_host_exists_only_when_the_tenant_enables_the_watcher(bool enabled, int expected)
{
// Opt-in (D-382): with the watcher off the check must not run at all, not merely stay quiet.
var hosts = CreateSurfaces(new AnalyzerConfiguration { EnableConfigMgrWatcher = enabled }).Hosts;
try
{
Assert.Equal(expected, hosts.Count(h => h is ConfigMgrClientHost));
}
finally
{
foreach (var host in hosts)
{
try { host.Dispose(); } catch { /* construction-only test — best-effort cleanup */ }
}
}
}
[Fact]
public void Ime_app_state_callback_is_chained_into_the_user_apps_settled_recheck()
{
@@ -0,0 +1,45 @@
using System;
using System.IO;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Shared.Models;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
{
/// <summary>
/// <see cref="TimelineEventStream.Publish"/> isolates subscribers: a throwing one must neither
/// break the emit path nor starve the subscribers after it, and its fault must reach the log
/// (Debug once, an identical repeat on Trace).
/// </summary>
public sealed class TimelineEventStreamTests
{
[Fact]
public void A_throwing_subscriber_is_logged_and_the_next_one_still_runs()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Trace);
var sut = new TimelineEventStream(logger);
var delivered = 0;
sut.EventEmitted += ThrowingSubscriber;
sut.EventEmitted += (_, _, _) => delivered++;
sut.Publish("app_install_started", EnrollmentPhase.Unknown, "ImeLogTracker");
sut.Publish("app_install_completed", EnrollmentPhase.Unknown, "ImeLogTracker");
Assert.Equal(2, delivered);
var lines = File.ReadAllLines(Path.Combine(tmp.Path, "agent.log"))
.Where(l => l.Contains("TimelineEventStream: subscriber"))
.ToArray();
Assert.Equal(2, lines.Length);
Assert.Contains("[DEBUG]", lines[0]);
Assert.Contains("ThrowingSubscriber threw: subscriber bug", lines[0]);
Assert.Contains("[TRACE]", lines[1]);
}
private static void ThrowingSubscriber(string eventType, EnrollmentPhase phase, string source) =>
throw new InvalidOperationException("subscriber bug");
}
}
@@ -2,7 +2,9 @@ using System;
using System.Diagnostics;
using System.Threading;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Security;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using Xunit;
// xUnit1031 (no blocking Task.Wait in tests) intentionally suppressed — the API
@@ -22,9 +24,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Security
/// Drives <see cref="TenantIdAwaiter.WaitForTenantIdCore"/> through every interesting
/// path with a fake <see cref="IRegistryChangeSignal"/> + scripted probe so the
/// orchestration logic is verified without touching the registry. The public
/// <see cref="TenantIdAwaiter.WaitForTenantId"/> wrapper isn't covered here — the
/// HKCU integration test in <c>RegistryWatcherIntegrationTests</c> proves the
/// CompositeRegistryChangeSignal / RegNotifyChangeKeyValue plumbing separately.
/// <c>WaitForTenantId</c> wrapper is covered through its internal overload with a scripted
/// resolver (which probes log); the HKCU integration test in
/// <c>RegistryWatcherIntegrationTests</c> proves the CompositeRegistryChangeSignal /
/// RegNotifyChangeKeyValue plumbing separately.
/// <para>
/// Single-threaded collection: these tests use <c>Thread.Sleep</c> as a synchronisation
/// primitive (waiting for the awaiter to enter its WaitAny loop before triggering the
@@ -258,5 +261,44 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Security
logger: null!,
ct: CancellationToken.None));
}
[Fact]
public void Initial_miss_never_probes_with_the_logger()
{
// AgentBootstrap probes with its logger before it calls the awaiter; the resolver's
// miss block must not land a second time from the awaiter's own first check.
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
int loggedProbes = 0, silentProbes = 0;
var result = TenantIdAwaiter.WaitForTenantId(
timeoutSeconds: 1,
logger: logger,
ct: CancellationToken.None,
resolve: l => { if (l != null) loggedProbes++; else silentProbes++; return null!; },
signalFactory: () => new FakeSignal());
Assert.Null(result);
Assert.Equal(0, loggedProbes);
Assert.True(silentProbes >= 1, $"expected a silent first check, saw {silentProbes}");
}
[Fact]
public void Initial_hit_probes_once_more_with_the_logger_for_the_source_line()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
var loggedProbes = 0;
var result = TenantIdAwaiter.WaitForTenantId(
timeoutSeconds: 600,
logger: logger,
ct: CancellationToken.None,
resolve: l => { if (l != null) loggedProbes++; return "tenant-1"; },
signalFactory: () => throw new InvalidOperationException("no wait expected on a hit"));
Assert.Equal("tenant-1", result);
Assert.Equal(1, loggedProbes);
}
}
}
@@ -258,13 +258,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
using var f = new Fixture();
using var adapter = new AadJoinWatcherAdapter(
f.Watcher, f.Ingress, f.Clock,
onRealUserJoined: () => throw new InvalidOperationException("boom"));
onRealUserJoined: () => throw new InvalidOperationException("boom"),
logger: f.Logger);
// The signal post completes BEFORE the callback fires — even if the callback
// throws, the decision signal must already be on the bus.
adapter.TriggerFromTest("alice@contoso.com", "x");
Assert.Single(f.Ingress.Posted, p => p.Kind == DecisionSignalKind.AadUserJoinedLate);
// ...and the fault is in the log instead of vanishing.
Assert.Contains(
"[WARN] AadJoinWatcherAdapter: onRealUserJoined callback threw: boom",
System.IO.File.ReadAllText(System.IO.Path.Combine(f.Tmp.Path, "agent.log")));
}
}
}
@@ -92,6 +92,21 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
Assert.Equal(ClockNow.AddMinutes(-1), info.OccurredAtUtc);
}
[Fact]
public void Stale_post_install_detection_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-check", 0);
adapter.TriggerPostInstallDetectionFromTest(app, "Detected", afterReboot: false, ClockNow.AddDays(-7));
Assert.Empty(f.InfoEvents(SharedEventTypes.AppPostInstallDetection));
adapter.TriggerPostInstallDetectionFromTest(app, "Detected", afterReboot: false, ClockNow.AddMinutes(-1));
var info = Assert.Single(f.InfoEvents(SharedEventTypes.AppPostInstallDetection));
Assert.Equal(ClockNow.AddMinutes(-1), info.OccurredAtUtc);
}
[Fact]
public void Poll_driven_do_telemetry_stamps_clock_ignoring_unrelated_last_matched_line()
{
@@ -663,6 +663,50 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
Assert.Equal("00:01:45.159", info.Payload["doDownloadDuration"]);
}
[Fact]
public void PostInstallDetection_emits_the_check_after_the_install_as_its_own_info_event()
{
using var f = new ImeLogTrackerAdapterFixture();
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = AppPackageState.Restore(
"0e3be4ce-790b-4081-831c-d72d92f3cc9b", 0, "Contoso VPN",
AppRunAs.System, AppIntent.Install, AppTargeted.Device,
new HashSet<string>(),
AppInstallationState.Installed, true, 100, 0, 0,
exitCode: "0", exitCodeClass: "Success");
adapter.TriggerPostInstallDetectionFromTest(app, "Detected", afterReboot: false, f.Clock.UtcNow.AddSeconds(-5));
var info = Assert.Single(f.InfoEvents(SharedEventTypes.AppPostInstallDetection));
Assert.Equal("ImeLogTracker", info.Payload![SignalPayloadKeys.Source]);
Assert.Equal(EventSeverity.Info.ToString(), info.Payload[SignalPayloadKeys.Severity]);
Assert.Equal(app.Id, info.Payload["appId"]);
Assert.Equal("Contoso VPN", info.Payload["appName"]);
Assert.Equal("Detected", info.Payload["postInstallDetection"]);
Assert.Equal("false", info.Payload["afterReboot"]);
Assert.Equal("Success", info.Payload["exitCodeClass"]);
// detectionResult is the check before the install; this event never carries it.
Assert.False(info.Payload.ContainsKey("detectionResult"));
// Informational only: no app state signal.
Assert.Empty(f.DecisionSignals(DecisionSignalKind.AppInstallCompleted));
}
[Fact]
public void PostInstallDetection_not_detected_is_a_warning_and_the_check_after_a_restart_says_so()
{
using var f = new ImeLogTrackerAdapterFixture();
using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
var app = new AppPackageState("8a1c2f6e-5b7d-4e93-9c4a-0f2d6b8e1a37", 0);
adapter.TriggerPostInstallDetectionFromTest(app, "NotDetected", afterReboot: true, f.Clock.UtcNow.AddSeconds(-5));
var info = Assert.Single(f.InfoEvents(SharedEventTypes.AppPostInstallDetection));
Assert.Equal(EventSeverity.Warning.ToString(), info.Payload![SignalPayloadKeys.Severity]);
Assert.Equal("NotDetected", info.Payload["postInstallDetection"]);
Assert.Equal("true", info.Payload["afterReboot"]);
Assert.Contains("after the restart", info.Payload[SignalPayloadKeys.Message]);
}
[Fact]
public void DoTelemetry_null_app_or_empty_id_is_ignored()
{
@@ -126,6 +126,47 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Telemetry
Assert.Equal(2, collector.CollectInvocationCount);
}
[Fact]
public void Stop_then_Dispose_logs_Stopped_once()
{
// Hosts call Stop and then Dispose, which stops again; the log used to show
// "[X] Stopped" twice in the same millisecond.
using var tmp = new TempDirectory();
var collector = new BlockingCollector(NewPost(), NewLogger(tmp));
collector.Start();
collector.Stop();
collector.Dispose();
var log = File.ReadAllText(Path.Combine(tmp.Path, "logs", "agent.log"));
Assert.Equal(1, CountOccurrences(log, "[BlockingCollector] Stopped"));
}
[Fact]
public void Dispose_without_Start_logs_no_Stopped_line()
{
using var tmp = new TempDirectory();
var logger = NewLogger(tmp);
var collector = new BlockingCollector(NewPost(), logger);
logger.Info("marker"); // make sure the log file exists
collector.Dispose();
var log = File.ReadAllText(Path.Combine(tmp.Path, "logs", "agent.log"));
Assert.DoesNotContain("[BlockingCollector] Stopped", log);
}
private static int CountOccurrences(string text, string value)
{
int count = 0, index = 0;
while ((index = text.IndexOf(value, index, StringComparison.Ordinal)) >= 0)
{
count++;
index += value.Length;
}
return count;
}
/// <summary>
/// Test-only collector subclass: signals when <see cref="Collect"/> is entered and
/// blocks until the test releases it, so we can exercise the reentrancy gate
@@ -14,8 +14,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
{
/// <summary>
/// <see cref="BackendTelemetryUploader"/> emits upload-cadence log lines (flushing / ingest
/// OK / ingest TRANSIENT / ingest PERMANENT) so the transport path is observable. The
/// success-path lines (flushing, ingest OK) are pipeline mechanics and live on Debug;
/// OK / ingest TRANSIENT / ingest PERMANENT) so the transport path is observable. The send
/// ("flushing") is mechanics and lives on Trace, the success record ("ingest OK") on Verbose;
/// failures (TRANSIENT/PERMANENT/TIMEOUT/NETWORK) live on Warning/Error and remain
/// visible at the default Info level. We assert on log-file content because AgentLogger
/// writes to disk; checking the file is the most faithful production proxy.
@@ -54,11 +54,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
}
[Fact]
public async Task UploadBatch_logs_flush_start_and_ingest_OK_on_success_at_debug()
public async Task UploadBatch_logs_flush_start_at_trace_and_ingest_OK_at_verbose()
{
using var tmp = new TempDirectory();
// Success-path transport lines live on Debug; capture at that level to assert them.
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Debug);
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Trace);
var handler = new RecordingHttpMessageHandler();
handler.QueueStatus(HttpStatusCode.OK);
@@ -75,11 +74,35 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
// AgentLogger writes each line with File.AppendAllText — content is already on disk.
var logContent = ReadLogs(tmp.Path);
Assert.Contains("BackendTelemetryUploader: flushing 2 item(s)", logContent);
// Each upload now carries a per-request correlation id (X-Correlation-ID) for
// end-to-end tracing; it precedes the item count in the cadence log lines.
Assert.Contains("[TRACE] BackendTelemetryUploader: flushing 2 item(s)", logContent);
// Each upload carries a per-request correlation id (X-Correlation-ID) for end-to-end
// tracing; the success record carries the batch's item range so it stands alone.
Assert.Contains("[VERBOSE] BackendTelemetryUploader: ingest OK (corr=", logContent);
Assert.Contains("items=2, firstId=1, lastId=2, bytes=", logContent);
}
[Fact]
public async Task UploadBatch_success_at_verbose_logs_the_record_without_the_send_line()
{
using var tmp = new TempDirectory();
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Verbose);
var handler = new RecordingHttpMessageHandler();
handler.QueueStatus(HttpStatusCode.OK);
using var http = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(30) };
var sut = new BackendTelemetryUploader(
httpClient: http,
baseUrl: "https://backend.test",
tenantId: "T1",
logger: logger);
var result = await sut.UploadBatchAsync(new[] { NewEventItem(1) }, CancellationToken.None);
Assert.True(result.Success);
var logContent = ReadLogs(tmp.Path);
Assert.DoesNotContain("BackendTelemetryUploader: flushing", logContent);
Assert.Contains("BackendTelemetryUploader: ingest OK (corr=", logContent);
Assert.Contains("items=2", logContent);
}
[Fact]
@@ -3,6 +3,7 @@ using System;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Agent.V2.Core.Transport.Telemetry;
using AutopilotMonitor.Shared.Models;
@@ -33,10 +34,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
public FakeBackendTelemetryUploader Uploader { get; } = new FakeBackendTelemetryUploader();
public TelemetryUploadOrchestrator Sut { get; }
public Rig()
public Rig(AgentLogger? logger = null)
{
Spool = new TelemetrySpool(Tmp.Path, Clock);
Sut = new TelemetryUploadOrchestrator(Spool, Uploader, Clock, batchSize: 10, retryBackoffs: new[] { TimeSpan.Zero });
Sut = new TelemetryUploadOrchestrator(Spool, Uploader, Clock, batchSize: 10, retryBackoffs: new[] { TimeSpan.Zero }, logger: logger);
}
public void Dispose() { Sut.Dispose(); Tmp.Dispose(); }
@@ -140,7 +141,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
[Fact]
public async Task Handler_exception_does_not_break_drain_cursor()
{
using var rig = new Rig();
using var logTmp = new TempDirectory();
var logger = new AgentLogger(logTmp.Path, AgentLogLevel.Info);
using var rig = new Rig(logger);
rig.Sut.Enqueue(Draft());
rig.Uploader.QueueOkWithSignals(deviceKillSignal: true);
@@ -150,6 +153,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
// Upload still succeeded — the cursor moves, drain returns success.
Assert.Equal(1, drain.UploadedItems);
Assert.Equal(0, drain.FailedBatches);
// The handler fault is no longer silent.
Assert.Contains(
"[WARN] TelemetryUploadOrchestrator: ServerResponseReceived handler threw: handler bug",
System.IO.File.ReadAllText(System.IO.Path.Combine(logTmp.Path, "agent.log")));
}
/// <summary>
@@ -53,7 +53,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Configuration
/// <summary>
/// Log verbosity level: Info (default), Debug, Verbose.
/// Log verbosity level: Info (default), Debug, Verbose, Trace (see <see cref="AgentLogLevel"/>).
/// Overridable via remote config.
/// </summary>
public AgentLogLevel LogLevel { get; set; } = AgentLogLevel.Info;
@@ -151,9 +151,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Configuration
try
{
if (attempt == 1)
_logger.Info("Fetching remote configuration from backend...");
_logger.Debug("Fetching remote configuration from backend...");
else
_logger.Info($"Fetching remote configuration from backend (attempt {attempt}/{maxAttempts})...");
_logger.Debug($"Fetching remote configuration from backend (attempt {attempt}/{maxAttempts})...");
var config = await CallBackendAsync();
@@ -208,7 +208,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Configuration
if (attempt < maxAttempts)
{
var delay = InitialFetchRetryBackoff[attempt - 1];
_logger.Info($"Retrying remote config fetch in {delay.TotalSeconds:0}s...");
_logger.Debug($"Retrying remote config fetch in {delay.TotalSeconds:0}s...");
try { await DelayBetweenAttemptsAsync(delay); }
catch (TaskCanceledException) { break; }
}
@@ -1,13 +1,24 @@
using System;
using System.Collections.Concurrent;
using System.IO;
namespace AutopilotMonitor.Agent.V2.Core.Logging
{
/// <summary>
/// Log verbosity levels for the agent.
/// Info = normal operational messages (default)
/// Debug = includes DEBUG-tagged lines (component state, config, decisions)
/// Verbose = includes VERBOSE-tagged lines (per-event details, hot-path tracing)
/// Log verbosity levels for the agent. Each level adds to the one before it.
/// Info = the enrollment flow an admin follows: one line per thing that happened
/// (state change, milestone, result), repeated only when its content changed.
/// Debug = why and how: decision details, extra attributes, suppression decisions,
/// attempts in retry loops. Grows with the number of apps, scripts and phases,
/// not with elapsed time.
/// Verbose = everything known about one thing: full payloads, raw JSON, adapter mappings,
/// the record of each upload batch. Every line carries content of its own.
/// Trace = the mechanics: watcher arm/fire, poll ticks without a result, debounce,
/// per-item enqueue, per-signal pass-through. Grows with time or with the number
/// of notifications; one line alone says almost nothing.
/// An identical repeat of a line goes to Trace after its first occurrence (repeatKey).
/// A caught unexpected exception is never logged below Debug. Warning and Error are always
/// written.
/// </summary>
public enum AgentLogLevel
{
@@ -32,6 +43,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Logging
private AgentLogLevel _logLevel;
private readonly object _lockObject = new object();
// Last message written under each repeatKey; bounded because callers key by call site
// plus subject (rule, category, file, policy).
private readonly ConcurrentDictionary<string, string> _lastMessageByRepeatKey =
new ConcurrentDictionary<string, string>(StringComparer.Ordinal);
private readonly long _maxFileSizeBytes;
private readonly string _logDirectory;
private readonly string _logFileBaseName; // "agent"
@@ -122,21 +138,48 @@ namespace AutopilotMonitor.Agent.V2.Core.Logging
Log("TRACE", message);
}
public void Verbose(string message)
/// <param name="repeatKey">Names the call site and its subject. A message equal to the
/// last one written under this key goes to Trace instead.</param>
public void Verbose(string message, string repeatKey = null)
{
if (_logLevel >= AgentLogLevel.Verbose)
Log("VERBOSE", message);
if (_logLevel < AgentLogLevel.Verbose) return;
if (IsRepeat(repeatKey, message)) Trace(message);
else Log("VERBOSE", message);
}
public void Debug(string message)
/// <param name="repeatKey">Names the call site and its subject. A message equal to the
/// last one written under this key goes to Trace instead.</param>
public void Debug(string message, string repeatKey = null)
{
if (_logLevel >= AgentLogLevel.Debug)
Log("DEBUG", message);
if (_logLevel < AgentLogLevel.Debug) return;
if (IsRepeat(repeatKey, message)) Trace(message);
else Log("DEBUG", message);
}
public void Info(string message)
/// <param name="repeatKey">Names the call site and its subject. A message equal to the
/// last one written under this key goes to Trace instead.</param>
public void Info(string message, string repeatKey = null)
{
Log("INFO", message);
if (IsRepeat(repeatKey, message)) Trace(message);
else Log("INFO", message);
}
// Records the message under the key and reports whether it equals the previous one.
// Only reached once the requested level is enabled, so a line that was never written
// cannot turn its first visible occurrence into a repeat.
private bool IsRepeat(string repeatKey, string message)
{
if (repeatKey == null) return false;
var repeat = false;
_lastMessageByRepeatKey.AddOrUpdate(
repeatKey,
message,
(_, previous) =>
{
repeat = string.Equals(previous, message, StringComparison.Ordinal);
return message;
});
return repeat;
}
public void Warning(string message)
@@ -114,7 +114,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
public string AppType { get; private set; }
/// <summary>Install attempt number (1 = first try). Increments on each "Execute retry N" line per check-in cycle.</summary>
public int AttemptNumber { get; private set; }
/// <summary>Detection rule result: "Detected" or "NotDetected". From DetectionActionHandler log lines.</summary>
/// <summary>
/// IME's detection check outside the check right after an install: Detected, NotDetected or
/// DetectedDifferentVersion — for an app being installed, the check before the install. The
/// check after the install is reported through OnPostInstallDetection instead (D-392).
/// </summary>
public string DetectionResult { get; private set; }
// Delivery Optimization telemetry (populated from [DO TEL] log entries OR Get-DeliveryOptimizationStatus poll)
@@ -426,7 +426,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
if (_logger == null) return;
var stateList = string.Join(", ", this.Select(x => $"{x.Name ?? x.Id}:{x.InstallationState}"));
_logger.Debug($"App states [{Count}]: {stateList}");
_logger.Verbose($"App states [{Count}]: {stateList}");
}
}
}
@@ -19,7 +19,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
public partial class ImeLogTracker
{
// PR3-A2: dedup state for `IME impersonation` lines. ~24 identical per session at
// DEBUG flooded the log; we now emit on user change + a 60s rollup with the count.
// DEBUG flooded the log; a user change logs at Debug, the 60s rollup with the count at Trace.
private string _lastImpersonationUser;
private int _impersonationRepeatCount;
private DateTime _impersonationLastRollupUtc = DateTime.MinValue;
@@ -111,12 +111,45 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
var now = DateTime.UtcNow;
if (now - _impersonationLastRollupUtc >= ImpersonationRollupInterval)
{
_logger.Debug($"IME impersonation: same as before (user='{current}', n={_impersonationRepeatCount} since last rollup)");
_logger.Trace($"IME impersonation: same as before (user='{current}', n={_impersonationRepeatCount} since last rollup)");
_impersonationLastRollupUtc = now;
_impersonationRepeatCount = 0;
}
}
/// <summary>
/// Info for what a line of this enrollment reports. A line replayed from a previous
/// enrollment's log (historic-replay guard) is context, not progress: Debug. Only for
/// handlers that run while that line is processed, since the flag describes the line.
/// </summary>
private void LogLineActivity(string message, string repeatKey = null)
{
if (_currentLineIsHistoricReplay) _logger.Debug(message + " (historic line)", repeatKey);
else _logger.Info(message, repeatKey);
}
/// <summary>
/// Result of IME's check right after an install (D-392). After an exit code that asked for a
/// restart that check decides nothing: IME sets no error then and checks again after the
/// restart (IME-POST-REBOOT-DETECTION marks that check), so it is not reported.
/// </summary>
private void HandlePostInstallDetection(string appId, string detection, bool afterReboot)
{
var pkg = _packageStates.GetPackage(appId);
if (pkg == null) return;
if (!afterReboot
&& (string.Equals(pkg.ExitCodeClass, "SoftReboot", StringComparison.OrdinalIgnoreCase)
|| string.Equals(pkg.ExitCodeClass, "HardReboot", StringComparison.OrdinalIgnoreCase)))
{
_logger.Debug($"ImeLogTracker: check after the install of {pkg.Name ?? appId} precedes the requested restart ({detection}), IME decides after it");
return;
}
_logger.Info($"ImeLogTracker: check after the install of {pkg.Name ?? appId}: {detection}{(afterReboot ? " (after the restart)" : string.Empty)}");
try { OnPostInstallDetection?.Invoke(pkg, detection, afterReboot, LastMatchedLogTimestamp); }
catch (Exception ex) { _logger.Warning($"OnPostInstallDetection handler threw: {ex.Message}"); }
}
private void HandleDoTelemetry(string json)
{
try
@@ -254,7 +287,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// map). Prefer the source CMTrace timestamp; latest start wins on a policy re-run.
var startedAtUtc = LastMatchedLogTimestamp ?? UtcNowProvider();
_healthScriptStartTimes[id] = (startedAtUtc, CaptureLastMatchedProvenance());
_logger.Info($"ImeLogTracker: health script started: {id}");
LogLineActivity($"ImeLogTracker: health script started: {id}", repeatKey: "ImeLogTracker.hsStarted:" + id);
// A replayed line of a previous enrollment bypasses the recurrence gate: the
// adapter drops its event, and a dropped run must not count as the policy's
@@ -263,7 +296,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
&& !_recurringScripts.OnStart(id, startedAtUtc, policyType, LastMatchedPatternId))
{
_stateDirty = true;
_logger.Debug($"ImeLogTracker: health script {id} is a recurring policy — start held until its result is known");
_logger.Debug($"ImeLogTracker: health script {id} is a recurring policy — start held until its result is known", repeatKey: "ImeLogTracker.hsStartHeld:" + id);
return;
}
_stateDirty = true;
@@ -479,7 +512,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
RecordInvocationMarker(null, isClose: false);
NoteInvocationActivity();
if (!string.IsNullOrEmpty(kind) && !string.Equals(kind, "powershell", StringComparison.OrdinalIgnoreCase))
_logger.Debug($"ImeLogTracker: AgentExecutor invocation of kind '{kind}' — exit/output lines not captured as a platform script");
_logger.Trace($"ImeLogTracker: AgentExecutor invocation of kind '{kind}' — exit/output lines not captured as a platform script");
}
private void HandleAgentExecutorCompleted()
@@ -1054,10 +1087,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
DurationBasis = "script_runtime",
};
_logger.Info($"ImeLogTracker: health-script {scriptPart} early-signal for {id}: " +
$"compliance={compliance}, exit={exitCode}, " +
$"stdout={(stdout == null ? "n/a" : stdout.Length + " chars")}, " +
$"stderr={(stderr == null ? "n/a" : stderr.Length + " chars")}");
LogLineActivity($"ImeLogTracker: health-script {scriptPart} early-signal for {id}: " +
$"compliance={compliance}, exit={exitCode}, " +
$"stdout={(stdout == null ? "n/a" : stdout.Length + " chars")}, " +
$"stderr={(stderr == null ? "n/a" : stderr.Length + " chars")}",
repeatKey: "ImeLogTracker.hsEarly:" + scriptPart + ":" + id);
EmitScriptEvent(enriched);
@@ -1281,11 +1315,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
EmitScriptEvent(postDetection);
}
_logger.Info($"ImeLogTracker: health-script result emitted for {policyId} " +
$"(status={remediationStatus?.ToString() ?? "?"}, " +
$"firstDetectExit={firstDetectExit?.ToString() ?? "n/a"}, " +
$"remediationExit={remediationExit?.ToString() ?? "n/a"}, " +
$"lastDetectExit={lastDetectExit?.ToString() ?? "n/a"})");
// "result for", not "emitted": the recurrence gate in EmitScriptEvent may hold a
// repeat back and logs that itself.
LogLineActivity($"ImeLogTracker: health-script result for {policyId} " +
$"(status={remediationStatus?.ToString() ?? "?"}, " +
$"firstDetectExit={firstDetectExit?.ToString() ?? "n/a"}, " +
$"remediationExit={remediationExit?.ToString() ?? "n/a"}, " +
$"lastDetectExit={lastDetectExit?.ToString() ?? "n/a"})",
repeatKey: "ImeLogTracker.hsResult:" + policyId);
}
private static ScriptExecutionState BuildHealthScriptPhase(
@@ -1355,7 +1392,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
_stateDirty = true;
if (!emit)
{
_logger.Debug($"ImeLogTracker: health script {script.PolicyId} {script.ScriptPart} repeats its last reported result — counted, not emitted");
_logger.Debug($"ImeLogTracker: health script {script.PolicyId} {script.ScriptPart} repeats its last reported result — counted, not emitted", repeatKey: "ImeLogTracker.hsRepeat:" + script.PolicyId + ":" + script.ScriptPart);
return;
}
if (releasedStart != null) RaiseScriptStarted(releasedStart);
@@ -1411,7 +1448,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
private void HandleImeStarted()
{
_logger.Info("ImeLogTracker: IME Agent Started detected");
LogLineActivity("ImeLogTracker: IME Agent Started detected");
// Log any currently active app — it will be re-evaluated by new log entries after IME restart.
// We intentionally do NOT mark it as Installed here because IME may retry the app.
@@ -1487,11 +1524,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
_logger.Debug(
"ImeLogTracker: zero-app user session observed before the user ESP phase " +
$"(current phase: {_lastEspPhaseDetected ?? "(none)"}) - deferring until AccountSetup");
$"(current phase: {_lastEspPhaseDetected ?? "(none)"}) - deferring until AccountSetup", repeatKey: "ImeLogTracker.zeroAppDeferred");
return;
}
_logger.Info("ImeLogTracker: user session enumerated with zero targeted apps - treating as user session completed");
_logger.Info("ImeLogTracker: user session enumerated with zero targeted apps - treating as user session completed", repeatKey: "ImeLogTracker.zeroAppUserSession");
OnUserSessionCompleted?.Invoke();
}
@@ -1509,7 +1546,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// which would corrupt tracking if we allowed it to trigger a phase change.
if (phaseOrd < _currentPhaseOrder)
{
_logger.Debug($"ImeLogTracker: ignoring backward phase transition to {espPhaseString} (current phase order: {_currentPhaseOrder})");
_logger.Trace($"ImeLogTracker: ignoring backward phase transition to {espPhaseString} (current phase order: {_currentPhaseOrder})");
return;
}
@@ -1550,7 +1587,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
_phasePackageSnapshots[_lastEspPhaseDetected] =
new List<AppPackageState>(_packageStates);
_logger.Info($"ImeLogTracker: Snapshotted {_packageStates.CountAll} package states from {_lastEspPhaseDetected} phase");
_logger.Debug($"ImeLogTracker: Snapshotted {_packageStates.CountAll} package states from {_lastEspPhaseDetected} phase");
}
_packageStates.Clear();
@@ -1564,12 +1601,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// First detection of any phase OR a real transition into a new phase: surface on Info
// so phase boundaries are visible without enabling Debug. Re-matches of the same phase
// (IME re-emits the phase string periodically as it re-evaluates app sets) stay on
// Debug to avoid Info repetition.
// (IME re-emits the phase string periodically as it re-evaluates app sets) are
// identical repeats and go to Trace (D-394).
if (isFirstOrChangedPhase)
_logger.Info($"ImeLogTracker: ESP phase detected: {espPhaseString}");
else
_logger.Debug($"ImeLogTracker: ESP phase detected: {espPhaseString}");
_logger.Trace($"ImeLogTracker: ESP phase detected: {espPhaseString}");
ActivatePatterns(logPhaseIsCurrentPhase);
OnEspPhaseChanged?.Invoke(espPhaseString);
@@ -1623,7 +1660,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
// Ignore user-targeted packages during device setup (we only track device phase in general)
_packageStates.AddUpdateFromJsonPolicies(policies, ignoreUserTargeted: false);
_logger.Info($"ImeLogTracker: discovered {policies.Count} policies, tracking {_packageStates.Count} packages");
_logger.Info($"ImeLogTracker: discovered {policies.Count} policies, tracking {_packageStates.Count} packages", repeatKey: "ImeLogTracker.policies");
OnPoliciesDiscovered?.Invoke(policiesJson);
}
}
@@ -1687,7 +1724,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
if (changed)
{
_logger.Debug($"ImeLogTracker: {pkg.Name ?? id} downloading: {bytes}/{ofbytes}");
_logger.Verbose($"ImeLogTracker: {pkg.Name ?? id} downloading: {bytes}/{ofbytes}");
OnAppStateChanged?.Invoke(pkg, oldState, AppInstallationState.Downloading);
}
}
@@ -83,7 +83,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
catch (FileNotFoundException) { }
catch (IOException ex)
{
_logger.Debug($"ImeLogTracker: IO error reading {filePath}: {ex.Message}");
_logger.Debug($"ImeLogTracker: IO error reading {filePath}: {ex.Message}", repeatKey: "ImeLogTracker.ioError:" + filePath);
}
}
@@ -516,7 +516,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
"updatestateskipped", "updatestateerror", "updatestatepostponed",
"captureexitcode", "capturehresult", "captureexitcodeclass", "captureappversion",
"captureapptypewinget", "captureapptypemsi", "captureattemptnumber",
"capturedetectionresult", "esptrackstatus", "policiesdiscovered",
"capturedetectionresult", "markpostinstalldetection", "esptrackstatus", "policiesdiscovered",
"ignorecompletedapp", "updatename", "updatewin32appstate",
"cancelstuckandsetcurrent", "updatedotelemetry",
// Not app-mutating, but a stale token-failure replayed from a previous
@@ -588,7 +588,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
_currentLineIsHistoricReplay = isStaleReplayLine;
if (isStaleReplayLine && AppMutatingActions.Contains(pattern.Action?.ToLower() ?? string.Empty))
{
_logger.Debug($"ImeLogTracker: skipped app action '{pattern.Action}' for historic line ({ResolveEntryUtc(entry):o})");
_logger.Trace($"ImeLogTracker: skipped app action '{pattern.Action}' for historic line ({ResolveEntryUtc(entry):o})");
return;
}
@@ -684,7 +684,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
break;
case "enrollmentcompleted":
_logger.Info("ImeLogTracker: User session completed detected");
LogLineActivity("ImeLogTracker: User session completed detected", repeatKey: "ImeLogTracker.userSessionCompleted");
OnUserSessionCompleted?.Invoke();
break;
@@ -790,10 +790,28 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
}
break;
case "markpostinstalldetection":
// The check right after an install starts (D-392); its result line follows.
if (!string.IsNullOrEmpty(id))
_postInstallCheckPending[id] = pattern.Parameters.ContainsKey("afterReboot")
&& pattern.Parameters["afterReboot"] == "true";
break;
case "capturedetectionresult":
var detectionVal = match.Groups["detection"]?.Value;
if (!string.IsNullOrEmpty(id) && !string.IsNullOrEmpty(detectionVal))
if (string.IsNullOrEmpty(id) || string.IsNullOrEmpty(detectionVal))
break;
bool afterReboot;
if (_postInstallCheckPending.TryGetValue(id, out afterReboot))
{
// detectionResult stays the check before the install.
_postInstallCheckPending.Remove(id);
HandlePostInstallDetection(id, detectionVal, afterReboot);
}
else
{
_packageStates.GetPackage(id)?.UpdateDetectionResult(detectionVal);
}
break;
case "updatestatepostponed":
@@ -50,6 +50,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// because setcurrentapp, esptrackstatus etc. see IDs that never enter packageStates.
private readonly HashSet<string> _seenAppIds = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
// IME's check right after an install (D-392): app id → "after the restart the installer
// requested". Set by IME-POST-INSTALL-DETECTION / IME-POST-REBOOT-DETECTION, consumed by
// the app's next detection result line, which IME always logs last in that check.
// Transient on purpose: a marker whose result line was never read must not survive an
// agent restart and turn a later ordinary check into a post-install result.
private readonly Dictionary<string, bool> _postInstallCheckPending = new Dictionary<string, bool>(StringComparer.OrdinalIgnoreCase);
// Forward-only phase progression: prevents accidental phase bounce (e.g. DeviceSetup
// re-detected during AccountSetup if IME re-evaluates device apps and logs the old phase).
private static readonly Dictionary<string, int> EspPhaseOrder = new Dictionary<string, int>(StringComparer.OrdinalIgnoreCase)
@@ -513,6 +520,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
// consumer must stamp poll-driven telemetry with the clock — inheriting an unrelated
// line's LastMatchedLogTimestamp put a tz-skewed time on the event (session df1fcf47).
public Action<AppPackageState, DateTime?> OnDoTelemetryReceived { get; set; }
/// <summary>
/// IME's check right after an install found its result (D-392): the package, the detection
/// state (Detected, NotDetected, DetectedDifferentVersion), whether the check followed the
/// restart the installer requested, and the result line's timestamp. Not raised for the
/// check before a requested restart: IME decides only after it.
/// </summary>
public Action<AppPackageState, string, bool, DateTime?> OnPostInstallDetection { get; set; }
public Action<ScriptExecutionState> OnScriptCompleted { get; set; }
/// <summary>
@@ -0,0 +1,105 @@
#nullable enable
using System;
using System.Collections.Generic;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Persistence;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.Shared;
using AutopilotMonitor.Shared.Models;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
/// <summary>
/// The V1 ConfigMgr client check, run on every poll: emits <c>configmgr_client_detected</c>
/// with the V1 payload when the client is first seen, and again when what it reports changes
/// (the service starts, a site code is assigned) — the client often installs after the agent
/// started. A <see cref="StartupEventGate"/> fingerprint keeps a restart into the same state
/// silent. Observational only: emission goes through <see cref="InformationalEventPost"/>.
/// </summary>
internal sealed class ConfigMgrClientDetector
{
internal const string SourceLabel = "ConfigMgrClientDetector";
/// <summary>Emissions per agent run; a flapping service must not flood the timeline.</summary>
internal const int MaxEmissionsPerRun = 10;
private readonly string _sessionId;
private readonly string _tenantId;
private readonly InformationalEventPost _post;
private readonly AgentLogger _logger;
private readonly IClock _clock;
private readonly StartupEventGate? _startupGate;
private string? _lastFingerprint;
private int _emissions;
private bool _checkedOnce;
public ConfigMgrClientDetector(
string sessionId,
string tenantId,
InformationalEventPost post,
AgentLogger logger,
IClock clock,
StartupEventGate? startupGate = null)
{
_sessionId = sessionId;
_tenantId = tenantId;
_post = post ?? throw new ArgumentNullException(nameof(post));
_logger = logger;
_clock = clock ?? throw new ArgumentNullException(nameof(clock));
_startupGate = startupGate;
}
/// <summary>Host timer callback and test seam — one probe round.</summary>
internal void Check()
{
var trigger = _checkedOnce ? "poll" : "startup";
_checkedOnce = true;
var snapshot = ConfigMgrClientProbe.Read(_logger);
if (!snapshot.Detected || snapshot.Fingerprint == _lastFingerprint || _emissions >= MaxEmissionsPerRun)
return;
_lastFingerprint = snapshot.Fingerprint;
if (_startupGate != null && !_startupGate.ShouldEmit(
Constants.EventTypes.ConfigMgrClientDetected, StartupEventGate.HashString(snapshot.Fingerprint)))
{
_logger?.Debug("ConfigMgrClientDetector: state already reported by a previous agent run — suppressed.");
return;
}
_emissions++;
var score = snapshot.ConfidenceScore;
var versionSuffix = snapshot.Version != null ? $", v{snapshot.Version}" : "";
var siteSuffix = snapshot.SiteCode != null ? $", site {snapshot.SiteCode}" : "";
_post.Emit(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
Timestamp = _clock.UtcNow,
EventType = Constants.EventTypes.ConfigMgrClientDetected,
Severity = EventSeverity.Info,
Source = SourceLabel,
Phase = EnrollmentPhase.Unknown,
Message = $"ConfigMgr client detected (confidence {score}/100): CcmExec {snapshot.ServiceState}{versionSuffix}{siteSuffix}",
Data = new Dictionary<string, object>
{
["ccmRegistryFound"] = snapshot.RegistryFound,
["ccmDirectoryFound"] = snapshot.DirectoryFound,
["ccmServiceState"] = snapshot.ServiceState,
["ccmVersion"] = snapshot.Version ?? "unknown",
["siteCode"] = snapshot.SiteCode ?? "unknown",
["confidenceScore"] = score,
["detectedAt"] = trigger,
}
});
_startupGate?.MarkEmitted(Constants.EventTypes.ConfigMgrClientDetected);
_logger?.Info(
$"ConfigMgrClientDetector: client detected (trigger={trigger}, confidence={score}, " +
$"service={snapshot.ServiceState}, version={snapshot.Version ?? "?"}, site={snapshot.SiteCode ?? "?"}).");
}
}
}
@@ -0,0 +1,146 @@
#nullable enable
using System;
using System.IO;
using System.ServiceProcess;
using AutopilotMonitor.Agent.V2.Core.Logging;
using Microsoft.Win32;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
/// <summary>
/// Reads the Configuration Manager client's footprint the way the V1 agent did: the
/// <c>CCM</c> key, the version from <c>CCMSetup</c>, the assigned site code, the
/// <c>%windir%\CCM</c> folder and the <c>CcmExec</c> service. Fail-soft: any failure yields
/// <see cref="ConfigMgrClientSnapshot.Empty"/>. The service is queried only when its key
/// exists, so devices without the client never throw on every poll.
/// </summary>
internal static class ConfigMgrClientProbe
{
internal const string CcmKeyPath = @"SOFTWARE\Microsoft\CCM";
internal const string CcmSetupKeyPath = @"SOFTWARE\Microsoft\CCMSetup";
internal const string MobileClientKeyPath = @"SOFTWARE\Microsoft\SMS\Mobile Client";
internal const string CcmExecServiceKeyPath = @"SYSTEM\CurrentControlSet\Services\CcmExec";
internal const string CcmExecServiceName = "CcmExec";
/// <summary>Service state when <c>CcmExec</c> is not installed (the V1 payload value).</summary>
internal const string ServiceNotFound = "not_found";
/// <summary>Test seam; use <see cref="ScopedOverride"/> to guarantee cleanup.</summary>
internal static Func<ConfigMgrClientSnapshot>? TestOverride;
public static ConfigMgrClientSnapshot Read(AgentLogger? logger = null)
{
var probe = TestOverride;
if (probe != null) return probe();
try
{
// The agent is AnyCPU; the client writes the 64-bit view.
using var hklm = RegistryKey.OpenBaseKey(RegistryHive.LocalMachine, RegistryView.Registry64);
bool registryFound;
using (var ccm = hklm.OpenSubKey(CcmKeyPath))
registryFound = ccm != null;
string? version;
using (var setup = hklm.OpenSubKey(CcmSetupKeyPath))
version = NonEmpty(setup?.GetValue("LastValidVersion")?.ToString());
string? siteCode;
using (var mobileClient = hklm.OpenSubKey(MobileClientKeyPath))
siteCode = NonEmpty(mobileClient?.GetValue("AssignedSiteCode")?.ToString());
bool serviceInstalled;
using (var service = hklm.OpenSubKey(CcmExecServiceKeyPath))
serviceInstalled = service != null;
var directoryFound = Directory.Exists(
Path.Combine(Environment.GetFolderPath(Environment.SpecialFolder.Windows), "CCM"));
return new ConfigMgrClientSnapshot(
registryFound, directoryFound, serviceInstalled ? ReadServiceState() : ServiceNotFound, version, siteCode);
}
catch (Exception ex)
{
logger?.Debug($"ConfigMgrClientProbe: read failed: {ex.Message}");
return ConfigMgrClientSnapshot.Empty;
}
}
private static string ReadServiceState()
{
try
{
using (var controller = new ServiceController(CcmExecServiceName))
return controller.Status.ToString();
}
catch (InvalidOperationException)
{
return ServiceNotFound; // removed between the key read and the query
}
}
private static string? NonEmpty(string? value) => string.IsNullOrWhiteSpace(value) ? null : value!.Trim();
/// <summary>Sets <see cref="TestOverride"/> for the scope and restores the previous value on Dispose.</summary>
internal sealed class ScopedOverride : IDisposable
{
private readonly Func<ConfigMgrClientSnapshot>? _previous;
private int _disposed;
public ScopedOverride(Func<ConfigMgrClientSnapshot> probe)
{
_previous = TestOverride;
TestOverride = probe;
}
public void Dispose()
{
if (System.Threading.Interlocked.Exchange(ref _disposed, 1) == 1) return;
TestOverride = _previous;
}
}
}
/// <summary>One read of the client's footprint, with the V1 confidence score.</summary>
internal sealed class ConfigMgrClientSnapshot
{
public static readonly ConfigMgrClientSnapshot Empty =
new ConfigMgrClientSnapshot(false, false, ConfigMgrClientProbe.ServiceNotFound, null, null);
public ConfigMgrClientSnapshot(bool registryFound, bool directoryFound, string serviceState, string? version, string? siteCode)
{
RegistryFound = registryFound;
DirectoryFound = directoryFound;
ServiceState = serviceState;
Version = version;
SiteCode = siteCode;
}
public bool RegistryFound { get; }
public bool DirectoryFound { get; }
/// <summary><see cref="System.ServiceProcess.ServiceControllerStatus"/> name, or <see cref="ConfigMgrClientProbe.ServiceNotFound"/>.</summary>
public string ServiceState { get; }
public string? Version { get; }
public string? SiteCode { get; }
/// <summary>
/// The V1 weights: the folder alone is too weak (it can be a remnant); the portal shows the
/// detection from 50 on.
/// </summary>
public int ConfidenceScore =>
(DirectoryFound ? 10 : 0)
+ (RegistryFound ? 20 : 0)
+ (Version != null ? 15 : 0)
+ (SiteCode != null ? 15 : 0)
+ (ServiceState != ConfigMgrClientProbe.ServiceNotFound ? 20 : 0)
+ (ServiceState == nameof(ServiceControllerStatus.Running) ? 20 : 0);
public bool Detected => ConfidenceScore > 0;
/// <summary>Everything the event reports; a change re-emits.</summary>
public string Fingerprint => $"{RegistryFound}|{DirectoryFound}|{ServiceState}|{Version}|{SiteCode}";
}
}
@@ -225,7 +225,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// Check against exclusion list
if (IsExcludedUser(owner))
{
_logger.Debug($"DesktopArrivalDetector: explorer.exe PID {proc.Id} owned by excluded user '{owner}' — skipping");
_logger.Debug($"DesktopArrivalDetector: explorer.exe PID {proc.Id} owned by excluded user '{owner}' — skipping", repeatKey: "DesktopArrivalDetector.excludedUser");
// Trace this decision once so it's visible in the backend
if (!_excludedUserTraced)
@@ -238,7 +238,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
$"explorer.exe found but owned by excluded user '{owner}' — not a real user desktop",
new Dictionary<string, object> { { "pid", proc.Id }, { "session", proc.SessionId }, { "owner", owner } });
}
catch (Exception ex) { _logger.Verbose($"DesktopArrivalDetector: OnTraceEvent failed: {ex.Message}"); }
catch (Exception ex) { _logger.Debug($"DesktopArrivalDetector: OnTraceEvent failed: {ex.Message}"); }
}
continue;
}
@@ -254,7 +254,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
$"Real user desktop detected (explorer.exe PID {proc.Id}, user '[redacted]')",
new Dictionary<string, object> { { "pid", proc.Id }, { "session", proc.SessionId }, { "owner", "[redacted]" } });
}
catch (Exception ex) { _logger.Verbose($"DesktopArrivalDetector: OnTraceEvent failed: {ex.Message}"); }
catch (Exception ex) { _logger.Debug($"DesktopArrivalDetector: OnTraceEvent failed: {ex.Message}"); }
// First-poll observability snapshot still fires before we stop polling —
// there is value in distinguishing "found on first poll" (Stage already
@@ -335,7 +335,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{ "wtsErrorCount", _wtsErrorCountSinceStart },
});
}
catch (Exception ex) { _logger.Verbose($"DesktopArrivalDetector: first-poll emit failed: {ex.Message}"); }
catch (Exception ex) { _logger.Debug($"DesktopArrivalDetector: first-poll emit failed: {ex.Message}"); }
}
/// <summary>
@@ -371,7 +371,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{ "wtsErrorCount", _wtsErrorCountSinceStart },
});
}
catch (Exception ex) { _logger.Verbose($"DesktopArrivalDetector: no-candidate emit failed: {ex.Message}"); }
catch (Exception ex) { _logger.Debug($"DesktopArrivalDetector: no-candidate emit failed: {ex.Message}"); }
}
/// <summary>
@@ -393,7 +393,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{ "startReason", startReason },
});
}
catch (Exception ex) { _logger.Verbose($"DesktopArrivalDetector: detector-started emit failed: {ex.Message}"); }
catch (Exception ex) { _logger.Debug($"DesktopArrivalDetector: detector-started emit failed: {ex.Message}"); }
}
/// <summary>
@@ -445,7 +445,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
}
catch (Exception ex)
{
_logger.Verbose($"DesktopArrivalDetector: OOBE state check failed: {ex.Message}");
_logger.Debug($"DesktopArrivalDetector: OOBE state check failed: {ex.Message}", repeatKey: "DesktopArrivalDetector.oobeCheckFailed");
}
}
@@ -471,7 +471,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
public void Stop()
{
_logger.Info("Stopping ESP and Hello tracker");
// Hosts call Stop and then Dispose, which stops again; the second pass finds nothing.
if (_helloTracker != null || _shellCoreTracker != null || _provisioningTracker != null || _modernDeploymentTracker != null)
_logger.Info("Stopping ESP and Hello tracker");
DisposeTracker(ref _modernDeploymentTracker, "ModernDeployment", t => t.Stop());
DisposeProvisioningTracker();
@@ -20,13 +20,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
internal const string None = "none";
internal const string Unavailable = "unavailable";
internal const string DevicePreparation = "device_preparation";
private const string FailedSuffix = "_failed";
internal enum CategoryState { Absent, Running, Done, Failed }
// ESP order: device preparation, device setup, account setup.
private static readonly (string ValueName, string Phase)[] Categories =
{
("DevicePreparationCategory.Status", "device_preparation"),
("DevicePreparationCategory.Status", DevicePreparation),
("DeviceSetupCategory.Status", "device_setup"),
("AccountSetupCategory.Status", "account_setup"),
};
@@ -60,7 +62,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
var states = Categories.Select((_, i) => Classify(i < statusJson.Count ? statusJson[i] : null)).ToList();
for (var i = 0; i < Categories.Length; i++)
if (states[i] == CategoryState.Failed) return Categories[i].Phase + "_failed";
if (states[i] == CategoryState.Failed) return Categories[i].Phase + FailedSuffix;
for (var i = 0; i < Categories.Length; i++)
if (states[i] == CategoryState.Running) return Categories[i].Phase;
@@ -69,6 +71,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
return lastDone == Categories.Length - 1 ? "esp_done" : Categories[lastDone].Phase + "_done";
}
/// <summary>
/// Whether device preparation can still hold the ESP in a <see cref="Read"/> result: it
/// runs or failed, or the phase is unknown (<see cref="None"/>, <see cref="Unavailable"/>).
/// False once device preparation is done, whichever later phase the ESP is in.
/// </summary>
internal static bool DevicePreparationOpen(string phase) =>
string.IsNullOrEmpty(phase)
|| phase == None
|| phase == Unavailable
|| phase == DevicePreparation
|| phase == DevicePreparation + FailedSuffix;
/// <summary>
/// One category value: done (<c>categorySucceeded=true</c>, or every subcategory succeeded
/// or notRequired), failed (<c>false</c>, or a failed subcategory), running (anything
@@ -98,7 +98,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
if (rootKey == null)
{
logger?.Debug("EspPolicyProviderProbe: EnrollmentStatusTracking registry key not found");
logger?.Debug("EspPolicyProviderProbe: EnrollmentStatusTracking registry key not found", repeatKey: "EspPolicyProviderProbe.noTrackingKey");
return EspPolicyProviderSnapshot.Empty;
}
@@ -39,6 +39,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// dispatch-guard exempt), never into decision state.
/// </para>
/// <para>
/// Phase gate: <c>DevicePreparation</c> providers count only while
/// <see cref="EspPhaseSnapshot.DevicePreparationOpen"/> holds. Once device preparation is done
/// their values hold nothing: a ConfigMgr client installed as a Win32 app registers its
/// provider after its own install with <c>InstallationState=1</c>, and nothing completes it.
/// </para>
/// <para>
/// Duplicate suppression: in-process one-shot per provider key, plus a
/// <see cref="StartupEventGate"/> fingerprint over the sorted set of currently-stalled keys so
/// an agent restart into the same stall does not re-report it — while a NEW provider joining
@@ -75,6 +81,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
private readonly IClock _clock;
private readonly StartupEventGate? _startupGate;
private readonly TimeSpan _dwell;
private readonly Func<string> _espPhaseReader;
private readonly Dictionary<string, DateTime> _firstSeenIncompleteUtc =
new Dictionary<string, DateTime>(StringComparer.OrdinalIgnoreCase);
@@ -94,7 +101,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
AgentLogger logger,
IClock clock,
StartupEventGate? startupGate = null,
TimeSpan? dwell = null)
TimeSpan? dwell = null,
Func<string>? espPhaseReader = null)
{
_sessionId = sessionId;
_tenantId = tenantId;
@@ -103,6 +111,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
_clock = clock ?? throw new ArgumentNullException(nameof(clock));
_startupGate = startupGate;
_dwell = dwell ?? TimeSpan.FromMinutes(DwellMinutes);
_espPhaseReader = espPhaseReader ?? EspPhaseSnapshot.Read;
}
/// <summary>Host timer callback and test seam — one probe + evaluation round.</summary>
@@ -111,7 +120,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
var snapshot = EspPolicyProviderProbe.Read(_logger);
var eval = EvaluateStallTransition(
snapshot, _firstSeenIncompleteUtc, _firedKeys,
_sidecarMissingSinceUtc, _sidecarMissingFired, _clock.UtcNow, _dwell);
_sidecarMissingSinceUtc, _sidecarMissingFired, _clock.UtcNow, _dwell,
EspPhaseSnapshot.DevicePreparationOpen(_espPhaseReader()));
_firstSeenIncompleteUtc.Clear();
foreach (var kv in eval.UpdatedFirstSeenUtc)
@@ -133,6 +143,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// <param name="sidecarMissingAlreadyFired">Arm-2 one-shot latch (never re-report).</param>
/// <param name="nowUtc">Evaluation timestamp.</param>
/// <param name="dwell">Continuous-condition threshold (shared by both arms).</param>
/// <param name="devicePreparationOpen">Whether device preparation can still hold the ESP (<see cref="EspPhaseSnapshot.DevicePreparationOpen"/>); false drops <c>DevicePreparation</c> providers from arm 1.</param>
internal static StallEvaluation EvaluateStallTransition(
EspPolicyProviderSnapshot snapshot,
IReadOnlyDictionary<string, DateTime> firstSeenIncompleteUtc,
@@ -140,9 +151,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
DateTime? sidecarMissingSinceUtc,
bool sidecarMissingAlreadyFired,
DateTime nowUtc,
TimeSpan dwell)
TimeSpan dwell,
bool devicePreparationOpen = true)
{
var result = new StallEvaluation();
var result = new StallEvaluation { DevicePreparationOpen = devicePreparationOpen };
// Missing root key or no registered providers = normal early enrollment: clear all
// dwell state (a condition must be continuously OBSERVED to accrue dwell).
@@ -152,8 +164,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// Arm 1 — a registered provider continuously incomplete.
foreach (var provider in snapshot.Providers)
{
if (provider.IsComplete)
continue; // completed → falls out of the dwell map (reset)
if (provider.IsComplete || !result.Counts(provider))
continue; // completed or past its phase → falls out of the dwell map (reset)
var firstSeen = firstSeenIncompleteUtc.TryGetValue(provider.Key, out var seen)
? seen
@@ -197,7 +209,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// 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))
.Where(p => !p.IsComplete && eval.Counts(p) && _firedKeys.Contains(p.Key))
.Select(p => p.Key)
.ToList();
if (_sidecarMissingFired && HasSetupAppsProvider(snapshot) && !snapshot.SidecarRegistered)
@@ -259,9 +271,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
if (eval.SidecarMissingStalledForMinutes != null)
data["sidecarMissingForMinutes"] = Math.Round(eval.SidecarMissingStalledForMinutes.Value, 1);
// The Setup/Apps wait has no timeout; device preparation gives up after the provider's
// Timeout node (CSP default 15 min).
var setupAppsWait = eval.SidecarMissingStalledForMinutes != null
|| eval.NewlyStalled.Any(s => s.Provider.Kind == EspPolicyProviderProbe.KindSetupApps);
var message =
"ESP Setup/Apps tracking stalled: " + string.Join("; ", messageParts) +
" — the ESP waits on its app-tracking providers without any timeout";
"ESP policy provider stalled: " + string.Join("; ", messageParts) +
(setupAppsWait
? " — the ESP waits on its Setup/Apps providers without any timeout"
: " — device preparation waits on its providers until their timeout");
_post.Emit(new EnrollmentEvent
{
@@ -298,6 +316,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// <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; }
/// <summary>The phase gate of this round; the cross-restart fingerprint applies the same filter.</summary>
public bool DevicePreparationOpen { get; set; }
/// <summary>Whether arm 1 considers <paramref name="provider"/> in this round.</summary>
public bool Counts(PolicyProviderState provider)
=> DevicePreparationOpen || provider.Kind != EspPolicyProviderProbe.KindDevicePreparation;
}
internal readonly struct StalledProvider
@@ -418,7 +418,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
}
else
{
_logger.Debug("Periodic Hello policy check: No WHfB policy found yet - will check again");
_logger.Trace("Periodic Hello policy check: No WHfB policy found yet - will check again");
}
}
}
@@ -636,7 +636,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
severity = EventSeverity.Info;
message = "Windows Hello for Business provisioned successfully - NGC key registered";
shouldTriggerHelloCompleted = MarkHelloCompleted();
_logger.Info("Windows Hello provisioning COMPLETED successfully");
// A repeat (live plus backfill) is already reported by MarkHelloCompleted.
if (shouldTriggerHelloCompleted) _logger.Info("Windows Hello provisioning COMPLETED successfully");
break;
case EventId_NgcKeyRegistrationFailed: // 301
@@ -644,7 +645,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
severity = EventSeverity.Error;
message = "Windows Hello for Business provisioning failed - NGC key registration error";
shouldTriggerHelloCompleted = MarkHelloCompleted();
_logger.Info("Windows Hello provisioning COMPLETED with failure");
if (shouldTriggerHelloCompleted) _logger.Info("Windows Hello provisioning COMPLETED with failure");
break;
case EventId_ProvisioningWillNotLaunch: // 360
@@ -658,7 +659,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
severity = EventSeverity.Warning;
message = "Windows Hello for Business provisioning blocked";
shouldTriggerHelloCompleted = MarkHelloCompleted();
_logger.Info("Windows Hello provisioning COMPLETED (blocked)");
if (shouldTriggerHelloCompleted) _logger.Info("Windows Hello provisioning COMPLETED (blocked)");
break;
case EventId_PinStatus: // 376
@@ -719,12 +720,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
|| eventType == Constants.EventTypes.DeviceRegistrationEvent
});
_logger.Info($"Hello event detected: {eventType} (EventID {eventId}{(isBackfill ? ", backfill" : "")})");
_logger.Debug($"Hello event detected: {eventType} (EventID {eventId}{(isBackfill ? ", backfill" : "")})");
if (shouldTriggerHelloCompleted)
{
EmitHelloPolicyDetectionMismatch(eventType, eventId, timestamp);
try { HelloCompleted?.Invoke(this, EventArgs.Empty); } catch { }
try { HelloCompleted?.Invoke(this, EventArgs.Empty); }
catch (Exception ex) { _logger.Warning($"HelloTracker: HelloCompleted handler threw: {ex.Message}"); }
}
}
@@ -969,12 +971,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
ImmediateUpload = shouldTriggerHelloCompleted
});
_logger.Info($"HelloForBusiness event detected: {eventType} (EventID {eventId}{(isBackfill ? ", backfill" : "")})");
_logger.Debug($"HelloForBusiness event detected: {eventType} (EventID {eventId}{(isBackfill ? ", backfill" : "")})");
if (shouldTriggerHelloCompleted)
{
EmitHelloPolicyDetectionMismatch(eventType, eventId, timestamp);
try { HelloCompleted?.Invoke(this, EventArgs.Empty); } catch { }
try { HelloCompleted?.Invoke(this, EventArgs.Empty); }
catch (Exception ex) { _logger.Warning($"HelloTracker: HelloCompleted handler threw: {ex.Message}"); }
}
}
@@ -545,7 +545,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
if (description.IndexOf("WhiteGlove", StringComparison.OrdinalIgnoreCase) < 0)
{
_logger.Trace($"ManagementService Event 509 without WhiteGlove keyword — ignoring: {description}");
_logger.Debug($"ManagementService Event 509 without WhiteGlove keyword — ignoring: {description}", repeatKey: "ModernDeploymentTracker.nonWhiteGlove509");
return;
}
@@ -624,7 +624,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
using (record)
{
found++;
_logger.Info($"Backfill found ManagementService Event {record.Id} at {record.TimeCreated:O}");
_logger.Debug($"Backfill found ManagementService Event {record.Id} at {record.TimeCreated:O}");
ProcessRecord(record, "ManagementService", ManagementChannel, isBackfill: true);
}
}
@@ -97,7 +97,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
hasValues: entries.Any(e => !oobeOnly || IsOobeName(e.Key)), line: line);
}
/// <summary>One agent.log line per present key, one naming the absent keys.</summary>
/// <summary>
/// One agent.log line per present key, one naming the absent keys. Debug: registry detail
/// behind the update page; the oobe_update_state event carries the content.
/// </summary>
public static void Log(AgentLogger logger, string moment, IReadOnlyList<KeyState> states)
{
if (logger == null || states == null) return;
@@ -110,11 +113,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
absent.Add(state.Path);
continue;
}
logger.Info($"OOBE update registry ({moment}): HKLM\\{state.Path}: {state.Line}");
logger.Debug($"OOBE update registry ({moment}): HKLM\\{state.Path}: {state.Line}");
}
if (absent.Count > 0)
logger.Info($"OOBE update registry ({moment}): absent: {string.Join(", ", absent)}");
logger.Debug($"OOBE update registry ({moment}): absent: {string.Join(", ", absent)}");
}
/// <summary>
@@ -514,13 +514,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
changedCount++;
bool isNew = !_lastProvisioningJson.ContainsKey(categoryName);
// Guard: the raw-JSON interpolation is materialized regardless of log
// level (Trace() only drops the string after it is built), and this runs
// per changed category every poll — skip the alloc when Trace is off.
if (_logger.LogLevel >= AgentLogLevel.Trace)
{
_logger.Trace($"CheckProvisioningStatus: {categoryName} — {(isNew ? "NEW" : "CHANGED")} (json length={jsonValue.Length})");
_logger.Trace($"CheckProvisioningStatus: {categoryName} — raw JSON: {jsonValue}");
}
// level (Verbose() only drops the string after it is built), and this runs
// per changed category every poll — skip the alloc when Verbose is off.
if (_logger.LogLevel >= AgentLogLevel.Verbose)
_logger.Verbose($"CheckProvisioningStatus: {categoryName} {(isNew ? "new" : "changed")}, raw JSON: {jsonValue}");
_lastProvisioningJson[categoryName] = jsonValue;
// TryFireProvisioningFailure (inside ProcessCategoryStatus) arms the
@@ -1007,7 +1004,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
bool isFirstSeen = !_provisioningCategorySeen.Contains(categoryName);
bool categorySucceededChanged = HasCategorySucceededChanged(categoryName, categorySucceeded);
_logger.Trace($"ProcessCategory: {categoryLabel} — succeeded={categorySucceeded?.ToString() ?? "null"}, " +
_logger.Verbose($"ProcessCategory: {categoryLabel} — succeeded={categorySucceeded?.ToString() ?? "null"}, " +
$"isFirstSeen={isFirstSeen}, succeededChanged={categorySucceededChanged}, " +
$"subcategories={subcategories.Count} [{string.Join(", ", subcategories.Select(s => $"{s.Name}={s.State}"))}]");
@@ -1050,7 +1047,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
var failureTransitions = transitions.Where(t => t.IsFailure).ToList();
if (transitions.Count > 0)
{
_logger.Trace($"ProcessCategory: {categoryLabel} — subcategory transitions: " +
_logger.Debug($"ProcessCategory: {categoryLabel} — subcategory transitions: " +
string.Join(", ", transitions.Select(t => $"{t.SubcategoryName}: {t.OldState}→{t.NewState} (failure={t.IsFailure})")));
}
@@ -1115,7 +1112,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
var errorCode = TryExtractErrorCode(failedSubcategoryInfo?.StatusText);
_logger.Info(
_logger.Debug(
$"Provisioning subcategory failure: {categoryLabel}/{failedSubcategoryName ?? "category-level"} — " +
$"escalating as {failureTypeName} (errorCode={errorCode ?? "n/a"})");
_logger.Warning($"Provisioning failure detected: {failureTypeName}");
@@ -1886,7 +1883,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
Data = eventData
});
_logger.Info($"Provisioning status event: {categoryLabel} — {statusText} (succeeded={succeeded?.ToString() ?? "in_progress"})");
_logger.Info($"Provisioning status event: {categoryLabel} — {statusText} (succeeded={succeeded?.ToString() ?? "in_progress"})", repeatKey: "ProvisioningStatus.event:" + categoryLabel);
}
private void EmitRawRegistryDump(string categoryLabel, string rawJson, string trigger)
@@ -266,24 +266,27 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
try
{
var stoppedAny = false;
lock (_stateLock)
{
DisposeAndNull(ref _servicesAppearanceWatcher);
DisposeAndNull(ref _machineSoftwareAppearanceWatcher);
DisposeAndNull(ref _userSoftwareAppearanceWatcher);
DisposeAndNull(ref _uninstallAppearanceWatcher);
stoppedAny |= DisposeAndNull(ref _servicesAppearanceWatcher);
stoppedAny |= DisposeAndNull(ref _machineSoftwareAppearanceWatcher);
stoppedAny |= DisposeAndNull(ref _userSoftwareAppearanceWatcher);
stoppedAny |= DisposeAndNull(ref _uninstallAppearanceWatcher);
_serviceRealmjoinDebounce?.Dispose(); _serviceRealmjoinDebounce = null;
_machineRealmJoinDebounce?.Dispose(); _machineRealmJoinDebounce = null;
_userRealmJoinDebounce?.Dispose(); _userRealmJoinDebounce = null;
_uninstallDebounce?.Dispose(); _uninstallDebounce = null;
DisposeAndNull(ref _serviceRealmjoinWatcher);
DisposeAndNull(ref _machineRealmJoinWatcher);
DisposeAndNull(ref _userRealmJoinWatcher);
DisposeAndNull(ref _uninstallWatcher);
stoppedAny |= DisposeAndNull(ref _serviceRealmjoinWatcher);
stoppedAny |= DisposeAndNull(ref _machineRealmJoinWatcher);
stoppedAny |= DisposeAndNull(ref _userRealmJoinWatcher);
stoppedAny |= DisposeAndNull(ref _uninstallWatcher);
}
_logger.Info($"RealmJoinWatcher: stopped ({reason})");
// Hosts call Stop and then Dispose, which stops again; only the pass that
// stopped a watcher logs.
if (stoppedAny) _logger.Info($"RealmJoinWatcher: stopped ({reason})");
}
catch (Exception ex)
{
@@ -913,11 +916,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
}
}
private static void DisposeAndNull(ref RegistryWatcher? w)
private static bool DisposeAndNull(ref RegistryWatcher? w)
{
if (w == null) return;
if (w == null) return false;
try { w.Dispose(); } catch { }
w = null;
return true;
}
// Test seams — drive the read paths deterministically without touching the real registry.
@@ -384,7 +384,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
ImmediateUpload = true
});
_logger.Info($"Shell-Core event detected: {eventType} (EventID {eventId})");
_logger.Debug($"Shell-Core event detected: {eventType} (EventID {eventId})");
// Set the source-event timestamp BEFORE each event raise so adapters / coordinators
// can read it during their synchronous handler. Cleared in finally so a stale value
@@ -568,7 +568,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
}
catch (Exception ex)
{
_logger.Trace($"StallProbeCollector: eventlog scan of {channel} failed: {ex.Message}");
_logger.Debug($"StallProbeCollector: eventlog scan of {channel} failed: {ex.Message}", repeatKey: "StallProbeCollector.scanFailed:" + channel);
}
}
@@ -344,7 +344,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
_logger.Info($"Diagnostics package created: {zipFileName} ({zipBytes.Length / 1024} KB)");
// Fetch a short-lived upload URL just before uploading — never stored in config or on disk
_logger.Info("Requesting diagnostics upload URL from backend...");
_logger.Debug("Requesting diagnostics upload URL from backend...");
var uploadUrlResponse = await _apiClient.GetDiagnosticsUploadUrlAsync(
_configuration.TenantId,
_configuration.SessionId,
@@ -708,7 +708,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
// Expected outcome, not a packaging problem: the subtree is off limits by design.
foreach (var refused in refusedDirectories)
{
_logger.Info($"Diagnostics subfolder skipped by guard: {refused}");
_logger.Debug($"Diagnostics subfolder skipped by guard: {refused}");
ManifestLine($"SKIPPED DIR (path guard): {refused}");
}
@@ -800,7 +800,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
}
tracker.RecordIncluded(length);
_logger.Debug($"Added to diagnostics package: {entryName} ({length / 1024} KB)");
_logger.Verbose($"Added to diagnostics package: {entryName} ({length / 1024} KB)");
ManifestLine($"ADDED: {entryName} ({length} bytes)");
}
}
@@ -1066,7 +1066,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
{
try
{
_logger.Info($"Uploading diagnostics package (attempt {attempt}/{maxRetries}, {data.Length / 1024} KB)...");
_logger.Debug($"Uploading diagnostics package (attempt {attempt}/{maxRetries}, {data.Length / 1024} KB)...");
using var content = new ByteArrayContent(data);
content.Headers.Add("x-ms-blob-type", "BlockBlob");
@@ -1101,7 +1101,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
if (attempt < maxRetries)
{
var delay = TimeSpan.FromSeconds(Math.Pow(2, attempt)); // 2s, 4s, 8s
_logger.Info($"Retrying blob upload in {delay.TotalSeconds}s...");
_logger.Debug($"Retrying blob upload in {delay.TotalSeconds}s...");
await Task.Delay(delay);
}
}
@@ -97,7 +97,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
var dedupKey = BuildDedupKey(action);
if (!_seenActionIds.TryAdd(dedupKey, 0))
{
_logger.Debug($"ServerActionDispatcher: duplicate action '{action.Type}' ({dedupKey}) — skipping");
_logger.Debug($"ServerActionDispatcher: duplicate action '{action.Type}' ({dedupKey}) — skipping", repeatKey: "ServerActionDispatcher.duplicate:" + dedupKey);
continue;
}
@@ -50,7 +50,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
using (explorerProcess)
{
sessionId = (uint)explorerProcess.SessionId;
logger.Info($"UserSessionProcessLauncher: Found explorer.exe PID {explorerProcess.Id} in session {sessionId}");
logger.Debug($"UserSessionProcessLauncher: Found explorer.exe PID {explorerProcess.Id} in session {sessionId}");
}
// Get the interactive session token via WTS.
@@ -80,7 +80,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
return false;
}
logger.Info($"UserSessionProcessLauncher: Token duplicated and stamped to session {sessionId}");
logger.Debug($"UserSessionProcessLauncher: Token duplicated and stamped to session {sessionId}");
// Create an environment block for the user (using session-stamped token)
if (!ProcessNativeMethods.CreateEnvironmentBlock(out environment, dupToken, false))
@@ -121,7 +121,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
{
cxhProcess = FindProcessInSession("CloudExperienceHost", sessionId);
if (cxhProcess != null)
logger.Info($"UserSessionProcessLauncher: CloudExperienceHost PID {cxhProcess.Id} running " +
logger.Debug($"UserSessionProcessLauncher: CloudExperienceHost PID {cxhProcess.Id} running " +
$"in session {sessionId} — will monitor for exit during retries");
}
catch { }
@@ -162,7 +162,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
}
ProcessNativeMethods.CloseHandle(pi.hThread);
logger.Info($"UserSessionProcessLauncher: Attempt {attempt} — created PID {pi.dwProcessId}" +
logger.Debug($"UserSessionProcessLauncher: Attempt {attempt} — created PID {pi.dwProcessId}" +
$" [{(useExplicitDesktop ? "explicit" : "default")} desktop], verifying startup...");
// Wait 3s to verify the process survives DLL init + CLR bootstrap.
@@ -190,10 +190,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
// On 23H2: CXH never exits → WaitForExit times out → same as regular retry interval.
if (cxhProcess != null)
{
logger.Info($"UserSessionProcessLauncher: Attempt {attempt} — 0x8007045A, waiting for CXH exit (up to {retryIntervalSeconds}s)...");
logger.Debug($"UserSessionProcessLauncher: Attempt {attempt} — 0x8007045A, waiting for CXH exit (up to {retryIntervalSeconds}s)...");
if (cxhProcess.WaitForExit(retryIntervalSeconds * 1000))
{
logger.Info("UserSessionProcessLauncher: CloudExperienceHost exited — desktop should be available");
logger.Debug("UserSessionProcessLauncher: CloudExperienceHost exited — desktop should be available");
cxhProcess.Dispose();
cxhProcess = null;
System.Threading.Thread.Sleep(500); // brief delay for desktop init
@@ -201,7 +201,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime
}
else
{
logger.Info($"UserSessionProcessLauncher: Attempt {attempt} — 0x8007045A (desktop locked?) — retrying in {retryIntervalSeconds}s...");
logger.Debug($"UserSessionProcessLauncher: Attempt {attempt} — 0x8007045A (desktop locked?) — retrying in {retryIntervalSeconds}s...");
System.Threading.Thread.Sleep(retryIntervalSeconds * 1000);
}
continue;
@@ -81,7 +81,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
/// <summary>Final-shutdown scan — captures any AutoLogon written during the user phase.</summary>
public void AnalyzeAtShutdown()
{
_logger.Info($"{Name}: Running shutdown AutoLogon scan");
_logger.Debug($"{Name}: Running shutdown AutoLogon scan");
RunScan("shutdown");
}
@@ -91,7 +91,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
/// </summary>
public void AnalyzeAtDeviceSetupComplete()
{
_logger.Info($"{Name}: Running device-setup-complete AutoLogon scan");
_logger.Debug($"{Name}: Running device-setup-complete AutoLogon scan");
RunScan("device_setup_complete");
}
@@ -81,7 +81,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
public void AnalyzeAtStartup()
{
_logger.Info($"{Name}: scanning prefetch for a post-boot cmd.exe console artifact");
_logger.Debug($"{Name}: scanning prefetch for a post-boot cmd.exe console artifact");
try { RunScan(); }
catch (Exception ex) { _logger.Error($"{Name}: scan failed unexpectedly", ex); }
}
@@ -80,7 +80,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
public void AnalyzeAtStartup()
{
_logger.Info($"{Name}: Running startup analysis");
_logger.Debug($"{Name}: Running startup analysis");
RunAnalysis("startup");
}
@@ -114,13 +114,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
public void AnalyzeAtStartup()
{
_logger.Info($"{Name}: Running startup analysis");
_logger.Debug($"{Name}: Running startup analysis");
RunAnalysis("startup", EnrollmentPhase.Unknown);
}
public void AnalyzeAtShutdown()
{
_logger.Info($"{Name}: Running shutdown analysis");
_logger.Debug($"{Name}: Running shutdown analysis");
// At shutdown a user has logged in — their profile folder is expected. Detect logged-in
// users via explorer.exe owner (same technique as DesktopArrivalDetector); RunAnalysis
@@ -92,7 +92,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
public void AnalyzeAtStartup()
{
_logger.Info($"{Name}: Running startup analysis (baseline inventory)");
_logger.Debug($"{Name}: Running startup analysis (baseline inventory)");
try
{
// The collection ALWAYS runs — _startupInventory is the in-memory base for the
@@ -106,7 +106,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
Constants.EventTypes.SoftwareInventoryAnalysis + ":startup",
BuildInventoryFingerprint(_startupInventory)))
{
_logger.Info($"{Name}: baseline inventory unchanged since last emission — startup events suppressed (restart dedup), delta base kept in memory");
_logger.Debug($"{Name}: baseline inventory unchanged since last emission — startup events suppressed (restart dedup), delta base kept in memory");
return;
}
@@ -156,7 +156,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
{
if (Interlocked.CompareExchange(ref _part1ShutdownSnapshotEmitted, 1, 0) != 0)
{
_logger.Info($"{Name}: AnalyzeAtShutdown(whiteGlovePart=1) skipped — Part-1 snapshot already emitted (likely by WhiteGloveInventoryTrigger)");
_logger.Debug($"{Name}: AnalyzeAtShutdown(whiteGlovePart=1) skipped — Part-1 snapshot already emitted (likely by WhiteGloveInventoryTrigger)");
return;
}
}
@@ -164,12 +164,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Analyzers
{
if (Interlocked.CompareExchange(ref _part2ShutdownSnapshotEmitted, 1, 0) != 0)
{
_logger.Info($"{Name}: AnalyzeAtShutdown(whiteGlovePart=2) skipped — Part-2 snapshot already emitted");
_logger.Debug($"{Name}: AnalyzeAtShutdown(whiteGlovePart=2) skipped — Part-2 snapshot already emitted");
return;
}
}
_logger.Info($"{Name}: Running shutdown analysis (delta detection, whiteGlovePart={whiteGlovePart?.ToString() ?? "none"})");
_logger.Debug($"{Name}: Running shutdown analysis (delta detection, whiteGlovePart={whiteGlovePart?.ToString() ?? "none"})");
try
{
var currentInventory = CollectAndNormalize();
@@ -62,9 +62,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry
/// <summary>Stops the collection timer without disposing the collector.</summary>
public void Stop()
{
// Hosts call Stop and then Dispose, which stops again; only a running timer logs.
var wasRunning = _timer != null;
_timer?.Dispose();
_timer = null;
Logger.Info($"[{GetType().Name}] Stopped");
if (wasRunning) Logger.Info($"[{GetType().Name}] Stopped");
OnAfterStop();
}
@@ -117,7 +119,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry
// duration of any single slow Collect.
if (Interlocked.CompareExchange(ref _collecting, 1, 0) != 0)
{
Logger.Debug($"[{GetType().Name}] tick skipped — previous Collect still running");
Logger.Trace($"[{GetType().Name}] tick skipped — previous Collect still running");
return;
}
@@ -209,7 +209,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
default: modeLabel = $"{autopilotMode}"; break;
}
data["autopilotModeLabel"] = modeLabel;
_logger.Info($"EnrollmentTracker: AutopilotMode={autopilotMode} ({modeLabel})");
_logger.Info($"EnrollmentTracker: AutopilotMode={autopilotMode} ({modeLabel})", repeatKey: "DeviceInfo.autopilotMode");
}
// --- Interpret CloudAssignedDomainJoinMethod ---
@@ -238,7 +238,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
}
catch (Exception ex)
{
_logger.Trace($"EnrollmentTracker: Failed to parse PolicyJsonCache for DomainJoinMethod: {ex.Message}");
_logger.Debug($"EnrollmentTracker: Failed to parse PolicyJsonCache for DomainJoinMethod: {ex.Message}");
}
}
@@ -261,10 +261,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
if (isHybridJoin)
{
_logger.Info("EnrollmentTracker: Hybrid Azure AD Join profile detected");
_logger.Info("EnrollmentTracker: Hybrid Azure AD Join profile detected", repeatKey: "DeviceInfo.hybridProfile");
}
_logger.Info($"EnrollmentTracker: Read {data.Count} values from AutopilotPolicyCache");
_logger.Info($"EnrollmentTracker: Read {data.Count} values from AutopilotPolicyCache", repeatKey: "DeviceInfo.policyCache");
}
else
{
@@ -390,7 +390,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
{ "detectionRule", detectionRule }
});
_logger.Info($"EnrollmentTracker: enrollment type detected: {detectedType}");
_logger.Info($"EnrollmentTracker: enrollment type detected: {detectedType}", repeatKey: "DeviceInfo.enrollmentType");
}
catch (Exception ex)
{
@@ -810,7 +810,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
if (hasAnyEspEvidence)
{
var summary = BuildSummary(snapshot, tracking);
_logger.Info($"EnrollmentTracker: ESP configuration detected — {summary}");
_logger.Info($"EnrollmentTracker: ESP configuration detected — {summary}", repeatKey: "DeviceInfo.espConfig");
EmitDeviceInfoEvent(Constants.EventTypes.EspConfigDetected, $"ESP configuration: {summary}", data);
PostEspConfigDetectedSignal(snapshot);
}
@@ -89,7 +89,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
/// </summary>
public (string enrollmentType, bool isHybridJoin, bool? skipUserStatusPage, bool? skipDeviceStatusPage, int? autopilotMode, bool hasAadJoinedUser, bool isFooUserDetected) CollectAll()
{
_logger.Info("EnrollmentTracker: collecting device info (at start)");
_logger.Debug("EnrollmentTracker: collecting device info (at start)");
CollectOSInfoAndBootTime();
CollectNetworkAndDnsConfiguration();
@@ -113,7 +113,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
/// </summary>
public void CollectAtEnrollmentStart()
{
_logger.Info("EnrollmentTracker: collecting device info (at enrollment start)");
_logger.Debug("EnrollmentTracker: collecting device info (at enrollment start)");
CollectAadJoinStatus();
CollectAutopilotProfile();
@@ -134,7 +134,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
/// </summary>
public void RefreshEspConfiguration(string trigger)
{
_logger.Info($"EnrollmentTracker: re-collecting ESP configuration (trigger={trigger})");
_logger.Debug($"EnrollmentTracker: re-collecting ESP configuration (trigger={trigger})");
CollectEspConfiguration();
}
@@ -144,7 +144,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
/// </summary>
public void CollectAtEnd()
{
_logger.Info("EnrollmentTracker: collecting device info (at end)");
_logger.Debug("EnrollmentTracker: collecting device info (at end)");
// BitLocker can be enabled during enrollment via policy
CollectBitLockerStatus();
@@ -171,7 +171,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.DeviceInfo
values[valueName] = value.ToString();
}
logger.Info($"ZtdEvidence: read {values.Count} values from Diagnostics\\Autopilot");
logger.Info($"ZtdEvidence: read {values.Count} values from Diagnostics\\Autopilot", repeatKey: "ZtdEvidence.read");
return values.Count > 0 ? values : null;
}
}
@@ -130,7 +130,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather.Collectors
var resolvedPaths = ResolveLogPaths(filePath, rule.RuleId, context);
if (resolvedPaths.Count == 0)
{
context.Logger.Debug($"LogParser rule {rule.RuleId}: no files found for: {filePath}");
context.Logger.Debug($"LogParser rule {rule.RuleId}: no files found for: {filePath}", repeatKey: "LogParserCollector.noFiles:" + rule.RuleId + "|" + filePath);
context.DebugLog(rule.RuleId, GatherRuleDebugLog.StageLogParser,
$"no files matched target {filePath}" + (HasWildcard(Path.GetFileName(filePath)) ? " (wildcard)" : "") + " — nothing to parse");
return null;
@@ -456,7 +456,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather.Collectors
state.CommitLogPosition(rule.RuleId, filePath, endPosition, lineNumberBase + committedLines, head, heldTailStart);
if (matchCount > 0)
context.Logger.Debug($"LogParser rule {rule.RuleId}: {matchCount} matches from {linesRead} lines in {fileName}");
context.Logger.Verbose($"LogParser rule {rule.RuleId}: {matchCount} matches from {linesRead} lines in {fileName}");
// Per-file outcome — always written so a "matched 0" run is visible too.
context.DebugLog(rule.RuleId, GatherRuleDebugLog.StageLogParser,
@@ -496,7 +496,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather.Collectors
}
else if (start == LogReadStart.Replaced)
{
context.Logger.Info($"LogParser rule {rule.RuleId}: {fileName} was replaced since the last read — reading it from the beginning");
context.Logger.Debug($"LogParser rule {rule.RuleId}: {fileName} was replaced since the last read — reading it from the beginning");
context.DebugLog(rule.RuleId, GatherRuleDebugLog.StageLogParser,
$"{fileName}: file start changed since the last read (replaced or rewritten) — saved position {known.Position} discarded, reading from the beginning");
}
@@ -261,7 +261,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
interval
);
_intervalTimers[intervalRule.RuleId] = timer;
_logger.Info($" Interval rule {intervalRule.RuleId} scheduled every {intervalRule.IntervalSeconds}s");
_logger.Debug($" Interval rule {intervalRule.RuleId} scheduled every {intervalRule.IntervalSeconds}s");
DebugLog(intervalRule.RuleId, GatherRuleDebugLog.StageTrigger,
$"interval timer scheduled every {intervalRule.IntervalSeconds}s (first run after one full interval — no immediate execution)");
}
@@ -321,7 +321,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
continue;
}
_logger.Info($"Phase exit triggered rule {rule.RuleId} (left phase: {previousPhaseName}, now: {phaseName})");
_logger.Debug($"Phase exit triggered rule {rule.RuleId} (left phase: {previousPhaseName}, now: {phaseName})");
exitRules.Add(rule);
}
}
@@ -374,7 +374,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
foreach (var rule in deferredStartup)
{
var deferredRule = rule;
_logger.Info($"Phase {phaseName} activated deferred startup rule {deferredRule.RuleId}");
_logger.Debug($"Phase {phaseName} activated deferred startup rule {deferredRule.RuleId}");
DebugLog(deferredRule.RuleId, GatherRuleDebugLog.StageTrigger,
$"phase {phaseName} activated deferred startup rule");
ThreadPool.QueueUserWorkItem(_ => ExecuteRule(deferredRule));
@@ -405,7 +405,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
continue;
}
_logger.Info($"Phase change triggered rule {rule.RuleId} (phase: {phaseName})");
_logger.Debug($"Phase change triggered rule {rule.RuleId} (phase: {phaseName})");
DebugLog(rule.RuleId, GatherRuleDebugLog.StageTrigger, $"phase_change to {phaseName} fired");
ThreadPool.QueueUserWorkItem(_ => ExecuteRule(rule));
}
@@ -450,7 +450,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
continue;
}
_logger.Info($"Event triggered rule {rule.RuleId} (event: {eventType})");
_logger.Debug($"Event triggered rule {rule.RuleId} (event: {eventType})");
DebugLog(rule.RuleId, GatherRuleDebugLog.StageTrigger, $"on_event {eventType} fired");
ThreadPool.QueueUserWorkItem(_ => ExecuteRule(rule));
}
@@ -461,7 +461,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
{
try
{
_logger.Info($"Executing gather rule: {rule.RuleId} ({rule.Title})");
_logger.Info($"Executing gather rule: {rule.RuleId} ({rule.Title})", repeatKey: "GatherRuleExecutor.exec:" + rule.RuleId);
DebugLog(rule.RuleId, GatherRuleDebugLog.StageExec, $"executing: collector={rule.CollectorType}, target={rule.Target}");
var collectorType = rule.CollectorType?.ToLower();
@@ -673,7 +673,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
&& (int)_currentPhase >= (int)fromPhase)
{
_fromPhaseLatched.Add(rule.RuleId);
_logger.Info($"Gather rule {rule.RuleId}: from-phase scope latched at {_currentPhase} (activeFromPhase={rule.ActiveFromPhase})");
_logger.Debug($"Gather rule {rule.RuleId}: from-phase scope latched at {_currentPhase} (activeFromPhase={rule.ActiveFromPhase})");
}
}
}
@@ -755,7 +755,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
}
if (!emit)
_logger.Debug($"Gather rule {rule.RuleId}: result unchanged, emit suppressed (on_change)");
_logger.Trace($"Gather rule {rule.RuleId}: result unchanged, emit suppressed (on_change)");
return emit;
}
@@ -356,7 +356,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
{
var oldest = files.OrderBy(file => file.Value.LastTouched).First();
files.Remove(oldest.Key);
_logger.Info($"GatherRuleSessionState: rule {ruleId} tracks more than {MaxLogFilesPerRule} files — forgot the position of {Path.GetFileName(oldest.Key)}");
_logger.Debug($"GatherRuleSessionState: rule {ruleId} tracks more than {MaxLogFilesPerRule} files — forgot the position of {Path.GetFileName(oldest.Key)}");
}
private static string Prefix(string hash) => hash.Length > 8 ? hash.Substring(0, 8) : hash;
@@ -91,7 +91,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Gather
}
catch (Exception ex)
{
_logger.Debug($"[{SourceName}] failed to save state: {ex.Message}");
_logger.Debug($"[{SourceName}] failed to save state: {ex.Message}", repeatKey: "GatherRuleStatePersistence.save:" + SourceName);
return false;
}
}
@@ -196,7 +196,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
var leaf = Path.GetFileName(relativeName);
if (!string.IsNullOrEmpty(leaf) && _binaries.Contains(leaf))
{
_logger.Info($"[OfficeBinaryWatcher] core Office binary appeared: {leaf}");
_logger.Info($"[OfficeBinaryWatcher] core Office binary appeared: {leaf}", repeatKey: "OfficeBinaryWatcher.appeared:" + leaf);
Raise();
}
}
@@ -194,7 +194,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
{
// Debounce: C2R may start another short-lived worker after a small gap. Only
// close the window if none reappears within the settle period.
_logger.Debug($"[OfficeProcessWatcher] last worker exited — settling {_settleSeconds}s before closing the install window");
_logger.Trace($"[OfficeProcessWatcher] last worker exited — settling {_settleSeconds}s before closing the install window");
StartSettleTimer();
}
}
@@ -121,7 +121,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Office
}
_watchedKey = ancestor;
_mode = WatchMode.Bootstrap;
_logger.Debug($"[RegistryChangeWatcher] target HKLM\\{_targetSubKey} absent — bootstrap-watching HKLM\\{ancestorPath} (name-only)");
_logger.Debug($"[RegistryChangeWatcher] target HKLM\\{_targetSubKey} absent — bootstrap-watching HKLM\\{ancestorPath} (name-only)", repeatKey: "RegistryChangeWatcher.bootstrap:" + _targetSubKey);
if (!ArmNotify(subtree: false, BootstrapFilter)) return;
// TOCTOU: the target may have been created between TryOpen and arming the ancestor watch.
@@ -127,7 +127,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Process metrics read failed: {ex.Message}");
Logger.Debug($"Process metrics read failed: {ex.Message}", repeatKey: "AgentSelfMetricsCollector.process");
}
// --- Spool stats (P2 telemetry) ---
@@ -155,7 +155,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Spool metrics read failed: {ex.Message}");
Logger.Debug($"Spool metrics read failed: {ex.Message}", repeatKey: "AgentSelfMetricsCollector.spool");
}
}
@@ -186,7 +186,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Network metrics read failed: {ex.Message}");
Logger.Debug($"Network metrics read failed: {ex.Message}", repeatKey: "AgentSelfMetricsCollector.network");
}
// --- IME log tracker health ---
@@ -224,7 +224,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"IME tracker health read failed: {ex.Message}");
Logger.Debug($"IME tracker health read failed: {ex.Message}", repeatKey: "AgentSelfMetricsCollector.imeTracker");
}
}
@@ -262,7 +262,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Signal pipeline health read failed: {ex.Message}");
Logger.Debug($"Signal pipeline health read failed: {ex.Message}", repeatKey: "AgentSelfMetricsCollector.signalPipeline");
}
}
@@ -153,7 +153,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
{
if (_permanentlyDisabled || !_dormant) return;
_dormant = false;
Logger.Info("[DeliveryOptimizationCollector] Waking up — download activity detected");
Logger.Debug("[DeliveryOptimizationCollector] Waking up — download activity detected");
ResumeTimer();
}
@@ -167,7 +167,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
_officeActive = active;
if (active)
{
Logger.Info("[DeliveryOptimizationCollector] Office install active — sampling DO for Office CDN jobs");
Logger.Debug("[DeliveryOptimizationCollector] Office install active — sampling DO for Office CDN jobs");
WakeUp();
}
}
@@ -243,7 +243,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
if (!hasActiveDownloads && !hasPendingEnrichment && !officeKeepAwake)
{
Logger.Info("[DeliveryOptimizationCollector] Going dormant — no active downloads, pending enrichment or Office install");
Logger.Debug("[DeliveryOptimizationCollector] Going dormant — no active downloads, pending enrichment or Office install");
_dormant = true;
PauseTimer();
// Natural persistence point: all downloads are done — which is exactly when an
@@ -278,7 +278,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
{
_runspace = RunspaceFactory.CreateRunspace();
_runspace.Open();
Logger.Info("[DeliveryOptimizationCollector] PowerShell Runspace opened");
Logger.Debug("[DeliveryOptimizationCollector] PowerShell Runspace opened");
}
catch (Exception ex)
{
@@ -343,7 +343,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
_permanentlyDisabled = true;
return null;
}
Logger.Debug($"[DeliveryOptimizationCollector] PS error stream: {firstError}");
Logger.Debug($"[DeliveryOptimizationCollector] PS error stream: {firstError}", repeatKey: "DeliveryOptimizationCollector.psError");
}
return results;
@@ -386,7 +386,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
{
if (results.Count == 0)
{
Logger.Verbose("[DeliveryOptimizationCollector] No DO entries returned");
Logger.Trace("[DeliveryOptimizationCollector] No DO entries returned");
return;
}
@@ -568,8 +568,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
WriteToLogFile(logEntries);
}
Logger.Verbose($"[DeliveryOptimizationCollector] Poll: {results.Count} entries, " +
$"{progressCount} progress updates, {matchCount} new matches ({_enrichedAppIds.Count} total enriched)");
var pollSummary = $"[DeliveryOptimizationCollector] Poll: {results.Count} entries, " +
$"{progressCount} progress updates, {matchCount} new matches ({_enrichedAppIds.Count} total enriched)";
// A poll that found nothing new is a tick (Trace); one with progress or matches is content.
if (progressCount > 0 || matchCount > 0) Logger.Verbose(pollSummary);
else Logger.Trace(pollSummary);
}
// Office C2R content CDN hosts — version-independent (a FileId build marker like "_16_0_" would
@@ -80,6 +80,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
public void Stop()
{
// Hosts call Stop and then Dispose, which stops again; only a started detector logs.
var wasRunning = _connectivityCheckClient != null;
NetworkChange.NetworkAddressChanged -= OnNetworkAddressChanged;
lock (_stateLock)
@@ -91,7 +93,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
_connectivityCheckClient?.Dispose();
_connectivityCheckClient = null;
_logger.Info("NetworkChangeDetector: stopped");
if (wasRunning) _logger.Info("NetworkChangeDetector: stopped");
}
public void Dispose()
@@ -123,7 +123,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"CPU counter read failed: {ex.Message}");
Logger.Debug($"CPU counter read failed: {ex.Message}", repeatKey: "PerformanceCollector.cpu");
}
// Memory info via GlobalMemoryStatusEx (kernel32)
@@ -138,12 +138,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
else
{
Logger.Debug("GlobalMemoryStatusEx returned no data");
Logger.Debug("GlobalMemoryStatusEx returned no data", repeatKey: "PerformanceCollector.memoryNoData");
}
}
catch (Exception ex)
{
Logger.Debug($"Memory query failed: {ex.Message}");
Logger.Debug($"Memory query failed: {ex.Message}", repeatKey: "PerformanceCollector.memory");
}
// Disk queue length
@@ -154,7 +154,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Disk queue counter read failed: {ex.Message}");
Logger.Debug($"Disk queue counter read failed: {ex.Message}", repeatKey: "PerformanceCollector.diskQueue");
}
// Disk free space on system drive
@@ -181,7 +181,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Disk space query failed: {ex.Message}");
Logger.Debug($"Disk space query failed: {ex.Message}", repeatKey: "PerformanceCollector.diskSpace");
}
// Network throughput (bytes sent/received delta + rate)
@@ -271,7 +271,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Periodic
}
catch (Exception ex)
{
Logger.Debug($"Network throughput collection failed: {ex.Message}");
Logger.Debug($"Network throughput collection failed: {ex.Message}", repeatKey: "PerformanceCollector.network");
}
if (data.Count > 0)
@@ -174,7 +174,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Telemetry.Security
lock (_lock) { _startWatcher = null; }
// Surface the dead live detector so the backend can distinguish it from a clean run.
var handler = WatcherArmFailed;
try { handler?.Invoke(this, ex); } catch { /* never throw from Start */ }
try { handler?.Invoke(this, ex); }
catch (Exception handlerEx)
{
// Never throw from Start.
_logger.Warning($"[ConsoleBypassWatcher] WatcherArmFailed handler threw: {handlerEx.Message}");
}
}
// 2) Startup probe — catch a console already open before the watcher armed. Win32_Process
@@ -93,7 +93,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Transport
attempt.PrimaryError = error;
// Retry ipinfo.io once after a short delay (network may still be initializing during Autopilot)
logger?.Info($"GeoLocation: Retrying ipinfo.io after {RetryDelay.TotalSeconds}s...");
logger?.Debug($"GeoLocation: Retrying ipinfo.io after {RetryDelay.TotalSeconds}s...");
await Task.Delay(RetryDelay);
(result, error) = await TryProvider("ipinfo.io", IpInfoUrl, ParseIpInfo, logger);
@@ -131,7 +131,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Transport
{
try
{
logger?.Info($"GeoLocation: Querying {name}...");
logger?.Debug($"GeoLocation: Querying {name}...");
using (var httpResponse = await SharedHttpClient.GetAsync(url))
{
@@ -29,7 +29,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Transport
try
{
logger.Info($"NTP time check: querying {ntpServer}");
logger.Debug($"NTP time check: querying {ntpServer}");
// NTP request packet: 48 bytes, first byte = 0x1B (LI=0, VN=3, Mode=3)
var ntpData = new byte[48];
@@ -47,7 +47,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Transport
}
// Execute tzutil /s to set the timezone
logger.Info($"Timezone auto-set: setting timezone to {windowsId} (IANA: {ianaTimezone}, previous: {result.PreviousTimezone})");
logger.Debug($"Timezone auto-set: setting timezone to {windowsId} (IANA: {ianaTimezone}, previous: {result.PreviousTimezone})");
var psi = new ProcessStartInfo
{
@@ -190,7 +190,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
if (_transitionEmitter != null)
{
try { _transitionEmitter.Emit(step.Transition); }
catch { /* best-effort upload; local state already consistent */ }
catch (Exception ex)
{
// Best-effort upload; the local journal already holds the transition.
_logger.Debug($"DecisionStepProcessor: transition not handed to the upload spool: {ex.Message}", repeatKey: "DecisionStepProcessor.transitionEmit");
}
}
// 2) EffectRunner — Async-Methode vom Ingress-Worker-Thread sync ausführen.
@@ -271,21 +275,28 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
_currentState = step.NewState;
_consecutiveJournalFailures = 0;
// PR3-D1: per-step observability. Stage transitions and effect-bearing steps fire
// at DEBUG (operator-relevant); pure no-op steps (Stage unchanged + no effects)
// fire at VERBOSE so a steady stream of e.g. ClassifierTick + InformationalEvent
// pass-throughs doesn't drown the log.
// PR3-D1: per-step observability. A stage change is the enrollment flow (Info); other
// effect-bearing steps and dead ends are decision detail (Debug); InformationalEvent
// pass-throughs, the self-re-arming classifier tick and no-op steps are mechanics
// (Trace). The journal keeps every step either way.
var newStage = step.NewState.Stage;
if (previousStage != newStage || step.Effects.Count > 0)
{
_logger.Debug(
var line =
$"DecisionStep: ord={signal.SessionSignalOrdinal} kind={signal.Kind} " +
$"stage={previousStage}->{newStage} effects=[{string.Join(",", step.Effects.Select(e => e.Kind))}] " +
$"abort={effectResult.SessionMustAbort} failures={effectResult.Failures.Count}");
$"abort={effectResult.SessionMustAbort} failures={effectResult.Failures.Count}";
if (previousStage != newStage) _logger.Info(line);
else if (IsRoutineStep(signal, effectResult)) _logger.Trace(line);
else _logger.Debug(line);
}
else if (step.Transition.DeadEndReason != null)
{
_logger.Debug($"DecisionStep: ord={signal.SessionSignalOrdinal} kind={signal.Kind} stage={previousStage} dead end ({step.Transition.DeadEndReason})");
}
else
{
_logger.Verbose($"DecisionStep: ord={signal.SessionSignalOrdinal} kind={signal.Kind} stage={previousStage} (no-op)");
_logger.Trace($"DecisionStep: ord={signal.SessionSignalOrdinal} kind={signal.Kind} stage={previousStage} (no-op)");
}
// 5) Terminal-stage detection (M4.6.β). Fires exactly once per agent run when the
@@ -505,6 +516,21 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
return _passThroughStepsSinceSnapshot >= SnapshotPassThroughFloor;
}
/// <summary>
/// A step that runs for every informational event, or for the classifier tick that re-arms
/// itself every 30 s, without changing the stage. Decided by the signal, not the effect:
/// real decisions emit timeline entries too. A failed effect run is never routine.
/// </summary>
private static bool IsRoutineStep(DecisionSignal signal, EffectRunResult effectResult)
{
if (effectResult.SessionMustAbort || effectResult.Failures.Count > 0) return false;
if (signal.Kind == DecisionSignalKind.InformationalEvent) return true;
return signal.Kind == DecisionSignalKind.DeadlineFired
&& signal.Payload != null
&& signal.Payload.TryGetValue(SignalPayloadKeys.Deadline, out var deadline)
&& string.Equals(deadline, DeadlineNames.ClassifierTick, StringComparison.Ordinal);
}
private void TryTriggerQuarantine(string reason)
{
try
@@ -517,6 +517,24 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
startupGate: _startupEventGate));
}
// ConfigMgr client presence (the V1 check) — opt-in per tenant (portal toggle →
// AnalyzerConfiguration.EnableConfigMgrWatcher, default off). When off, the host is
// never created, so devices of other tenants run no check at all.
if (analyzers.EnableConfigMgrWatcher)
{
hosts.Add(new ConfigMgrClientHost(
sessionId: sessionId,
tenantId: tenantId,
logger: logger,
ingress: ingress,
clock: clock,
startupGate: _startupEventGate));
}
else
{
logger.Info("DefaultComponentFactory: ConfigMgrClientHost not created (EnableConfigMgrWatcher=false)");
}
// Registry second pillar (audit 2026-08-17): IME's authoritative per-app state from
// HKLM\...\IntuneManagementExtension (Win32Apps EnforcementStateMessage,
// EspTrackingWin32Apps, StatusServiceReports) via snapshot-and-diff. Emits
@@ -206,7 +206,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
!string.IsNullOrEmpty(lastVerdictId) &&
snapshotHash == lastVerdictId)
{
_logger?.Debug(
_logger?.Trace(
$"EffectRunner: classifier {effect.ClassifierId} skipped (snapshotHash unchanged: {ShortHash(snapshotHash)})");
return new ClassifierEffectOutcome(invoked: false, skippedByAntiLoop: true, failure: null);
}
@@ -456,7 +456,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
// (eventType, phase) here. Fed to the collector-host factory at step 14 so gather-rule
// phase_change/on_event triggers key off the ENGINE-REDUCED timeline (RealmJoin gate
// et al. respected) instead of raw pre-reduce signals — see TimelineEventStream doc.
_timelineEvents = new TimelineEventStream();
_timelineEvents = new TimelineEventStream(_logger);
_timelineEmitter = new EventTimelineEmitter(eventEmitter, _timelineEvents);
_backPressureObserver = new BackPressureEventObserver(eventEmitter, _clock);
@@ -836,7 +836,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
}),
payload: payload);
_logger.Info(
_logger.Debug(
$"EnrollmentOrchestrator: EspConfigDetected bootstrap posted (SkipUser={snapshot.SkipUser?.ToString() ?? "unknown"}, SkipDevice={snapshot.SkipDevice?.ToString() ?? "unknown"}, AllowContinueAnyway={snapshot.AllowContinueAnyway?.ToString() ?? "unknown"}, SyncFailureTimeoutMinutes={snapshot.SyncFailureTimeoutMinutes?.ToString() ?? "unknown"}).");
}
catch (Exception ex)
@@ -33,7 +33,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
Func<bool>? isHybridJoinProbe = null)
{
_watcher = new AadJoinWatcher(logger);
_adapter = new AadJoinWatcherAdapter(_watcher, ingress, clock, onRealUserJoined: onRealUserJoined);
_adapter = new AadJoinWatcherAdapter(_watcher, ingress, clock, onRealUserJoined: onRealUserJoined, logger: logger);
var post = new InformationalEventPost(ingress, clock);
_hybridLoginPendingDetector = new HybridLoginPendingDetector(
watcher: _watcher,
@@ -50,7 +50,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
{
if (Interlocked.Exchange(ref _fired, 1) == 1)
{
_logger.Info("AutoLogonDeviceSetupTrigger: duplicate DeviceSetupProvisioningComplete ignored (already fired)");
_logger.Debug("AutoLogonDeviceSetupTrigger: duplicate DeviceSetupProvisioningComplete ignored (already fired)");
return;
}

Some files were not shown because too many files have changed in this diff Show More