fix(security): IME log-pattern pack is anchored and linear (all 90 patterns start with ^, IME-APP-VERSION spells the report-delta JSON out instead of a chained [^}]*? scan) and the ImeLogTracker read loop is bounded — BoundedLineReader (32 MB per line, evidence: real 5.6 MB "Get policies" lines; exact byte bookmarks, no decoder read-ahead loss on cancel), 2 s per-line matching budget across all patterns, held-back unterminated EOF tails (≤1 MB, 1 s settle) instead of dropping them and raw-matching fragments, a complete entry after a dropped one is no longer swallowed as its close, one Warning per pass (oversizedLines/regexTimeouts/lineBudgetBreaks) instead of silent Debug timeouts; unanchored PS-SCRIPT-CONTEXT false positives on [Win32App] SideCarScript… lines (which overwrote the pending platform script's RunContext) are gone; --run-ime-matching assembles multiline entries like the tracker

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-08-30 14:03:50 +02:00
parent f432353efa
commit 09492e908c
103 changed files with 1478 additions and 278 deletions
@@ -0,0 +1,116 @@
---
type: concept
title: IME Log Tracker — Anchored Patterns and the Bounded Read Loop
description: Why every shipped IME log pattern starts with '^', why the on-device matcher reads lines through a byte-bounded reader with a per-line matching budget, and what an operator sees when a hostile log file is tailed — the IME Logs folder is writable by standard users and the SYSTEM tracker must stay linear on whatever lands there.
resource: src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime
tags: [agent, ime, regex, redos, log-tracker, reliability, security]
timestamp: 2026-08-30
---
# Problem
`ImeLogTracker` tails every file in `%ProgramData%\Microsoft\IntuneManagementExtension\Logs`
whose name matches the IME log families and matches each entry against every active pattern of
the shipped pack (`rules/ime-log-patterns/*.json` → `rules/dist/ime-log-patterns.json`, embedded
in agent and backend, delivered live through the config channel). That folder is writable by a
standard user, so the input is untrusted: anyone signed in during enrollment can append lines.
Before 2026-08-30 three things multiplied:
* **Unanchored patterns with unbounded lazy gaps.** `\[Win32App\]\[EspManager\] … registered.*?App name: (?<name>.*?)$`
re-scans its `.*?` tail at every offset where the literal prefix occurs; repeating the prefix
*m* times in one line of *n* chars costs O(m·n). `IME-APP-VERSION` chained two lazy scans
(`.*?"DetectedIdentityVersion":\{[^}]*?"NewValue"`) and was quadratic even when anchored.
* **Per-pattern timeout, no per-line budget.** Each regex had a 1 s timeout, the timeout was
swallowed at Debug, and the loop tried all ~80 active patterns for every line — one crafted
line concatenating several trigger prefixes cost several seconds of SYSTEM CPU.
* **Unbounded line length.** `StreamReader.ReadLineAsync` materializes the whole line before
anyone can look at its size; a multi-hundred-MB line is an OutOfMemory in the poll loop, which
retries from the same bookmark every second.
Genuine IME decision signals (app failures, enforcement states, ESP phases, user-session
completion) queue behind that work — a monitoring blackout during the enrollment window.
# Design
## Anchored, linear pattern pack
* **Every shipped pattern starts with `^`.** The tracker compiles with
`IgnoreCase | Compiled | Singleline` and no `Multiline`, so `^` is the start of the matched
string — `CmTraceLogEntry.Message`, i.e. the text after `<![LOG[` (for multiline entries the
assembled entry, still offset 0). .NET treats a leading `^` as a beginning anchor: a
non-matching pattern costs O(prefix), never a scan. Evidence for the invariant: across eight
real diagnostics sets (~9,000 entries, all six log families) every match of the old pack began
at offset 0 — except one class of mid-line hits that were false positives (below).
* **No chained unbounded scans.** `IME-APP-VERSION` now spells the report-delta JSON out
(`\{(?:"OldValue":[^,}]{0,64},)?"NewValue":"`) instead of scanning `[^}]*?` at every
occurrence. The test `ImeLogPatternPackLinearityTests` rejects `[^x]*` shapes outright.
* **Raw lines.** A line that fails CMTrace parsing (orphaned continuation lines, lines after a
dropped entry) is still matched raw; with `^` it matches only if it *begins* with the pattern.
Field data: the unanchored `PS-SCRIPT-CONTEXT` fired 122 times on
`[Win32App] SideCarScriptDetectionManager Launch powershell executor in machine session`
(Win32 detection scripts in AppWorkload.log), each time overwriting the pending *platform*
script's `RunContext`. Anchoring removed that contamination; it is asserted by test.
* **Custom patterns are not rewritten.** Tenant-authored patterns (and cached pre-anchor
configs) keep their semantics; `CompilePatterns` names the enabled patterns without `^` once
at Info so a pass summary's budget breaks can be attributed.
## Bounded read loop (`CheckLogFilesAsync`)
* **`BoundedLineReader`** replaces `StreamReader`: byte-oriented, splits on `\n`, strips one
`\r`, decodes UTF-8 per line, honours a BOM only at absolute file offset 0. A line beyond
`MaxEntryBytes` (32 MB) is never materialized — the reader keeps the capped prefix, discards
the rest while scanning for the terminator and flags `LastLineTruncated`. Its `Position` is
the exact offset of the next unread byte, so bookmarks are exact (the StreamReader's decoder
read-ahead used to lose up to a buffer of lines on a cancelled pass).
* **Why 32 MB.** Real logs carry single lines of ~110 KB routinely
(`IntuneManagementExtension.log` policy dumps) and one large tenant's `AppWorkload.log`
writes a 5.6 MB `Get policies = […]` line that `IME-POLICIES` legitimately captures (app
names for the dashboard). A "few KB" cap would drop genuine entries; with anchored patterns
the CPU cost of a large line is O(n) for the handful of patterns whose prefix matches, so the
cap only has to bound memory. The same constant caps an assembled multiline entry.
* **Oversized lines are dropped, not matched.** Captures on a cut line would be wrong. If the
capped prefix opens a CMTrace entry without closing it, the existing `skippingDroppedEntry`
mechanism skips the entry's continuation lines instead of raw-matching them; a line that
opens a *new* entry always ends the skip and is processed itself.
* **Per-line matching budget.** `MatchLine` runs all active patterns under a 2 s Stopwatch
budget; a pattern that times out is skipped and counted, and once the budget is spent the
remaining patterns are skipped for that line (matches already handled stand). No genuine line
comes near it — the budget exists for unanchored custom patterns and hostile input.
* **Held-back tails.** An unterminated tail at EOF (a physical line without `\n`, or a
multiline entry without `]LOG]!>`) is normally the writer mid-write. Instead of dropping it
(and raw-matching its remainder next pass) the bookmark stays at the entry start. The hold
lasts until the entry completes or the file has stood still for `HeldTailSettle` (1 s), and
only for tails up to 1 MB — a never-closing hostile tail costs a handful of re-reads, then is
processed as-is and the bookmark advances.
* **One Warning per pass and file.** `oversizedLines`, `regexTimeouts`, `lineBudgetBreaks` and
the first skipped pattern ID are logged in a single line after the pass when any is non-zero
(fail-soft with a trace); the first timeout per pattern per process additionally names the
pattern at Debug. No per-line logging, so a hostile file cannot flood the agent log.
* **Deliberately not done: per-file preemption.** The first pass over a legitimate
`AppWorkload.log` can be hundreds of MB and runs in one pass by design; after the changes
above the work per byte is linear and small, so a writer can only delay processing in
proportion to the bytes it writes.
# Verification
* `ImeLogPatternPackLinearityTests` loads the shipped pack, asserts the `^` invariant, runs four
hostile constructions (repeated prefix, the reported `"DetectedIdentityVersion":{x`
repetition, long word runs, prefix+keywords with newlines; 512 KB each) against every pattern
with the agent's exact regex options and fails on a timeout or > 150 ms (best of three),
and re-matches representative real lines with their captures.
* `BoundedLineReaderTests`, `ImeLogTrackerReadLoopHardeningTests` (oversized single line,
oversized multiline opener, held-back tail, settle, cancelled pass bookmark, single Warning).
* Parity: the old and new packs were run over eight real diagnostics sets with the tracker's
assembly semantics; the match sets are identical apart from the removed `PS-SCRIPT-CONTEXT`
false positives. `--run-ime-matching` (the agent's offline matcher) now assembles multiline
entries like the tracker so it reproduces the same result.
# Citations
* `src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.LogProcessing.cs` — `CheckLogFilesAsync`, `MatchLine`, `HoldBackTail`
* `src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/BoundedLineReader.cs`
* `src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs` — `MaxEntryBytes`, `HeldTailSettle`, `CompilePatterns`
* `rules/ime-log-patterns/*.json`, `rules/scripts/combine.js`
* `src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/Ime/ImeLogPatternPackLinearityTests.cs`
* [CMTrace Time Resolution](cmtrace-time-resolution.md) — the linear CMTrace line parser this loop feeds
+1
View File
@@ -29,6 +29,7 @@ https://docs.autopilotmonitor.com (separate repository).
* [Secure Boot CA-2023 Detection](agent/secureboot-ca2023-detection.md) - Why ANALYZE-SEC-001 v3 reads the UEFI db/KEK variables directly instead of trusting the SecureBoot\Servicing registry, and how the one-sided uefiCa2023FirmwareConfirmed marker plus a not_exists precondition give absence-tolerant suppression across old and new agents.
* [Continue-Anyway Observation Mode](agent/continue-anyway-observation.md) - EnableEspContinueAnywayObservation (ConfigVersion 37, operator-set): Device-phase ESP terminal failures on Continue-Anyway profiles get a bounded 60-min observation instead of an immediate hard fail; the DAD-validated real-user desktop + Hello gate detect the true end, the session completes Succeeded + EspSoftFailure (amber "with issues" badge), expiry un-defangs to the original esp_terminal_failure.
* [CMTrace Time Resolution](agent/cmtrace-time-resolution.md) - Converting bias-less CMTrace local times to UTC without trusting any process's timezone belief: per-line self-anchoring on the 15-minute offset grid for provably fresh lines, uniform marked reader-zone fallback for backlog, and the provenance vocabulary (bias / line-anchored / reader-zone-fallback) that keeps every event re-derivable; plus the linear-cost CMTrace line parser (first open / last parseable trailer, timeout-backed) and the agent multiline caps.
* [IME Log Tracker — Anchored Patterns and the Bounded Read Loop](agent/ime-log-tracker-matching-budget.md) - The IME Logs folder is user-writable, so the SYSTEM tracker must stay linear on hostile input: every shipped pattern starts with `^` (a non-match is O(prefix)), no chained unbounded scans, a byte-bounded line reader (32 MB — real `Get policies` lines reach 5.6 MB) with exact bookmarks, a 2 s per-line matching budget, held-back unterminated tails, and one Warning per pass instead of silent Debug timeouts.
* [Registry App-State Second Pillar](agent/registry-app-state-pillar.md) - IME's authoritative per-app state read straight from the registry (Win32Apps EnforcementStateMessage, EspTrackingWin32Apps, StatusServiceReports) via a snapshot-and-diff watcher; registry/log reconciliation doubles as the built-in IME log-pattern drift alarm.
* [WDP Scenario Gates & Completion Backstop](agent/wdp-scenario-gates.md) - How the agent gates Autopilot/ESP-only machinery off on Windows Device Preparation sessions (deterministic ExecutionContext marker, fail-toward-Classic), which noise it suppresses (ZTD probe, esp_config unknown, ModernDeployment 100/417/418/1005, starved sweep), and the WDP completion model: High-confidence seed, desktop-based arm D, and the 30-min device_prep_completion backstop.
* [Local Admin Analyzer](agent/local-admin-analyzer.md) - What local_admin_analysis asserts at enrollment start/end: every local account inventoried, disabled ones included (a /active:no backdoor is dormant at both scans), Administrators membership read from the SAM by well-known SID (NetLocalGroupGetMembers, WMI-independent), unexpected admin members scored +40, built-ins matched by well-known RID (localized Guest/Administrator never flagged), shutdown-time dynamic allowance never covers a local SAM account (CWE-807), junctions and $GUID folders are not profiles, non-local members (Entra role SIDs) listed but never flagged, built-in Administrator enabled-state reported but not scored.
+4
View File
@@ -1,5 +1,9 @@
# Log
## 2026-08-30 (7)
* **New**: `agent/ime-log-tracker-matching-budget.md` — the shipped IME pattern pack is anchored (`^` on all 90 patterns, `IME-APP-VERSION` without the chained `[^}]*?` scan) and the tracker's read loop is bounded: `BoundedLineReader` (32 MB per line, exact byte bookmarks), 2 s per-line matching budget, held-back unterminated EOF tails with a 1 s settle, one Warning per pass (`oversizedLines` / `regexTimeouts` / `lineBudgetBreaks`); the unanchored `PS-SCRIPT-CONTEXT` false positives on `[Win32App] SideCarScript…` lines are gone. `--run-ime-matching` assembles multiline entries like the tracker. Registered in `index.md`.
## 2026-08-30 (6)
* **Update**: `rules/rule-id-namespace.md` — guard 1 rewritten: gather RuleStats (tenant + `global_*` rows) are now resolved against the tenant's active gather catalog (`EventIngestProcessor.ResolveFiredGatherRules`), metadata catalog-sourced, unknown IDs dropped — same design as the analyze path; the `IsReservedBuiltInId` pattern gate on device-supplied IDs is gone.
+90 -90
View File
@@ -4,7 +4,7 @@
{
"patternId": "HS-COMPLIANCE",
"category": "always",
"pattern": "\\[HS\\] the (?<part>pre|post)-rem(?:e)?diation detection script compliance result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"pattern": "^\\[HS\\] the (?<part>pre|post)-rem(?:e)?diation detection script compliance result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"action": "healthScriptDetectionResult",
"parameters": {
"scriptType": "remediation"
@@ -15,7 +15,7 @@
{
"patternId": "HS-COMPLIANCE-POST",
"category": "always",
"pattern": "\\[HS\\] the (?<part>post) detection script result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"pattern": "^\\[HS\\] the (?<part>post) detection script result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"action": "healthScriptDetectionResult",
"parameters": {
"scriptType": "remediation"
@@ -26,7 +26,7 @@
{
"patternId": "HS-EXITCODE",
"category": "always",
"pattern": "\\[HS\\] exit code of the script is (?<exitCode>-?\\d+)",
"pattern": "^\\[HS\\] exit code of the script is (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"parameters": {
"scriptType": "remediation"
@@ -37,7 +37,7 @@
{
"patternId": "HS-NEW-RESULT",
"category": "always",
"pattern": "\\[HS\\] new result = (?<json>\\{[\\s\\S]*\\})\\s*$",
"pattern": "^\\[HS\\] new result = (?<json>\\{[\\s\\S]*\\})\\s*$",
"action": "healthScriptResult",
"parameters": {
"scriptType": "remediation"
@@ -48,7 +48,7 @@
{
"patternId": "HS-RUN-CONTEXT",
"category": "always",
"pattern": "\\[HS\\] The policy needs be run as (?<context>System|User)",
"pattern": "^\\[HS\\] The policy needs be run as (?<context>System|User)",
"action": "scriptContext",
"parameters": {
"scriptType": "remediation"
@@ -59,7 +59,7 @@
{
"patternId": "HS-SCRIPT-START",
"category": "always",
"pattern": "\\[HS\\] ProcessScript PolicyId: (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) PolicyType: (?<policyType>\\d+)",
"pattern": "^\\[HS\\] ProcessScript PolicyId: (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) PolicyType: (?<policyType>\\d+)",
"action": "scriptStarted",
"parameters": {
"scriptType": "remediation"
@@ -70,7 +70,7 @@
{
"patternId": "HS-STDERR",
"category": "always",
"pattern": "\\[HS\\] err output = (?<output>.*)",
"pattern": "^\\[HS\\] err output = (?<output>.*)",
"action": "scriptOutput",
"parameters": {
"scriptType": "remediation",
@@ -82,7 +82,7 @@
{
"patternId": "HS-STDOUT",
"category": "always",
"pattern": "\\[HS\\] std output = (?<output>.*)",
"pattern": "^\\[HS\\] std output = (?<output>.*)",
"action": "scriptOutput",
"parameters": {
"scriptType": "remediation",
@@ -94,7 +94,7 @@
{
"patternId": "IME-AGENT-VERSION",
"category": "always",
"pattern": "Agent version is: (?<agentVersion>[\\d.]+)",
"pattern": "^Agent version is: (?<agentVersion>[\\d.]+)",
"action": "imeAgentVersion",
"description": "Captures the Intune Management Extension agent version number.",
"enabled": true
@@ -102,7 +102,7 @@
{
"patternId": "IME-ALREADY-DETECTED-1",
"category": "otherPhases",
"pattern": "\\[Win32App\\] Completed detectionManager SideCar\\w+?DetectionManager, applicationDetectedByCurrentRule: True",
"pattern": "^\\[Win32App\\] Completed detectionManager SideCar\\w+?DetectionManager, applicationDetectedByCurrentRule: True",
"action": "ignoreCompletedApp",
"description": "Detects when an app from a previous ESP phase is detected as already installed, so it should be ignored in the current phase.",
"enabled": true
@@ -110,7 +110,7 @@
{
"patternId": "IME-ALREADY-DETECTED-2",
"category": "otherPhases",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"action": "ignoreCompletedApp",
"description": "Detects enforcement success in a non-current phase, indicating an app completed in a previous phase should be ignored.",
"enabled": true
@@ -118,7 +118,7 @@
{
"patternId": "IME-APP-TYPE-MSI",
"category": "always",
"pattern": "\\[Win32App\\].*?\\bMSI App (?<id>{GUID})",
"pattern": "^\\[Win32App\\].*?\\bMSI App (?<id>{GUID})",
"action": "captureAppTypeMsi",
"description": "Detects an MSI-based Win32 app via the 'MSI App <guid>' phrase in the ESP retry configuration line. Marks AppType as 'MSI' for that app id.",
"enabled": true
@@ -126,7 +126,7 @@
{
"patternId": "IME-APP-TYPE-WINGET",
"category": "always",
"pattern": "\\[Win32App\\]\\[WinGetApp\\].*?app with id: (?<id>{GUID})",
"pattern": "^\\[Win32App\\]\\[WinGetApp\\].*?app with id: (?<id>{GUID})",
"action": "captureAppTypeWinGet",
"description": "Detects a WinGet-backed Store app by any [Win32App][WinGetApp] handler log line (Detection/Applicability/Operation). Marks AppType as 'WinGet' for that app id.",
"enabled": true
@@ -134,7 +134,7 @@
{
"patternId": "IME-APP-VERSION",
"category": "always",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: (?<id>{GUID}).*?\"DetectedIdentityVersion\":\\{[^}]*?\"NewValue\":\"(?<appVersion>[^\"]+)\"",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: (?<id>{GUID}).*?\"DetectedIdentityVersion\":\\{(?:\"OldValue\":[^,}]{0,64},)?\"NewValue\":\"(?<appVersion>[^\"]+)\"",
"action": "captureAppVersion",
"description": "Captures the product version IME detected after an app install (e.g. \"11.2.1787.0\"). Source: [ReportingManager] Detection state update with DetectedIdentityVersion.NewValue. Used by App Dashboard to show version-level failure breakdowns.",
"enabled": true
@@ -142,7 +142,7 @@
{
"patternId": "IME-ATTEMPT-NUMBER",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ===Step=== Execute retry (?<attempt>\\d+)$",
"pattern": "^\\[Win32App\\] ===Step=== Execute retry (?<attempt>\\d+)$",
"action": "captureAttemptNumber",
"parameters": {
"useCurrentApp": "true"
@@ -153,7 +153,7 @@
{
"patternId": "IME-CACHE-MISS",
"category": "always",
"pattern": "\\[Win32App\\] Content cache miss for app \\(id = {GUID}, name = (?<name>.*?)\\), start downloading",
"pattern": "^\\[Win32App\\] Content cache miss for app \\(id = {GUID}, name = (?<name>.*?)\\), start downloading",
"action": "updateName",
"description": "Captures 'Content cache miss for app (id = <guid>, name = <name>), start downloading...' (ContentManager.cs) as a secondary app-name source. Fires right before a real download begins, so it resolves names for exactly the apps that will produce download/install activity — a redundancy for IME-POLICIES-based naming after IME retired the old name-bearing processing lines.",
"enabled": true
@@ -161,7 +161,7 @@
{
"patternId": "IME-DECRYPT-FAILED",
"category": "currentPhase",
"pattern": "Decryption is failed for appId {GUID}",
"pattern": "^Decryption is failed for appId {GUID}",
"action": "updateStateError",
"description": "Detects when app content decryption fails, indicating a corrupted or tampered download.",
"enabled": true
@@ -169,7 +169,7 @@
{
"patternId": "IME-DETECTED-INSTALLED-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DetectionState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}Installed\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DetectionState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}Installed\"{1,2}",
"action": "updateStateInstalled",
"description": "Detects when an app's detection state transitions to Installed (new ReportingManager format). 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.",
"enabled": true
@@ -177,7 +177,7 @@
{
"patternId": "IME-DETECTED-INSTALLED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: {GUID} resulted in action status: Success and detection state: Detected",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: {GUID} resulted in action status: Success and detection state: Detected",
"action": "updateStateInstalled",
"description": "Detects when an app's detection action handler reports successful detection (app is installed).",
"enabled": true
@@ -185,7 +185,7 @@
{
"patternId": "IME-DETECTED-OLD",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID} ",
"pattern": "^\\[Win32App\\] Detected app {GUID} ",
"action": "updateStateInstalled",
"description": "Detects when an app is detected as installed (old log format). DISABLED 2026-08-17: the standalone 'Detected app <guid> ' line no longer exists in IME 1.97.107; this regex instead matched the 'Detected app ... and intent is to install, skip applicability check' line, colliding with IME-SKIP-INSTALL-DETECTED and firing updateStateInstalled and updateStateSkipped on the same physical line (see tasks/ime-v1-code-audit-2026-08-17.md).",
"enabled": false
@@ -193,7 +193,7 @@
{
"patternId": "IME-DETECTION-RESULT",
"category": "always",
"pattern": "\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: (?<id>{GUID}) resulted in action status: Success and detection state: (?<detection>DetectedDifferentVersion|NotDetected|Detected)",
"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.",
"enabled": true
@@ -201,7 +201,7 @@
{
"patternId": "IME-DO-TEL",
"category": "currentPhase",
"pattern": "\\[DO TEL\\] = (?<doTelJson>\\{.*\\})",
"pattern": "^\\[DO TEL\\] = (?<doTelJson>\\{.*\\})",
"action": "updateDoTelemetry",
"description": "Captures Delivery Optimization telemetry JSON after a DO download completes. Contains file size, peer caching stats, download mode, and duration.",
"enabled": true
@@ -209,7 +209,7 @@
{
"patternId": "IME-DO-TIMEOUT-1",
"category": "currentPhase",
"pattern": "\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b).*?intunewin-bin_{GUID}",
"pattern": "^\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b).*?intunewin-bin_{GUID}",
"action": "updateStatePostponed",
"description": "Detects when a Delivery Optimization download times out for a specific app (identified by GUID in filename).",
"enabled": true
@@ -217,7 +217,7 @@
{
"patternId": "IME-DO-TIMEOUT-2",
"category": "currentPhase",
"pattern": "\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b)",
"pattern": "^\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b)",
"action": "updateStatePostponed",
"parameters": {
"useCurrentApp": "true"
@@ -228,7 +228,7 @@
{
"patternId": "IME-DOWNLOADING",
"category": "currentPhase",
"pattern": "\\[StatusService\\] Downloading app \\(id = {GUID}.*?\\) via (?<tech>\\w+), bytes (?<bytes>\\w+)/(?<ofbytes>\\w+) for user",
"pattern": "^\\[StatusService\\] Downloading app \\(id = {GUID}.*?\\) via (?<tech>\\w+), bytes (?<bytes>\\w+)/(?<ofbytes>\\w+) for user",
"action": "updateStateDownloading",
"description": "Captures app download progress including technology (DO/CDN), bytes downloaded, and total bytes.",
"enabled": true
@@ -236,7 +236,7 @@
{
"patternId": "IME-ENFORCEMENT-SUCCESS",
"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}\\w+\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{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}\\w+\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{1,2}",
"action": "updateStateInstalled",
"description": "Detects when an app's enforcement state transitions to Success in an Execution state report delta. OldValue is deliberately unpinned: besides InProgressDownloadCompleted it can be Error (retry succeeding in a later check-in), InProgressPendingReboot (post-reboot completion) or null (first write) — the previously pinned InProgressDownloadCompleted missed those legitimate success paths (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.",
"enabled": true
@@ -244,7 +244,7 @@
{
"patternId": "IME-ENFORCEMENT-SUCCESS-OLD",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"action": "updateStateInstalled",
"parameters": {
"useCurrentApp": "true"
@@ -255,7 +255,7 @@
{
"patternId": "IME-ERROR-DOWNLOAD",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Download state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgress\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}ErrorDownloadingContent\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Download state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgress\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}ErrorDownloadingContent\"{1,2}",
"action": "updateStateError",
"description": "Detects when an app's enforcement state transitions to ErrorDownloadingContent. 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.",
"enabled": true
@@ -263,7 +263,7 @@
{
"patternId": "IME-ERROR-ENFORCEMENT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Error\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Error\\b",
"action": "updateStateError",
"parameters": {
"useCurrentApp": "true"
@@ -274,7 +274,7 @@
{
"patternId": "IME-ERROR-NO-CONTENT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Didn't get content info from service",
"pattern": "^\\[Win32App\\] Didn't get content info from service",
"action": "updateStateError",
"parameters": {
"useCurrentApp": "true"
@@ -285,7 +285,7 @@
{
"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}",
"action": "updateStateError",
"parameters": {
"checkTo": "true"
@@ -296,7 +296,7 @@
{
"patternId": "IME-ERROR-TIMEOUT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Installation is timeout",
"pattern": "^\\[Win32App\\] Installation is timeout",
"action": "updateStateError",
"parameters": {
"useCurrentApp": "true"
@@ -307,7 +307,7 @@
{
"patternId": "IME-ERROR-UNMAPPED-EXIT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Admin did NOT set mapping for lpExitCode\\W+(?<exitCode>\\d+) of app\\W+{GUID}",
"pattern": "^\\[Win32App\\] Admin did NOT set mapping for lpExitCode\\W+(?<exitCode>\\d+) of app\\W+{GUID}",
"action": "updateStateError",
"description": "Detects when an app installer returned an exit code that has no mapping configured in Intune.",
"enabled": true
@@ -315,7 +315,7 @@
{
"patternId": "IME-ESP-APP-REGISTERED",
"category": "always",
"pattern": "\\[Win32App\\]\\[EspManager\\] In EspPhase: \\w+\\. App {GUID} has been registered.*?App name: (?<name>.*?)$",
"pattern": "^\\[Win32App\\]\\[EspManager\\] In EspPhase: \\w+\\. App {GUID} has been registered.*?App name: (?<name>.*?)$",
"action": "updateName",
"description": "Captures the ESP tracked-app registration line ('App <guid> has been registered[ for user <id>]. App name: <name>', EspManager.cs) as an app-name source. Primary replacement for the retired IME-UPDATE-NAME-1/2/3 whose emitters were removed with IME's old V1/V2 processing pipeline; also documents exactly which apps IME registered for ESP tracking. Category 'always' so names resolve even before the first ApplicationPoller EspPhase line is seen.",
"enabled": true
@@ -323,7 +323,7 @@
{
"patternId": "IME-ESP-PHASE",
"category": "always",
"pattern": "\\[Win32App\\] (?:In|The) EspPhase: (?<espPhase>\\w+)",
"pattern": "^\\[Win32App\\] (?:In|The) EspPhase: (?<espPhase>\\w+)",
"action": "espPhaseDetected",
"description": "Detects ESP phase transitions reported by IME Win32App processing (e.g., DeviceSetup, AccountSetup).",
"enabled": true
@@ -331,7 +331,7 @@
{
"patternId": "IME-ESP-TRACK-STATUS",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[EspManager\\] Updating ESP tracked install status from (?<from>\\w+) to (?<to>\\w+) for application {GUID}",
"pattern": "^\\[Win32App\\]\\[EspManager\\] Updating ESP tracked install status from (?<from>\\w+) to (?<to>\\w+) for application {GUID}",
"action": "espTrackStatus",
"description": "Captures ESP tracked install status transitions (e.g., InProgress to Installed) for a specific app. No trailing anchor: IME 1.97 (Dec 2025) appends ' with name: <appName>.' after the GUID (EspManager.cs), which broke the previous '\\.' suffix. 'from' can be the literal string 'null' on first tracking.",
"enabled": true
@@ -339,7 +339,7 @@
{
"patternId": "IME-EXITCODE",
"category": "currentPhase",
"pattern": "\\[Win32App\\] lpExitCode (?<exitCode>-?\\d+)$",
"pattern": "^\\[Win32App\\] lpExitCode (?<exitCode>-?\\d+)$",
"action": "captureExitCode",
"parameters": {
"useCurrentApp": "true"
@@ -350,7 +350,7 @@
{
"patternId": "IME-EXITCODE-MAPPED-FAILED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] lpExitCode is defined as Failed$",
"pattern": "^\\[Win32App\\] lpExitCode is defined as Failed$",
"action": "updateStateError",
"parameters": {
"useCurrentApp": "true"
@@ -361,7 +361,7 @@
{
"patternId": "IME-GRS-CLEARED",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ExecutionActionHandler\\] Encountered early subgraph termination\\. Clearing GRS for app with id: {GUID} so it can be retried during the next check-in\\.",
"pattern": "^\\[Win32App\\]\\[ExecutionActionHandler\\] Encountered early subgraph termination\\. Clearing GRS for app with id: {GUID} so it can be retried during the next check-in\\.",
"action": "updateStatePostponed",
"description": "IME aborted the app's subgraph before enforcement finished and cleared its GRS entry so the app retries on the next check-in (ExecutionActionHandler, AppWorkload.log). Maps to Postponed: the install did not complete this pass but is scheduled to run again - previously this looked like an unexplained gap. Wording verified in IME 1.97 and 1.104.",
"enabled": true
@@ -369,7 +369,7 @@
{
"patternId": "IME-GRS-SKIP",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID} to (?:install|uninstall) is in GRS\\. The app will not be enforced\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID} to (?:install|uninstall) is in GRS\\. The app will not be enforced\\.",
"action": "updateStatePostponed",
"description": "GRS (Global Retry Schedule) skip: the app failed recently and IME will not re-enforce it this check-in ('App with id: <guid> to install is in GRS. The app will not be enforced.', EnforcementActionProcessor / MixedEnforcementActionProcessor). THE canonical reason an app silently does nothing for up to 24h - previously invisible. Lives in AppActionProcessor.log, which the agent tails since the 2026-08-18 release; wording verified in IME 1.97 and 1.104.",
"enabled": true
@@ -377,7 +377,7 @@
{
"patternId": "IME-HRESULT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] hResultFromWin32 (?<hresult>-?\\d+)$",
"pattern": "^\\[Win32App\\] hResultFromWin32 (?<hresult>-?\\d+)$",
"action": "captureHResult",
"parameters": {
"useCurrentApp": "true"
@@ -388,7 +388,7 @@
{
"patternId": "IME-IMPERSONATION",
"category": "always",
"pattern": "After impersonation: (?<user>.*?)$",
"pattern": "^After impersonation: (?<user>.*?)$",
"action": "imeImpersonation",
"description": "Detects when IME impersonates a user context for app installation.",
"enabled": true
@@ -396,7 +396,7 @@
{
"patternId": "IME-INSTALL-HANDLER",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ExecutionActionHandler\\] Handler invoked with execution type: Install for policy with id: {GUID}",
"pattern": "^\\[Win32App\\]\\[ExecutionActionHandler\\] Handler invoked with execution type: Install for policy with id: {GUID}",
"action": "updateStateInstalling",
"description": "Detects when the IME execution handler starts installing an app.",
"enabled": true
@@ -404,7 +404,7 @@
{
"patternId": "IME-LAUNCH-INSTALLER",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Launch Win32AppInstaller in \\w+? session",
"pattern": "^\\[Win32App\\] Launch Win32AppInstaller in \\w+? session",
"action": "updateStateInstalling",
"parameters": {
"useCurrentApp": "true"
@@ -415,7 +415,7 @@
{
"patternId": "IME-NO-ACTION",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] No action required for app with id: {GUID}",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] No action required for app with id: {GUID}",
"action": "updateStateSkipped",
"description": "Detects when IME determines no action is required for an app (already in desired state).",
"enabled": true
@@ -423,7 +423,7 @@
{
"patternId": "IME-NOT-APPLICABLE-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ApplicabilityActionHandler\\] Applicability check for policy with id: {GUID} resulted in action status: Success and applicability state: NotApplicable",
"pattern": "^\\[Win32App\\]\\[ApplicabilityActionHandler\\] Applicability check for policy with id: {GUID} resulted in action status: Success and applicability state: NotApplicable",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability check returns NotApplicable (requirements not met).",
"enabled": true
@@ -431,7 +431,7 @@
{
"patternId": "IME-NOT-APPLICABLE-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Applicability state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}ApplicabilityState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}ScriptRequirementRuleNotMet\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Applicability state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}ApplicabilityState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}ScriptRequirementRuleNotMet\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability state is set to ScriptRequirementRuleNotMet (PowerShell requirement script returned false). 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.",
"enabled": true
@@ -439,7 +439,7 @@
{
"patternId": "IME-NOT-APPLICABLE-3",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}None\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}None\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's desired state is set to None (not targeted or not applicable). 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.",
"enabled": true
@@ -447,7 +447,7 @@
{
"patternId": "IME-NOT-APPLICABLE-4",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}NotPresent\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}NotPresent\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's desired state is set to NotPresent (targeted for uninstall or not required). 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.",
"enabled": true
@@ -455,7 +455,7 @@
{
"patternId": "IME-NOT-TARGETED-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, targeted intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, targeted intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"action": "updateStateSkipped",
"description": "Detects when an app with RequiredInstall intent is classified as NotApplicableOrNotTargeted (new log format).",
"enabled": true
@@ -463,7 +463,7 @@
{
"patternId": "IME-NOT-TARGETED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, effective intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, effective intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"action": "updateStateSkipped",
"description": "Detects when an app with effective RequiredInstall intent is classified as NotApplicableOrNotTargeted.",
"enabled": true
@@ -471,7 +471,7 @@
{
"patternId": "IME-POLICIES",
"category": "currentPhase",
"pattern": "Get policies =\\s*(?<policies>.*)",
"pattern": "^Get policies =\\s*(?<policies>.*)",
"action": "policiesDiscovered",
"description": "Captures the JSON policies list discovered by IME, used to build the app inventory.",
"enabled": true
@@ -479,7 +479,7 @@
{
"patternId": "IME-RESTART-STOP-PROCESSING",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] A restart is required to continue processing apps\\. Stop processing\\.",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] A restart is required to continue processing apps\\. Stop processing\\.",
"action": "updateStatePostponed",
"parameters": {
"useCurrentApp": "true"
@@ -490,7 +490,7 @@
{
"patternId": "IME-SESSION-CHANGE",
"category": "always",
"pattern": "OnSessionChange:? (?<change>.*?)$",
"pattern": "^OnSessionChange:? (?<change>.*?)$",
"action": "imeSessionChange",
"description": "Detects Windows session change events (logon, logoff, lock, unlock) reported by IME.",
"enabled": true
@@ -498,7 +498,7 @@
{
"patternId": "IME-SET-CURRENT-1",
"category": "always",
"pattern": "\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name",
"pattern": "^\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name",
"action": "setCurrentApp",
"description": "Detects when IME begins processing an app with its dependency chain, setting it as the current app. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -506,7 +506,7 @@
{
"patternId": "IME-SET-CURRENT-2",
"category": "always",
"pattern": "\\[Win32App\\] ExecManager: processing targeted app.*?\\bid\\W+{GUID}",
"pattern": "^\\[Win32App\\] ExecManager: processing targeted app.*?\\bid\\W+{GUID}",
"action": "setCurrentApp",
"description": "Detects when the IME ExecManager starts processing a targeted app, setting it as current. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -514,7 +514,7 @@
{
"patternId": "IME-SET-CURRENT-3",
"category": "always",
"pattern": "\\[Win32App\\] ===Step=== Start to Present app {GUID}",
"pattern": "^\\[Win32App\\] ===Step=== Start to Present app {GUID}",
"action": "setCurrentApp",
"description": "Detects the start of app presentation step in IME, setting the app as current. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -522,7 +522,7 @@
{
"patternId": "IME-SET-CURRENT-4",
"category": "always",
"pattern": "\\[Win32App\\] SetCurrentDirectory:.*?\\\\{GUID}_\\d+",
"pattern": "^\\[Win32App\\] SetCurrentDirectory:.*?\\\\{GUID}_\\d+",
"action": "setCurrentApp",
"description": "Detects when IME sets the working directory for an app's staging folder, setting it as current.",
"enabled": true
@@ -530,7 +530,7 @@
{
"patternId": "IME-SHUTDOWN",
"category": "currentPhase",
"pattern": "EMS Agent received shutdown signal",
"pattern": "^EMS Agent received shutdown signal",
"action": "updateStatePostponed",
"parameters": {
"useCurrentApp": "true"
@@ -541,7 +541,7 @@
{
"patternId": "IME-SKIP-APPLICABILITY-NOTMET",
"category": "currentPhase",
"pattern": "\\[Win32App\\] (?=.*?\\bapplicability\\b)(?=.*?NotMet\\b).*?\\bapp\\W+{GUID}\\b",
"pattern": "^\\[Win32App\\] (?=.*?\\bapplicability\\b)(?=.*?NotMet\\b).*?\\bapp\\W+{GUID}\\b",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability check returns NotMet (old log format with lookaheads). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -549,7 +549,7 @@
{
"patternId": "IME-SKIP-DEPENDENCY-DETECT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] app\\W+{GUID}\\b.*?\\bis a dependency\\b.*?\\bDetect Only mode\\b.*?\\bfinished processing",
"pattern": "^\\[Win32App\\] app\\W+{GUID}\\b.*?\\bis a dependency\\b.*?\\bDetect Only mode\\b.*?\\bfinished processing",
"action": "updateStateSkipped",
"description": "Detects when a dependency app in Detect Only mode finishes processing (no install needed). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -557,7 +557,7 @@
{
"patternId": "IME-SKIP-DETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID}.*?skip next step",
"pattern": "^\\[Win32App\\] Detected app {GUID}.*?skip next step",
"action": "updateStateSkipped",
"description": "Detects when an already-detected app is skipped for further processing steps (old log format). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -565,7 +565,7 @@
{
"patternId": "IME-SKIP-FILTERS",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] All apps in the subgraph are not applicable due to assignment filters\\. Skipping processing\\.",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] All apps in the subgraph are not applicable due to assignment filters\\. Skipping processing\\.",
"action": "updateStateSkipped",
"parameters": {
"useCurrentApp": "true"
@@ -576,7 +576,7 @@
{
"patternId": "IME-SKIP-INSTALL-DETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID} and intent is to install, skip applicability check",
"pattern": "^\\[Win32App\\] Detected app {GUID} and intent is to install, skip applicability check",
"action": "updateStateSkipped",
"description": "Detects when an app targeted for install is already detected/installed, so the install is skipped (old log format).",
"enabled": true
@@ -584,7 +584,7 @@
{
"patternId": "IME-SKIP-UNINSTALL-NOTDETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Not detected app {GUID} and intent is to un-install, skip applicability check",
"pattern": "^\\[Win32App\\] Not detected app {GUID} and intent is to un-install, skip applicability check",
"action": "updateStateSkipped",
"description": "Detects when an app targeted for uninstall is not detected, so the uninstall is skipped (old log format).",
"enabled": true
@@ -592,7 +592,7 @@
{
"patternId": "IME-SKIP-UNINSTALL-NOTDETECTED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] NOT detected app {GUID}.*?skip un-installation",
"pattern": "^\\[Win32App\\] NOT detected app {GUID}.*?skip un-installation",
"action": "updateStateSkipped",
"description": "Detects when an app is not detected and uninstall is skipped (alternate old log format). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -600,7 +600,7 @@
{
"patternId": "IME-STARTED",
"category": "always",
"pattern": "EMS Agent Started",
"pattern": "^EMS Agent Started",
"action": "imeStarted",
"description": "Detects when the Intune Management Extension (IME) agent starts up.",
"enabled": true
@@ -608,7 +608,7 @@
{
"patternId": "IME-STOP-SIGNAL",
"category": "currentPhase",
"pattern": "EMS Agent received stop signal",
"pattern": "^EMS Agent received stop signal",
"action": "updateStatePostponed",
"parameters": {
"useCurrentApp": "true"
@@ -619,7 +619,7 @@
{
"patternId": "IME-SUBGRAPH",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] Processing subgraph with app ids: {GUID}",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] Processing subgraph with app ids: {GUID}",
"action": "cancelStuckAndSetCurrent",
"description": "Detects when V3Processor starts a new subgraph, cancelling any stuck app and setting the new app as current.",
"enabled": true
@@ -627,7 +627,7 @@
{
"patternId": "IME-TOKEN-FAILURE",
"category": "always",
"pattern": "Failed to get AAD token\\..*?errorCode = (?<errorCode>.*?)$",
"pattern": "^Failed to get AAD token\\..*?errorCode = (?<errorCode>.*?)$",
"action": "imeTokenFailure",
"description": "IME token acquisition failure ('Failed to get AAD token. len = N using client id ... and resource id ..., errorCode = N', IntuneTokenManager, IntuneManagementExtension.log). This line appears ROUTINELY during the device phase (no user token exists yet), so the agent holds the failure pending: any IME-TOKEN-SUCCESS match clears it, and the ime_token_failure Warning fires only when no success follows for the whole 30-min grace window (then deduped to one Warning per distinct errorCode). A genuine auth outage (WAM broken, conditional access, network) runs long enough to hit the window. Verified against IME 1.97 and 1.104 decompiled sources.",
"enabled": true
@@ -635,7 +635,7 @@
{
"patternId": "IME-TOKEN-SUCCESS",
"category": "always",
"pattern": "Successfully get the token",
"pattern": "^Successfully get the token",
"action": "espPhaseDetected",
"parameters": {
"phase": "AccountSetup"
@@ -646,7 +646,7 @@
{
"patternId": "IME-UPDATE-NAME-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ExecManager: processing targeted app.*?name\\W+(?<name>.*?)\\W+id\\W+{GUID}",
"pattern": "^\\[Win32App\\] ExecManager: processing targeted app.*?name\\W+(?<name>.*?)\\W+id\\W+{GUID}",
"action": "updateName",
"description": "Captures the app name from ExecManager processing log (old format: name before id). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -654,7 +654,7 @@
{
"patternId": "IME-UPDATE-NAME-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name (?<name>.*?)$",
"pattern": "^\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name (?<name>.*?)$",
"action": "updateName",
"description": "Captures the app name from ProcessAppWithDependencies log entry. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -662,7 +662,7 @@
{
"patternId": "IME-UPDATE-NAME-3",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Processing app \\(id={GUID}, name = (?<name>.*?)\\)",
"pattern": "^\\[Win32App\\] Processing app \\(id={GUID}, name = (?<name>.*?)\\)",
"action": "updateName",
"description": "Captures the app name from the Processing app log entry. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -670,7 +670,7 @@
{
"patternId": "IME-USER-SESSION-COMPLETED",
"category": "always",
"pattern": "\\[Win32App\\] \\.+ Completed user session \\d+, userId: (?<userId>[a-f0-9\\-]+), userSID: (?<userSid>S-[\\d\\-]+) \\.+",
"pattern": "^\\[Win32App\\] \\.+ Completed user session \\d+, userId: (?<userId>[a-f0-9\\-]+), userSID: (?<userSid>S-[\\d\\-]+) \\.+",
"action": "enrollmentCompleted",
"description": "Detects when IME completes a user session, indicating enrollment has finished for that user.",
"enabled": true
@@ -678,7 +678,7 @@
{
"patternId": "IME-USER-SESSION-ZERO-APPS",
"category": "always",
"pattern": "\\[Win32App\\] Get 0 apps for user session (?<sessionId>\\d+), user id = (?<userId>[a-f0-9\\-]+)",
"pattern": "^\\[Win32App\\] Get 0 apps for user session (?<sessionId>\\d+), user id = (?<userId>[a-f0-9\\-]+)",
"action": "userSessionZeroApps",
"description": "Detects when IME enumerated a user session and found zero targeted Win32 apps. IME then skips its 'Completed user session' line entirely (the zero-app branch in ApplicationPoller continues before that log statement), so this line is the only evidence that user-phase enforcement finished on a device with no user-targeted apps. Treated as equivalent to a completed user session.",
"enabled": true
@@ -686,7 +686,7 @@
{
"patternId": "IME-WIN32-STATE-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Got InstanceID: Win32App_{GUID}_\\d+, installationStateString: (?<state>\\d)",
"pattern": "^\\[Win32App\\] Got InstanceID: Win32App_{GUID}_\\d+, installationStateString: (?<state>\\d)",
"action": "updateWin32AppState",
"description": "Captures the Win32 app installation state string from instance ID tracking (old log format).",
"enabled": true
@@ -694,7 +694,7 @@
{
"patternId": "IME-WIN32-STATE-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] (?:Got|Set) (?:ESP )?win32App state (?<state>\\w+) for {GUID}",
"pattern": "^\\[Win32App\\] (?:Got|Set) (?:ESP )?win32App state (?<state>\\w+) for {GUID}",
"action": "updateWin32AppState",
"description": "Captures the Win32 app ESP state (e.g., Installed, InProgress) for a specific app.",
"enabled": true
@@ -702,7 +702,7 @@
{
"patternId": "IME-WINGET-ERROR",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Error",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Error",
"action": "updateStateError",
"description": "Marks a WinGet (new Store) app as failed when its operation progress reports phase Error (WinGetOperationInstallPhase: Downloading/Installing/Queued/Finished/Error). Before this pattern only the Installing phase was matched, so WinGet failures never surfaced as app errors (IME 1.97 audit 2026-08-17).",
"enabled": true
@@ -710,7 +710,7 @@
{
"patternId": "IME-WINGET-INSTALLING-1",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID} and user = .*?- Operation Phase = Installing",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID} and user = .*?- Operation Phase = Installing",
"action": "updateStateInstalling",
"description": "Detects WinGet app installation progress with Operation Phase = Installing (format variant 1).",
"enabled": true
@@ -718,7 +718,7 @@
{
"patternId": "IME-WINGET-INSTALLING-2",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Installing",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Installing",
"action": "updateStateInstalling",
"description": "Detects WinGet app installation progress with Operation Phase = Installing (format variant 2).",
"enabled": true
@@ -726,7 +726,7 @@
{
"patternId": "PS-AGENT-ERROR",
"category": "always",
"pattern": "error from script =(?<output>[\\s\\S]*)",
"pattern": "^error from script =(?<output>[\\s\\S]*)",
"action": "scriptOutput",
"parameters": {
"scriptType": "platform",
@@ -738,7 +738,7 @@
{
"patternId": "PS-AGENT-EXITCODE",
"category": "always",
"pattern": "Powershell exit code is (?<exitCode>-?\\d+)",
"pattern": "^Powershell exit code is (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"parameters": {
"scriptType": "platform"
@@ -749,7 +749,7 @@
{
"patternId": "PS-AGENT-INVOCATION",
"category": "always",
"pattern": "ExecutorLog AgentExecutor gets invoked",
"pattern": "^ExecutorLog AgentExecutor gets invoked",
"action": "resetPlatformScriptContext",
"description": "Marks the start of a new AgentExecutor.exe invocation. AgentExecutor hosts BOTH platform scripts (Policies\\Scripts\\<id>.ps1) and proactive-remediation scripts (IMECache\\HealthScripts\\<id>\\detect.ps1) and writes their lines interleaved into the shared AgentExecutor.log. The policyId-less 'Powershell exit code is N' / 'write output done' lines are otherwise routed to the last-started platform script via a sticky pointer, so a remediation invocation (whose start line does not match PS-AGENT-SCRIPT-START) leaks its exit/output into that platform script's result. This pattern resets the platform-script line-capture context at each invocation boundary so only the matching platform invocation captures its own exit/output.",
"enabled": true
@@ -757,7 +757,7 @@
{
"patternId": "PS-AGENT-OUTPUT",
"category": "always",
"pattern": "write output done\\. output = (?<output>[\\s\\S]*?), error = (?<error>[\\s\\S]*)",
"pattern": "^write output done\\. output = (?<output>[\\s\\S]*?), error = (?<error>[\\s\\S]*)",
"action": "scriptOutput",
"parameters": {
"scriptType": "platform"
@@ -768,7 +768,7 @@
{
"patternId": "PS-AGENT-SCRIPT-START",
"category": "always",
"pattern": "Adding argument powershell with value C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1",
"pattern": "^Adding argument powershell with value C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1",
"action": "scriptStarted",
"parameters": {
"scriptType": "platform",
@@ -780,7 +780,7 @@
{
"patternId": "PS-SCRIPT-CONTEXT",
"category": "always",
"pattern": "Launch powershell executor in (?<context>machine|user) session",
"pattern": "^Launch powershell executor in (?<context>machine|user) session",
"action": "scriptContext",
"description": "Captures whether a PowerShell script runs in machine (System) or user session context.",
"enabled": true
@@ -788,7 +788,7 @@
{
"patternId": "PS-SCRIPT-EXITCODE",
"category": "always",
"pattern": "Powershell execution is done, exitCode = (?<exitCode>-?\\d+)",
"pattern": "^Powershell execution is done, exitCode = (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"description": "Captures the PowerShell exit code when script execution completes in the IME log.",
"enabled": true
@@ -796,7 +796,7 @@
{
"patternId": "PS-SCRIPT-GENERATED",
"category": "always",
"pattern": "Script file C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1 is generated",
"pattern": "^Script file C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1 is generated",
"action": "scriptStarted",
"parameters": {
"scriptType": "platform"
@@ -807,7 +807,7 @@
{
"patternId": "PS-SCRIPT-RESULT",
"category": "always",
"pattern": "\\[PowerShell\\] User Id = [a-z0-9\\-]+, Policy id = (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}), policy result = (?<result>\\w+)",
"pattern": "^\\[PowerShell\\] User Id = [a-z0-9\\-]+, Policy id = (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}), policy result = (?<result>\\w+)",
"action": "scriptCompleted",
"parameters": {
"scriptType": "platform"
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-COMPLIANCE-POST",
"category": "always",
"pattern": "\\[HS\\] the (?<part>post) detection script result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"pattern": "^\\[HS\\] the (?<part>post) detection script result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"action": "healthScriptDetectionResult",
"parameters": { "scriptType": "remediation" },
"description": "Post-remediation detection result, current wording. IME 1.97 (Dec 2025) replaced the old '[HS] the post-remdiation detection script compliance result for ...' line (still covered by HS-COMPLIANCE for older logs) with '[HS] the post detection script result for <guid> is <True|False>' (ScriptProcessorV2.cs:721). The literal word 'post' in the line is captured as the part group so the handler classifies it as the post-detection phase.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-COMPLIANCE",
"category": "always",
"pattern": "\\[HS\\] the (?<part>pre|post)-rem(?:e)?diation detection script compliance result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"pattern": "^\\[HS\\] the (?<part>pre|post)-rem(?:e)?diation detection script compliance result for (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) is (?<compliance>True|False)",
"action": "healthScriptDetectionResult",
"parameters": { "scriptType": "remediation" },
"description": "Early-signal fallback for health-script detection / post-detection results. Microsoft IME emits this line immediately after each detection script runs, ~30-90 seconds before the consolidated [HS] new result = JSON line is logged (which only fires after IME's batch-send to the Microsoft service). Short Autopilot enrollments often end inside that gap, so this pattern guarantees at least the compliance verdict is captured. The full data version arrives later via HS-NEW-RESULT and replaces this sparse entry through the UI dedupe (dataCompleteness scoring). Tolerates both Microsoft's historical typo 'remdiation' and a future corrected 'remediation'. NOTE: IME 1.97 (Dec 2025) no longer emits the post- variant of this line; the post case is covered by HS-COMPLIANCE-POST.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-EXITCODE",
"category": "always",
"pattern": "\\[HS\\] exit code of the script is (?<exitCode>-?\\d+)",
"pattern": "^\\[HS\\] exit code of the script is (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"parameters": { "scriptType": "remediation" },
"description": "Captures the exit code of a health-script execution. Feeds the early-signal slot consumed by HS-COMPLIANCE so the user sees the real exit code (not just the inferred 0/1) before HS-NEW-RESULT arrives.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-NEW-RESULT",
"category": "always",
"pattern": "\\[HS\\] new result = (?<json>\\{[\\s\\S]*\\})\\s*$",
"pattern": "^\\[HS\\] new result = (?<json>\\{[\\s\\S]*\\})\\s*$",
"action": "healthScriptResult",
"parameters": { "scriptType": "remediation" },
"description": "Atomic final JSON of a health script run, covering all three phases (pre-detection / remediation / post-detection) emitted by IME after the policy completes. Single source of truth for health-script outcomes — replaces the line-by-line HS-COMPLIANCE/HS-EXITCODE/HS-STDOUT/HS-STDERR patterns. The end-anchor and [\\s\\S] character class are defensive against future format changes and multi-line CMTrace buffering.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-RUN-CONTEXT",
"category": "always",
"pattern": "\\[HS\\] The policy needs be run as (?<context>System|User)",
"pattern": "^\\[HS\\] The policy needs be run as (?<context>System|User)",
"action": "scriptContext",
"parameters": { "scriptType": "remediation" },
"description": "Captures the execution context (System or User) for a health-script. Feeds the early-signal slot consumed by HS-COMPLIANCE so context is visible immediately rather than waiting for HS-NEW-RESULT (which exposes RunAsAccount).",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-SCRIPT-START",
"category": "always",
"pattern": "\\[HS\\] ProcessScript PolicyId: (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) PolicyType: (?<policyType>\\d+)",
"pattern": "^\\[HS\\] ProcessScript PolicyId: (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}) PolicyType: (?<policyType>\\d+)",
"action": "scriptStarted",
"parameters": { "scriptType": "remediation" },
"description": "Detects when a Proactive Remediation (Health Script) starts processing. Captures PolicyId and PolicyType (6 = remediation). Drives the live script_started event for UI progress indication; the consolidated final result for the same PolicyId arrives later via HS-NEW-RESULT.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-STDERR",
"category": "always",
"pattern": "\\[HS\\] err output = (?<output>.*)",
"pattern": "^\\[HS\\] err output = (?<output>.*)",
"action": "scriptOutput",
"parameters": { "scriptType": "remediation", "outputType": "stderr" },
"description": "Captures standard error from a health-script execution. Feeds the early-signal slot consumed by HS-COMPLIANCE so stderr is visible immediately rather than waiting for HS-NEW-RESULT.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "HS-STDOUT",
"category": "always",
"pattern": "\\[HS\\] std output = (?<output>.*)",
"pattern": "^\\[HS\\] std output = (?<output>.*)",
"action": "scriptOutput",
"parameters": { "scriptType": "remediation", "outputType": "stdout" },
"description": "Captures standard output from a health-script execution. Feeds the early-signal slot consumed by HS-COMPLIANCE so the user sees stdout immediately rather than waiting for HS-NEW-RESULT.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-AGENT-VERSION",
"category": "always",
"pattern": "Agent version is: (?<agentVersion>[\\d.]+)",
"pattern": "^Agent version is: (?<agentVersion>[\\d.]+)",
"action": "imeAgentVersion",
"description": "Captures the Intune Management Extension agent version number.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ALREADY-DETECTED-1",
"category": "otherPhases",
"pattern": "\\[Win32App\\] Completed detectionManager SideCar\\w+?DetectionManager, applicationDetectedByCurrentRule: True",
"pattern": "^\\[Win32App\\] Completed detectionManager SideCar\\w+?DetectionManager, applicationDetectedByCurrentRule: True",
"action": "ignoreCompletedApp",
"description": "Detects when an app from a previous ESP phase is detected as already installed, so it should be ignored in the current phase.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ALREADY-DETECTED-2",
"category": "otherPhases",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"action": "ignoreCompletedApp",
"description": "Detects enforcement success in a non-current phase, indicating an app completed in a previous phase should be ignored.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-APP-TYPE-MSI",
"category": "always",
"pattern": "\\[Win32App\\].*?\\bMSI App (?<id>{GUID})",
"pattern": "^\\[Win32App\\].*?\\bMSI App (?<id>{GUID})",
"action": "captureAppTypeMsi",
"description": "Detects an MSI-based Win32 app via the 'MSI App <guid>' phrase in the ESP retry configuration line. Marks AppType as 'MSI' for that app id.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-APP-TYPE-WINGET",
"category": "always",
"pattern": "\\[Win32App\\]\\[WinGetApp\\].*?app with id: (?<id>{GUID})",
"pattern": "^\\[Win32App\\]\\[WinGetApp\\].*?app with id: (?<id>{GUID})",
"action": "captureAppTypeWinGet",
"description": "Detects a WinGet-backed Store app by any [Win32App][WinGetApp] handler log line (Detection/Applicability/Operation). Marks AppType as 'WinGet' for that app id.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-APP-VERSION",
"category": "always",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: (?<id>{GUID}).*?\"DetectedIdentityVersion\":\\{[^}]*?\"NewValue\":\"(?<appVersion>[^\"]+)\"",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: (?<id>{GUID}).*?\"DetectedIdentityVersion\":\\{(?:\"OldValue\":[^,}]{0,64},)?\"NewValue\":\"(?<appVersion>[^\"]+)\"",
"action": "captureAppVersion",
"description": "Captures the product version IME detected after an app install (e.g. \"11.2.1787.0\"). Source: [ReportingManager] Detection state update with DetectedIdentityVersion.NewValue. Used by App Dashboard to show version-level failure breakdowns.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ATTEMPT-NUMBER",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ===Step=== Execute retry (?<attempt>\\d+)$",
"pattern": "^\\[Win32App\\] ===Step=== Execute retry (?<attempt>\\d+)$",
"action": "captureAttemptNumber",
"parameters": {
"useCurrentApp": "true"
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-CACHE-MISS",
"category": "always",
"pattern": "\\[Win32App\\] Content cache miss for app \\(id = {GUID}, name = (?<name>.*?)\\), start downloading",
"pattern": "^\\[Win32App\\] Content cache miss for app \\(id = {GUID}, name = (?<name>.*?)\\), start downloading",
"action": "updateName",
"description": "Captures 'Content cache miss for app (id = <guid>, name = <name>), start downloading...' (ContentManager.cs) as a secondary app-name source. Fires right before a real download begins, so it resolves names for exactly the apps that will produce download/install activity — a redundancy for IME-POLICIES-based naming after IME retired the old name-bearing processing lines.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DECRYPT-FAILED",
"category": "currentPhase",
"pattern": "Decryption is failed for appId {GUID}",
"pattern": "^Decryption is failed for appId {GUID}",
"action": "updateStateError",
"description": "Detects when app content decryption fails, indicating a corrupted or tampered download.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DETECTED-INSTALLED-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DetectionState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}Installed\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Detection state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DetectionState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}Installed\"{1,2}",
"action": "updateStateInstalled",
"description": "Detects when an app's detection state transitions to Installed (new ReportingManager format). 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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DETECTED-INSTALLED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: {GUID} resulted in action status: Success and detection state: Detected",
"pattern": "^\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: {GUID} resulted in action status: Success and detection state: Detected",
"action": "updateStateInstalled",
"description": "Detects when an app's detection action handler reports successful detection (app is installed).",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DETECTED-OLD",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID} ",
"pattern": "^\\[Win32App\\] Detected app {GUID} ",
"action": "updateStateInstalled",
"description": "Detects when an app is detected as installed (old log format). DISABLED 2026-08-17: the standalone 'Detected app <guid> ' line no longer exists in IME 1.97.107; this regex instead matched the 'Detected app ... and intent is to install, skip applicability check' line, colliding with IME-SKIP-INSTALL-DETECTED and firing updateStateInstalled and updateStateSkipped on the same physical line (see tasks/ime-v1-code-audit-2026-08-17.md).",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DETECTION-RESULT",
"category": "always",
"pattern": "\\[Win32App\\]\\[DetectionActionHandler\\] Detection for policy with id: (?<id>{GUID}) resulted in action status: Success and detection state: (?<detection>DetectedDifferentVersion|NotDetected|Detected)",
"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.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DO-TEL",
"category": "currentPhase",
"pattern": "\\[DO TEL\\] = (?<doTelJson>\\{.*\\})",
"pattern": "^\\[DO TEL\\] = (?<doTelJson>\\{.*\\})",
"action": "updateDoTelemetry",
"description": "Captures Delivery Optimization telemetry JSON after a DO download completes. Contains file size, peer caching stats, download mode, and duration.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DO-TIMEOUT-1",
"category": "currentPhase",
"pattern": "\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b).*?intunewin-bin_{GUID}",
"pattern": "^\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b).*?intunewin-bin_{GUID}",
"action": "updateStatePostponed",
"description": "Detects when a Delivery Optimization download times out for a specific app (identified by GUID in filename).",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DO-TIMEOUT-2",
"category": "currentPhase",
"pattern": "\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b)",
"pattern": "^\\[Win32App DO\\] DO download(?=.*?\\bnot finished\\b)(?=.*?\\btimeout\\b)",
"action": "updateStatePostponed",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when a Delivery Optimization download times out (generic, uses current app context).",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-DOWNLOADING",
"category": "currentPhase",
"pattern": "\\[StatusService\\] Downloading app \\(id = {GUID}.*?\\) via (?<tech>\\w+), bytes (?<bytes>\\w+)/(?<ofbytes>\\w+) for user",
"pattern": "^\\[StatusService\\] Downloading app \\(id = {GUID}.*?\\) via (?<tech>\\w+), bytes (?<bytes>\\w+)/(?<ofbytes>\\w+) for user",
"action": "updateStateDownloading",
"description": "Captures app download progress including technology (DO/CDN), bytes downloaded, and total bytes.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ENFORCEMENT-SUCCESS-OLD",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Success\\b",
"action": "updateStateInstalled",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when enforcement state is set to Success for the current app (old log format).",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ENFORCEMENT-SUCCESS",
"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}\\w+\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{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}\\w+\"{1,2}|null),\"{1,2}NewValue\"{1,2}:\"{1,2}Success\"{1,2}",
"action": "updateStateInstalled",
"description": "Detects when an app's enforcement state transitions to Success in an Execution state report delta. OldValue is deliberately unpinned: besides InProgressDownloadCompleted it can be Error (retry succeeding in a later check-in), InProgressPendingReboot (post-reboot completion) or null (first write) — the previously pinned InProgressDownloadCompleted missed those legitimate success paths (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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-DOWNLOAD",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Download state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgress\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}ErrorDownloadingContent\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Download state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}EnforcementState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:\"{1,2}InProgress\"{1,2},\"{1,2}NewValue\"{1,2}:\"{1,2}ErrorDownloadingContent\"{1,2}",
"action": "updateStateError",
"description": "Detects when an app's enforcement state transitions to ErrorDownloadingContent. 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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-ENFORCEMENT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Setting enforcementState as\\W+Error\\b",
"pattern": "^\\[Win32App\\] Setting enforcementState as\\W+Error\\b",
"action": "updateStateError",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when enforcement state is set to Error for the current app (old log format).",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-NO-CONTENT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Didn't get content info from service",
"pattern": "^\\[Win32App\\] Didn't get content info from service",
"action": "updateStateError",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when IME cannot retrieve content info from the Intune service for the current app.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$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}",
"action": "updateStateError",
"parameters": {
"checkTo": "true"
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-TIMEOUT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Installation is timeout",
"pattern": "^\\[Win32App\\] Installation is timeout",
"action": "updateStateError",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when an app installation times out.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ERROR-UNMAPPED-EXIT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Admin did NOT set mapping for lpExitCode\\W+(?<exitCode>\\d+) of app\\W+{GUID}",
"pattern": "^\\[Win32App\\] Admin did NOT set mapping for lpExitCode\\W+(?<exitCode>\\d+) of app\\W+{GUID}",
"action": "updateStateError",
"description": "Detects when an app installer returned an exit code that has no mapping configured in Intune.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ESP-APP-REGISTERED",
"category": "always",
"pattern": "\\[Win32App\\]\\[EspManager\\] In EspPhase: \\w+\\. App {GUID} has been registered.*?App name: (?<name>.*?)$",
"pattern": "^\\[Win32App\\]\\[EspManager\\] In EspPhase: \\w+\\. App {GUID} has been registered.*?App name: (?<name>.*?)$",
"action": "updateName",
"description": "Captures the ESP tracked-app registration line ('App <guid> has been registered[ for user <id>]. App name: <name>', EspManager.cs) as an app-name source. Primary replacement for the retired IME-UPDATE-NAME-1/2/3 whose emitters were removed with IME's old V1/V2 processing pipeline; also documents exactly which apps IME registered for ESP tracking. Category 'always' so names resolve even before the first ApplicationPoller EspPhase line is seen.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ESP-PHASE",
"category": "always",
"pattern": "\\[Win32App\\] (?:In|The) EspPhase: (?<espPhase>\\w+)",
"pattern": "^\\[Win32App\\] (?:In|The) EspPhase: (?<espPhase>\\w+)",
"action": "espPhaseDetected",
"description": "Detects ESP phase transitions reported by IME Win32App processing (e.g., DeviceSetup, AccountSetup).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-ESP-TRACK-STATUS",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[EspManager\\] Updating ESP tracked install status from (?<from>\\w+) to (?<to>\\w+) for application {GUID}",
"pattern": "^\\[Win32App\\]\\[EspManager\\] Updating ESP tracked install status from (?<from>\\w+) to (?<to>\\w+) for application {GUID}",
"action": "espTrackStatus",
"description": "Captures ESP tracked install status transitions (e.g., InProgress to Installed) for a specific app. No trailing anchor: IME 1.97 (Dec 2025) appends ' with name: <appName>.' after the GUID (EspManager.cs), which broke the previous '\\.' suffix. 'from' can be the literal string 'null' on first tracking.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-EXITCODE-MAPPED-FAILED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] lpExitCode is defined as Failed$",
"pattern": "^\\[Win32App\\] lpExitCode is defined as Failed$",
"action": "updateStateError",
"parameters": { "useCurrentApp": "true" },
"description": "Marks the current app as failed when its exit code maps to Failed via the admin-defined return-code table ('[Win32App] lpExitCode is defined as <Failed|Success|SoftReboot|HardReboot|Retry>', Win32AppInstaller.cs). This is the NORMAL mapped-exit-code outcome; the previously matched 'Setting enforcementState as ... Error' line only fires on the rare no-mapping fallback path. The numeric exit code is captured separately by IME-EXITCODE, which precedes this line.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-EXITCODE",
"category": "currentPhase",
"pattern": "\\[Win32App\\] lpExitCode (?<exitCode>-?\\d+)$",
"pattern": "^\\[Win32App\\] lpExitCode (?<exitCode>-?\\d+)$",
"action": "captureExitCode",
"parameters": {
"useCurrentApp": "true"
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-GRS-CLEARED",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ExecutionActionHandler\\] Encountered early subgraph termination\\. Clearing GRS for app with id: {GUID} so it can be retried during the next check-in\\.",
"pattern": "^\\[Win32App\\]\\[ExecutionActionHandler\\] Encountered early subgraph termination\\. Clearing GRS for app with id: {GUID} so it can be retried during the next check-in\\.",
"action": "updateStatePostponed",
"description": "IME aborted the app's subgraph before enforcement finished and cleared its GRS entry so the app retries on the next check-in (ExecutionActionHandler, AppWorkload.log). Maps to Postponed: the install did not complete this pass but is scheduled to run again - previously this looked like an unexplained gap. Wording verified in IME 1.97 and 1.104.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-GRS-SKIP",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID} to (?:install|uninstall) is in GRS\\. The app will not be enforced\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID} to (?:install|uninstall) is in GRS\\. The app will not be enforced\\.",
"action": "updateStatePostponed",
"description": "GRS (Global Retry Schedule) skip: the app failed recently and IME will not re-enforce it this check-in ('App with id: <guid> to install is in GRS. The app will not be enforced.', EnforcementActionProcessor / MixedEnforcementActionProcessor). THE canonical reason an app silently does nothing for up to 24h - previously invisible. Lives in AppActionProcessor.log, which the agent tails since the 2026-08-18 release; wording verified in IME 1.97 and 1.104.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-HRESULT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] hResultFromWin32 (?<hresult>-?\\d+)$",
"pattern": "^\\[Win32App\\] hResultFromWin32 (?<hresult>-?\\d+)$",
"action": "captureHResult",
"parameters": {
"useCurrentApp": "true"
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-IMPERSONATION",
"category": "always",
"pattern": "After impersonation: (?<user>.*?)$",
"pattern": "^After impersonation: (?<user>.*?)$",
"action": "imeImpersonation",
"description": "Detects when IME impersonates a user context for app installation.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-INSTALL-HANDLER",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ExecutionActionHandler\\] Handler invoked with execution type: Install for policy with id: {GUID}",
"pattern": "^\\[Win32App\\]\\[ExecutionActionHandler\\] Handler invoked with execution type: Install for policy with id: {GUID}",
"action": "updateStateInstalling",
"description": "Detects when the IME execution handler starts installing an app.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-LAUNCH-INSTALLER",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Launch Win32AppInstaller in \\w+? session",
"pattern": "^\\[Win32App\\] Launch Win32AppInstaller in \\w+? session",
"action": "updateStateInstalling",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when the Win32 app installer process is launched in a user or system session.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NO-ACTION",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] No action required for app with id: {GUID}",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] No action required for app with id: {GUID}",
"action": "updateStateSkipped",
"description": "Detects when IME determines no action is required for an app (already in desired state).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-APPLICABLE-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ApplicabilityActionHandler\\] Applicability check for policy with id: {GUID} resulted in action status: Success and applicability state: NotApplicable",
"pattern": "^\\[Win32App\\]\\[ApplicabilityActionHandler\\] Applicability check for policy with id: {GUID} resulted in action status: Success and applicability state: NotApplicable",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability check returns NotApplicable (requirements not met).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-APPLICABLE-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Applicability state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}ApplicabilityState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}ScriptRequirementRuleNotMet\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Applicability state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}ApplicabilityState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}ScriptRequirementRuleNotMet\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability state is set to ScriptRequirementRuleNotMet (PowerShell requirement script returned false). 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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-APPLICABLE-3",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}None\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}None\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's desired state is set to None (not targeted or not applicable). 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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-APPLICABLE-4",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}NotPresent\"{1,2}",
"pattern": "^\\[Win32App\\]\\[ReportingManager\\] Desired state for app with id: {GUID} has been updated\\. Report delta: \\{\"{1,2}DesiredState\"{1,2}:\\{\"{1,2}OldValue\"{1,2}:null,\"{1,2}NewValue\"{1,2}:\"{1,2}NotPresent\"{1,2}",
"action": "updateStateSkipped",
"description": "Detects when an app's desired state is set to NotPresent (targeted for uninstall or not required). 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.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-TARGETED-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, targeted intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, targeted intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"action": "updateStateSkipped",
"description": "Detects when an app with RequiredInstall intent is classified as NotApplicableOrNotTargeted (new log format).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-NOT-TARGETED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, effective intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"pattern": "^\\[Win32App\\]\\[ActionProcessor\\] App with id: {GUID}, effective intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None\\.",
"action": "updateStateSkipped",
"description": "Detects when an app with effective RequiredInstall intent is classified as NotApplicableOrNotTargeted.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-POLICIES",
"category": "currentPhase",
"pattern": "Get policies =\\s*(?<policies>.*)",
"pattern": "^Get policies =\\s*(?<policies>.*)",
"action": "policiesDiscovered",
"description": "Captures the JSON policies list discovered by IME, used to build the app inventory.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-RESTART-STOP-PROCESSING",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] A restart is required to continue processing apps\\. Stop processing\\.",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] A restart is required to continue processing apps\\. Stop processing\\.",
"action": "updateStatePostponed",
"parameters": { "useCurrentApp": "true" },
"description": "Detects IME aborting app processing because an app requires a restart ('A restart is required to continue processing apps. Stop processing.', SideCarV3AppProcessor.cs). Postpones the current app: remaining apps do nothing until after the reboot, which previously looked like an unexplained stall mid-ESP.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SESSION-CHANGE",
"category": "always",
"pattern": "OnSessionChange:? (?<change>.*?)$",
"pattern": "^OnSessionChange:? (?<change>.*?)$",
"action": "imeSessionChange",
"description": "Detects Windows session change events (logon, logoff, lock, unlock) reported by IME.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SET-CURRENT-1",
"category": "always",
"pattern": "\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name",
"pattern": "^\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name",
"action": "setCurrentApp",
"description": "Detects when IME begins processing an app with its dependency chain, setting it as the current app. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SET-CURRENT-2",
"category": "always",
"pattern": "\\[Win32App\\] ExecManager: processing targeted app.*?\\bid\\W+{GUID}",
"pattern": "^\\[Win32App\\] ExecManager: processing targeted app.*?\\bid\\W+{GUID}",
"action": "setCurrentApp",
"description": "Detects when the IME ExecManager starts processing a targeted app, setting it as current. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SET-CURRENT-3",
"category": "always",
"pattern": "\\[Win32App\\] ===Step=== Start to Present app {GUID}",
"pattern": "^\\[Win32App\\] ===Step=== Start to Present app {GUID}",
"action": "setCurrentApp",
"description": "Detects the start of app presentation step in IME, setting the app as current. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SET-CURRENT-4",
"category": "always",
"pattern": "\\[Win32App\\] SetCurrentDirectory:.*?\\\\{GUID}_\\d+",
"pattern": "^\\[Win32App\\] SetCurrentDirectory:.*?\\\\{GUID}_\\d+",
"action": "setCurrentApp",
"description": "Detects when IME sets the working directory for an app's staging folder, setting it as current.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SHUTDOWN",
"category": "currentPhase",
"pattern": "EMS Agent received shutdown signal",
"pattern": "^EMS Agent received shutdown signal",
"action": "updateStatePostponed",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when the IME agent receives a shutdown signal, postponing the current app installation.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-APPLICABILITY-NOTMET",
"category": "currentPhase",
"pattern": "\\[Win32App\\] (?=.*?\\bapplicability\\b)(?=.*?NotMet\\b).*?\\bapp\\W+{GUID}\\b",
"pattern": "^\\[Win32App\\] (?=.*?\\bapplicability\\b)(?=.*?NotMet\\b).*?\\bapp\\W+{GUID}\\b",
"action": "updateStateSkipped",
"description": "Detects when an app's applicability check returns NotMet (old log format with lookaheads). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-DEPENDENCY-DETECT",
"category": "currentPhase",
"pattern": "\\[Win32App\\] app\\W+{GUID}\\b.*?\\bis a dependency\\b.*?\\bDetect Only mode\\b.*?\\bfinished processing",
"pattern": "^\\[Win32App\\] app\\W+{GUID}\\b.*?\\bis a dependency\\b.*?\\bDetect Only mode\\b.*?\\bfinished processing",
"action": "updateStateSkipped",
"description": "Detects when a dependency app in Detect Only mode finishes processing (no install needed). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-DETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID}.*?skip next step",
"pattern": "^\\[Win32App\\] Detected app {GUID}.*?skip next step",
"action": "updateStateSkipped",
"description": "Detects when an already-detected app is skipped for further processing steps (old log format). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-FILTERS",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] All apps in the subgraph are not applicable due to assignment filters\\. Skipping processing\\.",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] All apps in the subgraph are not applicable due to assignment filters\\. Skipping processing\\.",
"action": "updateStateSkipped",
"parameters": { "useCurrentApp": "true" },
"description": "Detects when all apps in a subgraph are skipped due to assignment filter exclusions.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-INSTALL-DETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Detected app {GUID} and intent is to install, skip applicability check",
"pattern": "^\\[Win32App\\] Detected app {GUID} and intent is to install, skip applicability check",
"action": "updateStateSkipped",
"description": "Detects when an app targeted for install is already detected/installed, so the install is skipped (old log format).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-UNINSTALL-NOTDETECTED-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] NOT detected app {GUID}.*?skip un-installation",
"pattern": "^\\[Win32App\\] NOT detected app {GUID}.*?skip un-installation",
"action": "updateStateSkipped",
"description": "Detects when an app is not detected and uninstall is skipped (alternate old log format). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SKIP-UNINSTALL-NOTDETECTED",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Not detected app {GUID} and intent is to un-install, skip applicability check",
"pattern": "^\\[Win32App\\] Not detected app {GUID} and intent is to un-install, skip applicability check",
"action": "updateStateSkipped",
"description": "Detects when an app targeted for uninstall is not detected, so the uninstall is skipped (old log format).",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-STARTED",
"category": "always",
"pattern": "EMS Agent Started",
"pattern": "^EMS Agent Started",
"action": "imeStarted",
"description": "Detects when the Intune Management Extension (IME) agent starts up.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-STOP-SIGNAL",
"category": "currentPhase",
"pattern": "EMS Agent received stop signal",
"pattern": "^EMS Agent received stop signal",
"action": "updateStatePostponed",
"parameters": { "useCurrentApp": "true" },
"description": "Detects an IME service stop ('EMS Agent received stop signal', EmsAgentService.OnStop) — fired on manual restarts and agent-updater restarts, unlike the OS-shutdown-only 'shutdown signal' line matched by IME-SHUTDOWN. Postpones the current app installation, mirroring IME-SHUTDOWN semantics.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-SUBGRAPH",
"category": "currentPhase",
"pattern": "\\[Win32App\\]\\[V3Processor\\] Processing subgraph with app ids: {GUID}",
"pattern": "^\\[Win32App\\]\\[V3Processor\\] Processing subgraph with app ids: {GUID}",
"action": "cancelStuckAndSetCurrent",
"description": "Detects when V3Processor starts a new subgraph, cancelling any stuck app and setting the new app as current.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-TOKEN-FAILURE",
"category": "always",
"pattern": "Failed to get AAD token\\..*?errorCode = (?<errorCode>.*?)$",
"pattern": "^Failed to get AAD token\\..*?errorCode = (?<errorCode>.*?)$",
"action": "imeTokenFailure",
"description": "IME token acquisition failure ('Failed to get AAD token. len = N using client id ... and resource id ..., errorCode = N', IntuneTokenManager, IntuneManagementExtension.log). This line appears ROUTINELY during the device phase (no user token exists yet), so the agent holds the failure pending: any IME-TOKEN-SUCCESS match clears it, and the ime_token_failure Warning fires only when no success follows for the whole 30-min grace window (then deduped to one Warning per distinct errorCode). A genuine auth outage (WAM broken, conditional access, network) runs long enough to hit the window. Verified against IME 1.97 and 1.104 decompiled sources.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-TOKEN-SUCCESS",
"category": "always",
"pattern": "Successfully get the token",
"pattern": "^Successfully get the token",
"action": "espPhaseDetected",
"parameters": { "phase": "AccountSetup" },
"description": "Detects successful token acquisition, indicating the AccountSetup ESP phase has started.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-UPDATE-NAME-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ExecManager: processing targeted app.*?name\\W+(?<name>.*?)\\W+id\\W+{GUID}",
"pattern": "^\\[Win32App\\] ExecManager: processing targeted app.*?name\\W+(?<name>.*?)\\W+id\\W+{GUID}",
"action": "updateName",
"description": "Captures the app name from ExecManager processing log (old format: name before id). DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-UPDATE-NAME-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name (?<name>.*?)$",
"pattern": "^\\[Win32App\\] ProcessAppWithDependencies starts for {GUID} with name (?<name>.*?)$",
"action": "updateName",
"description": "Captures the app name from ProcessAppWithDependencies log entry. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-UPDATE-NAME-3",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Processing app \\(id={GUID}, name = (?<name>.*?)\\)",
"pattern": "^\\[Win32App\\] Processing app \\(id={GUID}, name = (?<name>.*?)\\)",
"action": "updateName",
"description": "Captures the app name from the Processing app log entry. DISABLED 2026-08-17: emitter no longer exists in current IME (1.97.107, Dec 2025) - the old V1/V2 app processing pipeline was removed and this line is not logged anymore (verified against decompiled source, see tasks/ime-v1-code-audit-2026-08-17.md). Kept for history.",
"enabled": false
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-USER-SESSION-COMPLETED",
"category": "always",
"pattern": "\\[Win32App\\] \\.+ Completed user session \\d+, userId: (?<userId>[a-f0-9\\-]+), userSID: (?<userSid>S-[\\d\\-]+) \\.+",
"pattern": "^\\[Win32App\\] \\.+ Completed user session \\d+, userId: (?<userId>[a-f0-9\\-]+), userSID: (?<userSid>S-[\\d\\-]+) \\.+",
"action": "enrollmentCompleted",
"description": "Detects when IME completes a user session, indicating enrollment has finished for that user.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-USER-SESSION-ZERO-APPS",
"category": "always",
"pattern": "\\[Win32App\\] Get 0 apps for user session (?<sessionId>\\d+), user id = (?<userId>[a-f0-9\\-]+)",
"pattern": "^\\[Win32App\\] Get 0 apps for user session (?<sessionId>\\d+), user id = (?<userId>[a-f0-9\\-]+)",
"action": "userSessionZeroApps",
"description": "Detects when IME enumerated a user session and found zero targeted Win32 apps. IME then skips its 'Completed user session' line entirely (the zero-app branch in ApplicationPoller continues before that log statement), so this line is the only evidence that user-phase enforcement finished on a device with no user-targeted apps. Treated as equivalent to a completed user session.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-WIN32-STATE-1",
"category": "currentPhase",
"pattern": "\\[Win32App\\] Got InstanceID: Win32App_{GUID}_\\d+, installationStateString: (?<state>\\d)",
"pattern": "^\\[Win32App\\] Got InstanceID: Win32App_{GUID}_\\d+, installationStateString: (?<state>\\d)",
"action": "updateWin32AppState",
"description": "Captures the Win32 app installation state string from instance ID tracking (old log format).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-WIN32-STATE-2",
"category": "currentPhase",
"pattern": "\\[Win32App\\] (?:Got|Set) (?:ESP )?win32App state (?<state>\\w+) for {GUID}",
"pattern": "^\\[Win32App\\] (?:Got|Set) (?:ESP )?win32App state (?<state>\\w+) for {GUID}",
"action": "updateWin32AppState",
"description": "Captures the Win32 app ESP state (e.g., Installed, InProgress) for a specific app.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-WINGET-ERROR",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Error",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Error",
"action": "updateStateError",
"description": "Marks a WinGet (new Store) app as failed when its operation progress reports phase Error (WinGetOperationInstallPhase: Downloading/Installing/Queued/Finished/Error). Before this pattern only the Installing phase was matched, so WinGet failures never surfaced as app errors (IME 1.97 audit 2026-08-17).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-WINGET-INSTALLING-1",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID} and user = .*?- Operation Phase = Installing",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID} and user = .*?- Operation Phase = Installing",
"action": "updateStateInstalling",
"description": "Detects WinGet app installation progress with Operation Phase = Installing (format variant 1).",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "IME-WINGET-INSTALLING-2",
"category": "currentPhase",
"pattern": "\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Installing",
"pattern": "^\\[WinGetMessageProcessor\\] Processing Progress for app = {GUID}.*?- Operation Phase = Installing",
"action": "updateStateInstalling",
"description": "Detects WinGet app installation progress with Operation Phase = Installing (format variant 2).",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-AGENT-ERROR",
"category": "always",
"pattern": "error from script =(?<output>[\\s\\S]*)",
"pattern": "^error from script =(?<output>[\\s\\S]*)",
"action": "scriptOutput",
"parameters": { "scriptType": "platform", "outputType": "stderr" },
"description": "Captures error output from AgentExecutor.log when a platform script produces stderr content.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-AGENT-EXITCODE",
"category": "always",
"pattern": "Powershell exit code is (?<exitCode>-?\\d+)",
"pattern": "^Powershell exit code is (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"parameters": { "scriptType": "platform" },
"description": "Captures the PowerShell exit code from AgentExecutor.log.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-AGENT-INVOCATION",
"category": "always",
"pattern": "ExecutorLog AgentExecutor gets invoked",
"pattern": "^ExecutorLog AgentExecutor gets invoked",
"action": "resetPlatformScriptContext",
"description": "Marks the start of a new AgentExecutor.exe invocation. AgentExecutor hosts BOTH platform scripts (Policies\\Scripts\\<id>.ps1) and proactive-remediation scripts (IMECache\\HealthScripts\\<id>\\detect.ps1) and writes their lines interleaved into the shared AgentExecutor.log. The policyId-less 'Powershell exit code is N' / 'write output done' lines are otherwise routed to the last-started platform script via a sticky pointer, so a remediation invocation (whose start line does not match PS-AGENT-SCRIPT-START) leaks its exit/output into that platform script's result. This pattern resets the platform-script line-capture context at each invocation boundary so only the matching platform invocation captures its own exit/output.",
"enabled": true
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-AGENT-OUTPUT",
"category": "always",
"pattern": "write output done\\. output = (?<output>[\\s\\S]*?), error = (?<error>[\\s\\S]*)",
"pattern": "^write output done\\. output = (?<output>[\\s\\S]*?), error = (?<error>[\\s\\S]*)",
"action": "scriptOutput",
"parameters": { "scriptType": "platform" },
"description": "Captures both stdout and stderr from AgentExecutor.log when a platform script completes. The output group contains stdout, the error group contains stderr.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-AGENT-SCRIPT-START",
"category": "always",
"pattern": "Adding argument powershell with value C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1",
"pattern": "^Adding argument powershell with value C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1",
"action": "scriptStarted",
"parameters": { "scriptType": "platform", "source": "agentexecutor" },
"description": "Detects platform script identification in AgentExecutor.log. Captures PolicyId from the script file path for stdout/stderr correlation.",
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-SCRIPT-CONTEXT",
"category": "always",
"pattern": "Launch powershell executor in (?<context>machine|user) session",
"pattern": "^Launch powershell executor in (?<context>machine|user) session",
"action": "scriptContext",
"description": "Captures whether a PowerShell script runs in machine (System) or user session context.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-SCRIPT-EXITCODE",
"category": "always",
"pattern": "Powershell execution is done, exitCode = (?<exitCode>-?\\d+)",
"pattern": "^Powershell execution is done, exitCode = (?<exitCode>-?\\d+)",
"action": "scriptExitCode",
"description": "Captures the PowerShell exit code when script execution completes in the IME log.",
"enabled": true
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-SCRIPT-GENERATED",
"category": "always",
"pattern": "Script file C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1 is generated",
"pattern": "^Script file C:\\\\.*\\\\Policies\\\\Scripts\\\\[a-z0-9\\-]+_(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})\\.ps1 is generated",
"action": "scriptStarted",
"parameters": { "scriptType": "platform" },
"description": "Detects when a platform PowerShell script file is generated by IME. Captures the PolicyId from the script file path.",
+1 -1
View File
@@ -2,7 +2,7 @@
"$schema": "../schema/ime-log-pattern.schema.json",
"patternId": "PS-SCRIPT-RESULT",
"category": "always",
"pattern": "\\[PowerShell\\] User Id = [a-z0-9\\-]+, Policy id = (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}), policy result = (?<result>\\w+)",
"pattern": "^\\[PowerShell\\] User Id = [a-z0-9\\-]+, Policy id = (?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}), policy result = (?<result>\\w+)",
"action": "scriptCompleted",
"parameters": { "scriptType": "platform" },
"description": "Captures the final result (Success/Failed) of a platform PowerShell script execution with its PolicyId.",
@@ -0,0 +1,116 @@
using System.IO;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
public sealed class BoundedLineReaderTests
{
private static BoundedLineReader Over(byte[] bytes, int cap = 1024, long start = 0)
{
var ms = new MemoryStream(bytes);
ms.Position = start;
return new BoundedLineReader(ms, cap);
}
private static byte[] B(string s) => Encoding.UTF8.GetBytes(s);
[Fact]
public async Task Splits_on_LF_and_strips_one_CR_with_exact_positions()
{
var r = Over(B("ab\r\ncd\n\r\nef"));
Assert.Equal("ab", await r.ReadLineAsync(CancellationToken.None));
Assert.Equal(0, r.LastLineStart);
Assert.Equal(4, r.Position);
Assert.True(r.LastLineTerminated);
Assert.Equal("cd", await r.ReadLineAsync(CancellationToken.None));
Assert.Equal(4, r.LastLineStart);
Assert.Equal(7, r.Position);
Assert.Equal("", await r.ReadLineAsync(CancellationToken.None));
Assert.Equal(7, r.LastLineStart);
Assert.Equal(9, r.Position);
Assert.Equal("ef", await r.ReadLineAsync(CancellationToken.None));
Assert.Equal(9, r.LastLineStart);
Assert.Equal(11, r.Position);
Assert.False(r.LastLineTerminated);
Assert.Null(await r.ReadLineAsync(CancellationToken.None));
}
[Fact]
public async Task Bom_is_skipped_only_at_file_offset_zero()
{
var bom = new byte[] { 0xEF, 0xBB, 0xBF };
var bytes = new byte[bom.Length * 2 + 4];
bom.CopyTo(bytes, 0);
B("a\n").CopyTo(bytes, 3);
bom.CopyTo(bytes, 5);
B("b\n").CopyTo(bytes, 8);
var r = Over(bytes);
Assert.Equal("a", await r.ReadLineAsync(CancellationToken.None));
Assert.Equal("b", await r.ReadLineAsync(CancellationToken.None));
// Starting mid-file (a later pass) never treats the first bytes as a BOM.
var r2 = Over(bytes, start: 5);
Assert.Equal("b", await r2.ReadLineAsync(CancellationToken.None));
Assert.Equal(5, r2.LastLineStart);
}
[Fact]
public async Task Multibyte_utf8_across_the_read_buffer_boundary_decodes_intact()
{
// 64 KB read buffer: put a 3-byte char straddling the boundary.
var sb = new StringBuilder();
while (Encoding.UTF8.GetByteCount(sb.ToString()) < 64 * 1024 - 1) sb.Append('x');
var text = sb + "€tail\n";
var r = Over(B(text), cap: 1024 * 1024);
Assert.Equal(text.TrimEnd('\n'), await r.ReadLineAsync(CancellationToken.None));
}
[Fact]
public async Task Line_over_the_cap_is_truncated_to_the_cap_and_the_rest_discarded()
{
var big = new string('z', 5000);
var r = Over(B("<![LOG[" + big + "\nnext\n"), cap: 100);
var first = await r.ReadLineAsync(CancellationToken.None);
Assert.True(r.LastLineTruncated);
Assert.True(r.LastLineTerminated);
Assert.Equal(100, first.Length);
Assert.StartsWith("<![LOG[", first);
Assert.Equal(0, r.LastLineStart);
Assert.Equal(7 + 5000 + 1, r.Position);
Assert.Equal("next", await r.ReadLineAsync(CancellationToken.None));
Assert.False(r.LastLineTruncated);
}
[Fact]
public async Task Unterminated_tail_over_the_cap_is_reported_as_truncated_and_unterminated()
{
var r = Over(B(new string('q', 300)), cap: 50);
var line = await r.ReadLineAsync(CancellationToken.None);
Assert.Equal(50, line.Length);
Assert.True(r.LastLineTruncated);
Assert.False(r.LastLineTerminated);
Assert.Equal(300, r.Position);
Assert.Null(await r.ReadLineAsync(CancellationToken.None));
}
[Fact]
public async Task Empty_stream_returns_null_immediately()
{
var r = Over(new byte[0]);
Assert.Null(await r.ReadLineAsync(CancellationToken.None));
Assert.Equal(0, r.Position);
}
}
}
@@ -0,0 +1,368 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Text;
using System.Text.RegularExpressions;
using AutopilotMonitor.Shared.Models;
using Newtonsoft.Json;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
/// <summary>
/// Guards the shipped IME log-pattern pack (<c>rules/ime-log-patterns/*.json</c>, the same
/// files combine.js embeds into agent and backend) against super-linear backtracking.
/// <para>
/// The IME Logs folder is writable by standard users and the SYSTEM tracker matches every
/// appended line against every active pattern. Unanchored patterns with unbounded lazy gaps
/// (<c>.*?</c>, <c>[^}]*?</c>, lookaheads) let one crafted line burn the full 1 s timeout per
/// pattern; anchoring at the message start ('^') makes a non-matching pattern O(prefix), and
/// bounding the nested scan in IME-APP-VERSION removes the remaining quadratic case.
/// </para>
/// Compiled with exactly the options <c>ImeLogTracker.CompilePatterns</c> uses.
/// </summary>
public sealed class ImeLogPatternPackLinearityTests
{
private const string GuidPattern = @"(?<id>[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12})";
private const RegexOptions AgentOptions = RegexOptions.IgnoreCase | RegexOptions.Compiled | RegexOptions.Singleline;
private static readonly TimeSpan AgentTimeout = TimeSpan.FromSeconds(1);
// Generous for a loaded CI box; a super-linear pattern on these inputs takes the full
// 1 s timeout (or throws), never tens of milliseconds.
private const int MaxMillisPerMatch = 150;
private const int HostileBytes = 512 * 1024;
private const string Guid1 = "5c95bf94-1cf4-4629-88d1-3f616e7a405c";
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}");
}
private static List<ImeLogPattern> LoadAll()
{
var list = new List<ImeLogPattern>();
foreach (var file in Directory.GetFiles(FindRulesPatternDir(), "*.json").OrderBy(f => f, StringComparer.Ordinal))
{
var p = JsonConvert.DeserializeObject<ImeLogPattern>(File.ReadAllText(file));
Assert.NotNull(p);
Assert.False(string.IsNullOrEmpty(p!.PatternId), $"{file}: patternId missing");
Assert.False(string.IsNullOrEmpty(p.Pattern), $"{file}: pattern missing");
list.Add(p);
}
Assert.True(list.Count >= 80, $"expected the full pack, found {list.Count}");
return list;
}
private static Regex Compile(ImeLogPattern p)
=> new Regex(p.Pattern.Replace("{GUID}", GuidPattern), AgentOptions, AgentTimeout);
public static IEnumerable<object[]> AllPatternIds()
=> LoadAll().Select(p => new object[] { p.PatternId });
private static ImeLogPattern Get(string id)
=> LoadAll().Single(p => string.Equals(p.PatternId, id, StringComparison.OrdinalIgnoreCase));
/// <summary>
/// The literal run at the start of a pattern (after '^'), with regex escapes resolved —
/// what an attacker would repeat to force a re-scan at every occurrence.
/// </summary>
internal static string LiteralPrefix(string pattern)
{
var sb = new StringBuilder();
var i = pattern.StartsWith("^", StringComparison.Ordinal) ? 1 : 0;
while (i < pattern.Length)
{
var c = pattern[i];
if (c == '\\' && i + 1 < pattern.Length)
{
var n = pattern[i + 1];
if (char.IsLetterOrDigit(n)) break; // \d, \w, \s… — a class, not a literal
sb.Append(n);
i += 2;
continue;
}
if ("(.*+?[{|$".IndexOf(c) >= 0) break;
sb.Append(c);
i++;
}
return sb.ToString();
}
// ---------------------------------------------------------------- invariants
[Fact]
public void Every_shipped_pattern_is_anchored_at_the_message_start()
{
var unanchored = LoadAll().Where(p => !p.Pattern.StartsWith("^", StringComparison.Ordinal)).Select(p => p.PatternId).ToList();
Assert.True(unanchored.Count == 0,
"Shipped IME patterns must start with '^' (the matcher runs them over attacker-appendable lines; " +
"an unanchored pattern re-scans at every offset). Unanchored: " + string.Join(", ", unanchored));
}
[Fact]
public void Every_shipped_pattern_compiles_with_the_agent_options()
{
foreach (var p in LoadAll())
Compile(p);
}
[Fact]
public void No_shipped_pattern_uses_an_unbounded_negated_class_scan()
{
// '[^x]*?' after a lazy gap is the chained-quantifier shape that stays quadratic even
// when anchored (IME-APP-VERSION before the fix). Bounded forms '[^x]{0,N}?' are fine.
var offenders = LoadAll()
.Where(p => Regex.IsMatch(p.Pattern, @"\[\^[^\]]+\]\*\??"))
.Select(p => p.PatternId).ToList();
Assert.True(offenders.Count == 0, "Unbounded negated-class scans: " + string.Join(", ", offenders));
}
// ---------------------------------------------------------------- hostile inputs
private static IEnumerable<string> HostileInputsFor(ImeLogPattern p)
{
var prefix = LiteralPrefix(p.Pattern);
if (prefix.Length == 0) prefix = "[Win32App] ";
// (1) The prefix repeated: m start positions × O(n) tail scan for an unanchored pattern.
var repeated = new StringBuilder(HostileBytes + prefix.Length);
while (repeated.Length < HostileBytes) repeated.Append(prefix);
yield return repeated.ToString();
// (2) Prefix + GUID + repeated inner trigger with no closing brace / NewValue (APP-VERSION shape).
var inner = new StringBuilder(HostileBytes);
inner.Append(prefix).Append(Guid1);
while (inner.Length < HostileBytes) inner.Append("\"DetectedIdentityVersion\":{x");
yield return inner.ToString();
// (3) Prefix once, then a long run of word chars (greedy \w+/[^"]+ backtracking shape).
yield return prefix + Guid1 + new string('a', HostileBytes);
// (4) Prefix repeated with newlines and DO-timeout words but the trailing literal missing.
var mixed = new StringBuilder(HostileBytes);
while (mixed.Length < HostileBytes) mixed.Append(prefix).Append(" not finished timeout\n");
yield return mixed.ToString();
}
[Theory]
[MemberData(nameof(AllPatternIds))]
public void Pattern_completes_in_linear_time_on_hostile_lines(string patternId)
{
var p = Get(patternId);
var regex = Compile(p);
var n = 0;
foreach (var input in HostileInputsFor(p))
{
n++;
var best = TimeBestOfThree(regex, input, () => $"{patternId}: regex timeout on hostile input #{n} ({input.Length} chars)");
Assert.True(best < MaxMillisPerMatch,
$"{patternId}: hostile input #{n} ({input.Length} chars) took {best} ms — super-linear backtracking");
}
}
/// <summary>
/// Best of three timed runs after a warm-up call: the first Match of a Compiled regex
/// JIT-compiles its generated IL, and a loaded CI box adds scheduling noise — neither is
/// backtracking. A quadratic pattern is not rescued by a minimum: it takes the full
/// timeout every run.
/// </summary>
private static long TimeBestOfThree(Regex regex, string input, Func<string> timeoutMessage)
{
regex.Match("warm-up");
long best = long.MaxValue;
for (var run = 0; run < 3; run++)
{
var sw = Stopwatch.StartNew();
try
{
regex.Match(input);
}
catch (RegexMatchTimeoutException)
{
Assert.Fail(timeoutMessage());
}
sw.Stop();
best = Math.Min(best, sw.ElapsedMilliseconds);
}
return best;
}
[Fact]
public void The_reported_quadratic_APP_VERSION_input_is_now_fast()
{
// The finding's concrete input: prefix + GUID + ~20,000 × '"DetectedIdentityVersion":{x'.
var p = Get("IME-APP-VERSION");
var regex = Compile(p);
var sb = new StringBuilder();
sb.Append("[Win32App][ReportingManager] Detection state for app with id: ").Append(Guid1);
for (var i = 0; i < 20000; i++) sb.Append("\"DetectedIdentityVersion\":{x");
var input = sb.ToString();
Assert.False(regex.Match(input).Success);
var best = TimeBestOfThree(regex, input, () => "regex timeout on the reported input");
Assert.True(best < MaxMillisPerMatch, $"took {best} ms");
}
// ---------------------------------------------------------------- real-line fidelity
/// <summary>
/// Representative real IME messages (GUIDs/names neutralized) for the patterns whose
/// regex changed shape: the anchored pack must still match them with the same captures.
/// </summary>
public static IEnumerable<object[]> RealLines()
{
yield return new object[]
{
"IME-APP-VERSION",
"[Win32App][ReportingManager] Detection state for app with id: " + Guid1 + " has been updated. Report delta: {\"DetectionState\":{\"OldValue\":\"NotInstalled\",\"NewValue\":\"Installed\"},\"DetectedIdentityVersion\":{\"OldValue\":null,\"NewValue\":\"11.2.1952.0\"}}",
new[] { "id=" + Guid1, "appVersion=11.2.1952.0" }
};
yield return new object[]
{
"IME-ESP-APP-REGISTERED",
"[Win32App][EspManager] In EspPhase: DeviceSetup. App " + Guid1 + " has been registered. App name: Company Portal",
new[] { "id=" + Guid1, "name=Company Portal" }
};
yield return new object[]
{
"IME-CACHE-MISS",
"[Win32App] Content cache miss for app (id = " + Guid1 + ", name = Microsoft Teams - Autoupdate), start downloading...",
new[] { "id=" + Guid1, "name=Microsoft Teams - Autoupdate" }
};
yield return new object[]
{
"IME-DOWNLOADING",
"[StatusService] Downloading app (id = " + Guid1 + ", name Company Portal) via WinGet, bytes 0/100 for user 00000000-0000-0000-0000-000000000000",
new[] { "id=" + Guid1, "tech=WinGet", "bytes=0", "ofbytes=100" }
};
yield return new object[]
{
"IME-APP-TYPE-WINGET",
"[Win32App][WinGetApp][WinGetAppDetectionExecutor] Starting detection of app with id: " + Guid1 + " and context: SystemContext.",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-APP-TYPE-MSI",
"[Win32App] Autopilot ESP phase: DeviceSetup. MSI App " + Guid1 + " reset retriable error codes MaxRetries to 15 times and RetryIntervalInMinutes to 3 min for this check-in",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-SET-CURRENT-4",
@"[Win32App] SetCurrentDirectory: C:\Windows\IMECache\" + Guid1 + "_1",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-ERROR-REPORT",
"[Win32App][ReportingManager] Execution state for app with id: " + Guid1 + " has been updated. Report delta: {\"EnforcementState\":{\"OldValue\":null,\"NewValue\":\"InProgress\"}}",
new[] { "id=" + Guid1, "to=InProgress" }
};
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",
new[] { "errorCode=3399548929" }
};
yield return new object[]
{
"IME-ESP-TRACK-STATUS",
"[Win32App][EspManager] Updating ESP tracked install status from NotInstalled to InProgress for application " + Guid1 + " with name: Company Portal.",
new[] { "from=NotInstalled", "to=InProgress", "id=" + Guid1 }
};
yield return new object[]
{
"PS-AGENT-OUTPUT",
"write output done. output = OK. Hosts cleaned.\n\n, error = \n",
new[] { "output=OK. Hosts cleaned.\n\n", "error=\n" }
};
yield return new object[]
{
"PS-SCRIPT-GENERATED",
@"Script file C:\Program Files (x86)\Microsoft Intune Management Extension\Policies\Scripts\00000000-0000-0000-0000-000000000000_6269c24c-0a00-455b-b0b5-60e2e9026723.ps1 is generated.",
new[] { "id=6269c24c-0a00-455b-b0b5-60e2e9026723" }
};
yield return new object[]
{
"IME-NOT-TARGETED-1",
"[Win32App][ActionProcessor] App with id: " + Guid1 + ", targeted intent: RequiredInstall, and enforceability: Enforceable has projected enforcement classification: NotApplicableOrNotTargeted with desired state: None. Current state is:\nDetection = NotDetected",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-DETECTION-RESULT",
"[Win32App][DetectionActionHandler] Detection for policy with id: " + Guid1 + " resulted in action status: Success and detection state: NotDetected.",
new[] { "id=" + Guid1, "detection=NotDetected" }
};
yield return new object[]
{
"IME-ERROR-UNMAPPED-EXIT",
"[Win32App] Admin did NOT set mapping for lpExitCode: 1603 of app: " + Guid1,
new[] { "exitCode=1603", "id=" + Guid1 }
};
yield return new object[]
{
"IME-GRS-SKIP",
"[Win32App][ActionProcessor] App with id: " + Guid1 + " to install is in GRS. The app will not be enforced.",
new[] { "id=" + Guid1 }
};
yield return new object[]
{
"IME-ERROR-ENFORCEMENT",
"[Win32App] Setting enforcementState as: Error with lpExitCode: 1603 without mapping",
new string[0]
};
yield return new object[]
{
"PS-SCRIPT-CONTEXT",
"Launch powershell executor in machine session",
new[] { "context=machine" }
};
yield return new object[]
{
"IME-DO-TIMEOUT-2",
"[Win32App DO] DO download is not finished after 600 seconds, timeout",
new string[0]
};
}
[Theory]
[MemberData(nameof(RealLines))]
public void Anchored_pattern_still_matches_the_real_line_with_the_same_captures(string patternId, string message, string[] expectedGroups)
{
var regex = Compile(Get(patternId));
var m = regex.Match(message);
Assert.True(m.Success, $"{patternId} no longer matches: {message}");
Assert.Equal(0, m.Index);
foreach (var expected in expectedGroups)
{
var eq = expected.IndexOf('=');
var group = expected.Substring(0, eq);
var value = expected.Substring(eq + 1);
Assert.Equal(value, m.Groups[group].Value);
}
}
[Fact]
public void PS_SCRIPT_CONTEXT_no_longer_fires_on_Win32App_detection_script_lines()
{
// Before anchoring, the unanchored pattern matched these AppWorkload.log lines mid-message
// (122 hits in 8 real diagnostics sets) and HandleScriptContext overwrote the pending
// PLATFORM script's RunContext with a Win32 detection script's context.
var regex = Compile(Get("PS-SCRIPT-CONTEXT"));
Assert.DoesNotMatch(regex, "[Win32App] SideCarScriptDetectionManager Launch powershell executor in machine session");
Assert.DoesNotMatch(regex, "[Win32App] SideCarScriptRequirementManager Launch powershell executor in machine session");
}
}
}
@@ -448,8 +448,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
/// reacting to. A same-shaped entry under the cap still assembles and matches.
/// </summary>
[Theory]
[InlineData(2 * 1024 * 1024, false)] // over cap → dropped, warned
[InlineData(64 * 1024, true)] // under cap → assembled, matched
[InlineData(ImeLogTracker.MaxEntryBytes + 64 * 1024, false)] // over cap → dropped, warned
[InlineData(64 * 1024, true)] // under cap → assembled, matched
public async Task MultilineEntry_IsDroppedAndWarned_WhenItExceedsTheCharCap(int fillerChars, bool expectMatch)
{
using var h = new Harness();
@@ -0,0 +1,201 @@
using System;
using System.Collections.Generic;
using System.IO;
using System.Linq;
using System.Text;
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.Logging;
using AutopilotMonitor.Shared.Models;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime
{
/// <summary>
/// The read loop of <c>CheckLogFilesAsync</c> after the bounded-reader hardening: oversized
/// physical lines are dropped without starving the entries around them, an unterminated
/// EOF tail is held back for the writer instead of being raw-matched as fragments, a
/// cancelled pass leaves an exact bookmark, and a hostile pass leaves one Warning line.
/// </summary>
public sealed class ImeLogTrackerReadLoopHardeningTests
{
private static readonly DateTime T0 = new DateTime(2026, 8, 30, 10, 0, 0, DateTimeKind.Utc);
private const string LogName = "AppWorkload.log";
private static List<ImeLogPattern> Patterns() => new List<ImeLogPattern>
{
new ImeLogPattern
{
PatternId = "T-MARK", Category = "always", Enabled = true,
Pattern = @"^marker (?<n>\d+)", Action = "noop",
Parameters = new Dictionary<string, string>(),
},
};
private static string Entry(string message)
=> $"<![LOG[{message}]LOG]!><time=\"12:00:00.0000000\" date=\"8-30-2026\" component=\"X\" context=\"\" type=\"1\" thread=\"1\" file=\"\">";
private sealed class Harness : IDisposable
{
private readonly TempDirectory _tmp = new TempDirectory();
private readonly string _matchLog;
public ImeLogTracker Tracker { get; }
public DateTime Now { get; set; } = T0;
public string LogPath => Path.Combine(_tmp.Path, LogName);
public Harness()
{
var logDir = Path.Combine(_tmp.Path, "agent");
Directory.CreateDirectory(logDir);
_matchLog = Path.Combine(logDir, "ime-pattern-matches.log");
Tracker = new ImeLogTracker(_tmp.Path, Patterns(), new AgentLogger(logDir, AgentLogLevel.Info), matchLogPath: _matchLog);
Tracker.UtcNowProvider = () => Now;
}
public void Append(string text) => File.AppendAllText(LogPath, text, new UTF8Encoding(false));
public Task Pass(CancellationToken token = default) => Tracker.CheckLogFilesAsync(token);
/// <summary>Marker numbers matched so far, in order.</summary>
public List<int> Matched()
{
if (!File.Exists(_matchLog)) return new List<int>();
return File.ReadAllLines(_matchLog)
.Select(l => System.Text.RegularExpressions.Regex.Match(l, @"marker (\d+)"))
.Where(m => m.Success).Select(m => int.Parse(m.Groups[1].Value)).ToList();
}
public string AgentLogText()
{
var dir = Path.Combine(_tmp.Path, "agent");
return string.Join("\n", Directory.GetFiles(dir, "agent*.log").Select(File.ReadAllText));
}
public void Dispose()
{
Tracker.Dispose();
_tmp.Dispose();
}
}
[Fact]
public async Task Oversized_single_line_is_dropped_and_the_entries_around_it_still_match()
{
using var h = new Harness();
var huge = new string('x', ImeLogTracker.MaxEntryBytes + 10);
h.Append(Entry("marker 1") + "\n" + Entry("marker 2 " + huge) + "\n" + Entry("marker 3") + "\n");
await h.Pass();
Assert.Equal(new[] { 1, 3 }, h.Matched());
Assert.Contains("oversizedLines=1", h.AgentLogText());
}
[Fact]
public async Task Oversized_multiline_opener_skips_its_continuation_lines_instead_of_raw_matching_them()
{
using var h = new Harness();
var huge = new string('x', ImeLogTracker.MaxEntryBytes + 10);
// Opener over the cap without its close, then continuation lines that would each
// match raw if they reached the matcher, then the close, then a real entry.
h.Append("<![LOG[marker 5 " + huge + "\nmarker 6\nmarker 7\n]LOG]!><time=\"12:00:00.0000000\" date=\"8-30-2026\" component=\"X\" context=\"\" type=\"1\" thread=\"1\" file=\"\">\n"
+ Entry("marker 8") + "\n");
await h.Pass();
Assert.Equal(new[] { 8 }, h.Matched());
}
[Fact]
public async Task Unterminated_tail_is_held_back_until_the_writer_finishes_it()
{
using var h = new Harness();
h.Append(Entry("marker 1") + "\n");
await h.Pass();
Assert.Equal(new[] { 1 }, h.Matched());
// Writer mid-line: the closing tag and newline are not there yet.
h.Append("<![LOG[marker 2");
h.Now = T0.AddMilliseconds(100);
await h.Pass();
Assert.Equal(new[] { 1 }, h.Matched());
h.Append("]LOG]!><time=\"12:00:00.0000000\" date=\"8-30-2026\" component=\"X\" context=\"\" type=\"1\" thread=\"1\" file=\"\">\n");
h.Now = T0.AddMilliseconds(200);
await h.Pass();
Assert.Equal(new[] { 1, 2 }, h.Matched());
}
[Fact]
public async Task Held_tail_settles_after_the_file_stands_still_and_is_then_processed()
{
using var h = new Harness();
// A final line without newline that IS complete (archived file, writer gone).
h.Append(Entry("marker 1") + "\n" + Entry("marker 2"));
await h.Pass();
Assert.Equal(new[] { 1 }, h.Matched());
h.Now = T0.AddMilliseconds(500);
await h.Pass();
Assert.Equal(new[] { 1 }, h.Matched());
h.Now = T0.Add(ImeLogTracker.HeldTailSettle).AddMilliseconds(1);
await h.Pass();
Assert.Equal(new[] { 1, 2 }, h.Matched());
// And nothing is re-read afterwards.
h.Now = h.Now.AddSeconds(5);
await h.Pass();
Assert.Equal(new[] { 1, 2 }, h.Matched());
}
[Fact]
public async Task Cancelled_pass_bookmarks_exactly_so_nothing_is_lost_or_duplicated()
{
using var h = new Harness();
h.Append(Entry("marker 1") + "\n" + Entry("marker 2") + "\n" + Entry("marker 3") + "\n");
using (var cts = new CancellationTokenSource())
{
cts.Cancel();
await h.Pass(cts.Token);
}
Assert.Empty(h.Matched());
await h.Pass();
Assert.Equal(new[] { 1, 2, 3 }, h.Matched());
await h.Pass();
Assert.Equal(new[] { 1, 2, 3 }, h.Matched());
}
[Fact]
public async Task Hostile_pass_leaves_one_warning_summary_not_one_per_line()
{
using var h = new Harness();
var huge = new string('x', ImeLogTracker.MaxEntryBytes + 10);
var sb = new StringBuilder();
for (var i = 0; i < 3; i++) sb.Append(Entry("junk " + huge)).Append('\n');
sb.Append(Entry("marker 9")).Append('\n');
h.Append(sb.ToString());
await h.Pass();
Assert.Equal(new[] { 9 }, h.Matched());
var text = h.AgentLogText();
Assert.Equal(1, CountOf(text, "pass skipped work"));
Assert.Contains("oversizedLines=3", text);
}
private static int CountOf(string text, string needle)
{
var count = 0;
var idx = 0;
while ((idx = text.IndexOf(needle, idx, StringComparison.Ordinal)) >= 0) { count++; idx += needle.Length; }
return count;
}
}
}
@@ -0,0 +1,160 @@
using System;
using System.IO;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
/// <summary>
/// Byte-oriented, length-bounded line reader for tailing IME logs.
/// <para>
/// Why not <see cref="StreamReader.ReadLineAsync"/>: it materializes the whole line before the
/// caller can look at its length, so a single multi-hundred-MB line appended by any process
/// that can write to the IME Logs folder (standard users can) is allocated in full — an
/// OutOfMemory in the SYSTEM tracker's poll loop, which retries from the same position every
/// second. This reader stops accumulating at <see cref="MaxLineBytes"/>, discards the rest of
/// the line while scanning for the terminator, and reports the line as
/// <see cref="LastLineTruncated"/> with only the capped prefix returned. Its read-ahead is
/// tracked in bytes, so <see cref="Position"/> is the exact file offset of the next unread
/// byte — a consumer can bookmark the start of a line it did not process instead of the
/// StreamReader's opaque decoder position.
/// </para>
/// Semantics: '\n' terminates a line; one trailing '\r' is stripped (IME writes CRLF, never a
/// lone CR); a UTF-8 BOM is skipped only at absolute file offset 0; bytes are decoded as UTF-8
/// (invalid sequences become U+FFFD, matching the previous StreamReader behaviour). An
/// unterminated tail at EOF is returned with <see cref="LastLineTerminated"/> == false so the
/// caller can decide whether to hold it back for the writer to finish.
/// </summary>
internal sealed class BoundedLineReader
{
private const int ReadBufferSize = 64 * 1024;
private static readonly byte[] Utf8Bom = { 0xEF, 0xBB, 0xBF };
private readonly Stream _stream;
private readonly int _maxLineBytes;
private readonly byte[] _readBuffer = new byte[ReadBufferSize];
private int _readPos;
private int _readLen;
private long _readBufferFileOffset;
private bool _eof;
private byte[] _line = new byte[4096];
private int _lineLen;
/// <param name="stream">Seekable stream positioned at the first byte to read.</param>
/// <param name="maxLineBytes">Upper bound of bytes kept per line; the remainder is discarded.</param>
public BoundedLineReader(Stream stream, int maxLineBytes)
{
if (stream == null) throw new ArgumentNullException(nameof(stream));
if (maxLineBytes <= 0) throw new ArgumentOutOfRangeException(nameof(maxLineBytes));
_stream = stream;
_maxLineBytes = maxLineBytes;
_readBufferFileOffset = stream.Position;
}
/// <summary>Cap in bytes applied to every line.</summary>
public int MaxLineBytes => _maxLineBytes;
/// <summary>Absolute file offset of the next unread byte (exact — no decoder read-ahead).</summary>
public long Position => _readBufferFileOffset + _readPos;
/// <summary>Absolute file offset of the first byte of the line most recently returned.</summary>
public long LastLineStart { get; private set; }
/// <summary>True when the last returned line ended with '\n'; false for an EOF tail.</summary>
public bool LastLineTerminated { get; private set; }
/// <summary>True when the last returned line exceeded <see cref="MaxLineBytes"/> and was cut.</summary>
public bool LastLineTruncated { get; private set; }
/// <summary>
/// Reads the next line. Returns null at EOF when no bytes remain. A truncated line is
/// returned as its capped prefix (see <see cref="LastLineTruncated"/>).
/// </summary>
public async Task<string> ReadLineAsync(CancellationToken token)
{
LastLineStart = Position;
LastLineTerminated = false;
LastLineTruncated = false;
_lineLen = 0;
var sawAnyByte = false;
while (true)
{
if (_readPos >= _readLen)
{
if (_eof || !await FillAsync(token).ConfigureAwait(false))
{
if (!sawAnyByte) return null;
return Materialize();
}
}
sawAnyByte = true;
var newline = Array.IndexOf(_readBuffer, (byte)'\n', _readPos, _readLen - _readPos);
if (newline >= 0)
{
Append(_readPos, newline - _readPos);
_readPos = newline + 1;
LastLineTerminated = true;
return Materialize();
}
Append(_readPos, _readLen - _readPos);
_readPos = _readLen;
}
}
private async Task<bool> FillAsync(CancellationToken token)
{
_readBufferFileOffset += _readLen;
_readPos = 0;
_readLen = await _stream.ReadAsync(_readBuffer, 0, _readBuffer.Length, token).ConfigureAwait(false);
if (_readLen <= 0)
{
_readLen = 0;
_eof = true;
return false;
}
return true;
}
private void Append(int offset, int count)
{
if (count <= 0) return;
var room = _maxLineBytes - _lineLen;
if (count > room)
{
LastLineTruncated = true;
count = room;
if (count <= 0) return;
}
if (_lineLen + count > _line.Length)
{
var grown = new byte[Math.Max(_line.Length * 2, _lineLen + count)];
Buffer.BlockCopy(_line, 0, grown, 0, _lineLen);
_line = grown;
}
Buffer.BlockCopy(_readBuffer, offset, _line, _lineLen, count);
_lineLen += count;
}
private string Materialize()
{
var start = 0;
var len = _lineLen;
if (LastLineStart == 0 && len >= 3
&& _line[0] == Utf8Bom[0] && _line[1] == Utf8Bom[1] && _line[2] == Utf8Bom[2])
{
start = 3;
len -= 3;
}
// Only a terminated line can carry a CR before its LF; a capped line has had its
// tail (and thus any CR) discarded, so the check is skipped there.
if (LastLineTerminated && !LastLineTruncated && len > 0 && _line[start + len - 1] == (byte)'\r')
len--;
return len == 0 ? string.Empty : Encoding.UTF8.GetString(_line, start, len);
}
}
}
@@ -1,5 +1,6 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Text;
@@ -117,118 +118,182 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
{
stream.Seek(startPos, SeekOrigin.Begin);
using (var reader = new StreamReader(stream, Encoding.UTF8, detectEncodingFromByteOrderMarks: true, bufferSize: 1024, leaveOpen: true))
var reader = new BoundedLineReader(stream, MaxEntryBytes);
var stats = new PassStats();
// Buffer for multiline CMTrace entries (e.g. AgentExecutor.log
// "write output done. output = ..." spans many lines)
StringBuilder multiLineBuffer = null;
int multiLineCount = 0;
// Set after a capped entry is dropped: its remaining physical lines
// are skipped instead of being matched as raw text, until the entry
// closes or a new entry begins (so no real entry is lost).
bool skippingDroppedEntry = false;
// File offset where the entry currently being assembled/processed
// begins — the bookmark to fall back to when that entry is NOT
// consumed (cancellation, or a held-back unterminated tail).
long entryStart = startPos;
// Where the next pass resumes. EOF unless an entry is left unconsumed.
long resumePos;
while (true)
{
// Buffer for multiline CMTrace entries (e.g. AgentExecutor.log
// "write output done. output = ..." spans many lines)
StringBuilder multiLineBuffer = null;
int multiLineCount = 0;
// Set after a capped entry is dropped: its remaining physical lines
// are skipped instead of being matched as raw text, until the entry
// closes or a new entry begins (so no real entry is lost).
bool skippingDroppedEntry = false;
string line;
while ((line = await reader.ReadLineAsync()) != null)
// CancellationToken.None: cancellation is honoured by the explicit
// check below (exact bookmark) rather than by an exception out of
// the read, which the poll loop would log as an error.
var line = await reader.ReadLineAsync(CancellationToken.None);
if (line == null)
{
if (token.IsCancellationRequested) break;
if (skippingDroppedEntry)
// EOF. An in-flight multiline entry here is an entry the writer
// has not finished — hold it back (see HoldBackTail) instead of
// dropping it and raw-matching its remaining lines next pass.
if (multiLineBuffer != null && HoldBackTail(filePath, entryStart, fileInfo.Length, passNowUtc))
{
if (line.Contains("]LOG]!>")) { skippingDroppedEntry = false; continue; }
if (!line.StartsWith("<![LOG[")) continue;
skippingDroppedEntry = false;
resumePos = entryStart;
break;
}
resumePos = reader.Position;
break;
}
// --- Multiline CMTrace buffering ---
// CMTrace entries: <![LOG[message]LOG]!><time=...>
// When message contains newlines, the entry spans multiple lines.
// We buffer until we find the closing ]LOG]!> tag.
if (token.IsCancellationRequested)
{
// Exact bookmark: nothing of this line (or of the multiline
// entry it belongs to) has been handled.
resumePos = multiLineBuffer != null ? entryStart : reader.LastLineStart;
break;
}
if (multiLineBuffer == null)
entryStart = reader.LastLineStart;
// A physical line over the cap is never matched: its captures would be
// cut and the regexes would run over attacker-sized input. The capped
// prefix is enough to tell whether it opened an entry whose remaining
// lines must be skipped rather than raw-matched.
if (reader.LastLineTruncated)
{
stats.OversizedLines++;
if (multiLineBuffer != null)
{
// Continuing a multiline entry
multiLineBuffer.Append('\n').Append(line);
multiLineCount++;
if (line.Contains("]LOG]!>"))
{
// Entry complete — use the assembled line
line = multiLineBuffer.ToString();
multiLineBuffer = null;
multiLineCount = 0;
}
else if (multiLineCount >= MaxMultiLineBufferLines || multiLineBuffer.Length >= MaxMultiLineBufferChars)
{
// Safety limit — discard to bound memory and parser work. Warning
// (not Debug) so a capped entry is visible in the client log at the
// default level: a real IME entry this large would be news.
_logger.Warning($"ImeLogTracker: discarding multiline CMTrace buffer in {Path.GetFileName(filePath)} after {multiLineCount} lines / {multiLineBuffer.Length} chars (cap {MaxMultiLineBufferLines} lines / {MaxMultiLineBufferChars} chars) — entry dropped");
multiLineBuffer = null;
multiLineCount = 0;
skippingDroppedEntry = true;
continue;
}
else
{
// Still accumulating — read next line
continue;
}
multiLineBuffer = null;
multiLineCount = 0;
skippingDroppedEntry = true;
}
else if (line.StartsWith("<![LOG[") && !line.Contains("]LOG]!>"))
{
// Start of a multiline CMTrace entry
multiLineBuffer = new StringBuilder(line);
multiLineCount = 1;
skippingDroppedEntry = true;
}
continue;
}
if (!reader.LastLineTerminated && multiLineBuffer == null
&& HoldBackTail(filePath, reader.LastLineStart, fileInfo.Length, passNowUtc))
{
// Unterminated single line at EOF: the writer is mid-line.
resumePos = reader.LastLineStart;
break;
}
if (skippingDroppedEntry)
{
// A line opening a new entry ends the skip and is processed
// itself — checked BEFORE the close-tag test, because a complete
// single-line entry contains both and must not be consumed as
// the dropped entry's close.
if (line.StartsWith("<![LOG["))
skippingDroppedEntry = false;
else
{
if (line.Contains("]LOG]!>")) skippingDroppedEntry = false;
continue;
}
}
// --- Normal processing (single-line or completed multiline) ---
CmTraceLogEntry entry;
string messageToMatch;
if (CmTraceLogParser.TryParseLine(line, out entry))
// --- Multiline CMTrace buffering ---
// CMTrace entries: <![LOG[message]LOG]!><time=...>
// When message contains newlines, the entry spans multiple lines.
// We buffer until we find the closing ]LOG]!> tag.
if (multiLineBuffer != null)
{
// Continuing a multiline entry
multiLineBuffer.Append('\n').Append(line);
multiLineCount++;
if (line.Contains("]LOG]!>"))
{
messageToMatch = entry.Message;
if (entry.HasTimestamp && !entry.BiasMinutes.HasValue)
calibrationAnchor = entry;
// Entry complete — use the assembled line
line = multiLineBuffer.ToString();
multiLineBuffer = null;
multiLineCount = 0;
}
else if (multiLineCount >= MaxMultiLineBufferLines || multiLineBuffer.Length >= MaxEntryBytes)
{
// Safety limit — discard to bound memory and parser work. Warning
// (not Debug) so a capped entry is visible in the client log at the
// default level: a real IME entry this large would be news.
_logger.Warning($"ImeLogTracker: discarding multiline CMTrace buffer in {Path.GetFileName(filePath)} after {multiLineCount} lines / {multiLineBuffer.Length} chars (cap {MaxMultiLineBufferLines} lines / {MaxEntryBytes} chars) — entry dropped");
multiLineBuffer = null;
multiLineCount = 0;
skippingDroppedEntry = true;
continue;
}
else
{
// Non-CMTrace line - match raw
messageToMatch = line;
entry = null;
}
if (string.IsNullOrEmpty(messageToMatch)) continue;
// Simulation mode delay
if (SimulationMode && entry != null)
{
await ApplySimulationDelay(ResolveEntryUtc(entry), token);
}
// Match against active patterns
foreach (var pattern in _activePatterns)
{
try
{
var match = pattern.Regex.Match(messageToMatch);
if (match.Success)
{
WriteMatchLog(filePath, line, pattern.PatternId);
HandlePatternMatch(pattern, match, messageToMatch, entry);
}
}
catch (RegexMatchTimeoutException)
{
_logger.Debug($"ImeLogTracker: regex timeout for pattern '{pattern.PatternId}' — skipped to prevent ReDoS");
}
// Still accumulating — read next line
continue;
}
}
else if (line.StartsWith("<![LOG[") && !line.Contains("]LOG]!>"))
{
// Start of a multiline CMTrace entry
multiLineBuffer = new StringBuilder(line);
multiLineCount = 1;
continue;
}
// --- Normal processing (single-line or completed multiline) ---
CmTraceLogEntry entry;
string messageToMatch;
if (CmTraceLogParser.TryParseLine(line, out entry))
{
messageToMatch = entry.Message;
if (entry.HasTimestamp && !entry.BiasMinutes.HasValue)
calibrationAnchor = entry;
}
else
{
// Non-CMTrace line - match raw
messageToMatch = line;
entry = null;
}
if (string.IsNullOrEmpty(messageToMatch)) continue;
// Simulation mode delay
if (SimulationMode && entry != null)
{
await ApplySimulationDelay(ResolveEntryUtc(entry), token);
}
MatchLine(filePath, line, messageToMatch, entry, stats);
}
_positionTracker.SetPosition(filePath, stream.Position);
ClearHeldTailIfConsumed(filePath, resumePos);
_positionTracker.SetPosition(filePath, resumePos);
_stateDirty = true;
// One line per pass and file, never per hostile line: the counters are
// the operator's only trace that matching was skipped or cut short.
if (stats.RegexTimeouts > 0 || stats.BudgetBreaks > 0 || stats.OversizedLines > 0)
{
_logger.Warning(
$"ImeLogTracker: {Path.GetFileName(filePath)} pass skipped work — " +
$"oversizedLines={stats.OversizedLines} (cap {MaxEntryBytes} bytes), " +
$"regexTimeouts={stats.RegexTimeouts}, lineBudgetBreaks={stats.BudgetBreaks}" +
(stats.FirstSkippedPatternId != null ? $", firstSkippedPattern={stats.FirstSkippedPatternId}" : string.Empty));
}
// Calibrate AFTER the pass: this pass's lines were resolved with the
// offset established previously, at most one poll (100 ms) old. Buffering
// the pass to calibrate first is not an option — the first pass of
@@ -247,6 +312,89 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
}
}
private sealed class PassStats
{
public int RegexTimeouts;
public int BudgetBreaks;
public int OversizedLines;
public string FirstSkippedPatternId;
}
/// <summary>
/// Matches one message against every active pattern under the per-line budget. A
/// pattern that times out is skipped (counted); once the aggregate budget is spent the
/// remaining patterns are skipped for this line (counted, first skipped ID recorded) —
/// matches already handled on this line stand.
/// </summary>
private void MatchLine(string filePath, string line, string messageToMatch, CmTraceLogEntry entry, PassStats stats)
{
var started = Stopwatch.GetTimestamp();
for (var i = 0; i < _activePatterns.Count; i++)
{
var pattern = _activePatterns[i];
if (Stopwatch.GetTimestamp() - started > LineMatchBudgetTicks)
{
stats.BudgetBreaks++;
if (stats.FirstSkippedPatternId == null) stats.FirstSkippedPatternId = pattern.PatternId;
return;
}
try
{
var match = pattern.Regex.Match(messageToMatch);
if (match.Success)
{
WriteMatchLog(filePath, line, pattern.PatternId);
HandlePatternMatch(pattern, match, messageToMatch, entry);
}
}
catch (RegexMatchTimeoutException)
{
stats.RegexTimeouts++;
if (_timeoutLoggedPatternIds.Add(pattern.PatternId))
_logger.Debug($"ImeLogTracker: regex timeout for pattern '{pattern.PatternId}' (message length {messageToMatch.Length}) — skipped; further timeouts of this pattern are only counted");
}
}
}
/// <summary>
/// Decides whether an unterminated tail starting at <paramref name="tailStart"/> is held
/// back for the writer to finish. True = do not process, resume from the tail start next
/// pass. False = process it now. A tail longer than <see cref="HeldTailMaxBytes"/> is
/// never held (re-reading it each poll is the cost to bound); a tail at the same start seen for longer than
/// <see cref="HeldTailSettle"/> is released so a never-completing tail is bounded to a
/// handful of re-reads.
/// </summary>
private bool HoldBackTail(string filePath, long tailStart, long fileLength, DateTime nowUtc)
{
if (fileLength - tailStart > HeldTailMaxBytes)
{
_heldTails.Remove(filePath);
return false;
}
HeldTail held;
if (_heldTails.TryGetValue(filePath, out held) && held.Start == tailStart)
{
if (nowUtc - held.FirstHeldUtc >= HeldTailSettle)
{
_heldTails.Remove(filePath);
return false;
}
return true;
}
_heldTails[filePath] = new HeldTail { Start = tailStart, FirstHeldUtc = nowUtc };
return true;
}
private void ClearHeldTailIfConsumed(string filePath, long resumePos)
{
HeldTail held;
if (_heldTails.TryGetValue(filePath, out held) && held.Start != resumePos)
_heldTails.Remove(filePath);
}
// Actions that mutate app/phase tracking state (_packageStates, _phasePackageSnapshots,
// _currentPhaseOrder, DO telemetry) — the historic-replay guard skips these for source
// lines from a previous enrollment so replayed apps never enter tracked state,

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