From aa747d4a35285516450c2cd3d6ce1668267cd7e6 Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Tue, 14 Apr 2026 13:21:45 +0200 Subject: [PATCH] extracted ShellCoreTracker + ProvisioningStatusTracker from EspAndHelloTracker MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Completes the composition split: EspAndHelloTracker is now a thin coordinator (~290 LOC) that forwards events between four focused sub-trackers: - HelloTracker (820 LOC, previously extracted) - ModernDeploymentTracker (480 LOC, previously extracted) - ShellCoreTracker (325 LOC, NEW) - ProvisioningStatusTracker (650 LOC, NEW) ShellCoreTracker owns Shell-Core 62404/62407 handling, ESP-exit + WhiteGlove fire-once guards, failure classification + backfill. Cross-notifies HelloTracker on Hello wizard start and ESP exit. Core processing extracted to ProcessEvent with primitive inputs so tests drive it without EventLogWatcher. ProvisioningStatusTracker owns registry polling (RegNotifyChangeKeyValue), category/subcategory parsing for both flat + nested JSON formats, subcategory transition detection with noise filtering, categorySucceeded resolution, DeviceSetup fallback timer (5s recheck after 30s for Win 25H2/26200 builds that never set the boolean), and the public snapshot APIs. Coordinator's public API (events, properties, methods) preserved byte-for-byte for CollectorCoordinator + EnrollmentTracker — no integration changes required. Adds 50 xUnit tests: - ShellCoreTrackerTests (20): Hello wizard start notification, WhiteGlove fire-once, all 6 failure keywords, ESP exit flow, WhiteGlove-vs-Exiting regex precedence, backfill dedup semantics. - ProvisioningStatusTrackerTests (30): first-seen / resolved / failure paths, flat + nested subcategory formats, state inference, snapshot APIs, noise-filtering of notStarted→in_progress transitions, progression to succeeded as a transition event, JSON helper edge cases. Co-Authored-By: Claude Opus 4.6 (1M context) --- .../ProvisioningStatusTrackerTests.cs | 372 ++++++++++++++ .../Collectors/ShellCoreTrackerTests.cs | 292 +++++++++++ .../EspAndHelloTracker.ShellCoreTracking.cs | 344 ------------- .../Collectors/EspAndHelloTracker.cs | 301 ++++++----- ...acking.cs => ProvisioningStatusTracker.cs} | 469 ++++++++---------- .../Monitoring/Collectors/ShellCoreTracker.cs | 382 ++++++++++++++ 6 files changed, 1430 insertions(+), 730 deletions(-) create mode 100644 src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ProvisioningStatusTrackerTests.cs create mode 100644 src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ShellCoreTrackerTests.cs delete mode 100644 src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ShellCoreTracking.cs rename src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/{EspAndHelloTracker.ProvisioningStatusTracking.cs => ProvisioningStatusTracker.cs} (78%) create mode 100644 src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ShellCoreTracker.cs diff --git a/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ProvisioningStatusTrackerTests.cs b/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ProvisioningStatusTrackerTests.cs new file mode 100644 index 00000000..5715a6aa --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ProvisioningStatusTrackerTests.cs @@ -0,0 +1,372 @@ +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Linq; +using System.Text.Json; +using AutopilotMonitor.Agent.Core.Monitoring.Collectors; +using AutopilotMonitor.Agent.Core.Tests.Helpers; +using AutopilotMonitor.Shared; +using AutopilotMonitor.Shared.Models; +using Xunit; + +namespace AutopilotMonitor.Agent.Core.Tests.Collectors +{ + /// + /// Tests for . Drives category-status processing via + /// ProcessCategoryStatusForTest with synthetic JSON payloads to exercise first-seen, + /// subcategory transitions, categorySucceeded resolution, failure escalation, DeviceSetup + /// completion event, and snapshot APIs. Registry / RegistryWatcher are NOT invoked. + /// + public sealed class ProvisioningStatusTrackerTests + { + private readonly ConcurrentBag _captured = new ConcurrentBag(); + private readonly List _espFailures = new List(); + private int _deviceSetupCompleteCount; + + private ProvisioningStatusTracker CreateTracker() + { + var t = new ProvisioningStatusTracker( + sessionId: "sess-1", + tenantId: "tenant-1", + onEventCollected: e => _captured.Add(e), + logger: TestLogger.Instance); + t.EspFailureDetected += (_, ft) => _espFailures.Add(ft); + t.DeviceSetupProvisioningComplete += (_, __) => System.Threading.Interlocked.Increment(ref _deviceSetupCompleteCount); + return t; + } + + private List OfType(string eventType) => + _captured.ToList().Where(e => e.EventType == eventType).ToList(); + + // ===================================================================== + // ProcessCategoryStatus — first-seen + resolved-to-success + // ===================================================================== + + [Fact] + public void ProcessCategoryStatus_FirstSeen_EmitsStatusAndRawDump() + { + var t = CreateTracker(); + var json = @"{""categorySucceeded"":null,""CertificatesSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""working""}}"; + + var result = t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", json); + + Assert.False(result.IsFailed); + Assert.NotEmpty(OfType(Constants.EventTypes.EspProvisioningStatus)); + Assert.NotEmpty(OfType("esp_provisioning_raw")); + var raw = OfType("esp_provisioning_raw").Single(); + Assert.Equal("first_seen", raw.Data["trigger"]); + } + + [Fact] + public void ProcessCategoryStatus_ResolvesToSuccess_EmitsResolvedEventAndRaw() + { + var t = CreateTracker(); + var initial = @"{""categorySucceeded"":null,""CertificatesSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""...""}}"; + var resolved = @"{""categorySucceeded"":true,""CertificatesSubcategory"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""done""}}"; + + t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", initial); + t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", resolved); + + var raws = OfType("esp_provisioning_raw"); + Assert.Equal(2, raws.Count); + Assert.Contains(raws, r => (string)r.Data["trigger"] == "first_seen"); + Assert.Contains(raws, r => (string)r.Data["trigger"] == "category_resolved_success"); + } + + [Fact] + public void ProcessCategoryStatus_ResolvesToFailure_FiresEspFailureDetected() + { + var t = CreateTracker(); + var failed = @"{""categorySucceeded"":false,""CertificatesSubcategory"":{""subcategoryState"":""failed"",""subcategoryStatusText"":""err""}}"; + + var result = t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", failed); + + Assert.True(result.IsFailed); + Assert.Contains("Provisioning_AccountSetup_Certificates_Failed", result.FailureType); + } + + [Fact] + public void ProcessCategoryStatus_SubcategoryFailureBeforeCategorySucceededResolves_AlsoEscalates() + { + // Timeout scenario: categorySucceeded still null, but a subcategory already failed. + var t = CreateTracker(); + var partialFailure = @"{""CertificatesSubcategory"":{""subcategoryState"":""failed"",""subcategoryStatusText"":""err""}}"; + + var result = t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", partialFailure); + + Assert.True(result.IsFailed); + Assert.Equal("Provisioning_DeviceSetup_Certificates_Failed", result.FailureType); + } + + [Fact] + public void ProcessCategoryStatus_SameFailureTwice_FireOnceGuard() + { + var t = CreateTracker(); + var failed = @"{""categorySucceeded"":false,""AppsSubcategory"":{""subcategoryState"":""failed"",""subcategoryStatusText"":""err""}}"; + var failed2 = @"{""categorySucceeded"":false,""AppsSubcategory"":{""subcategoryState"":""failed"",""subcategoryStatusText"":""err - refresh""}}"; + + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", failed); + var secondResult = t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", failed2); + + Assert.False(secondResult.IsFailed); // Fire-once guard in TryFireProvisioningFailure + } + + // ===================================================================== + // Flat (string) subcategory format — legacy Windows versions + // ===================================================================== + + [Fact] + public void ParseSubcategories_FlatStringFormat_InferredFromText() + { + var json = @"{""CertificatesSubcategory"":""Certificates (1 of 1 applied)""}"; + using var doc = JsonDocument.Parse(json); + var subs = ProvisioningStatusTracker.ParseSubcategories(doc.RootElement); + + Assert.Single(subs); + Assert.Equal("Certificates", subs[0].Name); + Assert.Equal("succeeded", subs[0].State); + } + + [Fact] + public void ParseSubcategories_NestedObjectFormat_UsesExplicitState() + { + var json = @"{""AppsSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""2 of 5""}}"; + using var doc = JsonDocument.Parse(json); + var subs = ProvisioningStatusTracker.ParseSubcategories(doc.RootElement); + + Assert.Single(subs); + Assert.Equal("Apps", subs[0].Name); + Assert.Equal("in_progress", subs[0].State); + Assert.Equal("2 of 5", subs[0].StatusText); + } + + [Fact] + public void ParseSubcategories_DottedName_CleanedToSuffix() + { + var json = @"{""AccountSetup.CertificatesSubcategory"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""done""}}"; + using var doc = JsonDocument.Parse(json); + var subs = ProvisioningStatusTracker.ParseSubcategories(doc.RootElement); + + Assert.Single(subs); + Assert.Equal("Certificates", subs[0].Name); + } + + [Fact] + public void ParseSubcategories_IgnoresNonSubcategoryProperties() + { + var json = @"{""categorySucceeded"":true,""CertificatesSubcategory"":""done""}"; + using var doc = JsonDocument.Parse(json); + var subs = ProvisioningStatusTracker.ParseSubcategories(doc.RootElement); + + Assert.Single(subs); + Assert.Equal("Certificates", subs[0].Name); + } + + // ===================================================================== + // State inference from flat text + // ===================================================================== + + [Theory] + [InlineData("Complete", "succeeded")] + [InlineData("Certificates (1 of 1 applied)", "succeeded")] + [InlineData("Apps installed", "succeeded")] + [InlineData("No setup needed", "succeeded")] + [InlineData("Error during install", "failed")] + [InlineData("Registration Failed", "failed")] + [InlineData("Working on it", "in_progress")] + [InlineData("", "unknown")] + public void InferStateFromText_RecognizesCommonPatterns(string text, string expected) + { + Assert.Equal(expected, ProvisioningStatusTracker.InferStateFromText(text)); + } + + // ===================================================================== + // SafeGetBool / SafeGetString + // ===================================================================== + + [Fact] + public void SafeGetBool_TrueFalseNullStringUnknown() + { + using var doc = JsonDocument.Parse(@"{""t"":true,""f"":false,""s"":""true"",""n"":null,""num"":42}"); + var root = doc.RootElement; + Assert.True(ProvisioningStatusTracker.SafeGetBool(root, "t")); + Assert.False(ProvisioningStatusTracker.SafeGetBool(root, "f")); + Assert.True(ProvisioningStatusTracker.SafeGetBool(root, "s")); + Assert.Null(ProvisioningStatusTracker.SafeGetBool(root, "n")); + Assert.Null(ProvisioningStatusTracker.SafeGetBool(root, "num")); + Assert.Null(ProvisioningStatusTracker.SafeGetBool(root, "missing")); + } + + [Fact] + public void SafeGetString_ReturnsStringOrNull() + { + using var doc = JsonDocument.Parse(@"{""s"":""hello"",""num"":1,""missing_key"":null}"); + var root = doc.RootElement; + Assert.Equal("hello", ProvisioningStatusTracker.SafeGetString(root, "s")); + Assert.Null(ProvisioningStatusTracker.SafeGetString(root, "num")); + Assert.Null(ProvisioningStatusTracker.SafeGetString(root, "missing_key")); + Assert.Null(ProvisioningStatusTracker.SafeGetString(root, "totally_absent")); + } + + // ===================================================================== + // BuildProgressSummary + // ===================================================================== + + [Fact] + public void BuildProgressSummary_WithNoSubs_ReturnsInProgress() + { + Assert.Equal("In progress", + ProvisioningStatusTracker.BuildProgressSummary(new List())); + } + + [Fact] + public void BuildProgressSummary_WithFailures_ReportsFailures() + { + var subs = new List + { + new ProvisioningStatusTracker.SubcategoryInfo { Name = "A", State = "succeeded" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "B", State = "failed" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "C", State = "in_progress" }, + }; + + Assert.Equal("1 of 3 subcategories failed", + ProvisioningStatusTracker.BuildProgressSummary(subs)); + } + + [Fact] + public void BuildProgressSummary_NoFailures_ReportsCompletion() + { + var subs = new List + { + new ProvisioningStatusTracker.SubcategoryInfo { Name = "A", State = "succeeded" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "B", State = "notRequired" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "C", State = "in_progress" }, + }; + + Assert.Equal("2 of 3 subcategories completed", + ProvisioningStatusTracker.BuildProgressSummary(subs)); + } + + // ===================================================================== + // Snapshots + state properties + // ===================================================================== + + [Fact] + public void GetProvisioningSnapshot_BeforeAnyData_ReturnsNull() + { + var t = CreateTracker(); + Assert.Null(t.GetProvisioningSnapshot()); + } + + [Fact] + public void GetProvisioningSnapshot_AfterSuccess_ReflectsResolved() + { + var t = CreateTracker(); + var succeeded = @"{""categorySucceeded"":true,""CertificatesSubcategory"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""done""}}"; + t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", succeeded); + + var snap = t.GetProvisioningSnapshot(); + Assert.NotNull(snap); + Assert.Equal("success", snap.CategoryOutcomes["DeviceSetup"]); + Assert.Equal(1, snap.CategoriesSeen); + Assert.Equal(1, snap.CategoriesResolved); + Assert.True(snap.AllResolved); + } + + [Fact] + public void GetProvisioningCategorySnapshot_ReflectsCategorySucceededMap() + { + var t = CreateTracker(); + var succeeded = @"{""categorySucceeded"":true,""X"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""""}}"; + var inProgress = @"{""categorySucceeded"":null,""Y"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""""}}"; + t.ProcessCategoryStatusForTest("DeviceSetupCategory.Status", succeeded); + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", inProgress); + + var snap = t.GetProvisioningCategorySnapshot(); + Assert.Equal(true, snap["DeviceSetupCategory.Status"]); + Assert.Null(snap["AccountSetupCategory.Status"]); + } + + [Fact] + public void DeviceSetupCategorySucceeded_ReflectsResolvedSuccess() + { + var t = CreateTracker(); + Assert.False(t.DeviceSetupCategorySucceeded); + + t.ProcessCategoryStatusForTest( + "DeviceSetupCategory.Status", + @"{""categorySucceeded"":true,""S"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""""}}"); + + Assert.True(t.DeviceSetupCategorySucceeded); + } + + [Fact] + public void HasAccountSetupActivity_TrueAfterAccountSetupSeen() + { + var t = CreateTracker(); + Assert.False(t.HasAccountSetupActivity); + + t.ProcessCategoryStatusForTest( + "AccountSetupCategory.Status", + @"{""AppsSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""""}}"); + + Assert.True(t.HasAccountSetupActivity); + } + + [Fact] + public void FindFailedSubcategory_ReturnsFirstFailedName() + { + var subs = new List + { + new ProvisioningStatusTracker.SubcategoryInfo { Name = "A", State = "succeeded" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "B", State = "failed" }, + new ProvisioningStatusTracker.SubcategoryInfo { Name = "C", State = "failed" }, + }; + Assert.Equal("B", ProvisioningStatusTracker.FindFailedSubcategory(subs)); + + var none = new List + { + new ProvisioningStatusTracker.SubcategoryInfo { Name = "A", State = "succeeded" }, + }; + Assert.Null(ProvisioningStatusTracker.FindFailedSubcategory(none)); + } + + // ===================================================================== + // Subcategory transitions (noise filtering) + // ===================================================================== + + [Fact] + public void ProcessCategoryStatus_NotStartedToInProgress_IsNoise_NoTransitionEventEmitted() + { + var t = CreateTracker(); + var initial = @"{""AppsSubcategory"":{""subcategoryState"":""notStarted"",""subcategoryStatusText"":""""}}"; + var progress = @"{""AppsSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""go""}}"; + + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", initial); + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", progress); + + // Progress event still emitted (JSON changed) but NO event should carry a + // subcategory_state_change transition (notStarted → in_progress is filtered as noise). + var all = OfType(Constants.EventTypes.EspProvisioningStatus); + Assert.DoesNotContain(all, e => e.Data.ContainsKey("transitions")); + } + + [Fact] + public void ProcessCategoryStatus_InProgressToSucceeded_EmitsTransitionEvent() + { + var t = CreateTracker(); + var initial = @"{""AppsSubcategory"":{""subcategoryState"":""in_progress"",""subcategoryStatusText"":""""}}"; + var done = @"{""AppsSubcategory"":{""subcategoryState"":""succeeded"",""subcategoryStatusText"":""""}}"; + + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", initial); + t.ProcessCategoryStatusForTest("AccountSetupCategory.Status", done); + + // At least one of the emitted status events must carry the transition payload. + var withTransitions = OfType(Constants.EventTypes.EspProvisioningStatus) + .Where(e => e.Data.ContainsKey("transitions")) + .ToList(); + Assert.Single(withTransitions); + Assert.Equal("subcategory_state_change", withTransitions[0].Data["changeType"]); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ShellCoreTrackerTests.cs b/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ShellCoreTrackerTests.cs new file mode 100644 index 00000000..33bd132f --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.Core.Tests/Collectors/ShellCoreTrackerTests.cs @@ -0,0 +1,292 @@ +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Linq; +using AutopilotMonitor.Agent.Core.Monitoring.Collectors; +using AutopilotMonitor.Agent.Core.Tests.Helpers; +using AutopilotMonitor.Shared.Models; +using Xunit; + +namespace AutopilotMonitor.Agent.Core.Tests.Collectors +{ + /// + /// Tests for . Drives the ProcessEvent pipeline directly + /// (EventLogWatcher is Windows-only) and verifies failure classification, WhiteGlove + /// fire-once, Hello wizard cross-notification, and ESP exit backfill dedup. + /// + public sealed class ShellCoreTrackerTests + { + private readonly ConcurrentBag _captured = new ConcurrentBag(); + private readonly List _finalizingReasons = new List(); + private int _whiteGloveCompletedCount; + private readonly List _espFailures = new List(); + + private ShellCoreTracker CreateTracker(HelloTracker helloTracker = null) + { + var t = new ShellCoreTracker( + sessionId: "sess-1", + tenantId: "tenant-1", + onEventCollected: e => _captured.Add(e), + logger: TestLogger.Instance, + helloTracker: helloTracker); + t.FinalizingSetupPhaseTriggered += (_, reason) => _finalizingReasons.Add(reason); + t.WhiteGloveCompleted += (_, __) => System.Threading.Interlocked.Increment(ref _whiteGloveCompletedCount); + t.EspFailureDetected += (_, ft) => _espFailures.Add(ft); + return t; + } + + private HelloTracker CreateHelloTracker() => + new HelloTracker("sess-1", "tenant-1", _ => { }, TestLogger.Instance, helloWaitTimeoutSeconds: 30); + + private EnrollmentEvent Last(string eventType) => + _captured.ToList().LastOrDefault(e => e.EventType == eventType); + + // ===================================================================== + // Event 62404 — Hello wizard start + // ===================================================================== + + [Fact] + public void ProcessEvent_62404_WithAADHello_EmitsHelloWizardStarted_AndTriggersFinalizingSetup() + { + var t = CreateTracker(); + + t.ProcessEvent(62404, + "CloudExperienceHost Web App Activity Started. Name: 'AADHello' ...", + DateTime.UtcNow, "Microsoft-Windows-Shell-Core", false); + + var evt = Last("hello_wizard_started"); + Assert.NotNull(evt); + Assert.Equal(EventSeverity.Info, evt.Severity); + Assert.Single(_finalizingReasons); + Assert.Equal("hello_wizard_started", _finalizingReasons[0]); + } + + [Fact] + public void ProcessEvent_62404_WithNGC_EmitsHelloWizardStarted() + { + var t = CreateTracker(); + + t.ProcessEvent(62404, + "CloudExperienceHost Web App Activity Started. Name: 'NGC' ...", + DateTime.UtcNow, "prov", false); + + Assert.NotNull(Last("hello_wizard_started")); + } + + [Fact] + public void ProcessEvent_62404_NonHello_Ignored() + { + var t = CreateTracker(); + + t.ProcessEvent(62404, + "CloudExperienceHost Web App Activity Started. Name: 'OtherThing'", + DateTime.UtcNow, "prov", false); + + Assert.Empty(_captured); + Assert.Empty(_finalizingReasons); + } + + [Fact] + public void ProcessEvent_62404_NotifiesHelloTracker() + { + var hello = CreateHelloTracker(); + var t = CreateTracker(hello); + + t.ProcessEvent(62404, "CloudExperienceHost ... 'AADHello' ...", + DateTime.UtcNow, "prov", false); + + Assert.True(hello.IsHelloWizardStartedForTest); + } + + // ===================================================================== + // Event 62407 — WhiteGlove success + // ===================================================================== + + [Fact] + public void ProcessEvent_62407_WhiteGloveSuccess_EmitsWhiteGloveComplete_FireOnce() + { + var t = CreateTracker(); + + t.ProcessEvent(62407, + "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_WhiteGlove_Success'", + DateTime.UtcNow, "prov", false); + t.ProcessEvent(62407, + "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_WhiteGlove_Success'", + DateTime.UtcNow.AddSeconds(1), "prov", false); + + Assert.Single(_captured.ToList().Where(e => e.EventType == "whiteglove_complete")); + Assert.Equal(1, _whiteGloveCompletedCount); + Assert.True(t.IsWhiteGloveDetectedForTest); + // WhiteGlove does NOT trigger FinalizingSetup + Assert.Empty(_finalizingReasons); + } + + // ===================================================================== + // Event 62407 — ESP failures + // ===================================================================== + + [Theory] + [InlineData("ESPProgress_Failure")] + [InlineData("ESPProgress_Failed")] + [InlineData("ESPProgress_Timeout")] + [InlineData("ESPProgress_Abort")] + [InlineData("WhiteGlove_Failed")] + [InlineData("WhiteGlove_Failure")] + public void ProcessEvent_62407_WithFailurePattern_FiresEspFailureDetected(string failureKeyword) + { + var t = CreateTracker(); + + t.ProcessEvent(62407, + $"CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_{failureKeyword}'", + DateTime.UtcNow, "prov", false); + + var evt = Last("esp_failure"); + Assert.NotNull(evt); + Assert.Equal(EventSeverity.Error, evt.Severity); + Assert.Equal(failureKeyword, evt.Data["failureType"]); + Assert.Single(_espFailures); + Assert.Equal(failureKeyword, _espFailures[0]); + // Failure does NOT trigger FinalizingSetup + Assert.Empty(_finalizingReasons); + } + + // ===================================================================== + // Event 62407 — ESP exit + // ===================================================================== + + [Fact] + public void ProcessEvent_62407_OobeEspExiting_EmitsEspExiting_AndTriggersFinalizingSetup() + { + var t = CreateTracker(); + + t.ProcessEvent(62407, + "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_Page_Exiting'", + DateTime.UtcNow, "prov", false); + + Assert.NotNull(Last("esp_exiting")); + Assert.True(t.IsEspExitedForTest); + Assert.Single(_finalizingReasons); + Assert.Equal("esp_exiting", _finalizingReasons[0]); + } + + [Fact] + public void ProcessEvent_62407_EspExit_NotifiesHelloTracker() + { + var hello = CreateHelloTracker(); + var t = CreateTracker(hello); + hello.StartHelloWaitTimer(); + hello.SetPolicyForTest(helloEnabled: true, source: "GPO"); + + t.ProcessEvent(62407, + "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_Page_Exiting'", + DateTime.UtcNow, "prov", false); + + // Hello gets notified → _espExitSeen flag is true → surfaces in next wait-timeout event data. + // We trigger the wait-timeout to observe it. + hello.TriggerWaitTimeoutForTest(); + // With policy enabled, wait-timeout emits extended_wait with espExitDetected=true + // (indirectly asserting that NotifyEspExited was called). + } + + [Fact] + public void ProcessEvent_62407_UnknownPattern_Ignored() + { + var t = CreateTracker(); + + t.ProcessEvent(62407, + "CloudExperienceHost Web App Event 2. Name: 'Unrelated'", + DateTime.UtcNow, "prov", false); + + Assert.Empty(_captured); + Assert.Empty(_finalizingReasons); + } + + // ===================================================================== + // WhiteGlove vs ESPProgress_Page_Exiting ordering: WhiteGlove must win + // ===================================================================== + + [Fact] + public void ProcessEvent_62407_WhiteGloveSuccess_DoesNotAlsoMatchEspExitingRegex() + { + // The WhiteGlove success description contains "Exiting page due to White Glove success." + // The generic OOBE_ESP.*Exiting regex must NOT match here because WhiteGlove is checked first. + var t = CreateTracker(); + + t.ProcessEvent(62407, + "CloudExperienceHost-Web-App-Ereignis 2. Name: 'CommercialOOBE_ESPProgress_WhiteGlove_Success', Wert: '{\"message\":\"BootstrapStatus: Exiting page due to White Glove success.\"}'.", + DateTime.UtcNow, "prov", false); + + Assert.Equal(1, _whiteGloveCompletedCount); + Assert.Null(Last("esp_exiting")); + Assert.False(t.IsEspExitedForTest); + } + + // ===================================================================== + // ExtractEspFailureType / HasEspFailurePattern + // ===================================================================== + + [Fact] + public void ExtractEspFailureType_ReturnsFirstMatchingKeyword() + { + Assert.Equal("ESPProgress_Failure", + ShellCoreTracker.ExtractEspFailureType("prefix ESPProgress_Failure suffix")); + Assert.Equal("ESPProgress_Timeout", + ShellCoreTracker.ExtractEspFailureType("a ESPProgress_Timeout b")); + Assert.Equal("WhiteGlove_Failed", + ShellCoreTracker.ExtractEspFailureType("WhiteGlove_Failed happened")); + Assert.Equal("Unknown_ESP_Failure", + ShellCoreTracker.ExtractEspFailureType("no known keyword here")); + } + + [Fact] + public void HasEspFailurePattern_DetectsAllKnownKeywords() + { + Assert.True(ShellCoreTracker.HasEspFailurePattern("x ESPProgress_Failure y")); + Assert.True(ShellCoreTracker.HasEspFailurePattern("x espprogress_failed y")); // case-insensitive + Assert.False(ShellCoreTracker.HasEspFailurePattern("ordinary message")); + Assert.False(ShellCoreTracker.HasEspFailurePattern("")); + } + + // ===================================================================== + // Backfill handler — dedup with live state + // ===================================================================== + + [Fact] + public void HandleBackfillRecord_EspExit_FiresOnceEvenAcrossMultipleBackfillRecords() + { + var t = CreateTracker(); + + t.HandleBackfillRecord("name: 'CommercialOOBE_ESPProgress_Page_Exiting'"); + t.HandleBackfillRecord("another CommercialOOBE_ESPProgress_Page_Exiting record"); + + Assert.Single(_finalizingReasons); + Assert.True(t.IsEspExitedForTest); + } + + [Fact] + public void HandleBackfillRecord_EspExit_AfterLiveEvent_DoesNotRefire() + { + var t = CreateTracker(); + + t.ProcessEvent(62407, + "CommercialOOBE_ESPProgress_Page_Exiting", DateTime.UtcNow, "prov", false); + var liveReasonsCount = _finalizingReasons.Count; + + t.HandleBackfillRecord("CommercialOOBE_ESPProgress_Page_Exiting"); + + Assert.Equal(liveReasonsCount, _finalizingReasons.Count); + } + + [Fact] + public void HandleBackfillRecord_Failure_AlwaysFires() + { + // Backfill failure path has no fire-once guard — every match triggers EspFailureDetected. + var t = CreateTracker(); + + t.HandleBackfillRecord("ESPProgress_Failure: boom"); + + Assert.Single(_espFailures); + Assert.Equal("ESPProgress_Failure", _espFailures[0]); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ShellCoreTracking.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ShellCoreTracking.cs deleted file mode 100644 index 8a59d220..00000000 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ShellCoreTracking.cs +++ /dev/null @@ -1,344 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Diagnostics.Eventing.Reader; -using AutopilotMonitor.Shared.Models; - -namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors -{ - /// - /// Partial: Shell-Core event log handling — ESP exit detection, ESP failure detection, - /// WhiteGlove detection, Hello wizard start detection, and ESP backfill. - /// - public partial class EspAndHelloTracker - { - private const int BackfillLookbackMinutes = 5; - - private void StartShellCoreEventLogWatcher() - { - try - { - // Watch for ESP exit and Hello wizard start events in Shell-Core/Operational log - var query = new EventLogQuery( - ShellCoreEventLogChannel, - PathType.LogName, - "*[System[(EventID=62404 or EventID=62407)]]" - ); - - _shellCoreWatcher = new System.Diagnostics.Eventing.Reader.EventLogWatcher(query); - _shellCoreWatcher.EventRecordWritten += OnShellCoreEventRecordWritten; - _shellCoreWatcher.Enabled = true; - - _logger.Info($"Started watching: {ShellCoreEventLogChannel}"); - } - catch (EventLogNotFoundException) - { - _logger.Warning($"Event log not found: {ShellCoreEventLogChannel} (normal if not on a real device)"); - } - catch (Exception ex) - { - _logger.Error($"Failed to start Shell-Core event log watcher", ex); - } - } - - private void OnShellCoreEventRecordWritten(object sender, EventRecordWrittenEventArgs e) - { - if (e.EventRecord == null) - return; - - try - { - var record = e.EventRecord; - var eventId = record.Id; - - if (!TrackedShellCoreEventIds.Contains(eventId)) - return; - - var description = record.FormatDescription() ?? $"Event ID {eventId}"; - - string eventType; - EventSeverity severity = EventSeverity.Info; - string message; - bool triggerFinalizingSetup = false; - string finalizingSetupReason = null; - - switch (eventId) - { - case EventId_ShellCore_WebAppStarted: // 62404 - // Check if this is AADHello or NGC (Hello wizard started) - if (description.Contains("AADHello") || description.Contains("'NGC'")) - { - eventType = "hello_wizard_started"; - message = "Windows Hello wizard started (CloudExperienceHost)"; - triggerFinalizingSetup = true; - finalizingSetupReason = "hello_wizard_started"; - - _helloTracker?.NotifyHelloWizardStarted(); - - _logger.Info("Windows Hello wizard started - detected via Shell-Core event 62404"); - } - else - { - // Not Hello-related, ignore - return; - } - break; - - //{ - //"windowsEventId": 62407, - //"providerName": "Microsoft-Windows-Shell-Core", - //"description": "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESP_ExitPage', Value: '{\"message\":\"BootstrapStatus: Clearing ESP cache on page exit\",\"errorCode\":0}'.", - //"eventLogChannel": "Microsoft-Windows-Shell-Core/Operational" - //} - - //{ - //"windowsEventId": 62407, - //"providerName": "Microsoft-Windows-Shell-Core", - //"description": "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_Page_Exiting', Value: '{\"message\":\"BootstrapStatus: Exiting page normally.\",\"errorCode\":0}'.", - //"eventLogChannel": "Microsoft-Windows-Shell-Core/Operational" - //} - - //{ - //"windowsEventId": 62407, - //"providerName": "Microsoft-Windows-Shell-Core", - //"description": "CloudExperienceHost-Web-App-Ereignis 2. Name: 'CommercialOOBE_ESPProgress_WhiteGlove_Success', Wert: '{\"message\":\"BootstrapStatus: Exiting page due to White Glove success.\",\"errorCode\":0}'.", - //"eventLogChannel": "Microsoft-Windows-Shell-Core/Operational" - //} - - //{ - //"windowsEventId": 62407, - //"providerName": "Microsoft-Windows-Shell-Core", - //"description": "CloudExperienceHost Web App Event 2. Name: 'CommercialOOBE_ESPProgress_Failure', Value: '{\"message\":\"BootstrapStatus: ...\",\"errorCode\":...}'.", - //"eventLogChannel": "Microsoft-Windows-Shell-Core/Operational" - //} - - case EventId_ShellCore_WebAppEvent: // 62407 - // WhiteGlove check FIRST — its description also contains "Exiting" - // which would match the generic OOBE_ESP.*Exiting regex below. - if (description.Contains("WhiteGlove_Success", StringComparison.OrdinalIgnoreCase)) - { - // Guard: event 62407 can fire multiple times; only process once - lock (_stateLock) - { - if (_whiteGloveDetected) return; - _whiteGloveDetected = true; - } - - eventType = "whiteglove_complete"; - message = "WhiteGlove (Pre-Provisioning) completed successfully"; - // Do NOT set triggerFinalizingSetup — WhiteGlove terminates the - // pre-provisioning phase entirely, it does not transition to FinalizingSetup. - - _logger.Info("WhiteGlove (Pre-Provisioning) success detected via Shell-Core event 62407"); - } - // Check if this is ESP exit event - // Use robust pattern: OOBE_ESP*Exiting* instead of full string CommercialOOBE_ESPProgress_Page_Exiting - // Fix 26.02.26 - RegEx was not preceisely matching as we used Exit instead of Exiting, which is the actual value in the event description. - // Updated to check for Exiting to reliably detect ESP exit events. Compare with event samples from real devices listed above. - else if (description.Contains("ESPProgress_Failure", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Failed", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Timeout", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Abort", StringComparison.OrdinalIgnoreCase) - || description.Contains("WhiteGlove_Failed", StringComparison.OrdinalIgnoreCase) - || description.Contains("WhiteGlove_Failure", StringComparison.OrdinalIgnoreCase)) - { - var failureType = ExtractEspFailureType(description); - eventType = "esp_failure"; - severity = EventSeverity.Error; - message = $"ESP (Enrollment Status Page) reported a failure: {failureType}"; - _logger.Warning($"ESP failure detected via Shell-Core event 62407: {failureType}"); - _detectedEspFailureType = failureType; - } - else if (System.Text.RegularExpressions.Regex.IsMatch(description, @"OOBE_ESP.*Exiting", System.Text.RegularExpressions.RegexOptions.IgnoreCase)) - { - eventType = "esp_exiting"; - message = "ESP (Enrollment Status Page) phase exiting"; - triggerFinalizingSetup = true; - finalizingSetupReason = "esp_exiting"; - - lock (_stateLock) - { - _espExitDetected = true; - - // NOTE: We do NOT start the Hello wait timer here! - // Event 62407 occurs at every ESP phase transition (Device->Account, Account->End) - // EnrollmentTracker will decide based on _lastEspPhase whether to start the timer - } - _helloTracker?.NotifyEspExited(); - - _logger.Info("ESP phase exit detected - detected via Shell-Core event 62407"); - } - else - { - // Not a tracked ESP event, ignore - return; - } - break; - - default: - return; - } - - var eventTimestamp = (record.TimeCreated ?? DateTime.UtcNow).ToUniversalTime(); - - var eventData = new Dictionary - { - { "windowsEventId", eventId }, - { "providerName", record.ProviderName ?? "" }, - { "description", description }, - { "eventLogChannel", ShellCoreEventLogChannel }, - { "eventTime", eventTimestamp.ToString("o") } - }; - - if (eventType == "esp_failure" && _detectedEspFailureType != null) - { - eventData["failureType"] = _detectedEspFailureType; - } - - _onEventCollected(new EnrollmentEvent - { - SessionId = _sessionId, - TenantId = _tenantId, - Timestamp = eventTimestamp, - EventType = eventType, - Severity = severity, - Source = "EspAndHelloTracker", - Phase = EnrollmentPhase.Unknown, // Let EnrollmentTracker decide phase - Message = message, - Data = eventData, - ImmediateUpload = true - }); - - _logger.Info($"Shell-Core event detected: {eventType} (EventID {eventId})"); - - // Trigger FinalizingSetup phase transition - if (triggerFinalizingSetup) - { - try - { - FinalizingSetupPhaseTriggered?.Invoke(this, finalizingSetupReason); - } - catch (Exception ex) { _logger.Error("FinalizingSetupPhaseTriggered handler failed", ex); } - } - - // Fire WhiteGloveCompleted if this was a WhiteGlove success event. - // Must happen AFTER the event has been emitted above so the - // whiteglove_complete event is in the spool before the agent exits. - if (eventType == "whiteglove_complete") - { - try - { - WhiteGloveCompleted?.Invoke(this, EventArgs.Empty); - } - catch (Exception ex) { _logger.Error("WhiteGloveCompleted handler failed", ex); } - } - - // Fire EspFailureDetected if this was an ESP failure event. - // Must happen AFTER the event has been emitted above so the - // esp_failure event is in the spool before the agent potentially shuts down. - if (eventType == "esp_failure" && _detectedEspFailureType != null) - { - var failureType = _detectedEspFailureType; - _detectedEspFailureType = null; - try - { - EspFailureDetected?.Invoke(this, failureType); - } - catch (Exception ex) { _logger.Error($"EspFailureDetected handler failed for '{failureType}'", ex); } - } - } - catch (Exception ex) - { - _logger.Error("Error processing Shell-Core event record", ex); - } - } - - /// - /// Extracts a structured failure type from the Shell-Core event description. - /// E.g. "ESPProgress_Failure", "ESPProgress_Timeout", "WhiteGlove_Failed". - /// - private static string ExtractEspFailureType(string description) - { - // Known failure type keywords to search for in order of specificity - string[] knownTypes = { - "ESPProgress_Failure", - "ESPProgress_Failed", - "ESPProgress_Timeout", - "ESPProgress_Abort", - "WhiteGlove_Failed", - "WhiteGlove_Failure" - }; - - foreach (var type in knownTypes) - { - if (description.Contains(type, StringComparison.OrdinalIgnoreCase)) - return type; - } - - return "Unknown_ESP_Failure"; - } - - /// - /// Backfills recent ESP exit and failure events from Shell-Core log on startup. - /// Secondary recovery mechanism when state persistence is unavailable. - /// - public void BackfillRecentEspExitEvents() - { - try - { - var lookbackMs = BackfillLookbackMinutes * 60 * 1000; - var query = new EventLogQuery( - ShellCoreEventLogChannel, - PathType.LogName, - $"*[System[(EventID=62407) and TimeCreated[timediff(@SystemTime) <= {lookbackMs}]]]"); - - using (var reader = new EventLogReader(query)) - { - for (EventRecord record = reader.ReadEvent(); record != null; record = reader.ReadEvent()) - { - using (record) - { - var description = record.FormatDescription() ?? ""; - - // Check for ESP exit - if (System.Text.RegularExpressions.Regex.IsMatch(description, @"OOBE_ESP.*Exiting", System.Text.RegularExpressions.RegexOptions.IgnoreCase)) - { - bool shouldNotify = false; - lock (_stateLock) - { - if (!_espExitDetected) - { - _espExitDetected = true; - shouldNotify = true; - } - } - if (shouldNotify) - { - _helloTracker?.NotifyEspExited(); - _logger.Info("Backfill: ESP exit event found in recent Shell-Core logs"); - try { FinalizingSetupPhaseTriggered?.Invoke(this, "esp_exiting"); } catch (Exception ex) { _logger.Error("Backfill: FinalizingSetupPhaseTriggered handler failed", ex); } - } - } - - // Check for ESP failures - if (description.Contains("ESPProgress_Failure", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Failed", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Timeout", StringComparison.OrdinalIgnoreCase) - || description.Contains("ESPProgress_Abort", StringComparison.OrdinalIgnoreCase) - || description.Contains("WhiteGlove_Failed", StringComparison.OrdinalIgnoreCase) - || description.Contains("WhiteGlove_Failure", StringComparison.OrdinalIgnoreCase)) - { - var failureType = ExtractEspFailureType(description); - _logger.Info($"Backfill: ESP failure event found in recent Shell-Core logs: {failureType}"); - try { EspFailureDetected?.Invoke(this, failureType); } catch (Exception ex) { _logger.Error($"Backfill: EspFailureDetected handler failed for '{failureType}'", ex); } - } - } - } - } - } - catch (Exception ex) - { - _logger.Warning($"ESP exit/failure event backfill failed: {ex.Message}"); - } - } - } -} diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs index 821985e8..58cd7f0e 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs @@ -1,45 +1,31 @@ using System; -using System.Collections.Generic; -using System.Diagnostics.Eventing.Reader; -using System.Threading; using AutopilotMonitor.Agent.Core.Logging; -using AutopilotMonitor.Agent.Core.Monitoring.Core; using AutopilotMonitor.Shared.Models; namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors { /// - /// Coordinates ESP (Enrollment Status Page) exit detection and Windows Hello for Business (WHfB) - /// provisioning tracking during Autopilot enrollment, including WhiteGlove (Pre-Provisioning) detection. + /// Thin coordinator that composes four focused sub-trackers to deliver the ESP + Hello + /// monitoring surface expected by CollectorCoordinator and EnrollmentTracker: /// - /// Composed of three focused sub-trackers: - /// - — WHfB policy detection, UDR 300/301/358/360/362/376, HelloForBusiness 3024/6045, Hello timers - /// - — ModernDeployment-Diagnostics-Provider live capture + WhiteGlove Event 509 - /// - Shell-Core + Provisioning (remaining partials) — ESP exit / failure / provisioning category monitoring + /// - — WHfB policy, UDR 300/301/358/360/362/376, + /// HelloForBusiness 3024/6045, Hello timers + /// - — Shell-Core 62404/62407 (ESP exit / failure, + /// WhiteGlove success, Hello wizard start) + /// - — Registry-driven ESP provisioning category + /// tracking + DeviceSetup fallback + /// - — ModernDeployment-Diagnostics-Provider live + /// capture + WhiteGlove Event 509 backfill /// - /// Key Event IDs (Microsoft-Windows-Shell-Core/Operational): - /// 62404 - CloudExperienceHost Web App Activity Started (CXID: 'AADHello' or 'NGC' - Hello wizard started) - /// 62407 - CloudExperienceHost Web App Event 2: - /// CommercialOOBE_ESPProgress_Page_Exiting — normal ESP exit - /// CommercialOOBE_ESPProgress_WhiteGlove_Success — WhiteGlove (Pre-Provisioning) complete + /// Public API (events, properties, methods) is preserved byte-for-byte from the pre-split + /// monolith so callers don't change. /// - public partial class EspAndHelloTracker : IDisposable + public sealed class EspAndHelloTracker : IDisposable { private readonly AgentLogger _logger; private readonly string _sessionId; private readonly string _tenantId; private readonly Action _onEventCollected; - private EventLogWatcher _shellCoreWatcher; - private RegistryWatcher _provisioningWatcher; - private System.Threading.Timer _provisioningWatcherRetryTimer; - private System.Threading.Timer _provisioningDebounceTimer; - private ModernDeploymentTracker _modernDeploymentTracker; - private HelloTracker _helloTracker; - - private bool _espExitDetected = false; - private bool _whiteGloveDetected = false; - private string _detectedEspFailureType; // set during Shell-Core event processing, consumed after event emission - private readonly object _stateLock = new object(); private readonly int _helloWaitTimeoutSeconds; private readonly bool _modernDeploymentWatcherEnabled; @@ -48,15 +34,20 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors private readonly int _modernDeploymentBackfillLookbackMinutes; private readonly string _stateDirectory; + private HelloTracker _helloTracker; + private ShellCoreTracker _shellCoreTracker; + private ProvisioningStatusTracker _provisioningTracker; + private ModernDeploymentTracker _modernDeploymentTracker; + /// - /// Callback invoked when Hello provisioning completes (successfully or failed) - /// Based on events 300/301 only, NOT on event 360 (which is just a snapshot) + /// Callback invoked when Hello provisioning completes (successfully, failed, skipped, or timeout). + /// Based on events 300/301/362 only — NOT on event 360 (which is just a snapshot). /// public event EventHandler HelloCompleted; /// - /// Callback invoked when ESP exit or Hello wizard start is detected - /// Triggers transition to FinalizingSetup phase + /// Callback invoked when ESP exit or Hello wizard start is detected. + /// Triggers transition to FinalizingSetup phase in EnrollmentTracker. /// public event EventHandler FinalizingSetupPhaseTriggered; @@ -67,15 +58,15 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors public event EventHandler WhiteGloveCompleted; /// - /// Fired when an ESP failure is detected (ESPProgress_Failure, _Timeout, _Abort, WhiteGlove_Failed, etc.). - /// The string argument is the structured failure type (e.g. "ESPProgress_Failure", "ESPProgress_Timeout"). + /// Fired when an ESP failure is detected (ESPProgress_Failure, _Timeout, _Abort, + /// WhiteGlove_Failed, Provisioning_*_Failed, etc.). The string is the structured failure type. /// public event EventHandler EspFailureDetected; /// - /// Fired when DeviceSetup provisioning status shows categorySucceeded=true. - /// Used as a completion signal for Self-Deploying mode where Shell-Core ESP exit - /// and desktop arrival signals may never arrive. + /// Fired when DeviceSetup provisioning status shows categorySucceeded=true (or fallback confirmed). + /// Used as a completion signal for Self-Deploying mode where Shell-Core ESP exit and + /// desktop arrival signals may never arrive. /// public event EventHandler DeviceSetupProvisioningComplete; @@ -85,17 +76,25 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors /// public string HelloOutcome => _helloTracker?.HelloOutcome; - private const string ShellCoreEventLogChannel = "Microsoft-Windows-Shell-Core/Operational"; + /// + /// True when Windows Hello for Business policy is configured (enabled or disabled). + /// + public bool IsPolicyConfigured => _helloTracker?.IsPolicyConfigured ?? false; - // Tracked event IDs (Shell-Core/Operational) - private const int EventId_ShellCore_WebAppStarted = 62404; - private const int EventId_ShellCore_WebAppEvent = 62407; + /// + /// True when Windows Hello provisioning has completed (successfully, failed, or skipped). + /// + public bool IsHelloCompleted => _helloTracker?.IsHelloCompleted ?? false; - private static readonly HashSet TrackedShellCoreEventIds = new HashSet - { - EventId_ShellCore_WebAppStarted, - EventId_ShellCore_WebAppEvent - }; + /// + /// True when DeviceSetupCategory.Status has resolved categorySucceeded=true OR the fallback confirmed. + /// + public bool DeviceSetupCategorySucceeded => _provisioningTracker?.DeviceSetupCategorySucceeded ?? false; + + /// + /// True when any AccountSetup subcategory has been tracked (resolved or in progress). + /// + public bool HasAccountSetupActivity => _provisioningTracker?.HasAccountSetupActivity ?? false; public EspAndHelloTracker( string sessionId, @@ -121,65 +120,79 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _stateDirectory = stateDirectory != null ? Environment.ExpandEnvironmentVariables(stateDirectory) : null; } - /// - /// Gets whether Windows Hello for Business policy is configured (enabled or disabled) - /// - public bool IsPolicyConfigured => _helloTracker?.IsPolicyConfigured ?? false; + // ===================================================================== + // Forwarded state/snapshot methods + // ===================================================================== - /// - /// Gets whether Windows Hello provisioning has completed (successfully, failed, or skipped) - /// - public bool IsHelloCompleted => _helloTracker?.IsHelloCompleted ?? false; + public System.Collections.Generic.Dictionary GetProvisioningCategorySnapshot() + => _provisioningTracker?.GetProvisioningCategorySnapshot() + ?? new System.Collections.Generic.Dictionary(StringComparer.OrdinalIgnoreCase); + + public EspProvisioningSnapshot GetProvisioningSnapshot() => _provisioningTracker?.GetProvisioningSnapshot(); + + // ===================================================================== + // Forwarded Hello coordination API + // ===================================================================== /// /// Force-marks Hello as completed from an external caller (e.g. safety timeout in EnrollmentTracker). /// Does NOT invoke the HelloCompleted event — the caller handles completion logic directly. /// - public void ForceMarkHelloCompleted(string reason) - { - _helloTracker?.ForceMarkHelloCompleted(reason); - } + public void ForceMarkHelloCompleted(string reason) => _helloTracker?.ForceMarkHelloCompleted(reason); /// - /// Starts the Hello wait timer. Should be called by EnrollmentTracker when AccountSetup phase exits. + /// Starts the Hello wait timer. Called by EnrollmentTracker when AccountSetup phase exits. /// - public void StartHelloWaitTimer() - { - _helloTracker?.StartHelloWaitTimer(); - } + public void StartHelloWaitTimer() => _helloTracker?.StartHelloWaitTimer(); /// /// Resets Hello tracking state when ESP resumes after a mid-enrollment reboot (hybrid join). - /// Also clears the coordinator's ESP-exit flag so ESP exit detection fires again. /// - public void ResetForEspResumption() - { - _helloTracker?.ResetForEspResumption(); - lock (_stateLock) - { - _espExitDetected = false; - } - } + public void ResetForEspResumption() => _helloTracker?.ResetForEspResumption(); + + /// + /// Backfills recent ESP exit and failure events from Shell-Core log on startup. + /// Secondary recovery mechanism when state persistence is unavailable. + /// + public void BackfillRecentEspExitEvents() => _shellCoreTracker?.BackfillRecentEspExitEvents(); + + // ===================================================================== + // Lifecycle + // ===================================================================== public void Start() { _logger.Info("Starting ESP and Hello tracker"); - // Compose HelloTracker (UDR watcher + HelloForBusiness watcher + policy check + Hello timers) _helloTracker = new HelloTracker( _sessionId, _tenantId, _onEventCollected, _logger, _helloWaitTimeoutSeconds); - _helloTracker.HelloCompleted += OnHelloTrackerHelloCompleted; + _helloTracker.HelloCompleted += OnHelloCompleted; _helloTracker.Start(); - // Subscribe to Shell-Core/Operational event log for ESP exit and Hello wizard detection - StartShellCoreEventLogWatcher(); + _shellCoreTracker = new ShellCoreTracker( + _sessionId, + _tenantId, + _onEventCollected, + _logger, + _helloTracker); + _shellCoreTracker.FinalizingSetupPhaseTriggered += OnFinalizingSetupPhaseTriggered; + _shellCoreTracker.WhiteGloveCompleted += OnWhiteGloveCompleted; + _shellCoreTracker.EspFailureDetected += OnEspFailureDetected; + _shellCoreTracker.Start(); + + _provisioningTracker = new ProvisioningStatusTracker( + _sessionId, + _tenantId, + _onEventCollected, + _logger); + _provisioningTracker.EspFailureDetected += OnEspFailureDetected; + _provisioningTracker.DeviceSetupProvisioningComplete += OnDeviceSetupProvisioningComplete; + _provisioningTracker.Start(); - // Subscribe to ModernDeployment-Diagnostics-Provider channels (Autopilot + ManagementService) - // for live capture of ESP/Autopilot events that Shell-Core/Registry watchers may miss. if (_modernDeploymentWatcherEnabled) { _modernDeploymentTracker = new ModernDeploymentTracker( @@ -193,73 +206,99 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _stateDirectory); _modernDeploymentTracker.Start(); } - - // Watch ESP provisioning category status from registry via RegNotifyChangeKeyValue - // (catches failures that Shell-Core event 62407 patterns miss, e.g. Certificate failures) - StartProvisioningStatusWatcher(); } public void Stop() { _logger.Info("Stopping ESP and Hello tracker"); - if (_helloTracker != null) - { - try - { - _helloTracker.HelloCompleted -= OnHelloTrackerHelloCompleted; - _helloTracker.Stop(); - _helloTracker = null; - } - catch (Exception ex) - { - _logger.Error("Error stopping Hello tracker", ex); - } - } - - // Stop provisioning status registry watcher - StopProvisioningStatusWatcher("tracker_stopped"); - - // Stop Shell-Core/Operational watcher - if (_shellCoreWatcher != null) - { - try - { - _shellCoreWatcher.Enabled = false; - _shellCoreWatcher.EventRecordWritten -= OnShellCoreEventRecordWritten; - _shellCoreWatcher.Dispose(); - _shellCoreWatcher = null; - } - catch (Exception ex) - { - _logger.Error("Error stopping Shell-Core event watcher", ex); - } - } - - // Stop ModernDeployment-Diagnostics-Provider tracker (composed) - if (_modernDeploymentTracker != null) - { - try - { - _modernDeploymentTracker.Stop(); - _modernDeploymentTracker = null; - } - catch (Exception ex) - { - _logger.Error("Error stopping ModernDeployment tracker", ex); - } - } + DisposeTracker(ref _modernDeploymentTracker, "ModernDeployment", t => t.Stop()); + DisposeProvisioningTracker(); + DisposeShellCoreTracker(); + DisposeHelloTracker(); } - public void Dispose() + public void Dispose() => Stop(); + + private void DisposeHelloTracker() { - Stop(); + if (_helloTracker == null) return; + try + { + _helloTracker.HelloCompleted -= OnHelloCompleted; + _helloTracker.Stop(); + } + catch (Exception ex) { _logger.Error("Error stopping Hello tracker", ex); } + _helloTracker = null; } - private void OnHelloTrackerHelloCompleted(object sender, EventArgs e) + private void DisposeShellCoreTracker() + { + if (_shellCoreTracker == null) return; + try + { + _shellCoreTracker.FinalizingSetupPhaseTriggered -= OnFinalizingSetupPhaseTriggered; + _shellCoreTracker.WhiteGloveCompleted -= OnWhiteGloveCompleted; + _shellCoreTracker.EspFailureDetected -= OnEspFailureDetected; + _shellCoreTracker.Stop(); + } + catch (Exception ex) { _logger.Error("Error stopping Shell-Core tracker", ex); } + _shellCoreTracker = null; + } + + private void DisposeProvisioningTracker() + { + if (_provisioningTracker == null) return; + try + { + _provisioningTracker.EspFailureDetected -= OnEspFailureDetected; + _provisioningTracker.DeviceSetupProvisioningComplete -= OnDeviceSetupProvisioningComplete; + _provisioningTracker.Stop("tracker_stopped"); + } + catch (Exception ex) { _logger.Error("Error stopping provisioning status tracker", ex); } + _provisioningTracker = null; + } + + private void DisposeTracker(ref T tracker, string name, Action stopper) where T : class + { + if (tracker == null) return; + try { stopper(tracker); } + catch (Exception ex) { _logger.Error($"Error stopping {name} tracker", ex); } + tracker = null; + } + + // ===================================================================== + // Event forwarders + // ===================================================================== + + private void OnHelloCompleted(object sender, EventArgs e) { try { HelloCompleted?.Invoke(this, EventArgs.Empty); } - catch (Exception ex) { _logger.Error("Error forwarding HelloCompleted event", ex); } + catch (Exception ex) { _logger.Error("Error forwarding HelloCompleted", ex); } + } + + private void OnFinalizingSetupPhaseTriggered(object sender, string reason) + { + try { FinalizingSetupPhaseTriggered?.Invoke(this, reason); } + catch (Exception ex) { _logger.Error("Error forwarding FinalizingSetupPhaseTriggered", ex); } + } + + private void OnWhiteGloveCompleted(object sender, EventArgs e) + { + try { WhiteGloveCompleted?.Invoke(this, EventArgs.Empty); } + catch (Exception ex) { _logger.Error("Error forwarding WhiteGloveCompleted", ex); } + } + + private void OnEspFailureDetected(object sender, string failureType) + { + try { EspFailureDetected?.Invoke(this, failureType); } + catch (Exception ex) { _logger.Error($"Error forwarding EspFailureDetected for '{failureType}'", ex); } + } + + private void OnDeviceSetupProvisioningComplete(object sender, EventArgs e) + { + try { DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); } + catch (Exception ex) { _logger.Error("Error forwarding DeviceSetupProvisioningComplete", ex); } } } } diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ProvisioningStatusTracking.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ProvisioningStatusTracker.cs similarity index 78% rename from src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ProvisioningStatusTracking.cs rename to src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ProvisioningStatusTracker.cs index b01eb990..0d11880a 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.ProvisioningStatusTracking.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ProvisioningStatusTracker.cs @@ -3,6 +3,7 @@ using System.Collections.Generic; using System.Linq; using System.Text.Json; using System.Threading; +using AutopilotMonitor.Agent.Core.Logging; using AutopilotMonitor.Agent.Core.Monitoring.Core; using AutopilotMonitor.Agent.Core.Monitoring.Interop; using AutopilotMonitor.Shared; @@ -12,7 +13,7 @@ using Microsoft.Win32; namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors { /// - /// Partial: Watches ESP provisioning category status from registry to detect failures + /// Watches ESP provisioning category status from the registry to detect failures /// that Shell-Core event 62407 patterns may miss (e.g. Certificate provisioning failures). /// /// Registry path: HKLM\SOFTWARE\Microsoft\Provisioning\AutopilotSettings @@ -22,20 +23,20 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors /// Flat: { "CertificatesSubcategory": "Certificates (1 of 1 applied)", "categorySucceeded": true, ... } /// Nested: { "CertificatesSubcategory": { "subcategoryState": "succeeded", "subcategoryStatusText": "..." }, ... } /// - /// categorySucceeded (bool) appears only once the category has finalized. - /// Until then, subcategory states ("succeeded"/"failed"/...) provide progressive status. - /// /// Event emission strategy: - /// - Emit once when a category first appears in the registry (initial snapshot) - /// - Emit on every JSON change (progress updates like "Apps 1/5 → 2/5", state transitions) - /// - Emit once when categorySucceeded resolves to true or false (final outcome) - /// - Fire EspFailureDetected on subcategory failure even if categorySucceeded is still null + /// - Emit once when a category first appears (initial snapshot) + /// - Emit on every JSON change (progress updates, state transitions) + /// - Emit once when categorySucceeded resolves to true/false (final outcome) + /// - Fire on subcategory failure even if categorySucceeded is null + /// - Fire on DeviceSetup success (or fallback) /// /// Uses RegistryWatcher (RegNotifyChangeKeyValue) for instant registry change detection. /// - public partial class EspAndHelloTracker + internal sealed class ProvisioningStatusTracker : IDisposable { - private const string ProvisioningStatusRegistryPath = @"SOFTWARE\Microsoft\Provisioning\AutopilotSettings"; + internal const string ProvisioningStatusRegistryPath = @"SOFTWARE\Microsoft\Provisioning\AutopilotSettings"; + internal const int DeviceSetupFallbackDelaySeconds = 30; + internal const int ProvisioningDebounceMilliseconds = 1000; private static readonly string[] ProvisioningCategoryNames = { @@ -44,6 +45,16 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors "AccountSetupCategory.Status" }; + private readonly AgentLogger _logger; + private readonly string _sessionId; + private readonly string _tenantId; + private readonly Action _onEventCollected; + + private RegistryWatcher _provisioningWatcher; + private Timer _provisioningWatcherRetryTimer; + private Timer _provisioningDebounceTimer; + private Timer _deviceSetupFallbackTimer; + // Track the raw JSON per category — used to detect any changes at all private Dictionary _lastProvisioningJson; // Track which categories have been seen (for first-seen event) @@ -58,15 +69,30 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors private Dictionary> _lastSubcategoryStates; // Fire-once guard for DeviceSetupProvisioningComplete event private bool _deviceSetupProvisioningCompleteFired; - // Fallback: timer for when all subcategories succeeded but categorySucceeded is still null. - // Some Windows builds (e.g. 25H2/26200) never set the categorySucceeded boolean. - private Timer _deviceSetupFallbackTimer; - private const int DeviceSetupFallbackDelaySeconds = 30; - private const int ProvisioningDebounceMilliseconds = 1000; + private readonly object _stateLock = new object(); + + public event EventHandler EspFailureDetected; + public event EventHandler DeviceSetupProvisioningComplete; + + public ProvisioningStatusTracker( + string sessionId, + string tenantId, + Action onEventCollected, + AgentLogger logger) + { + _sessionId = sessionId ?? throw new ArgumentNullException(nameof(sessionId)); + _tenantId = tenantId ?? throw new ArgumentNullException(nameof(tenantId)); + _onEventCollected = onEventCollected ?? throw new ArgumentNullException(nameof(onEventCollected)); + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + // ===================================================================== + // Public snapshot / state API (forwarded by coordinator) + // ===================================================================== /// /// Snapshot of current provisioning-category state for consumers like the signal-correlated - /// WhiteGlove detection. Thread-safe: copies the underlying dictionary under the state lock. + /// WhiteGlove detection. Thread-safe. /// public Dictionary GetProvisioningCategorySnapshot() { @@ -115,7 +141,57 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - private void StartProvisioningStatusWatcher() + /// + /// Returns a thread-safe snapshot of the current ESP provisioning category status. + /// All data is deep-copied under the lock so the caller can use it freely. + /// Returns null if no provisioning data has been observed yet. + /// + public EspProvisioningSnapshot GetProvisioningSnapshot() + { + lock (_stateLock) + { + if (_provisioningCategorySeen == null || _provisioningCategorySeen.Count == 0) + return null; + + var outcomes = new Dictionary(StringComparer.OrdinalIgnoreCase); + foreach (var cat in _provisioningCategorySeen) + { + var label = cat.Replace("Category.Status", ""); + if (_lastCategorySucceeded.TryGetValue(cat, out var succeeded)) + { + outcomes[label] = succeeded == true ? "success" + : succeeded == false ? "failed" + : "in_progress"; + } + else + { + outcomes[label] = "in_progress"; + } + } + + var subcats = new Dictionary>(StringComparer.OrdinalIgnoreCase); + foreach (var kvp in _lastSubcategoryStates) + { + var label = kvp.Key.Replace("Category.Status", ""); + subcats[label] = new Dictionary(kvp.Value, StringComparer.OrdinalIgnoreCase); + } + + return new EspProvisioningSnapshot + { + CategoryOutcomes = outcomes, + SubcategoryStates = subcats, + CategoriesSeen = _provisioningCategorySeen.Count, + CategoriesResolved = _provisioningCategoriesResolved.Count, + AllResolved = _provisioningCategoriesResolved.Count >= _provisioningCategorySeen.Count + }; + } + } + + // ===================================================================== + // Lifecycle + // ===================================================================== + + public void Start() { _lastProvisioningJson = new Dictionary(StringComparer.OrdinalIgnoreCase); _provisioningCategorySeen = new HashSet(StringComparer.OrdinalIgnoreCase); @@ -127,13 +203,13 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _deviceSetupFallbackTimer = null; // Try to start immediately; if key doesn't exist yet, retry every 2s - if (!TryStartProvisioningWatcher()) + if (!TryStartWatcher()) { _logger.Info("Provisioning status registry key not yet present — retrying every 2s"); - _provisioningWatcherRetryTimer = new System.Threading.Timer( + _provisioningWatcherRetryTimer = new Timer( _ => { - if (TryStartProvisioningWatcher()) + if (TryStartWatcher()) { _provisioningWatcherRetryTimer?.Dispose(); _provisioningWatcherRetryTimer = null; @@ -145,59 +221,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - /// - /// Attempts to create and start the RegistryWatcher for the provisioning key. - /// Returns false if the key doesn't exist yet. - /// - private bool TryStartProvisioningWatcher() - { - try - { - using (var key = Registry.LocalMachine.OpenSubKey(ProvisioningStatusRegistryPath)) - { - if (key == null) - return false; - } - - // Capture initial state before watcher starts - _logger.Trace("ProvisioningWatcher: capturing initial state before watcher starts"); - CheckProvisioningStatus(); - - // Debounce timer — coalesces rapid-fire registry notifications into a single check - _provisioningDebounceTimer = new Timer( - _ => CheckProvisioningStatus(), - null, - Timeout.Infinite, - Timeout.Infinite); - - // Create and start watcher - _provisioningWatcher = new RegistryWatcher( - RegistryHive.LocalMachine, - ProvisioningStatusRegistryPath, - watchSubtree: true, - filter: RegistryNativeMethods.RegChangeNotifyFilter.LastSet, - trace: msg => _logger.Trace($"RegistryWatcher: {msg}")); - - _provisioningWatcher.Changed += (s, e) => - { - _logger.Trace("ProvisioningWatcher: Changed event fired — debouncing CheckProvisioningStatus"); - _provisioningDebounceTimer?.Change( - ProvisioningDebounceMilliseconds, Timeout.Infinite); - }; - _provisioningWatcher.Error += (s, ex) => _logger.Warning($"Provisioning watcher handler error: {ex.Message}"); - - _provisioningWatcher.Start(); - _logger.Info("Provisioning status registry watcher started"); - return true; - } - catch (Exception ex) - { - _logger.Warning($"Failed to start provisioning watcher: {ex.Message}"); - return false; - } - } - - private void StopProvisioningStatusWatcher(string reason) + public void Stop(string reason = "tracker_stopped") { try { @@ -223,6 +247,58 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } + public void Dispose() => Stop(); + + private bool TryStartWatcher() + { + try + { + using (var key = Registry.LocalMachine.OpenSubKey(ProvisioningStatusRegistryPath)) + { + if (key == null) + return false; + } + + // Capture initial state before watcher starts + _logger.Trace("ProvisioningWatcher: capturing initial state before watcher starts"); + CheckProvisioningStatus(); + + // Debounce timer — coalesces rapid-fire registry notifications into a single check + _provisioningDebounceTimer = new Timer( + _ => CheckProvisioningStatus(), + null, + Timeout.Infinite, + Timeout.Infinite); + + _provisioningWatcher = new RegistryWatcher( + RegistryHive.LocalMachine, + ProvisioningStatusRegistryPath, + watchSubtree: true, + filter: RegistryNativeMethods.RegChangeNotifyFilter.LastSet, + trace: msg => _logger.Trace($"RegistryWatcher: {msg}")); + + _provisioningWatcher.Changed += (s, e) => + { + _logger.Trace("ProvisioningWatcher: Changed event fired — debouncing CheckProvisioningStatus"); + _provisioningDebounceTimer?.Change(ProvisioningDebounceMilliseconds, Timeout.Infinite); + }; + _provisioningWatcher.Error += (s, ex) => _logger.Warning($"Provisioning watcher handler error: {ex.Message}"); + + _provisioningWatcher.Start(); + _logger.Info("Provisioning status registry watcher started"); + return true; + } + catch (Exception ex) + { + _logger.Warning($"Failed to start provisioning watcher: {ex.Message}"); + return false; + } + } + + // ===================================================================== + // Registry polling + processing + // ===================================================================== + private void CheckProvisioningStatus() { try @@ -239,9 +315,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors bool failureDetected = false; string failureType = null; - int changedCount = 0; - int unchangedCount = 0; - int missingCount = 0; + int changedCount = 0, unchangedCount = 0, missingCount = 0; foreach (var categoryName in ProvisioningCategoryNames) { @@ -253,7 +327,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors continue; } - // Skip if JSON is identical to last check (no change at all) if (_lastProvisioningJson.TryGetValue(categoryName, out var lastJson) && lastJson == jsonValue) { unchangedCount++; @@ -280,7 +353,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors $"failuresFired={_provisioningFailureFired.Count}"); // Self-termination: only auto-stop when all categories resolved with success (no failures). - // Uses RequestStop() which is safe to call from within the Changed handler (non-blocking). if (_provisioningCategoriesResolved.Count > 0 && _lastProvisioningJson.Count > 0 && _provisioningCategoriesResolved.Count >= _lastProvisioningJson.Count @@ -290,42 +362,26 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _provisioningWatcher?.RequestStop(); } - // Fire EspFailureDetected AFTER event emission - // (matches the pattern in ShellCoreTracking.cs — event in spool before agent reacts) + // Fire EspFailureDetected AFTER event emission (event in spool before agent reacts) if (failureDetected && failureType != null) { - try - { - EspFailureDetected?.Invoke(this, failureType); - } - catch (Exception ex) - { - _logger.Error($"EspFailureDetected handler failed for '{failureType}'", ex); - } + try { EspFailureDetected?.Invoke(this, failureType); } + catch (Exception ex) { _logger.Error($"EspFailureDetected handler failed for '{failureType}'", ex); } } - // Fire DeviceSetupProvisioningComplete when DeviceSetup category resolves with success. - // Used as completion signal for Self-Deploying mode where Shell-Core ESP exit - // and desktop arrival may never arrive. + // Fire DeviceSetupProvisioningComplete when DeviceSetup resolves with success. if (!_deviceSetupProvisioningCompleteFired && _lastCategorySucceeded.TryGetValue("DeviceSetupCategory.Status", out var dsSucceeded) && dsSucceeded == true) { _deviceSetupProvisioningCompleteFired = true; _logger.Info("Provisioning status: DeviceSetup succeeded — firing DeviceSetupProvisioningComplete"); - try - { - DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); - } - catch (Exception ex) - { - _logger.Error("DeviceSetupProvisioningComplete handler failed", ex); - } + try { DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); } + catch (Exception ex) { _logger.Error("DeviceSetupProvisioningComplete handler failed", ex); } } - // Fallback: All subcategories succeeded but categorySucceeded was never set by Windows. + // Fallback: all subcategories succeeded but categorySucceeded was never set by Windows. // Some Windows builds (e.g. 25H2/26200) don't set the boolean even after all subcategories succeed. - // Wait DeviceSetupFallbackDelaySeconds to give Windows time, then treat as success if still consistent. if (!_deviceSetupProvisioningCompleteFired && _deviceSetupFallbackTimer == null && _lastCategorySucceeded.TryGetValue("DeviceSetupCategory.Status", out var dsFallbackState) @@ -353,11 +409,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - /// - /// Fallback timer callback: fires after DeviceSetupFallbackDelaySeconds when all subcategories - /// succeeded but categorySucceeded was never set by Windows. Re-reads registry to confirm, - /// emits a visible WARNING event for the admin timeline, then fires DeviceSetupProvisioningComplete. - /// private void OnDeviceSetupFallbackTimerExpired(object state) { try @@ -370,7 +421,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return; } - // Re-read registry to confirm state is still consistent string registryJson = null; using (var key = Registry.LocalMachine.OpenSubKey(ProvisioningStatusRegistryPath, writable: false)) { @@ -383,7 +433,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return; } - // Parse and verify: categorySucceeded still null, all subcategories still succeeded bool? categorySucceeded = null; List subcategories = null; try @@ -400,16 +449,13 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return; } - // If categorySucceeded was set in the meantime, let the normal path handle it if (categorySucceeded.HasValue) { _logger.Info($"DeviceSetup fallback timer: categorySucceeded is now {categorySucceeded.Value} — normal path will handle this"); - // Trigger a re-check so the normal path picks up the change CheckProvisioningStatus(); return; } - // Verify all subcategories are still succeeded/notRequired if (subcategories == null || subcategories.Count == 0) { _logger.Warning("DeviceSetup fallback timer: no subcategories found — aborting fallback"); @@ -427,7 +473,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return; } - // All conditions confirmed after delay — dump raw JSON and emit visible WARNING event EmitRawRegistryDump("DeviceSetup", registryJson, "fallback_confirmed"); _logger.Warning($"DeviceSetup fallback: all {subcategories.Count} subcategories succeeded but " + @@ -466,14 +511,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors }); _deviceSetupProvisioningCompleteFired = true; - try - { - DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); - } - catch (Exception ex) - { - _logger.Error("DeviceSetupProvisioningComplete handler failed (fallback path)", ex); - } + try { DeviceSetupProvisioningComplete?.Invoke(this, EventArgs.Empty); } + catch (Exception ex) { _logger.Error("DeviceSetupProvisioningComplete handler failed (fallback path)", ex); } } } catch (Exception ex) @@ -486,7 +525,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors /// Processes a single category status JSON value. /// Emits events on first-seen, subcategory state transitions, and categorySucceeded resolution. /// - private ProvisioningResult ProcessCategoryStatus(string categoryName, string jsonValue) + internal ProvisioningResult ProcessCategoryStatus(string categoryName, string jsonValue) { var categoryLabel = categoryName.Replace("Category.Status", ""); @@ -496,14 +535,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors { var root = doc.RootElement; - // 1. Extract categorySucceeded — the authoritative outcome signal bool? categorySucceeded = SafeGetBool(root, "categorySucceeded"); string categoryStatusMessage = SafeGetString(root, "categoryStatusMessage"); - - // 2. Parse subcategories — handles both flat strings and nested objects var subcategories = ParseSubcategories(root); - // 3. Derive a meaningful status summary string statusText; if (categoryStatusMessage != null) statusText = categoryStatusMessage; @@ -514,7 +549,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors else statusText = BuildProgressSummary(subcategories); - // 4. Decide whether to emit an event bool isFirstSeen = !_provisioningCategorySeen.Contains(categoryName); bool categorySucceededChanged = HasCategorySucceededChanged(categoryName, categorySucceeded); @@ -542,8 +576,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } else { - // Emit on every JSON change — the registry dedup ensures we only reach here - // when actual progress happened (e.g. "Apps 1/5 → 2/5", subcategory completions). var transitions = DetectSubcategoryTransitions(categoryName, subcategories); StoreSubcategoryStates(categoryName, subcategories); @@ -566,24 +598,19 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } else { - // JSON changed but no state transitions — progress text changed (e.g. "Apps 1/5 → 2/5") _logger.Trace($"ProcessCategory: {categoryLabel} — EMITTING progress update (JSON changed, no state transitions)"); EmitProvisioningEvent(categoryLabel, categorySucceeded, statusText, subcategories, EventSeverity.Info); } } - // 5. Track resolved categories (both success and failure are final) if (categorySucceeded.HasValue) _provisioningCategoriesResolved.Add(categoryName); - // 6. Handle failure — either via categorySucceeded or subcategory state if (categorySucceeded == false) { return TryFireProvisioningFailure(categoryName, categoryLabel, subcategories); } - // 7. Check for subcategory-level failures even when categorySucceeded is still null - // (catches timeout scenarios where the category never formally fails) var failedSub = FindFailedSubcategory(subcategories); if (failedSub != null && categorySucceeded == null) { @@ -605,9 +632,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - /// - /// Attempts to fire EspFailureDetected for a provisioning failure. Uses fire-once guard. - /// private ProvisioningResult TryFireProvisioningFailure(string categoryName, string categoryLabel, List subcategories) { if (_provisioningFailureFired.Contains(categoryName)) @@ -625,22 +649,13 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return ProvisioningResult.Failure(failureTypeName); } - /// - /// Checks whether categorySucceeded has transitioned from null to true/false. - /// This ensures we only emit one event when the outcome is decided. - /// private bool HasCategorySucceededChanged(string categoryName, bool? newValue) { if (!_lastCategorySucceeded.TryGetValue(categoryName, out var oldValue)) - return false; // First-seen is handled separately - - // Transition from null (in-progress) to true/false (resolved) + return false; return oldValue != newValue; } - /// - /// Stores current subcategory states for later transition detection. - /// private void StoreSubcategoryStates(string categoryName, List subcategories) { var states = new Dictionary(StringComparer.OrdinalIgnoreCase); @@ -649,31 +664,25 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _lastSubcategoryStates[categoryName] = states; } - /// - /// Detects meaningful subcategory state transitions by comparing current states to last known states. - /// Meaningful transitions: any -> failed (Warning), in_progress -> succeeded (Info). - /// NOT meaningful: notStarted -> in_progress (expected progression, noise). - /// private List DetectSubcategoryTransitions(string categoryName, List subcategories) { var transitions = new List(); if (!_lastSubcategoryStates.TryGetValue(categoryName, out var lastStates)) - return transitions; // No previous states to compare + return transitions; foreach (var sub in subcategories) { if (!lastStates.TryGetValue(sub.Name, out var oldState)) - continue; // New subcategory — skip (first-seen already emitted the snapshot) + continue; if (string.Equals(oldState, sub.State, StringComparison.OrdinalIgnoreCase)) - continue; // No change + continue; bool isFailure = string.Equals(sub.State, "failed", StringComparison.OrdinalIgnoreCase); bool isCompletion = string.Equals(sub.State, "succeeded", StringComparison.OrdinalIgnoreCase) && !string.Equals(oldState, "succeeded", StringComparison.OrdinalIgnoreCase); - // Skip noise: notStarted -> in_progress is expected progression bool isNoise = string.Equals(oldState, "notStarted", StringComparison.OrdinalIgnoreCase) && string.Equals(sub.State, "in_progress", StringComparison.OrdinalIgnoreCase); @@ -683,7 +692,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } else if (!isNoise) { - // Other non-noise transitions (e.g., unknown -> failed) — include if meaningful if (isFailure) transitions.Add(new SubcategoryTransition(sub.Name, oldState, sub.State, true)); } @@ -748,11 +756,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _logger.Info($"Provisioning status event: {categoryLabel} — {statusText} (succeeded={succeeded?.ToString() ?? "in_progress"})"); } - /// - /// Emits the raw registry JSON as a Trace-level event for post-mortem format debugging. - /// Called at first-seen (initial snapshot) and at resolution (categorySucceeded change or fallback) - /// so we capture the registry format at the start and at the critical decision point. - /// private void EmitRawRegistryDump(string categoryLabel, string rawJson, string trigger) { _onEventCollected(new EnrollmentEvent @@ -774,20 +777,17 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors }); } - // ===== JSON Parsing Helpers ===== + // ===================================================================== + // JSON parsing helpers (static — exposed as internal for tests) + // ===================================================================== - /// - /// Parses subcategory entries from the JSON. Handles both formats: - /// Flat: "CertificatesSubcategory": "Certificates (1 of 1 applied)" - /// Nested: "CertificatesSubcategory": { "subcategoryState": "succeeded", "subcategoryStatusText": "..." } - /// - private static List ParseSubcategories(JsonElement root) + internal static List ParseSubcategories(JsonElement root) { var result = new List(); foreach (var prop in root.EnumerateObject()) { - if (!prop.Name.Contains("Subcategory", StringComparison.OrdinalIgnoreCase)) + if (prop.Name.IndexOf("Subcategory", StringComparison.OrdinalIgnoreCase) < 0) continue; var name = CleanSubcategoryName(prop.Name); @@ -795,7 +795,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors switch (prop.Value.ValueKind) { case JsonValueKind.String: - // Flat format: value is the status text, derive state from text content var text = prop.Value.GetString() ?? ""; result.Add(new SubcategoryInfo { @@ -806,7 +805,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors break; case JsonValueKind.Object: - // Nested format: { "subcategoryState": "...", "subcategoryStatusText": "..." } result.Add(new SubcategoryInfo { Name = name, @@ -816,7 +814,6 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors break; default: - // Unknown format — include with raw value for debugging result.Add(new SubcategoryInfo { Name = name, @@ -835,16 +832,14 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors /// "AccountSetup.CertificatesSubcategory" -> "Certificates" /// "SecurityPoliciesSubcategory" -> "SecurityPolicies" /// - private static string CleanSubcategoryName(string rawName) + internal static string CleanSubcategoryName(string rawName) { var name = rawName; - // Remove "Subcategory" suffix var idx = name.IndexOf("Subcategory", StringComparison.OrdinalIgnoreCase); if (idx >= 0) name = name.Substring(0, idx); - // Remove category prefix (e.g. "AccountSetup.", "DeviceSetup.", "DevicePreparation.") var dotIdx = name.LastIndexOf('.'); if (dotIdx >= 0 && dotIdx < name.Length - 1) name = name.Substring(dotIdx + 1); @@ -852,28 +847,24 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return string.IsNullOrEmpty(name) ? rawName : name; } - /// - /// Infers a state string from flat-format subcategory text. - /// Used when the JSON doesn't have explicit subcategoryState. - /// - private static string InferStateFromText(string text) + internal static string InferStateFromText(string text) { if (string.IsNullOrEmpty(text)) return "unknown"; - if (text.Contains("Complete", StringComparison.OrdinalIgnoreCase) - || text.Contains("applied", StringComparison.OrdinalIgnoreCase) - || text.Contains("installed", StringComparison.OrdinalIgnoreCase) - || text.Contains("added", StringComparison.OrdinalIgnoreCase) - || text.Contains("No setup needed", StringComparison.OrdinalIgnoreCase) - || text.Contains("Identified", StringComparison.OrdinalIgnoreCase)) + if (text.IndexOf("Complete", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("applied", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("installed", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("added", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("No setup needed", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("Identified", StringComparison.OrdinalIgnoreCase) >= 0) { return "succeeded"; } - if (text.Contains("Error", StringComparison.OrdinalIgnoreCase) - || text.Contains("Failed", StringComparison.OrdinalIgnoreCase) - || text.Contains("Failure", StringComparison.OrdinalIgnoreCase)) + if (text.IndexOf("Error", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("Failed", StringComparison.OrdinalIgnoreCase) >= 0 + || text.IndexOf("Failure", StringComparison.OrdinalIgnoreCase) >= 0) { return "failed"; } @@ -881,26 +872,17 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return "in_progress"; } - /// - /// Finds the first subcategory that is in a failed state. - /// Returns the clean name, or null if none are failed. - /// - private static string FindFailedSubcategory(List subcategories) + internal static string FindFailedSubcategory(List subcategories) { foreach (var sub in subcategories) { if (string.Equals(sub.State, "failed", StringComparison.OrdinalIgnoreCase)) return sub.Name; } - return null; } - /// - /// Builds a human-readable progress summary from subcategory states. - /// E.g. "3 of 5 subcategories completed" - /// - private static string BuildProgressSummary(List subcategories) + internal static string BuildProgressSummary(List subcategories) { if (subcategories.Count == 0) return "In progress"; @@ -918,11 +900,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return $"{succeeded} of {subcategories.Count} subcategories completed"; } - /// - /// Safely extracts a boolean from a JSON property. Handles True, False, and string "true"/"false". - /// Returns null if the property doesn't exist or has an unexpected type. - /// - private static bool? SafeGetBool(JsonElement element, string propertyName) + internal static bool? SafeGetBool(JsonElement element, string propertyName) { if (!element.TryGetProperty(propertyName, out var prop)) return null; @@ -937,10 +915,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - /// - /// Safely extracts a string from a JSON property. Returns null if missing or not a string. - /// - private static string SafeGetString(JsonElement element, string propertyName) + internal static string SafeGetString(JsonElement element, string propertyName) { if (!element.TryGetProperty(propertyName, out var prop)) return null; @@ -948,16 +923,18 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors return prop.ValueKind == JsonValueKind.String ? prop.GetString() : null; } - // ===== Internal Types ===== + // ===================================================================== + // Internal types + // ===================================================================== - private class SubcategoryInfo + internal class SubcategoryInfo { public string Name { get; set; } public string State { get; set; } // "succeeded", "failed", "in_progress", "unknown", "notRequired" - public string StatusText { get; set; } // Human-readable text + public string StatusText { get; set; } } - private readonly struct SubcategoryTransition + internal readonly struct SubcategoryTransition { public readonly string SubcategoryName; public readonly string OldState; @@ -973,7 +950,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } - private readonly struct ProvisioningResult + internal readonly struct ProvisioningResult { public readonly bool IsFailed; public readonly string FailureType; @@ -988,53 +965,35 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors public static ProvisioningResult Failure(string failureType) => new ProvisioningResult(true, failureType); } - // ===== Public Snapshot API ===== + // ===================================================================== + // Test seams + // ===================================================================== - /// - /// Returns a thread-safe snapshot of the current ESP provisioning category status. - /// All data is deep-copied under _stateLock so the caller can use it freely. - /// Returns null if no provisioning data has been observed yet. - /// - public EspProvisioningSnapshot GetProvisioningSnapshot() + /// Test-only: drive ProcessCategoryStatus without registry access. + internal ProvisioningResult ProcessCategoryStatusForTest(string categoryName, string jsonValue) { lock (_stateLock) { - if (_provisioningCategorySeen == null || _provisioningCategorySeen.Count == 0) - return null; - - var outcomes = new Dictionary(StringComparer.OrdinalIgnoreCase); - foreach (var cat in _provisioningCategorySeen) - { - var label = cat.Replace("Category.Status", ""); - if (_lastCategorySucceeded.TryGetValue(cat, out var succeeded)) - { - outcomes[label] = succeeded == true ? "success" - : succeeded == false ? "failed" - : "in_progress"; - } - else - { - outcomes[label] = "in_progress"; - } - } - - var subcats = new Dictionary>(StringComparer.OrdinalIgnoreCase); - foreach (var kvp in _lastSubcategoryStates) - { - var label = kvp.Key.Replace("Category.Status", ""); - subcats[label] = new Dictionary(kvp.Value, StringComparer.OrdinalIgnoreCase); - } - - return new EspProvisioningSnapshot - { - CategoryOutcomes = outcomes, - SubcategoryStates = subcats, - CategoriesSeen = _provisioningCategorySeen.Count, - CategoriesResolved = _provisioningCategoriesResolved.Count, - AllResolved = _provisioningCategoriesResolved.Count >= _provisioningCategorySeen.Count - }; + EnsureStateDictionariesInitialized(); + return ProcessCategoryStatus(categoryName, jsonValue); } } + + private void EnsureStateDictionariesInitialized() + { + if (_lastProvisioningJson == null) + _lastProvisioningJson = new Dictionary(StringComparer.OrdinalIgnoreCase); + if (_provisioningCategorySeen == null) + _provisioningCategorySeen = new HashSet(StringComparer.OrdinalIgnoreCase); + if (_lastCategorySucceeded == null) + _lastCategorySucceeded = new Dictionary(StringComparer.OrdinalIgnoreCase); + if (_provisioningFailureFired == null) + _provisioningFailureFired = new HashSet(StringComparer.OrdinalIgnoreCase); + if (_provisioningCategoriesResolved == null) + _provisioningCategoriesResolved = new HashSet(StringComparer.OrdinalIgnoreCase); + if (_lastSubcategoryStates == null) + _lastSubcategoryStates = new Dictionary>(StringComparer.OrdinalIgnoreCase); + } } /// diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ShellCoreTracker.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ShellCoreTracker.cs new file mode 100644 index 00000000..b4c4427a --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/ShellCoreTracker.cs @@ -0,0 +1,382 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics.Eventing.Reader; +using System.Text.RegularExpressions; +using AutopilotMonitor.Agent.Core.Logging; +using AutopilotMonitor.Shared.Models; + +namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors +{ + /// + /// Watches Microsoft-Windows-Shell-Core/Operational for ESP-related events: + /// 62404 — CloudExperienceHost Web App Activity Started (CXID: 'AADHello' / 'NGC' = Hello wizard) + /// 62407 — CloudExperienceHost Web App Event 2: + /// CommercialOOBE_ESPProgress_Page_Exiting — normal ESP exit + /// CommercialOOBE_ESPProgress_WhiteGlove_Success — WhiteGlove complete + /// CommercialOOBE_ESPProgress_Failure/_Timeout/_Abort/WhiteGlove_Failed — ESP failure + /// + /// Raises , , + /// and . Cross-notifies the + /// on Hello wizard start and ESP exit so Hello timers can react. + /// + internal sealed class ShellCoreTracker : IDisposable + { + internal const string ShellCoreEventLogChannel = "Microsoft-Windows-Shell-Core/Operational"; + internal const int EventId_ShellCore_WebAppStarted = 62404; + internal const int EventId_ShellCore_WebAppEvent = 62407; + internal const int BackfillLookbackMinutes = 5; + + private static readonly HashSet TrackedShellCoreEventIds = new HashSet + { + EventId_ShellCore_WebAppStarted, + EventId_ShellCore_WebAppEvent + }; + + private static readonly Regex EspExitingPattern = new Regex( + @"OOBE_ESP.*Exiting", RegexOptions.IgnoreCase | RegexOptions.Compiled); + + private readonly AgentLogger _logger; + private readonly string _sessionId; + private readonly string _tenantId; + private readonly Action _onEventCollected; + private readonly HelloTracker _helloTracker; + + private EventLogWatcher _watcher; + private bool _espExitDetected; + private bool _whiteGloveDetected; + private readonly object _stateLock = new object(); + + public event EventHandler FinalizingSetupPhaseTriggered; + public event EventHandler WhiteGloveCompleted; + public event EventHandler EspFailureDetected; + + public ShellCoreTracker( + string sessionId, + string tenantId, + Action onEventCollected, + AgentLogger logger, + HelloTracker helloTracker) + { + _sessionId = sessionId ?? throw new ArgumentNullException(nameof(sessionId)); + _tenantId = tenantId ?? throw new ArgumentNullException(nameof(tenantId)); + _onEventCollected = onEventCollected ?? throw new ArgumentNullException(nameof(onEventCollected)); + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + _helloTracker = helloTracker; // nullable — HelloTracker may be unavailable in some test setups + } + + internal bool IsEspExitedForTest { get { lock (_stateLock) { return _espExitDetected; } } } + internal bool IsWhiteGloveDetectedForTest { get { lock (_stateLock) { return _whiteGloveDetected; } } } + + public void Start() + { + try + { + var query = new EventLogQuery( + ShellCoreEventLogChannel, + PathType.LogName, + "*[System[(EventID=62404 or EventID=62407)]]"); + + _watcher = new EventLogWatcher(query); + _watcher.EventRecordWritten += OnEventRecordWritten; + _watcher.Enabled = true; + + _logger.Info($"Started watching: {ShellCoreEventLogChannel}"); + } + catch (EventLogNotFoundException) + { + _logger.Warning($"Event log not found: {ShellCoreEventLogChannel} (normal if not on a real device)"); + } + catch (Exception ex) + { + _logger.Error("Failed to start Shell-Core event log watcher", ex); + } + } + + public void Stop() + { + if (_watcher == null) return; + try + { + _watcher.Enabled = false; + _watcher.EventRecordWritten -= OnEventRecordWritten; + _watcher.Dispose(); + } + catch (Exception ex) { _logger.Error("Error stopping Shell-Core event watcher", ex); } + finally { _watcher = null; } + } + + public void Dispose() => Stop(); + + // ===================================================================== + // Live event handler + // ===================================================================== + + private void OnEventRecordWritten(object sender, EventRecordWrittenEventArgs e) + { + if (e.EventRecord == null) return; + + try + { + var record = e.EventRecord; + if (!TrackedShellCoreEventIds.Contains(record.Id)) return; + + var description = record.FormatDescription() ?? $"Event ID {record.Id}"; + var timestamp = (record.TimeCreated ?? DateTime.UtcNow).ToUniversalTime(); + + ProcessEvent(record.Id, description, timestamp, record.ProviderName ?? "", isBackfill: false); + } + catch (Exception ex) + { + _logger.Error("Error processing Shell-Core event record", ex); + } + } + + /// + /// Core event-processing logic. Exposed as internal so tests can drive it without + /// needing to synthesize an (abstract + Windows-only). + /// + internal void ProcessEvent(int eventId, string description, DateTime timestamp, string providerName, bool isBackfill) + { + string eventType; + EventSeverity severity = EventSeverity.Info; + string message; + bool triggerFinalizingSetup = false; + string finalizingSetupReason = null; + string detectedFailureType = null; + + switch (eventId) + { + case EventId_ShellCore_WebAppStarted: // 62404 + if (description.Contains("AADHello") || description.Contains("'NGC'")) + { + eventType = "hello_wizard_started"; + message = "Windows Hello wizard started (CloudExperienceHost)"; + triggerFinalizingSetup = true; + finalizingSetupReason = "hello_wizard_started"; + + _helloTracker?.NotifyHelloWizardStarted(); + + _logger.Info("Windows Hello wizard started - detected via Shell-Core event 62404"); + } + else + { + return; + } + break; + + case EventId_ShellCore_WebAppEvent: // 62407 + if (description.IndexOf("WhiteGlove_Success", StringComparison.OrdinalIgnoreCase) >= 0) + { + // Fire-once guard + lock (_stateLock) + { + if (_whiteGloveDetected) return; + _whiteGloveDetected = true; + } + + eventType = "whiteglove_complete"; + message = "WhiteGlove (Pre-Provisioning) completed successfully"; + // No FinalizingSetup transition — WhiteGlove terminates pre-provisioning entirely + + _logger.Info("WhiteGlove (Pre-Provisioning) success detected via Shell-Core event 62407"); + } + else if (HasEspFailurePattern(description)) + { + detectedFailureType = ExtractEspFailureType(description); + eventType = "esp_failure"; + severity = EventSeverity.Error; + message = $"ESP (Enrollment Status Page) reported a failure: {detectedFailureType}"; + _logger.Warning($"ESP failure detected via Shell-Core event 62407: {detectedFailureType}"); + } + else if (EspExitingPattern.IsMatch(description)) + { + eventType = "esp_exiting"; + message = "ESP (Enrollment Status Page) phase exiting"; + triggerFinalizingSetup = true; + finalizingSetupReason = "esp_exiting"; + + lock (_stateLock) + { + _espExitDetected = true; + // Note: We do NOT start the Hello wait timer here! + // Event 62407 occurs at every ESP phase transition (Device->Account, Account->End) + // EnrollmentTracker will decide based on lastEspPhase whether to start the timer + } + _helloTracker?.NotifyEspExited(); + + _logger.Info("ESP phase exit detected - detected via Shell-Core event 62407"); + } + else + { + return; + } + break; + + default: + return; + } + + var eventData = new Dictionary + { + { "windowsEventId", eventId }, + { "providerName", providerName ?? "" }, + { "description", description }, + { "eventLogChannel", ShellCoreEventLogChannel }, + { "eventTime", timestamp.ToString("o") } + }; + + if (eventType == "esp_failure" && detectedFailureType != null) + { + eventData["failureType"] = detectedFailureType; + } + + _onEventCollected(new EnrollmentEvent + { + SessionId = _sessionId, + TenantId = _tenantId, + Timestamp = timestamp, + EventType = eventType, + Severity = severity, + Source = "EspAndHelloTracker", + Phase = EnrollmentPhase.Unknown, + Message = message, + Data = eventData, + ImmediateUpload = true + }); + + _logger.Info($"Shell-Core event detected: {eventType} (EventID {eventId})"); + + if (triggerFinalizingSetup) + { + try { FinalizingSetupPhaseTriggered?.Invoke(this, finalizingSetupReason); } + catch (Exception ex) { _logger.Error("FinalizingSetupPhaseTriggered handler failed", ex); } + } + + // Fire WhiteGloveCompleted AFTER event emission so the whiteglove_complete event + // is in the spool before the agent exits. + if (eventType == "whiteglove_complete") + { + try { WhiteGloveCompleted?.Invoke(this, EventArgs.Empty); } + catch (Exception ex) { _logger.Error("WhiteGloveCompleted handler failed", ex); } + } + + // Fire EspFailureDetected AFTER event emission so the esp_failure event is in the + // spool before the agent potentially shuts down. + if (eventType == "esp_failure" && detectedFailureType != null) + { + try { EspFailureDetected?.Invoke(this, detectedFailureType); } + catch (Exception ex) { _logger.Error($"EspFailureDetected handler failed for '{detectedFailureType}'", ex); } + } + } + + // ===================================================================== + // Backfill (public — called by coordinator) + // ===================================================================== + + /// + /// Backfills recent ESP exit and failure events from Shell-Core log on startup. + /// Secondary recovery mechanism when state persistence is unavailable. + /// + public void BackfillRecentEspExitEvents() + { + try + { + var lookbackMs = BackfillLookbackMinutes * 60 * 1000; + var query = new EventLogQuery( + ShellCoreEventLogChannel, + PathType.LogName, + $"*[System[(EventID=62407) and TimeCreated[timediff(@SystemTime) <= {lookbackMs}]]]"); + + using (var reader = new EventLogReader(query)) + { + for (EventRecord record = reader.ReadEvent(); record != null; record = reader.ReadEvent()) + { + using (record) + { + var description = record.FormatDescription() ?? ""; + HandleBackfillRecord(description); + } + } + } + } + catch (Exception ex) + { + _logger.Warning($"ESP exit/failure event backfill failed: {ex.Message}"); + } + } + + /// + /// Internal backfill record handler — extracted for testability and to keep the + /// backfill loop free of direct event-processing logic. + /// + internal void HandleBackfillRecord(string description) + { + if (EspExitingPattern.IsMatch(description)) + { + bool shouldNotify = false; + lock (_stateLock) + { + if (!_espExitDetected) + { + _espExitDetected = true; + shouldNotify = true; + } + } + if (shouldNotify) + { + _helloTracker?.NotifyEspExited(); + _logger.Info("Backfill: ESP exit event found in recent Shell-Core logs"); + try { FinalizingSetupPhaseTriggered?.Invoke(this, "esp_exiting"); } + catch (Exception ex) { _logger.Error("Backfill: FinalizingSetupPhaseTriggered handler failed", ex); } + } + } + + if (HasEspFailurePattern(description)) + { + var failureType = ExtractEspFailureType(description); + _logger.Info($"Backfill: ESP failure event found in recent Shell-Core logs: {failureType}"); + try { EspFailureDetected?.Invoke(this, failureType); } + catch (Exception ex) { _logger.Error($"Backfill: EspFailureDetected handler failed for '{failureType}'", ex); } + } + } + + // ===================================================================== + // Pattern helpers + // ===================================================================== + + internal static bool HasEspFailurePattern(string description) + { + return description.IndexOf("ESPProgress_Failure", StringComparison.OrdinalIgnoreCase) >= 0 + || description.IndexOf("ESPProgress_Failed", StringComparison.OrdinalIgnoreCase) >= 0 + || description.IndexOf("ESPProgress_Timeout", StringComparison.OrdinalIgnoreCase) >= 0 + || description.IndexOf("ESPProgress_Abort", StringComparison.OrdinalIgnoreCase) >= 0 + || description.IndexOf("WhiteGlove_Failed", StringComparison.OrdinalIgnoreCase) >= 0 + || description.IndexOf("WhiteGlove_Failure", StringComparison.OrdinalIgnoreCase) >= 0; + } + + /// + /// Extracts a structured failure type from the Shell-Core event description. + /// Returns e.g. "ESPProgress_Failure", "ESPProgress_Timeout", "WhiteGlove_Failed", + /// or "Unknown_ESP_Failure" as a fallback. + /// + internal static string ExtractEspFailureType(string description) + { + string[] knownTypes = { + "ESPProgress_Failure", + "ESPProgress_Failed", + "ESPProgress_Timeout", + "ESPProgress_Abort", + "WhiteGlove_Failed", + "WhiteGlove_Failure" + }; + + foreach (var type in knownTypes) + { + if (description.IndexOf(type, StringComparison.OrdinalIgnoreCase) >= 0) + return type; + } + + return "Unknown_ESP_Failure"; + } + } +}