feat(agent): AppX/MSIX failure enrichment in ESP settle window (esp_appx_failure_analysis)

Session 2bc884b6: ESP failed AccountSetup/Apps with 0x80073cf9 while all 8
tracked Win32/WinGet apps succeeded — the failing app was a MSIX/Store app
that installs outside the IME Win32 pipeline and is invisible to
ImeLogTracker. The session ended as a blackbox failure.

When an Apps-subcategory failure arms the 30s settle window, the tracker now
queues a one-shot scan of Microsoft-Windows-AppXDeploymentServer/Operational
(Critical+Error, session window, 200-record/10s cap), scores candidate
packages (exact-HRESULT match > AppX-family error > time proximity, recency
bonus), and emits esp_appx_failure_analysis with flat RuleEngine fields plus
a capped candidates[] detail list — before enrollment_failed lands in the
timeline. Negative results are emitted too (no_appx_candidates points back
at Win32). Fire-once per session; scan runs lock-free on the threadpool;
settle expiry never waits; failures degrade to collector_degraded.

- New: AppxDeploymentFailureScanner (one-shot reader, injectable seam),
  AppxFailureAnalyzer (pure scoring/verdicts, incl. negative-decimal
  HRESULT + PackageFullName extraction from message/properties)
- ProvisioningStatusTracker: optional scanner/dispatcher ctor seams,
  MaybeStartAppxFailureScan at settle-arm time
- Rule ANALYZE-APP-014 (MSIX/Store app failure during ESP) keyed on
  verdict=appx_candidate_identified; dist regenerated
- MCP resource-catalog + web HRESULT badge + gather-rules eventTypes
- Tests: 16 analyzer + 7 trigger; settle-window fixture now injects a
  fake scanner + sync dispatcher (no real event log in tests)

Inert until agent redeploy (rule needs backend redeploy). Post-deploy
checks in tasks/todo.md.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-07-09 15:49:27 +02:00
parent 3bbfac165e
commit 50295e8304
13 changed files with 1347 additions and 5 deletions
+72
View File
@@ -0,0 +1,72 @@
{
"$schema": "../schema/analyze-rule.schema.json",
"ruleId": "ANALYZE-APP-014",
"title": "MSIX/Store App Failure During ESP (AppX Deployment)",
"description": "Detects when the Enrollment Status Page failed on the Apps subcategory and the agent's AppX deployment log scan identified a suspected MSIX/Store package. Store/MSIX apps install outside the Win32 pipeline, so the regular per-app tracking sees nothing — this correlation names the likely culprit.",
"severity": "warning",
"category": "apps",
"version": "1.0.0",
"enabled": true,
"baseConfidence": 75,
"preconditions": [
{
"source": "event_data",
"eventType": "esp_appx_failure_analysis",
"dataField": "verdict",
"operator": "equals",
"value": "appx_candidate_identified",
"description": "Scope this rule to sessions where the settle-window AppX scan found a package whose deployment error matches the ESP failure HRESULT. Weaker verdicts (appx_activity_no_hresult_match, no_appx_candidates) intentionally do not fire this rule — they carry too little signal for an admin-facing finding."
}
],
"conditions": [
{
"signal": "appx_candidate",
"source": "event_type",
"eventType": "esp_appx_failure_analysis",
"dataField": "topCandidatePackageName",
"operator": "exists",
"required": true
},
{
"signal": "esp_appx_family_errorcode",
"source": "event_type",
"eventType": "esp_failure_settle_started",
"dataField": "errorCode",
"operator": "regex",
"value": "^0x80073[cd]",
"required": false
}
],
"explanation": "The ESP **{{espCategory}}/Apps** subcategory failed with HRESULT **{{espErrorCode}}** — an error from the AppX/MSIX deployment stack, i.e. a **Microsoft Store / MSIX app**, not a Win32 app. These apps install via the EnterpriseModernAppManagement CSP and never appear in the IME Win32 sidecar logs, which is why all tracked Win32/WinGet apps in this session can look green while ESP still reports an Apps failure.\n\nThe agent scanned the AppXDeploymentServer event log during the failure settle window and identified **{{topCandidatePackageName}}** (package `{{topCandidatePackage}}`) as the most likely culprit — its deployment error matches the ESP failure code ({{candidateCount}} candidate(s) total, confidence: {{confidence}}).\n\n**This is a correlation-based assessment, not a confirmed root cause** — validate against the AppXDeploymentServer/Operational event log on the device or in the diagnostics archive before acting.",
"remediation": [
{
"title": "Confirm the failing package",
"steps": [
"Open Event Viewer → Applications and Services Logs → Microsoft → Windows → AppXDeploymentServer → Operational on the device (or in the diagnostics archive if uploaded)",
"Filter for Error-level events around the ESP failure time and confirm the package name and HRESULT match this finding",
"Look up the HRESULT: 0x80073cf9 = generic install failure, 0x80073cf0 = invalid/corrupt package, 0x80073cff = sideloading/licensing policy block, 0x80073d02 = blocked because app is in use"
]
},
{
"title": "Check Store app assignment and licensing",
"steps": [
"Intune portal → Apps → check the assignment of the suspected app: device context vs user context — user-context Store apps installing during Account Setup ESP are a common failure source",
"Verify the app's license type (online vs offline): online-licensed Store apps require the user's Entra ID token and Store connectivity during ESP",
"Check whether the Microsoft Store endpoints are reachable from the enrollment network (proxy/firewall allowlists)",
"If the app is not business-critical during provisioning: remove it from the ESP blocking-app list so a failure no longer terminates enrollment"
]
},
{
"title": "Consider repackaging",
"steps": [
"For maximum ESP reliability, wrap the app as a Win32 (.intunewin) deployment instead of a Store/MSIX assignment — Win32 installs are fully tracked and produce per-app failure telemetry",
"Alternatively deploy the app post-enrollment (available, not required) so it cannot block the ESP"
]
}
],
"relatedDocs": [
{ "title": "Microsoft Learn: Troubleshoot Windows Autopilot ESP error codes", "url": "https://learn.microsoft.com/en-us/autopilot/troubleshoot-tsg" },
{ "title": "Add Microsoft Store apps to Intune", "url": "https://learn.microsoft.com/en-us/mem/intune/apps/store-apps-microsoft" }
],
"tags": ["apps", "appx", "msix", "store", "esp", "0x80073cf9"]
}
+84
View File
@@ -553,6 +553,90 @@
"intune"
]
},
{
"ruleId": "ANALYZE-APP-014",
"title": "MSIX/Store App Failure During ESP (AppX Deployment)",
"description": "Detects when the Enrollment Status Page failed on the Apps subcategory and the agent's AppX deployment log scan identified a suspected MSIX/Store package. Store/MSIX apps install outside the Win32 pipeline, so the regular per-app tracking sees nothing — this correlation names the likely culprit.",
"severity": "warning",
"category": "apps",
"version": "1.0.0",
"enabled": true,
"baseConfidence": 75,
"preconditions": [
{
"source": "event_data",
"eventType": "esp_appx_failure_analysis",
"dataField": "verdict",
"operator": "equals",
"value": "appx_candidate_identified",
"description": "Scope this rule to sessions where the settle-window AppX scan found a package whose deployment error matches the ESP failure HRESULT. Weaker verdicts (appx_activity_no_hresult_match, no_appx_candidates) intentionally do not fire this rule — they carry too little signal for an admin-facing finding."
}
],
"conditions": [
{
"signal": "appx_candidate",
"source": "event_type",
"eventType": "esp_appx_failure_analysis",
"dataField": "topCandidatePackageName",
"operator": "exists",
"required": true
},
{
"signal": "esp_appx_family_errorcode",
"source": "event_type",
"eventType": "esp_failure_settle_started",
"dataField": "errorCode",
"operator": "regex",
"value": "^0x80073[cd]",
"required": false
}
],
"explanation": "The ESP **{{espCategory}}/Apps** subcategory failed with HRESULT **{{espErrorCode}}** — an error from the AppX/MSIX deployment stack, i.e. a **Microsoft Store / MSIX app**, not a Win32 app. These apps install via the EnterpriseModernAppManagement CSP and never appear in the IME Win32 sidecar logs, which is why all tracked Win32/WinGet apps in this session can look green while ESP still reports an Apps failure.\n\nThe agent scanned the AppXDeploymentServer event log during the failure settle window and identified **{{topCandidatePackageName}}** (package `{{topCandidatePackage}}`) as the most likely culprit — its deployment error matches the ESP failure code ({{candidateCount}} candidate(s) total, confidence: {{confidence}}).\n\n**This is a correlation-based assessment, not a confirmed root cause** — validate against the AppXDeploymentServer/Operational event log on the device or in the diagnostics archive before acting.",
"remediation": [
{
"title": "Confirm the failing package",
"steps": [
"Open Event Viewer → Applications and Services Logs → Microsoft → Windows → AppXDeploymentServer → Operational on the device (or in the diagnostics archive if uploaded)",
"Filter for Error-level events around the ESP failure time and confirm the package name and HRESULT match this finding",
"Look up the HRESULT: 0x80073cf9 = generic install failure, 0x80073cf0 = invalid/corrupt package, 0x80073cff = sideloading/licensing policy block, 0x80073d02 = blocked because app is in use"
]
},
{
"title": "Check Store app assignment and licensing",
"steps": [
"Intune portal → Apps → check the assignment of the suspected app: device context vs user context — user-context Store apps installing during Account Setup ESP are a common failure source",
"Verify the app's license type (online vs offline): online-licensed Store apps require the user's Entra ID token and Store connectivity during ESP",
"Check whether the Microsoft Store endpoints are reachable from the enrollment network (proxy/firewall allowlists)",
"If the app is not business-critical during provisioning: remove it from the ESP blocking-app list so a failure no longer terminates enrollment"
]
},
{
"title": "Consider repackaging",
"steps": [
"For maximum ESP reliability, wrap the app as a Win32 (.intunewin) deployment instead of a Store/MSIX assignment — Win32 installs are fully tracked and produce per-app failure telemetry",
"Alternatively deploy the app post-enrollment (available, not required) so it cannot block the ESP"
]
}
],
"relatedDocs": [
{
"title": "Microsoft Learn: Troubleshoot Windows Autopilot ESP error codes",
"url": "https://learn.microsoft.com/en-us/autopilot/troubleshoot-tsg"
},
{
"title": "Add Microsoft Store apps to Intune",
"url": "https://learn.microsoft.com/en-us/mem/intune/apps/store-apps-microsoft"
}
],
"tags": [
"apps",
"appx",
"msix",
"store",
"esp",
"0x80073cf9"
]
},
{
"ruleId": "ANALYZE-CORR-003",
"title": "Proxy Configuration Causing Download Failure",
@@ -0,0 +1,264 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
{
/// <summary>
/// Pure scoring/verdict coverage for the session-2bc884b6 AppX enrichment. No event log,
/// no tracker — records go in, scored candidates and an honest verdict come out.
/// </summary>
public sealed class AppxFailureAnalyzerTests
{
private static readonly DateTime FailureAt = new DateTime(2026, 7, 9, 12, 48, 57, DateTimeKind.Utc);
private static readonly DateTime WindowStart = FailureAt.AddMinutes(-30);
private const string PkgA = "Contoso.LineOfBusiness_1.2.3.4_x64__8wekyb3d8bbwe";
private const string PkgB = "Fabrikam.Tools_2.0.0.0_neutral__abcdefghjkmnp";
private static AppxFailureScanRequest Request(string? espErrorCode = "0x80073cf9")
=> new AppxFailureScanRequest(WindowStart, FailureAt, espErrorCode, "AccountSetup", "Apps");
private static AppxLogRecord Record(
string? message,
DateTime? timeUtc = null,
int eventId = 401,
params string[] properties)
{
return new AppxLogRecord
{
TimeCreatedUtc = timeUtc ?? FailureAt.AddMinutes(-1),
EventId = eventId,
Level = 2,
Message = message,
PropertyStrings = properties.ToList()
};
}
private static AppxFailureScanResult ScanWith(params AppxLogRecord[] records)
=> new AppxFailureScanResult { Records = records.ToList() };
// ------------------------------------------------------------------
// Scoring
// ------------------------------------------------------------------
[Fact]
public void HresultMatch_OutranksTimeProximity()
{
// PkgB failed earlier with the exact ESP HRESULT; PkgA has a recent error without one.
var scan = ScanWith(
Record($"Deployment of package {PkgA} was blocked.", FailureAt.AddMinutes(-1)),
Record($"Deployment operation on {PkgB} failed with error 0x80073CF9.", FailureAt.AddMinutes(-20)));
var analysis = AppxFailureAnalyzer.Analyze(Request(), scan);
Assert.Equal(PkgB, analysis.Candidates[0].PackageFullName);
Assert.Equal(AppxFailureAnalyzer.MatchTypeHresultMatch, analysis.Candidates[0].MatchType);
Assert.Equal(AppxFailureAnalyzer.MatchTypeTimeProximity, analysis.Candidates[1].MatchType);
Assert.True(analysis.Candidates[0].Score > analysis.Candidates[1].Score);
}
[Fact]
public void RecencyBonus_AppliedWithinTenMinutesOfFailure()
{
var recent = ScanWith(Record($"error 0x80073cf9 for {PkgA}", FailureAt.AddMinutes(-2)));
var old = ScanWith(Record($"error 0x80073cf9 for {PkgA}", FailureAt.AddMinutes(-25)));
var recentScore = AppxFailureAnalyzer.Analyze(Request(), recent).Candidates[0].Score;
var oldScore = AppxFailureAnalyzer.Analyze(Request(), old).Candidates[0].Score;
Assert.Equal(AppxFailureAnalyzer.ScoreHresultMatch + AppxFailureAnalyzer.ScoreRecencyBonus, recentScore);
Assert.Equal(AppxFailureAnalyzer.ScoreHresultMatch, oldScore);
}
// ------------------------------------------------------------------
// Extraction
// ------------------------------------------------------------------
[Fact]
public void PackageExtraction_FromMessage()
{
var packages = AppxFailureAnalyzer.ExtractPackageFullNames(
Record($"AppX Deployment operation failed for package {PkgA} with error 0x80073CF9."));
Assert.Equal(new[] { PkgA }, packages);
}
[Fact]
public void PackageExtraction_FromProperties_WhenFormatDescriptionFailed()
{
// Under SYSTEM/OOBE FormatDescription often throws → Message null; the raw event
// properties still carry the PackageFullName.
var record = Record(message: null, properties: new[] { PkgB, "some other property" });
var packages = AppxFailureAnalyzer.ExtractPackageFullNames(record);
Assert.Equal(new[] { PkgB }, packages);
}
[Fact]
public void NegativeDecimalProperty_ConvertsToHresult()
{
// -2147009287 == unchecked((int)0x80073CF9) — the form event properties use.
var record = Record(message: null, properties: new[] { "-2147009287" });
var hresults = AppxFailureAnalyzer.ExtractHresults(record);
Assert.Equal(new[] { "0x80073cf9" }, hresults);
}
[Fact]
public void HresultExtraction_NormalizesToLowercase_AndDedupes()
{
var record = Record($"error 0x80073CF9 then again 0x80073cf9", properties: new[] { "-2147009287" });
var hresults = AppxFailureAnalyzer.ExtractHresults(record);
Assert.Equal(new[] { "0x80073cf9" }, hresults);
}
// ------------------------------------------------------------------
// Aggregation
// ------------------------------------------------------------------
[Fact]
public void PerPackageDedupe_CountsOccurrences_KeepsLatestTimestamp()
{
var scan = ScanWith(
Record($"retry 1 failed for {PkgA} 0x80073cf9", FailureAt.AddMinutes(-9)),
Record($"retry 2 failed for {PkgA} 0x80073cf9", FailureAt.AddMinutes(-5)),
Record($"retry 3 failed for {PkgA} 0x80073cf9", FailureAt.AddMinutes(-7)));
var analysis = AppxFailureAnalyzer.Analyze(Request(), scan);
var candidate = Assert.Single(analysis.Candidates);
Assert.Equal(3, candidate.Occurrences);
Assert.Equal(FailureAt.AddMinutes(-5), candidate.TimeUtc);
Assert.Equal(1, analysis.TotalCandidateCount);
}
[Fact]
public void CandidatesCappedAtFive_TotalCountPreserved()
{
var records = Enumerable.Range(1, 7)
.Select(i => Record($"failed Vendor{i}.App{i}_1.0.0.{i}_x64__8wekyb3d8bbwe with 0x80073cf9"))
.ToArray();
var analysis = AppxFailureAnalyzer.Analyze(Request(), ScanWith(records));
Assert.Equal(AppxFailureAnalyzer.MaxCandidatesInPayload, analysis.Candidates.Count);
Assert.Equal(7, analysis.TotalCandidateCount);
}
[Fact]
public void MessageExcerpt_Truncated_AndNewlinesFlattened()
{
var longMessage = $"failure of {PkgA}\r\nline2 " + new string('x', 500);
var analysis = AppxFailureAnalyzer.Analyze(Request(null), ScanWith(Record(longMessage)));
var excerpt = analysis.Candidates[0].MessageExcerpt;
Assert.Equal(AppxFailureAnalyzer.MessageExcerptLength, excerpt.Length);
Assert.DoesNotContain("\n", excerpt);
}
// ------------------------------------------------------------------
// Verdicts / confidence
// ------------------------------------------------------------------
[Fact]
public void Verdict_CandidateIdentified_HighConfidence_WhenEspCodeIsAppxFamily()
{
var analysis = AppxFailureAnalyzer.Analyze(
Request("0x80073cf9"),
ScanWith(Record($"deployment of {PkgA} failed with 0x80073CF9")));
Assert.Equal(AppxFailureAnalyzer.VerdictCandidateIdentified, analysis.Verdict);
Assert.Equal("high", analysis.Confidence);
}
[Fact]
public void Verdict_CandidateIdentified_MediumConfidence_WhenEspCodeNotAppxFamily()
{
var analysis = AppxFailureAnalyzer.Analyze(
Request("0x87d1041c"),
ScanWith(Record($"deployment of {PkgA} failed with 0x87d1041c")));
Assert.Equal(AppxFailureAnalyzer.VerdictCandidateIdentified, analysis.Verdict);
Assert.Equal("medium", analysis.Confidence);
}
[Fact]
public void Verdict_ActivityNoHresultMatch_WhenErrorsDontMatchEspCode()
{
var analysis = AppxFailureAnalyzer.Analyze(
Request("0x80073cf9"),
ScanWith(Record($"deployment of {PkgA} failed with 0x80073d02")));
Assert.Equal(AppxFailureAnalyzer.VerdictActivityNoHresultMatch, analysis.Verdict);
Assert.Equal("low", analysis.Confidence);
Assert.Contains("0x80073d02", analysis.OtherHresultsSeen);
}
[Fact]
public void Verdict_ActivityNoHresultMatch_MediumConfidence_WhenEspCodeNull_AndFamilyErrorsSeen()
{
var analysis = AppxFailureAnalyzer.Analyze(
Request(espErrorCode: null),
ScanWith(Record($"deployment of {PkgA} failed with 0x80073cff")));
Assert.Equal(AppxFailureAnalyzer.VerdictActivityNoHresultMatch, analysis.Verdict);
Assert.Equal("medium", analysis.Confidence);
}
[Fact]
public void Verdict_ErrorsNoPackage_WhenHresultsButNoPackageName()
{
var analysis = AppxFailureAnalyzer.Analyze(
Request(),
ScanWith(Record("operation failed with 0x80073cf9 (no package in text)")));
Assert.Equal(AppxFailureAnalyzer.VerdictErrorsNoPackage, analysis.Verdict);
Assert.Empty(analysis.Candidates);
}
[Fact]
public void Verdict_NoCandidates_WhenWindowEmpty()
{
var analysis = AppxFailureAnalyzer.Analyze(Request(), ScanWith());
Assert.Equal(AppxFailureAnalyzer.VerdictNoCandidates, analysis.Verdict);
Assert.Equal("medium", analysis.Confidence);
Assert.Equal(0, analysis.ErrorEventCount);
}
[Fact]
public void Verdict_NoCandidates_LowConfidence_WhenScanTruncated()
{
var scan = ScanWith();
scan.Truncated = true;
var analysis = AppxFailureAnalyzer.Analyze(Request(), scan);
Assert.Equal(AppxFailureAnalyzer.VerdictNoCandidates, analysis.Verdict);
Assert.Equal("low", analysis.Confidence);
}
[Fact]
public void Verdict_ScanUnavailable_WhenChannelMissing()
{
var scan = new AppxFailureScanResult { ChannelAvailable = false, UnavailableReason = "channel_not_found" };
var analysis = AppxFailureAnalyzer.Analyze(Request(), scan);
Assert.Equal(AppxFailureAnalyzer.VerdictScanUnavailable, analysis.Verdict);
Assert.Equal("channel_not_found", analysis.ScanUnavailableReason);
}
[Theory]
[InlineData("0x80073cf9", true)]
[InlineData("0x80073CF0", true)]
[InlineData("0x80073d02", true)]
[InlineData("0x87d1041c", false)]
[InlineData("0x80070002", false)]
[InlineData(null, false)]
[InlineData("", false)]
[InlineData("0x8007", false)]
public void IsAppxFamilyHresult_MatchesOnlyAppxDeploymentRange(string hresult, bool expected)
{
Assert.Equal(expected, AppxFailureAnalyzer.IsAppxFamilyHresult(hresult));
}
}
}
@@ -0,0 +1,251 @@
using System;
using System.Collections.Generic;
using System.Linq;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration;
using AutopilotMonitor.DecisionCore.Engine;
using AutopilotMonitor.DecisionCore.Signals;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
{
/// <summary>
/// Test double for the settle-window AppX enrichment scan. Returns a canned result and
/// records every request — tests never touch the real event log (project rule: mock ALL
/// system calls).
/// </summary>
internal sealed class FakeAppxDeploymentFailureScanner : IAppxDeploymentFailureScanner
{
public AppxFailureScanResult Result { get; set; } = new AppxFailureScanResult();
public Exception? ThrowOnScan { get; set; }
public List<AppxFailureScanRequest> Requests { get; } = new List<AppxFailureScanRequest>();
public AppxFailureScanResult Scan(AppxFailureScanRequest request)
{
Requests.Add(request);
if (ThrowOnScan != null) throw ThrowOnScan;
return Result;
}
}
/// <summary>
/// Session 2bc884b6 coverage: an ESP Apps-subcategory failure (e.g. 0x80073cf9 from an
/// MSIX/Store app invisible to ImeLogTracker) must trigger exactly one AppX event-log scan
/// inside the settle window and emit <c>esp_appx_failure_analysis</c> with flat RuleEngine
/// fields — without disturbing the settle window's own EspFailureDetected flow.
/// </summary>
public sealed class AppxFailureScanTriggerTests
{
private static readonly DateTime Fixed = new DateTime(2026, 7, 9, 12, 48, 57, DateTimeKind.Utc);
private const string InProgressJson = @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Apps (Working)""}
}";
private const string AppsFailedJson = @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Apps (0x80073cf9)""}
}";
private sealed class Fixture : IDisposable
{
public TempDirectory Tmp { get; } = new TempDirectory();
public FakeSignalIngressSink Sink { get; } = new FakeSignalIngressSink();
public FakeAppxDeploymentFailureScanner Scanner { get; } = new FakeAppxDeploymentFailureScanner();
public List<EspFailureDetectedEventArgs> EspFailures { get; } = new List<EspFailureDetectedEventArgs>();
public ProvisioningStatusTracker Tracker { get; }
public Fixture()
{
var clock = new VirtualClock(Fixed);
var post = new InformationalEventPost(Sink, clock);
var logger = new AgentLogger(Tmp.Path, AgentLogLevel.Info);
Tracker = new ProvisioningStatusTracker(
sessionId: "S1",
tenantId: "T1",
post: post,
logger: logger,
appxScanner: Scanner,
backgroundDispatcher: action => action()); // synchronous — deterministic tests
Tracker.EspFailureDetected += (_, args) => EspFailures.Add(args);
}
public IReadOnlyList<(string EventType, string Severity, IReadOnlyDictionary<string, object> Data)> CapturedEvents()
{
return Sink.Posted
.Where(p => p.Kind == DecisionSignalKind.InformationalEvent && p.Payload != null)
.Select(p =>
{
var eventType = p.Payload!.TryGetValue(SignalPayloadKeys.EventType, out var et) ? et : "";
var severity = p.Payload!.TryGetValue(SignalPayloadKeys.Severity, out var sev) ? sev : "";
var data = p.TypedPayload as IReadOnlyDictionary<string, object>
?? (IReadOnlyDictionary<string, object>)new Dictionary<string, object>();
return (eventType, severity, data);
})
.ToList();
}
public (string EventType, string Severity, IReadOnlyDictionary<string, object> Data) AnalysisEvent()
=> CapturedEvents().SingleOrDefault(e => e.EventType == "esp_appx_failure_analysis");
public void Dispose()
{
Tracker.Dispose();
Tmp.Dispose();
}
}
private static AppxLogRecord FailedPackageRecord(string packageFullName, string hresult)
=> new AppxLogRecord
{
TimeCreatedUtc = Fixed.AddMinutes(-2),
EventId = 401,
Level = 2,
Message = $"Deployment operation on {packageFullName} failed with error {hresult}.",
};
[Fact]
public void AppsFailure_TriggersScan_WithEspContext_AndEmitsFlatFields()
{
using var f = new Fixture();
f.Scanner.Result = new AppxFailureScanResult
{
Records = { FailedPackageRecord("Contoso.LineOfBusiness_1.2.3.4_x64__8wekyb3d8bbwe", "0x80073CF9") },
ScanDurationMs = 42
};
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", AppsFailedJson);
var request = Assert.Single(f.Scanner.Requests);
Assert.Equal("0x80073cf9", request.EspErrorCode);
Assert.Equal("AccountSetup", request.EspCategory);
Assert.Equal("Apps", request.FailedSubcategory);
Assert.True(request.WindowStartUtc < request.WindowEndUtc);
var analysis = f.AnalysisEvent();
Assert.NotEqual(default, analysis);
Assert.Equal("Warning", analysis.Severity);
Assert.Equal("appx_candidate_identified", (string)analysis.Data["verdict"]);
Assert.Equal("high", (string)analysis.Data["confidence"]);
Assert.Equal("0x80073cf9", (string)analysis.Data["espErrorCode"]);
Assert.Equal("AccountSetup", (string)analysis.Data["espCategory"]);
Assert.Equal("Contoso.LineOfBusiness_1.2.3.4_x64__8wekyb3d8bbwe", (string)analysis.Data["topCandidatePackage"]);
Assert.Equal("Contoso.LineOfBusiness", (string)analysis.Data["topCandidatePackageName"]);
Assert.Equal("0x80073cf9", (string)analysis.Data["topCandidateHresult"]);
Assert.Equal("hresult_match", (string)analysis.Data["topCandidateMatchType"]);
Assert.Equal(1, (int)analysis.Data["candidateCount"]);
Assert.True(analysis.Data.ContainsKey("candidates"));
}
[Fact]
public void EnrichmentPrecedesSettleExpiry_AndSettleStillFires()
{
using var f = new Fixture();
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", AppsFailedJson);
// Analysis event is already emitted while the settle window is still pending.
Assert.NotEqual(default, f.AnalysisEvent());
Assert.Empty(f.EspFailures);
f.Tracker.TriggerSettleTimerForTest("AccountSetupCategory.Status");
var fired = Assert.Single(f.EspFailures);
Assert.Equal("Provisioning_AccountSetup_Apps_Failed", fired.FailureType);
Assert.Equal("0x80073cf9", fired.ErrorCode);
}
[Fact]
public void NonAppsFailure_DoesNotScan()
{
using var f = new Fixture();
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""inProgress"",""subcategoryStatusText"":""Working""}
}");
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", @"{
""categorySucceeded"": null,
""SecurityPoliciesSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Failed (0x800705b4)""}
}");
Assert.Empty(f.Scanner.Requests);
Assert.Equal(default, f.AnalysisEvent());
}
[Fact]
public void SecondAppsFailure_InOtherCategory_DoesNotRescan()
{
using var f = new Fixture();
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", AppsFailedJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", AppsFailedJson);
// Both categories arm their own settle window, but the scan is fire-once.
Assert.Single(f.Scanner.Requests);
Assert.Equal("DeviceSetup", f.Scanner.Requests[0].EspCategory);
}
[Fact]
public void ScannerThrows_EmitsCollectorDegraded_SettleWindowUnaffected()
{
using var f = new Fixture();
f.Scanner.ThrowOnScan = new InvalidOperationException("boom");
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", AppsFailedJson);
var degraded = f.CapturedEvents().SingleOrDefault(e => e.EventType == "collector_degraded");
Assert.NotEqual(default, degraded);
Assert.Equal("AppxDeploymentFailureScanner", (string)degraded.Data["collector"]);
Assert.Equal("scan_failed", (string)degraded.Data["reason"]);
Assert.Equal(default, f.AnalysisEvent());
f.Tracker.TriggerSettleTimerForTest("AccountSetupCategory.Status");
Assert.Single(f.EspFailures);
}
[Fact]
public void NoCandidates_EmitsInfoVerdict_NegativeEvidence()
{
using var f = new Fixture();
// Empty scan result — no AppX errors in the window.
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", AppsFailedJson);
var analysis = f.AnalysisEvent();
Assert.NotEqual(default, analysis);
Assert.Equal("Info", analysis.Severity);
Assert.Equal("no_appx_candidates", (string)analysis.Data["verdict"]);
Assert.Equal(0, (int)analysis.Data["candidateCount"]);
Assert.False(analysis.Data.ContainsKey("topCandidatePackage"));
}
[Fact]
public void AppsFailureWithoutHresult_OmitsEspErrorCodeKey()
{
using var f = new Fixture();
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", InProgressJson);
f.Tracker.ProcessCategoryStatusForTest("AccountSetupCategory.Status", @"{
""categorySucceeded"": null,
""AppsSubcategory"": {""subcategoryState"":""failed"",""subcategoryStatusText"":""Apps (Error)""}
}");
var request = Assert.Single(f.Scanner.Requests);
Assert.Null(request.EspErrorCode);
var analysis = f.AnalysisEvent();
Assert.NotEqual(default, analysis);
Assert.False(analysis.Data.ContainsKey("espErrorCode"));
}
}
}
@@ -48,7 +48,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.SystemSignals
sessionId: "S1",
tenantId: "T1",
post: post,
logger: logger);
logger: logger,
// Fake scanner + synchronous dispatcher: the Apps-failure tests below arm the
// settle window, which triggers the AppX enrichment scan — the default seams
// would hit the real event log via Task.Run (mock ALL system calls).
appxScanner: new FakeAppxDeploymentFailureScanner(),
backgroundDispatcher: action => action());
Tracker.EspFailureDetected += (_, args) => EspFailures.Add(args);
}
@@ -0,0 +1,164 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Eventing.Reader;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
/// <summary>
/// Scan request for <see cref="IAppxDeploymentFailureScanner"/>. Immutable snapshot of the
/// ESP failure context — the scan body runs on the threadpool and must not touch tracker state.
/// </summary>
internal sealed class AppxFailureScanRequest
{
/// <summary>Earliest TimeCreated to consider (monitoring start, capped lookback).</summary>
public DateTime WindowStartUtc { get; }
/// <summary>Time of the ESP failure observation (recency-bonus anchor).</summary>
public DateTime WindowEndUtc { get; }
/// <summary>ESP subcategory HRESULT (lower-case 0x-hex) or null.</summary>
public string EspErrorCode { get; }
/// <summary>ESP category label (DeviceSetup / AccountSetup).</summary>
public string EspCategory { get; }
/// <summary>Failed subcategory name (always "Apps" for this scan).</summary>
public string FailedSubcategory { get; }
public AppxFailureScanRequest(
DateTime windowStartUtc,
DateTime windowEndUtc,
string espErrorCode,
string espCategory,
string failedSubcategory)
{
WindowStartUtc = windowStartUtc;
WindowEndUtc = windowEndUtc;
EspErrorCode = string.IsNullOrEmpty(espErrorCode) ? null : espErrorCode;
EspCategory = string.IsNullOrEmpty(espCategory) ? null : espCategory;
FailedSubcategory = string.IsNullOrEmpty(failedSubcategory) ? null : failedSubcategory;
}
}
/// <summary>
/// One raw record read from the AppX deployment event log channel. Message and property
/// strings are both captured because <c>FormatDescription()</c> is unreliable under
/// SYSTEM/OOBE (missing message resources) while <c>record.Properties</c> usually still
/// carries the bare PackageFullName and error values.
/// </summary>
internal sealed class AppxLogRecord
{
public DateTime TimeCreatedUtc { get; set; }
public int EventId { get; set; }
public int Level { get; set; }
/// <summary>Rendered message, or null when FormatDescription failed.</summary>
public string Message { get; set; }
/// <summary>Raw event properties as strings (may be empty, never null).</summary>
public List<string> PropertyStrings { get; set; } = new List<string>();
}
/// <summary>Raw scan outcome — records plus availability/diagnostic info.</summary>
internal sealed class AppxFailureScanResult
{
/// <summary>False when the channel is missing or unreadable (scan_unavailable verdict).</summary>
public bool ChannelAvailable { get; set; } = true;
/// <summary>Short machine-readable reason when <see cref="ChannelAvailable"/> is false.</summary>
public string UnavailableReason { get; set; }
public List<AppxLogRecord> Records { get; set; } = new List<AppxLogRecord>();
public long ScanDurationMs { get; set; }
/// <summary>True when the record/time cap stopped the scan before the window was exhausted.</summary>
public bool Truncated { get; set; }
}
/// <summary>
/// Seam for the settle-window AppX enrichment scan — tests inject a fake; production uses
/// <see cref="AppxDeploymentFailureScanner"/>.
/// </summary>
internal interface IAppxDeploymentFailureScanner
{
AppxFailureScanResult Scan(AppxFailureScanRequest request);
}
/// <summary>
/// One-shot reader of <c>Microsoft-Windows-AppXDeploymentServer/Operational</c> — the channel
/// where MSIX/Store deployment failures land. Those installs run outside the IME Win32
/// pipeline, so ImeLogTracker never sees them; when ESP reports an Apps-subcategory failure
/// with an AppX-class HRESULT (e.g. 0x80073cf9) this scan is the only session-local source
/// that can name the failing package (session 2bc884b6).
/// Query pattern follows <see cref="StallProbeCollector"/>: XPath time+level filter,
/// ReverseDirection (newest first), hard record + wall-clock caps, per-record dispose.
/// </summary>
internal sealed class AppxDeploymentFailureScanner : IAppxDeploymentFailureScanner
{
internal const string Channel = "Microsoft-Windows-AppXDeploymentServer/Operational";
// Critical (1) + Error (2) only — Warning-level entries in this channel are routine
// servicing noise and would drown the correlation.
internal const int MaxRecords = 200;
internal const int MaxScanMilliseconds = 10000;
public AppxFailureScanResult Scan(AppxFailureScanRequest request)
{
var result = new AppxFailureScanResult();
var stopwatch = Stopwatch.StartNew();
var sinceStr = request.WindowStartUtc.ToString("yyyy-MM-ddTHH:mm:ss.fffZ");
var xpath = $"*[System[(Level >= 1 and Level <= 2) and TimeCreated[@SystemTime >= '{sinceStr}']]]";
try
{
var query = new EventLogQuery(Channel, PathType.LogName, xpath) { ReverseDirection = true };
using (var reader = new EventLogReader(query))
{
EventRecord record;
while ((record = reader.ReadEvent()) != null)
{
using (record)
{
if (result.Records.Count >= MaxRecords || stopwatch.ElapsedMilliseconds > MaxScanMilliseconds)
{
result.Truncated = true;
break;
}
var entry = new AppxLogRecord
{
TimeCreatedUtc = record.TimeCreated?.ToUniversalTime() ?? DateTime.MinValue,
EventId = record.Id,
Level = record.Level ?? 0,
};
// FormatDescription can throw under SYSTEM/OOBE (message resources
// not loadable) — the Properties fallback below is mandatory.
try { entry.Message = record.FormatDescription(); }
catch { entry.Message = null; }
try
{
foreach (var prop in record.Properties)
{
var s = prop?.Value?.ToString();
if (!string.IsNullOrEmpty(s))
entry.PropertyStrings.Add(s);
}
}
catch { /* best-effort — keep whatever was collected */ }
result.Records.Add(entry);
}
}
}
}
catch (EventLogNotFoundException)
{
result.ChannelAvailable = false;
result.UnavailableReason = "channel_not_found";
}
catch (UnauthorizedAccessException)
{
result.ChannelAvailable = false;
result.UnavailableReason = "access_denied";
}
stopwatch.Stop();
result.ScanDurationMs = stopwatch.ElapsedMilliseconds;
return result;
}
}
}
@@ -0,0 +1,308 @@
using System;
using System.Collections.Generic;
using System.Globalization;
using System.Linq;
using System.Text.RegularExpressions;
namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
{
/// <summary>
/// Aggregated candidate: one MSIX/Store package that failed in the scan window,
/// scored by how strongly its log records correlate with the ESP failure.
/// </summary>
internal sealed class AppxFailureCandidate
{
public string PackageFullName { get; set; }
/// <summary>Name segment of the PackageFullName (before the first underscore).</summary>
public string PackageName { get; set; }
public int Score { get; set; }
/// <summary>hresult_match | appx_family_error | time_proximity</summary>
public string MatchType { get; set; }
/// <summary>Distinct HRESULTs seen for this package (capped).</summary>
public List<string> Hresults { get; set; } = new List<string>();
/// <summary>EventId of the best-scoring record.</summary>
public int EventId { get; set; }
/// <summary>Latest occurrence in the window.</summary>
public DateTime TimeUtc { get; set; }
public int Occurrences { get; set; }
/// <summary>Truncated message (or property dump) of the best-scoring record.</summary>
public string MessageExcerpt { get; set; }
}
/// <summary>Analysis outcome — verdict + scored candidates, ready for event emission.</summary>
internal sealed class AppxFailureAnalysis
{
public string Verdict { get; set; }
/// <summary>high | medium | low — honesty marker, never certainty.</summary>
public string Confidence { get; set; }
/// <summary>Sorted descending by score, capped at <see cref="AppxFailureAnalyzer.MaxCandidatesInPayload"/>.</summary>
public List<AppxFailureCandidate> Candidates { get; set; } = new List<AppxFailureCandidate>();
/// <summary>Total distinct failing packages before the payload cap.</summary>
public int TotalCandidateCount { get; set; }
/// <summary>Error/critical records considered in the window.</summary>
public int ErrorEventCount { get; set; }
/// <summary>HRESULTs seen in the window that differ from the ESP error code (capped).</summary>
public List<string> OtherHresultsSeen { get; set; } = new List<string>();
/// <summary>Set when verdict is scan_unavailable.</summary>
public string ScanUnavailableReason { get; set; }
}
/// <summary>
/// Pure scoring/verdict logic for the settle-window AppX enrichment — no event log, no
/// tracker state, fully unit-testable. Careful time correlation is the point: the
/// AppXDeploymentServer channel also logs unrelated background servicing failures, so
/// candidates are scored (exact-HRESULT match &gt; AppX-family error &gt; time proximity)
/// and the verdict/confidence express suspicion, not certainty.
/// </summary>
internal static class AppxFailureAnalyzer
{
internal const int MaxCandidatesInPayload = 5;
internal const int MaxHresultsPerCandidate = 3;
internal const int MaxOtherHresults = 5;
internal const int MessageExcerptLength = 300;
internal const int RecencyBonusWindowMinutes = 10;
internal const int ScoreHresultMatch = 100;
internal const int ScoreAppxFamilyError = 70;
internal const int ScoreTimeProximity = 40;
internal const int ScoreRecencyBonus = 10;
internal const string MatchTypeHresultMatch = "hresult_match";
internal const string MatchTypeAppxFamilyError = "appx_family_error";
internal const string MatchTypeTimeProximity = "time_proximity";
internal const string VerdictCandidateIdentified = "appx_candidate_identified";
internal const string VerdictActivityNoHresultMatch = "appx_activity_no_hresult_match";
internal const string VerdictErrorsNoPackage = "appx_errors_no_package";
internal const string VerdictNoCandidates = "no_appx_candidates";
internal const string VerdictScanUnavailable = "scan_unavailable";
private static readonly Regex HResultPattern = new Regex(
@"\b0[xX][0-9a-fA-F]{8}\b",
RegexOptions.Compiled | RegexOptions.CultureInvariant);
// PackageFullName: Name_Version_Arch_ResourceId_PublisherHash.
// Version is dotted-quad; arch is a fixed set; the publisher hash is 13 chars of the
// Crockford-base32 subset Windows uses (no i/l/o/u). ResourceId may be empty.
private static readonly Regex PackageFullNamePattern = new Regex(
@"\b(?<name>[A-Za-z0-9][A-Za-z0-9.\-]{2,})_(?<ver>\d+(\.\d+){3})_(?<arch>x86|x64|arm|arm64|neutral)_(?<res>[A-Za-z0-9.\-~]*)_(?<hash>[a-hjkmnp-tv-z0-9]{13})\b",
RegexOptions.Compiled | RegexOptions.CultureInvariant | RegexOptions.IgnoreCase);
/// <summary>True for HRESULTs in the AppX/MSIX deployment error family (0x80073c##/0x80073d##).</summary>
internal static bool IsAppxFamilyHresult(string hresult)
{
if (string.IsNullOrEmpty(hresult) || hresult.Length != 10) return false;
return hresult.StartsWith("0x80073c", StringComparison.OrdinalIgnoreCase)
|| hresult.StartsWith("0x80073d", StringComparison.OrdinalIgnoreCase);
}
public static AppxFailureAnalysis Analyze(AppxFailureScanRequest request, AppxFailureScanResult scan)
{
var analysis = new AppxFailureAnalysis();
if (scan == null || !scan.ChannelAvailable)
{
analysis.Verdict = VerdictScanUnavailable;
analysis.Confidence = "low";
analysis.ScanUnavailableReason = scan?.UnavailableReason ?? "no_result";
return analysis;
}
analysis.ErrorEventCount = scan.Records.Count;
var byPackage = new Dictionary<string, AppxFailureCandidate>(StringComparer.OrdinalIgnoreCase);
var otherHresults = new List<string>();
bool anyHresultSeen = false;
foreach (var record in scan.Records)
{
var hresults = ExtractHresults(record);
var packages = ExtractPackageFullNames(record);
if (hresults.Count > 0) anyHresultSeen = true;
foreach (var hr in hresults)
{
if (!string.Equals(hr, request.EspErrorCode, StringComparison.OrdinalIgnoreCase)
&& !otherHresults.Contains(hr, StringComparer.OrdinalIgnoreCase)
&& otherHresults.Count < MaxOtherHresults)
{
otherHresults.Add(hr);
}
}
if (packages.Count == 0)
continue;
// Score this record once; every package named in it inherits the score.
string matchType;
int score;
if (request.EspErrorCode != null
&& hresults.Any(h => string.Equals(h, request.EspErrorCode, StringComparison.OrdinalIgnoreCase)))
{
matchType = MatchTypeHresultMatch;
score = ScoreHresultMatch;
}
else if (hresults.Any(IsAppxFamilyHresult))
{
matchType = MatchTypeAppxFamilyError;
score = ScoreAppxFamilyError;
}
else
{
matchType = MatchTypeTimeProximity;
score = ScoreTimeProximity;
}
if (record.TimeCreatedUtc >= request.WindowEndUtc.AddMinutes(-RecencyBonusWindowMinutes))
score += ScoreRecencyBonus;
foreach (var pkg in packages)
{
if (!byPackage.TryGetValue(pkg, out var candidate))
{
candidate = new AppxFailureCandidate
{
PackageFullName = pkg,
PackageName = pkg.Split('_')[0],
Score = -1,
};
byPackage[pkg] = candidate;
}
candidate.Occurrences++;
if (record.TimeCreatedUtc > candidate.TimeUtc)
candidate.TimeUtc = record.TimeCreatedUtc;
foreach (var hr in hresults)
{
if (candidate.Hresults.Count < MaxHresultsPerCandidate
&& !candidate.Hresults.Contains(hr, StringComparer.OrdinalIgnoreCase))
{
candidate.Hresults.Add(hr);
}
}
if (score > candidate.Score)
{
candidate.Score = score;
candidate.MatchType = matchType;
candidate.EventId = record.EventId;
candidate.MessageExcerpt = BuildExcerpt(record);
}
}
}
var sorted = byPackage.Values
.OrderByDescending(c => c.Score)
.ThenByDescending(c => c.TimeUtc)
.ToList();
analysis.TotalCandidateCount = sorted.Count;
analysis.Candidates = sorted.Take(MaxCandidatesInPayload).ToList();
analysis.OtherHresultsSeen = otherHresults;
// Verdict + confidence — suspicion levels, kept honest.
if (analysis.Candidates.Count > 0)
{
var top = analysis.Candidates[0];
if (top.MatchType == MatchTypeHresultMatch)
{
analysis.Verdict = VerdictCandidateIdentified;
analysis.Confidence = IsAppxFamilyHresult(request.EspErrorCode) ? "high" : "medium";
}
else
{
analysis.Verdict = VerdictActivityNoHresultMatch;
analysis.Confidence = request.EspErrorCode == null && top.MatchType == MatchTypeAppxFamilyError
? "medium"
: "low";
}
}
else if (anyHresultSeen)
{
analysis.Verdict = VerdictErrorsNoPackage;
analysis.Confidence = "low";
}
else
{
// Negative evidence: no AppX deployment errors in the window → the ESP Apps
// failure most likely came from the Win32/IME pipeline after all.
analysis.Verdict = VerdictNoCandidates;
analysis.Confidence = scan.Truncated ? "low" : "medium";
}
return analysis;
}
/// <summary>
/// Extracts normalized HRESULTs (lower-case 0x-hex) from the rendered message and from
/// raw property values, including the negative-decimal form event properties often use
/// (e.g. <c>-2147009543</c> → <c>0x80073cf9</c>).
/// </summary>
internal static List<string> ExtractHresults(AppxLogRecord record)
{
var result = new List<string>();
void AddNormalized(string hex)
{
var normalized = "0x" + hex.Substring(2).ToLowerInvariant();
if (!result.Contains(normalized, StringComparer.OrdinalIgnoreCase))
result.Add(normalized);
}
if (!string.IsNullOrEmpty(record.Message))
{
foreach (Match m in HResultPattern.Matches(record.Message))
AddNormalized(m.Value);
}
foreach (var prop in record.PropertyStrings)
{
foreach (Match m in HResultPattern.Matches(prop))
AddNormalized(m.Value);
// Whole-property negative decimal → HRESULT (high bit always set for negatives).
if (prop.Length <= 12 && prop.StartsWith("-", StringComparison.Ordinal)
&& int.TryParse(prop, NumberStyles.Integer, CultureInfo.InvariantCulture, out var dec)
&& dec < 0)
{
AddNormalized("0x" + ((uint)dec).ToString("x8", CultureInfo.InvariantCulture));
}
}
return result;
}
/// <summary>Union of PackageFullNames found in message and property strings.</summary>
internal static List<string> ExtractPackageFullNames(AppxLogRecord record)
{
var result = new List<string>();
void Scan(string text)
{
if (string.IsNullOrEmpty(text)) return;
foreach (Match m in PackageFullNamePattern.Matches(text))
{
if (!result.Contains(m.Value, StringComparer.OrdinalIgnoreCase))
result.Add(m.Value);
}
}
Scan(record.Message);
foreach (var prop in record.PropertyStrings)
Scan(prop);
return result;
}
private static string BuildExcerpt(AppxLogRecord record)
{
var text = !string.IsNullOrEmpty(record.Message)
? record.Message
: string.Join("; ", record.PropertyStrings);
if (string.IsNullOrEmpty(text))
return $"EventID {record.EventId}";
text = text.Replace("\r", " ").Replace("\n", " ");
return text.Length <= MessageExcerptLength ? text : text.Substring(0, MessageExcerptLength);
}
}
}
@@ -4,6 +4,7 @@ using System.Linq;
using System.Text.Json;
using System.Text.RegularExpressions;
using System.Threading;
using System.Threading.Tasks;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Interop;
using AutopilotMonitor.Agent.V2.Core.Monitoring.Runtime;
@@ -58,6 +59,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// write and IME workload log).
internal const int ProvisioningFailureSettleWindowSeconds = 30;
// Session 2bc884b6 enrichment: MSIX/Store app failures never touch the IME Win32 sidecar
// logs, so an ESP "Apps (0x80073cf9)" failure with all tracked apps green is a blackbox.
// When an Apps-subcategory failure arms the settle window, a one-shot scan of the AppX
// deployment event log runs on the threadpool and emits esp_appx_failure_analysis with
// scored package candidates. Lookback is capped so resumed/long sessions don't correlate
// against hours of unrelated servicing noise.
internal const int AppxScanLookbackCapHours = 4;
// Regex for HRESULT extraction from subcategory statusText (e.g. "Apps (0x87d1041c)").
// Language-invariant: the parenthesised hex tail is consistent across Windows locales.
private static readonly Regex HResultPattern = new Regex(
@@ -107,6 +116,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// failure details that fire after the settle window expires.
private Dictionary<string, Timer> _provisioningFailureSettleTimers;
private Dictionary<string, EspFailureDetectedEventArgs> _provisioningFailureSettleArgs;
// Session 2bc884b6: AppX enrichment scan seams + fire-once guard. The scanner and the
// dispatcher are injectable so tests never touch the real event log or the threadpool.
private readonly IAppxDeploymentFailureScanner _appxScanner;
private readonly Action<Action> _backgroundDispatcher;
private DateTime _monitoringStartUtc;
private bool _appxScanStarted;
private readonly object _stateLock = new object();
public event EventHandler<EspFailureDetectedEventArgs> EspFailureDetected;
@@ -125,12 +140,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
string sessionId,
string tenantId,
InformationalEventPost post,
AgentLogger logger)
AgentLogger logger,
IAppxDeploymentFailureScanner appxScanner = null,
Action<Action> backgroundDispatcher = null)
{
_sessionId = sessionId ?? throw new ArgumentNullException(nameof(sessionId));
_tenantId = tenantId ?? throw new ArgumentNullException(nameof(tenantId));
_post = post ?? throw new ArgumentNullException(nameof(post));
_logger = logger ?? throw new ArgumentNullException(nameof(logger));
_appxScanner = appxScanner ?? new AppxDeploymentFailureScanner();
_backgroundDispatcher = backgroundDispatcher ?? (action => Task.Run(action));
}
// =====================================================================
@@ -262,6 +281,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
_deviceSetupFallbackTimer = null;
_accountSetupProvisioningCompleteFired = false;
_accountSetupFallbackTimer = null;
_monitoringStartUtc = DateTime.UtcNow;
_appxScanStarted = false;
// Try to start immediately; if key doesn't exist yet, retry every 2s
if (!TryStartWatcher())
@@ -1042,6 +1063,175 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
$"Provisioning failure settle window armed: category={args.Category}, " +
$"failedSubcategory={args.FailedSubcategory ?? "n/a"}, errorCode={args.ErrorCode ?? "n/a"}, " +
$"settleSeconds={ProvisioningFailureSettleWindowSeconds}");
MaybeStartAppxFailureScan(args);
}
/// <summary>
/// Session 2bc884b6 enrichment: on an Apps-subcategory failure, queue a one-shot scan of
/// the AppX deployment event log so MSIX/Store failures — invisible to ImeLogTracker —
/// get named while the settle window is still open (the enrichment event lands before
/// enrollment_failed in the timeline). Fire-once per session: a second Apps failure in
/// the other category would rescan the same window for no new information.
/// <para>
/// Caller holds <see cref="_stateLock"/> — only the QUEUING happens here; the scan body
/// runs lock-free on the threadpool against an immutable request. The settle-window
/// expiry never waits for the scan (worst case the enrichment is lost at shutdown —
/// degraded enrichment only, the failure path is unchanged).
/// </para>
/// </summary>
private void MaybeStartAppxFailureScan(EspFailureDetectedEventArgs args)
{
if (!string.Equals(args.FailedSubcategory, "Apps", StringComparison.OrdinalIgnoreCase))
return;
if (_appxScanStarted)
return;
_appxScanStarted = true;
var now = DateTime.UtcNow;
var lookbackCap = now.AddHours(-AppxScanLookbackCapHours);
var windowStart = _monitoringStartUtc > lookbackCap ? _monitoringStartUtc : lookbackCap;
var request = new AppxFailureScanRequest(
windowStartUtc: windowStart,
windowEndUtc: now,
espErrorCode: args.ErrorCode,
espCategory: args.Category,
failedSubcategory: args.FailedSubcategory);
_logger.Info(
$"AppX failure scan queued: category={args.Category ?? "n/a"}, " +
$"errorCode={args.ErrorCode ?? "n/a"}, windowStartUtc={windowStart:o}");
_backgroundDispatcher(() => RunAppxFailureScan(request));
}
private void RunAppxFailureScan(AppxFailureScanRequest request)
{
try
{
var scan = _appxScanner.Scan(request);
var analysis = AppxFailureAnalyzer.Analyze(request, scan);
EmitAppxFailureAnalysis(request, scan, analysis);
}
catch (Exception ex)
{
_logger.Error("AppX failure scan failed", ex);
CollectorDegradationReporter.Report(
_post, _sessionId, _tenantId, "AppxDeploymentFailureScanner", "scan_failed", ex);
}
}
/// <summary>
/// Emits <c>esp_appx_failure_analysis</c>. Fields the RuleEngine matches on are FLAT
/// top-level (it cannot traverse nested collections — see the failedSubcategories
/// precedent in EmitProvisioningEvent); the <c>candidates</c> list is UI/MCP detail.
/// ImmediateUpload: the agent terminates ~30s after the settle window, same reasoning
/// as esp_apps_failure_correlation in EnrollmentTerminationHandler.
/// </summary>
private void EmitAppxFailureAnalysis(
AppxFailureScanRequest request,
AppxFailureScanResult scan,
AppxFailureAnalysis analysis)
{
var data = new Dictionary<string, object>
{
{ "verdict", analysis.Verdict },
{ "confidence", analysis.Confidence },
{ "espCategory", request.EspCategory ?? "unknown" },
{ "failedSubcategory", request.FailedSubcategory ?? "Apps" },
{ "candidateCount", analysis.TotalCandidateCount },
{ "errorEventCount", analysis.ErrorEventCount },
{ "windowStartUtc", request.WindowStartUtc.ToString("o") },
{ "windowEndUtc", request.WindowEndUtc.ToString("o") },
{ "scanDurationMs", scan.ScanDurationMs },
{ "channel", AppxDeploymentFailureScanner.Channel }
};
if (request.EspErrorCode != null)
data["espErrorCode"] = request.EspErrorCode;
if (analysis.ScanUnavailableReason != null)
data["scanError"] = analysis.ScanUnavailableReason;
if (scan.Truncated)
data["scanTruncated"] = true;
if (analysis.OtherHresultsSeen.Count > 0)
data["otherHresultsSeen"] = string.Join(",", analysis.OtherHresultsSeen);
var top = analysis.Candidates.FirstOrDefault();
if (top != null)
{
data["topCandidatePackage"] = top.PackageFullName;
data["topCandidatePackageName"] = top.PackageName;
data["topCandidateMatchType"] = top.MatchType;
data["topCandidateEventId"] = top.EventId;
data["topCandidateTimeUtc"] = top.TimeUtc.ToString("o");
if (top.Hresults.Count > 0)
data["topCandidateHresult"] = top.Hresults[0];
var candidateList = new List<object>();
foreach (var c in analysis.Candidates)
{
candidateList.Add(new Dictionary<string, object>
{
{ "packageFullName", c.PackageFullName },
{ "packageName", c.PackageName },
{ "score", c.Score },
{ "matchType", c.MatchType },
{ "hresults", string.Join(",", c.Hresults) },
{ "eventId", c.EventId },
{ "timeUtc", c.TimeUtc.ToString("o") },
{ "occurrences", c.Occurrences },
{ "messageExcerpt", c.MessageExcerpt }
});
}
data["candidates"] = candidateList;
}
string message;
var severity = EventSeverity.Info;
switch (analysis.Verdict)
{
case AppxFailureAnalyzer.VerdictCandidateIdentified:
severity = EventSeverity.Warning;
message = $"ESP Apps failure enrichment: suspected MSIX/Store package '{top.PackageName}'" +
(request.EspErrorCode != null ? $" matches ESP error {request.EspErrorCode}" : "") +
$" — {analysis.TotalCandidateCount} candidate(s) in AppX deployment log " +
"(assessment, not a confirmed root cause)";
break;
case AppxFailureAnalyzer.VerdictActivityNoHresultMatch:
message = $"ESP Apps failure enrichment: AppX deployment errors found (top package '{top.PackageName}') " +
$"but none match ESP error {request.EspErrorCode ?? "n/a"} — weak correlation " +
"(assessment, not a confirmed root cause)";
break;
case AppxFailureAnalyzer.VerdictErrorsNoPackage:
message = "ESP Apps failure enrichment: AppX deployment errors in window but no package name " +
"extractable — inconclusive";
break;
case AppxFailureAnalyzer.VerdictScanUnavailable:
message = $"ESP Apps failure enrichment: AppX deployment log unavailable " +
$"({analysis.ScanUnavailableReason}) — no assessment possible";
break;
default: // no_appx_candidates
message = "ESP Apps failure enrichment: no AppX deployment errors in window — failure likely " +
"originates outside the MSIX/Store pipeline (check Win32/IME apps)";
break;
}
_post.Emit(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
EventType = Constants.EventTypes.EspAppxFailureAnalysis,
Severity = severity,
Source = "EspAndHelloTracker",
Phase = EnrollmentPhase.Unknown,
Message = message,
Data = data,
ImmediateUpload = true
});
_logger.Info(
$"AppX failure analysis emitted: verdict={analysis.Verdict}, confidence={analysis.Confidence}, " +
$"candidates={analysis.TotalCandidateCount}/{analysis.ErrorEventCount} records, " +
$"durationMs={scan.ScanDurationMs}");
}
private void OnProvisioningFailureSettleExpired(string categoryName)
@@ -1 +1 @@
1255
1276
@@ -63,6 +63,7 @@ export const EVENT_TYPES_CATALOG = {
'app_install_skipped',
'app_install_starved',
'esp_apps_failure_correlation',
'esp_appx_failure_analysis',
'download_progress',
'do_telemetry',
'all_apps_completed',
@@ -471,6 +471,7 @@ namespace AutopilotMonitor.Shared
// ESP provisioning detail
public const string EspFailureSettleStarted = "esp_failure_settle_started";
public const string EspAppxFailureAnalysis = "esp_appx_failure_analysis"; // One-shot AppXDeploymentServer/Operational scan during the ESP failure settle window: candidate MSIX/Store packages behind an "Apps (0x…)" subcategory failure invisible to ImeLogTracker (session 2bc884b6). Assessment, not a confirmed root cause.
public const string EspProvisioningRaw = "esp_provisioning_raw";
public const string EspFailure = "esp_failure";
public const string EspExiting = "esp_exiting";
@@ -88,6 +88,8 @@ export const KNOWN_EVENT_TYPES: EventTypeEntry[] = [
description: "Generic ESP state change event." },
{ value: "esp_failure_advisory", label: "esp_failure_advisory", category: "esp",
description: "ESP reported a subcategory failure but the device had already progressed to AccountSetup with ContinueAnyway enabled — non-terminal advisory, the agent continues monitoring." },
{ value: "esp_appx_failure_analysis", label: "esp_appx_failure_analysis", category: "esp",
description: "AppX deployment log scan during the ESP failure settle window: suspected MSIX/Store package candidates behind an Apps-subcategory failure (assessment, not a confirmed root cause)." },
// -------- App installs --------
{ value: "app_install_started", label: "app_install_started", category: "app",
@@ -485,8 +485,8 @@ function EventRow({ event, showScriptOutput }: { event: EnrollmentEvent; showScr
defang). The HRESULT is extracted from the ESP registry statusText by the agent
(e.g. "Apps (0x87d1041c)") and surfaced as top-level event data so the UI can
render it without parsing nested text. */}
{(event.eventType === "enrollment_failed" || event.eventType === "esp_provisioning_status" || event.eventType === "esp_failure_advisory") && (() => {
const code = event.data?.errorCode ?? event.data?.failedSubcategoryErrorCode;
{(event.eventType === "enrollment_failed" || event.eventType === "esp_provisioning_status" || event.eventType === "esp_failure_advisory" || event.eventType === "esp_appx_failure_analysis") && (() => {
const code = event.data?.errorCode ?? event.data?.failedSubcategoryErrorCode ?? event.data?.espErrorCode;
const sub = event.data?.failedSubcategory ?? event.data?.failedSubcategories;
const isAdvisory = event.eventType === "esp_failure_advisory";
if (!code && !isAdvisory) return null;