diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Configuration/AgentConfiguration.cs b/src/Agent/AutopilotMonitor.Agent.Core/Configuration/AgentConfiguration.cs index f55793f1..9e452a2b 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Configuration/AgentConfiguration.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Configuration/AgentConfiguration.cs @@ -145,6 +145,13 @@ namespace AutopilotMonitor.Agent.Core.Configuration /// public int AuthFailureTimeoutMinutes { get; set; } = 0; + /// + /// Maximum agent lifetime in minutes. Safety net to prevent zombie agents. + /// The agent emits enrollment_failed with failureType "agent_timeout" when this expires. + /// 0 = disabled (no lifetime limit). Default: 360 (6 hours). + /// + public int AgentMaxLifetimeMinutes { get; set; } = 360; + /// /// Whether diagnostics upload is configured for this tenant. /// When true, the agent requests a short-lived upload URL from the backend just before uploading. diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/DesktopArrivalDetector.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/DesktopArrivalDetector.cs new file mode 100644 index 00000000..c8152a3a --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/DesktopArrivalDetector.cs @@ -0,0 +1,183 @@ +using System; +using System.Diagnostics; +using System.Management; +using System.Threading; +using AutopilotMonitor.Agent.Core.Logging; + +namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors +{ + /// + /// Detects when a real user desktop becomes available (explorer.exe under a non-system user). + /// Fires DesktopArrived event exactly once per agent lifetime. + /// Used for enrollment completion in no-ESP scenarios (WDP v2, ESP disabled) and + /// as a backup signal for AccountSetup phase correction. + /// + public class DesktopArrivalDetector : IDisposable + { + private readonly AgentLogger _logger; + private Timer _pollingTimer; + private bool _desktopArrived; + private const int PollingIntervalSeconds = 30; + + /// + /// System/service account names that should NOT be considered real users. + /// + private static readonly string[] ExcludedUserNames = + { + "SYSTEM", + "LOCAL SERVICE", + "NETWORK SERVICE", + "DefaultUser0", + "DefaultUser1", + "defaultuser0", + "defaultuser1" + }; + + /// + /// Fired exactly once when a real user desktop is detected (explorer.exe under a real user). + /// + public event EventHandler DesktopArrived; + + public DesktopArrivalDetector(AgentLogger logger) + { + _logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } + + public void Start() + { + _logger.Info("DesktopArrivalDetector: starting (polling every 30s)"); + _pollingTimer = new Timer( + PollForDesktop, + null, + TimeSpan.FromSeconds(5), // Initial check after 5s + TimeSpan.FromSeconds(PollingIntervalSeconds)); + } + + public void Stop() + { + _pollingTimer?.Dispose(); + _pollingTimer = null; + } + + private void PollForDesktop(object state) + { + if (_desktopArrived) + return; + + try + { + var explorerProcesses = Process.GetProcessesByName("explorer"); + foreach (var proc in explorerProcesses) + { + try + { + // Session 0 = SYSTEM session, skip + if (proc.SessionId == 0) + continue; + + var owner = GetProcessOwner(proc.Id); + if (owner == null) + continue; + + // Check against exclusion list + if (IsExcludedUser(owner)) + { + _logger.Debug($"DesktopArrivalDetector: explorer.exe PID {proc.Id} owned by excluded user '{owner}' — skipping"); + continue; + } + + // Real user desktop detected + _desktopArrived = true; + _logger.Info($"DesktopArrivalDetector: real user desktop detected (explorer.exe PID {proc.Id}, session {proc.SessionId}, user '{owner}')"); + + // Stop polling + _pollingTimer?.Dispose(); + _pollingTimer = null; + + try { DesktopArrived?.Invoke(this, EventArgs.Empty); } catch { } + return; + } + catch (Exception ex) + { + _logger.Debug($"DesktopArrivalDetector: error checking explorer.exe PID {proc.Id}: {ex.Message}"); + } + finally + { + proc.Dispose(); + } + } + } + catch (Exception ex) + { + _logger.Debug($"DesktopArrivalDetector: polling error: {ex.Message}"); + } + } + + /// + /// Gets the owner of a process using WMI (Win32_Process.GetOwner). + /// Returns "DOMAIN\User" or "User" string, or null on failure. + /// + private string GetProcessOwner(int processId) + { + try + { + using (var searcher = new ManagementObjectSearcher( + $"SELECT * FROM Win32_Process WHERE ProcessId = {processId}")) + { + foreach (ManagementObject obj in searcher.Get()) + { + var outParams = new object[2]; + var result = (uint)obj.InvokeMethod("GetOwner", outParams); + if (result == 0) + { + var user = outParams[0]?.ToString(); + var domain = outParams[1]?.ToString(); + return string.IsNullOrEmpty(domain) ? user : $"{domain}\\{user}"; + } + } + } + } + catch (Exception ex) + { + _logger.Debug($"DesktopArrivalDetector: WMI GetOwner failed for PID {processId}: {ex.Message}"); + } + + return null; + } + + /// + /// Returns true if the user name matches any excluded system/service account. + /// Handles both "User" and "DOMAIN\User" formats. + /// Also matches the pattern DefaultUser* (case-insensitive). + /// + private static bool IsExcludedUser(string fullUserName) + { + if (string.IsNullOrEmpty(fullUserName)) + return true; + + // Extract just the username part (after backslash if present) + var userName = fullUserName; + var backslashIndex = fullUserName.LastIndexOf('\\'); + if (backslashIndex >= 0 && backslashIndex < fullUserName.Length - 1) + userName = fullUserName.Substring(backslashIndex + 1); + + // Check exact matches + foreach (var excluded in ExcludedUserNames) + { + if (string.Equals(userName, excluded, StringComparison.OrdinalIgnoreCase)) + return true; + } + + // Check DefaultUser* pattern + if (userName.StartsWith("DefaultUser", StringComparison.OrdinalIgnoreCase)) + return true; + + return false; + } + + public void Dispose() + { + Stop(); + } + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs index a1f6d0f5..d0929540 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Collectors/EspAndHelloTracker.cs @@ -42,10 +42,11 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors private bool _espExitDetected = false; private bool _helloWizardStarted = 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 const int HelloCompletionTimeoutSeconds = 1500; + private const int HelloCompletionTimeoutSeconds = 300; private const int BackfillLookbackMinutes = 5; /// @@ -66,6 +67,18 @@ 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"). + /// + public event EventHandler EspFailureDetected; + + /// + /// Outcome of Hello provisioning. Set when Hello resolves (via events, timeout, or not configured). + /// Values: "completed", "timeout", "not_configured", "wizard_not_started", null (not yet resolved). + /// + public string HelloOutcome { get; private set; } + private const string EventLogChannel = "Microsoft-Windows-User Device Registration/Admin"; private const string ShellCoreEventLogChannel = "Microsoft-Windows-Shell-Core/Operational"; @@ -503,6 +516,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } _isHelloCompleted = true; + HelloOutcome = "completed"; StopHelloCompletionTimerLocked(); return true; } @@ -649,10 +663,12 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors || 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"; - _logger.Warning("ESP failure detected via Shell-Core event 62407"); + 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)) { @@ -728,6 +744,20 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } catch { } } + + // 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 { } + } } catch (Exception ex) { @@ -797,6 +827,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _logger.Info("Hello policy not detected as enabled — assuming Hello is not configured or was skipped"); _isHelloCompleted = true; + HelloOutcome = "not_configured"; StopHelloCompletionTimerLocked(); // Emit event for tracking @@ -913,6 +944,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors _logger.Warning($"Hello completion timeout ({HelloCompletionTimeoutSeconds}s) expired after wizard start without terminal event"); _isHelloCompleted = true; + HelloOutcome = _helloWizardStarted ? "timeout" : "wizard_not_started"; StopHelloCompletionTimerLocked(); _onEventCollected(new EnrollmentEvent @@ -942,6 +974,89 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors } } + /// + /// 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)) + { + lock (_stateLock) + { + if (!_espExitDetected) + { + _espExitDetected = true; + _logger.Info("Backfill: ESP exit event found in recent Shell-Core logs"); + try { FinalizingSetupPhaseTriggered?.Invoke(this, "esp_exiting"); } catch { } + } + } + } + + // 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 { } + } + } + } + } + } + catch (Exception ex) + { + _logger.Warning($"ESP exit/failure event backfill failed: {ex.Message}"); + } + } + private void BackfillRecentTerminalHelloEvents() { try diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Core/MonitoringService.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Core/MonitoringService.cs index a0fe3522..1d8ebefb 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Core/MonitoringService.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Core/MonitoringService.cs @@ -65,6 +65,14 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core private int _collectorIdleTimeoutMinutes = 15; private Timer _idleCheckTimer; + // Desktop arrival detection (no-ESP scenarios) + private DesktopArrivalDetector _desktopArrivalDetector; + + // Agent max lifetime safety net + private Timer _maxLifetimeTimer; + private readonly DateTime _agentStartTimeUtc = DateTime.UtcNow; + private bool _enrollmentTerminalEventSeen; + // Auth failure circuit breaker private int _consecutiveAuthFailures = 0; private DateTime? _firstAuthFailureTime = null; @@ -407,6 +415,27 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core ); _enrollmentTracker.Start(); } + + // Desktop arrival detector — detects real user desktop for no-ESP completion + _desktopArrivalDetector = new DesktopArrivalDetector(_logger); + _desktopArrivalDetector.DesktopArrived += OnDesktopArrived; + _desktopArrivalDetector.Start(); + + // Agent max lifetime safety net — prevents zombie agents + var maxLifetimeMinutes = collectors?.AgentMaxLifetimeMinutes ?? _configuration.AgentMaxLifetimeMinutes; + if (maxLifetimeMinutes > 0) + { + _maxLifetimeTimer = new Timer( + MaxLifetimeTimerCallback, + null, + TimeSpan.FromMinutes(maxLifetimeMinutes), + Timeout.InfiniteTimeSpan); + _logger.Info($"Agent max lifetime timer armed: {maxLifetimeMinutes} min"); + } + else + { + _logger.Info("Agent max lifetime timer disabled (0)"); + } } catch (Exception ex) { @@ -422,6 +451,16 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core _idleCheckTimer?.Dispose(); _idleCheckTimer = null; + _maxLifetimeTimer?.Dispose(); + _maxLifetimeTimer = null; + + if (_desktopArrivalDetector != null) + { + _desktopArrivalDetector.DesktopArrived -= OnDesktopArrived; + _desktopArrivalDetector.Dispose(); + _desktopArrivalDetector = null; + } + _performanceCollector?.Stop(); _performanceCollector?.Dispose(); _performanceCollector = null; @@ -435,6 +474,67 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core _enrollmentTracker = null; } + /// + /// Fires when the agent max lifetime expires. Emits enrollment_failed with failureType "agent_timeout". + /// The normal shutdown path (EmitEvent → enrollment_failed) handles everything from here. + /// + private void MaxLifetimeTimerCallback(object state) + { + if (_enrollmentTerminalEventSeen) + { + _logger.Debug("Max lifetime timer fired but terminal event already seen — ignoring"); + return; + } + + var uptimeMinutes = (DateTime.UtcNow - _agentStartTimeUtc).TotalMinutes; + _logger.Warning($"Agent max lifetime expired after {uptimeMinutes:F0} minutes — emitting enrollment_failed"); + + EmitEvent(new EnrollmentEvent + { + SessionId = _configuration.SessionId, + TenantId = _configuration.TenantId, + EventType = "enrollment_failed", + Severity = EventSeverity.Error, + Source = "MonitoringService", + Phase = EnrollmentPhase.Complete, + Message = $"Agent max lifetime expired ({uptimeMinutes:F0} min) — enrollment did not complete in time", + Data = new Dictionary + { + { "failureType", "agent_timeout" }, + { "failureSource", "max_lifetime_timer" }, + { "agentUptimeMinutes", Math.Round(uptimeMinutes, 1) } + } + }); + } + + /// + /// Fires when DesktopArrivalDetector detects explorer.exe under a real user. + /// Emits desktop_arrived event for the timeline and notifies EnrollmentTracker. + /// + private void OnDesktopArrived(object sender, EventArgs e) + { + if (_enrollmentTerminalEventSeen) + { + _logger.Debug("Desktop arrived but terminal event already seen — ignoring"); + return; + } + + // Emit informational event for the timeline (shows when user desktop appeared) + EmitEvent(new EnrollmentEvent + { + SessionId = _configuration.SessionId, + TenantId = _configuration.TenantId, + EventType = "desktop_arrived", + Severity = EventSeverity.Info, + Source = "DesktopArrivalDetector", + Phase = EnrollmentPhase.Unknown, + Message = "User desktop detected (explorer.exe under real user)" + }); + + // Notify EnrollmentTracker — it decides whether this triggers completion + _enrollmentTracker?.NotifyDesktopArrived(); + } + /// /// Returns true for events generated by periodic timers (not real enrollment activity) /// @@ -878,6 +978,15 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core _sessionPersistence.SaveSequence(evt.Sequence); } + // Cancel max lifetime timer on terminal events + if (evt.EventType == "whiteglove_complete" || + evt.EventType == "enrollment_complete" || + evt.EventType == "enrollment_failed") + { + _enrollmentTerminalEventSeen = true; + _maxLifetimeTimer?.Change(Timeout.Infinite, Timeout.Infinite); + } + // Check if this is a phase transition bool isPhaseTransition = false; if (evt.Phase != _lastPhase) diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentStatePersistence.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentStatePersistence.cs new file mode 100644 index 00000000..f7891e4c --- /dev/null +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentStatePersistence.cs @@ -0,0 +1,118 @@ +using System; +using System.Collections.Generic; +using System.IO; +using AutopilotMonitor.Agent.Core.Logging; +using Newtonsoft.Json; + +namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking +{ + /// + /// Handles persistence of EnrollmentTracker state to disk (JSON serialization). + /// Enables crash-recovery: after agent restart, completion signals already seen + /// (ESP exit, desktop arrival, etc.) are restored so the enrollment can complete. + /// Pattern follows ImeTrackerStatePersistence. + /// + public class EnrollmentStatePersistence + { + private readonly string _stateDirectory; + private readonly string _stateFilePath; + private readonly AgentLogger _logger; + + public EnrollmentStatePersistence(string stateDirectory, AgentLogger logger) + { + _stateDirectory = Environment.ExpandEnvironmentVariables(stateDirectory); + _stateFilePath = Path.Combine(_stateDirectory, "enrollment-state.json"); + _logger = logger; + } + + public string StateFilePath => _stateFilePath; + + /// + /// Loads persisted state from disk. Returns null if no state file exists or on error. + /// + public EnrollmentStateData Load() + { + if (!File.Exists(_stateFilePath)) + { + _logger.Info("EnrollmentStatePersistence: no persisted state found (fresh enrollment)"); + return null; + } + + try + { + var json = File.ReadAllText(_stateFilePath); + var state = JsonConvert.DeserializeObject(json); + if (state == null) + { + _logger.Warning("EnrollmentStatePersistence: persisted state file was empty or invalid"); + return null; + } + return state; + } + catch (Exception ex) + { + _logger.Warning($"EnrollmentStatePersistence: failed to load persisted state, starting fresh: {ex.Message}"); + return null; + } + } + + /// + /// Persists tracker state to disk as JSON (atomic write via temp file). + /// + public void Save(EnrollmentStateData state) + { + try + { + Directory.CreateDirectory(_stateDirectory); + var tempPath = _stateFilePath + ".tmp"; + File.WriteAllText(tempPath, JsonConvert.SerializeObject(state, Formatting.Indented)); + File.Copy(tempPath, _stateFilePath, overwrite: true); + try { File.Delete(tempPath); } catch { } + } + catch (Exception ex) + { + _logger.Debug($"EnrollmentStatePersistence: failed to save state: {ex.Message}"); + } + } + + /// + /// Deletes persisted state file. + /// + public void Delete() + { + try + { + if (File.Exists(_stateFilePath)) + { + File.Delete(_stateFilePath); + _logger.Info("EnrollmentStatePersistence: persisted state deleted"); + } + } + catch (Exception ex) + { + _logger.Debug($"EnrollmentStatePersistence: failed to delete state file: {ex.Message}"); + } + } + } + + // ---- DTO for state serialization ---- + + public class EnrollmentStateData + { + public bool EspEverSeen { get; set; } + public bool EspFinalExitSeen { get; set; } + public bool DesktopArrived { get; set; } + public string LastEspPhase { get; set; } + public bool IsWaitingForHello { get; set; } + public bool EnrollmentCompleteEmitted { get; set; } + public string EnrollmentType { get; set; } + + // Signal timestamps for audit trail + public DateTime? EspFirstSeenUtc { get; set; } + public DateTime? EspFinalExitUtc { get; set; } + public DateTime? DesktopArrivedUtc { get; set; } + public DateTime? HelloResolvedUtc { get; set; } + public DateTime? ImePatternSeenUtc { get; set; } + public List SignalsSeen { get; set; } = new List(); + } +} diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs index be73b466..baf0da13 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs @@ -35,6 +35,34 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking private bool _finalDeviceInfoCollected = false; // Ensure final device info is emitted only once private string _lastEmittedSummaryHash; // Track last emitted state-breakdown to avoid redundant summary events + // ESP failure handling (Phase 1) + private Timer _espFailureTimer; + private string _pendingEspFailureType; + private const int EspFailureGracePeriodSeconds = 60; + private static readonly HashSet RecoverableEspFailureTypes = new HashSet(StringComparer.OrdinalIgnoreCase) + { + "ESPProgress_Timeout" + }; + + // Unified completion logic (Phase 3A) + private bool _espEverSeen; + private bool _espFinalExitSeen; + private bool _enrollmentCompleteEmitted; + private bool _desktopArrived; + private readonly DateTime _agentStartTimeUtc = DateTime.UtcNow; + + // Device-Only ESP detection (Phase 3C) + private Timer _deviceOnlyEspTimer; + private const int DeviceOnlyEspTimerMinutes = 5; + + // State persistence for crash recovery + private readonly EnrollmentStatePersistence _statePersistence; + private EnrollmentStateData _stateData = new EnrollmentStateData(); + private bool _stateDirty; + + // Completion check throttling (max 1x/min per source) + private readonly Dictionary _lastCompletionCheckBySource = new Dictionary(); + // Default IME log folder private const string DefaultImeLogFolder = @"%ProgramData%\Microsoft\IntuneManagementExtension\Logs"; @@ -115,8 +143,11 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking _espAndHelloTracker = espAndHelloTracker; _deviceInfoCollector = new Collectors.DeviceInfoCollector(sessionId, tenantId, emitEvent, logger); - // Create ImeLogTracker with state persistence directory + // State persistence for crash recovery var stateDirectory = @"%ProgramData%\AutopilotMonitor\State"; + _statePersistence = new EnrollmentStatePersistence(stateDirectory, _logger); + + // Create ImeLogTracker with state persistence directory _imeLogTracker = new ImeLogTracker(_imeLogFolder, _imeLogPatterns, _logger, matchLogPath: imeMatchLogPath, stateDirectory: stateDirectory); _imeLogTracker.SimulationMode = simulationMode; _imeLogTracker.SpeedFactor = speedFactor; @@ -137,6 +168,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking _espAndHelloTracker.HelloCompleted += OnHelloCompleted; _espAndHelloTracker.FinalizingSetupPhaseTriggered += OnFinalizingSetupPhaseTriggered; _espAndHelloTracker.WhiteGloveCompleted += OnWhiteGloveCompleted; + _espAndHelloTracker.EspFailureDetected += OnEspFailureDetected; } } @@ -147,6 +179,9 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking { _logger.Info("EnrollmentTracker: starting"); + // Load persisted state for crash recovery + LoadState(); + // Start IME log tracking immediately — this is the critical enrollment watcher. // Device info collection (WMI + registry) runs in the background so it doesn't // delay the ImeLogTracker from catching early enrollment events. @@ -198,6 +233,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking { var result = _deviceInfoCollector.CollectAll(); _enrollmentType = result.enrollmentType; + _stateData.EnrollmentType = _enrollmentType; + _stateDirty = true; } /// @@ -228,6 +265,26 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking _logger.Info($"EnrollmentTracker: ESP phase changed from '{_lastEspPhase ?? "null"}' to '{phase}'"); _lastEspPhase = phase; _hasAutoSwitchedToAppsPhase = false; // Reset when ESP phase changes + _espEverSeen = true; + _stateData.EspEverSeen = true; + _stateData.LastEspPhase = phase; + if (_stateData.EspFirstSeenUtc == null) + _stateData.EspFirstSeenUtc = DateTime.UtcNow; + RecordSignal($"esp_phase_{phase}"); + + // ESP phase change means ESP is progressing — cancel any pending failure grace period + CancelPendingEspFailure(); + + // Cancel device-only ESP timer if AccountSetup phase detected + if (string.Equals(phase, "AccountSetup", StringComparison.OrdinalIgnoreCase)) + { + if (_deviceOnlyEspTimer != null) + { + _logger.Info("EnrollmentTracker: AccountSetup detected — cancelling device-only ESP timer"); + _deviceOnlyEspTimer.Dispose(); + _deviceOnlyEspTimer = null; + } + } // Map ESP phase to EnrollmentPhase (phase change events) var enrollmentPhase = EnrollmentPhase.DeviceSetup; @@ -358,6 +415,11 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking break; case AppInstallationState.Installing: + // Only emit the strategic event once when install actually starts. + // Progress-only updates (oldState == Installing, just progress/bytes changed) + // are skipped — same pattern as Downloading above. + if (oldState == AppInstallationState.Installing) + return; eventType = "app_install_started"; break; @@ -496,6 +558,11 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking private void HandleUserSessionCompleted() { _logger.Info("EnrollmentTracker: User session completed (detected from IME log)"); + _stateData.ImePatternSeenUtc = DateTime.UtcNow; + RecordSignal("ime_pattern"); + + // User session completed successfully — cancel any pending ESP failure + CancelPendingEspFailure(); // Stop summary timer if running _summaryTimer?.Change(Timeout.Infinite, Timeout.Infinite); @@ -531,70 +598,41 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking // or when the agent is stopped/times out return; } - - if (helloPolicyConfigured && helloCompleted) - { - _logger.Info("EnrollmentTracker: Windows Hello provisioning has completed. Enrollment can complete."); - } - else - { - _logger.Info("EnrollmentTracker: No Windows Hello policy detected. Enrollment can complete."); - } } - // Emit enrollment completed event - _emitEvent(new EnrollmentEvent - { - SessionId = _sessionId, - TenantId = _tenantId, - EventType = "enrollment_complete", - Severity = EventSeverity.Info, - Source = "ImeLogTracker", - Phase = EnrollmentPhase.Complete, - Message = "Autopilot enrollment completed successfully (user session completed)" - }); - - // Write enrollment complete marker for cleanup retry detection - WriteEnrollmentCompleteMarker(); - - // Clean up persisted tracker state so next enrollment starts fresh - _imeLogTracker?.DeleteState(); + TryEmitEnrollmentComplete("ime_pattern"); } /// - /// Called when Windows Hello provisioning completes (via HelloDetector event) - /// If we were waiting for Hello, now we can mark enrollment as complete + /// Called when Windows Hello provisioning completes (via EspAndHelloTracker event). + /// Multiple completion paths: IME pattern was waiting for Hello, ESP final exit + Hello composite, + /// or Desktop arrival + Hello. /// private void OnHelloCompleted(object sender, EventArgs e) { - _logger.Info("EnrollmentTracker: Received HelloCompleted event from HelloDetector"); + _logger.Info("EnrollmentTracker: Received HelloCompleted event from EspAndHelloTracker"); + _stateData.HelloResolvedUtc = DateTime.UtcNow; + RecordSignal("hello_resolved"); if (_isWaitingForHello) { - _logger.Info("EnrollmentTracker: Hello provisioning completed while waiting - marking enrollment as complete now"); + _logger.Info("EnrollmentTracker: Hello provisioning completed while waiting (IME path) - marking enrollment as complete now"); _isWaitingForHello = false; - - // Emit enrollment completed event - _emitEvent(new EnrollmentEvent - { - SessionId = _sessionId, - TenantId = _tenantId, - EventType = "enrollment_complete", - Severity = EventSeverity.Info, - Source = "EnrollmentTracker", - Phase = EnrollmentPhase.Complete, - Message = "Autopilot enrollment completed successfully (Hello provisioning completed)" - }); - - // Write enrollment complete marker for cleanup retry detection - WriteEnrollmentCompleteMarker(); - - // Clean up persisted tracker state so next enrollment starts fresh - _imeLogTracker?.DeleteState(); + TryEmitEnrollmentComplete("ime_hello"); + } + else if (_espFinalExitSeen) + { + _logger.Info("EnrollmentTracker: Hello completed + ESP final exit seen — composite completion"); + TryEmitEnrollmentComplete("esp_hello_composite"); + } + else if (_desktopArrived) + { + _logger.Info("EnrollmentTracker: Hello completed + desktop arrived — desktop-hello completion"); + TryEmitEnrollmentComplete("desktop_hello"); } else { - _logger.Debug("EnrollmentTracker: HelloCompleted event received but not waiting - ignoring"); + _logger.Debug("EnrollmentTracker: HelloCompleted event received but no completion trigger active yet"); } } @@ -628,6 +666,96 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking // Der State wird fuer Part 2 benoetigt falls der Tracker weiterlaufen muss. } + /// + /// Called when an ESP failure is detected (ESPProgress_Failure, _Timeout, _Abort, WhiteGlove_Failed, etc.). + /// Terminal failures emit enrollment_failed immediately. + /// Recoverable failures (e.g. ESPProgress_Timeout) get a grace period before failure. + /// + private void OnEspFailureDetected(object sender, string failureType) + { + _logger.Info($"EnrollmentTracker: ESP failure detected: {failureType}"); + + if (RecoverableEspFailureTypes.Contains(failureType)) + { + // Recoverable failure — start grace period timer + _logger.Info($"EnrollmentTracker: '{failureType}' is recoverable — starting {EspFailureGracePeriodSeconds}s grace period"); + _pendingEspFailureType = failureType; + + // Cancel existing timer if any (e.g. second timeout event) + _espFailureTimer?.Dispose(); + _espFailureTimer = new Timer( + OnEspFailureGracePeriodExpired, + null, + TimeSpan.FromSeconds(EspFailureGracePeriodSeconds), + TimeSpan.FromMilliseconds(-1)); + } + else + { + // Terminal failure — emit enrollment_failed immediately + _logger.Info($"EnrollmentTracker: '{failureType}' is terminal — emitting enrollment_failed immediately"); + EmitEnrollmentFailed(failureType, "esp_failure"); + } + } + + /// + /// Called when the ESP failure grace period expires without recovery. + /// Emits enrollment_failed. + /// + private void OnEspFailureGracePeriodExpired(object state) + { + var failureType = _pendingEspFailureType ?? "unknown"; + _logger.Warning($"EnrollmentTracker: ESP failure grace period ({EspFailureGracePeriodSeconds}s) expired for '{failureType}' — emitting enrollment_failed"); + _pendingEspFailureType = null; + + EmitEnrollmentFailed(failureType, "esp_failure_grace_expired"); + } + + /// + /// Cancels any pending ESP failure grace period timer (called when recovery is detected). + /// + private void CancelPendingEspFailure() + { + if (_espFailureTimer != null) + { + _logger.Info($"EnrollmentTracker: ESP recovery detected — cancelling pending failure for '{_pendingEspFailureType}'"); + _espFailureTimer.Dispose(); + _espFailureTimer = null; + _pendingEspFailureType = null; + } + } + + /// + /// Emits an enrollment_failed event. The MonitoringService handles shutdown identically to enrollment_complete. + /// + private void EmitEnrollmentFailed(string failureType, string failureSource) + { + // Stop summary timer + _summaryTimer?.Change(Timeout.Infinite, Timeout.Infinite); + _summaryTimerActive = false; + + _emitEvent(new EnrollmentEvent + { + SessionId = _sessionId, + TenantId = _tenantId, + EventType = "enrollment_failed", + Severity = EventSeverity.Error, + Source = "EnrollmentTracker", + Phase = EnrollmentPhase.Complete, + Message = $"Autopilot enrollment failed: {failureType}", + Data = new Dictionary + { + { "failureType", failureType }, + { "failureSource", failureSource }, + { "signalsSeen", _stateData.SignalsSeen }, + { "agentUptimeSeconds", (DateTime.UtcNow - _agentStartTimeUtc).TotalSeconds } + } + }); + + // Clean up persisted tracker state + _imeLogTracker?.DeleteState(); + _statePersistence.Delete(); + } + /// /// Called when ESP exit or Hello wizard start is detected (via HelloDetector Shell-Core events) /// Triggers transition to FinalizingSetup phase @@ -639,10 +767,20 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking // If ESP exiting, check which phase we're in if (reason == "esp_exiting") { - if (string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase)) + _espEverSeen = true; + + if (string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase) || _desktopArrived) { - // AccountSetup phase exiting - this is the final ESP exit, start Hello wait timer - _logger.Info("EnrollmentTracker: AccountSetup phase exiting - enrollment nearing completion, starting Hello wait timer"); + // Final ESP exit: either AccountSetup phase detected OR desktop arrived (backup) + var phaseInfo = string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase) + ? "AccountSetup" + : $"{_lastEspPhase ?? "unknown"} (desktop arrival backup)"; + _logger.Info($"EnrollmentTracker: ESP final exit from {phaseInfo} — marking _espFinalExitSeen, starting Hello wait timer"); + + _espFinalExitSeen = true; + _stateData.EspFinalExitSeen = true; + _stateData.EspFinalExitUtc = DateTime.UtcNow; + RecordSignal("esp_final_exit"); // Emit phase change event to FinalizingSetup _emitEvent(new EnrollmentEvent @@ -653,13 +791,14 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking Severity = EventSeverity.Info, Source = "EnrollmentTracker", Phase = EnrollmentPhase.FinalizingSetup, - Message = "ESP phase: FinalizingSetup (AccountSetup completed, waiting for final steps)", + Message = $"ESP phase: FinalizingSetup ({phaseInfo} completed, waiting for final steps)", Data = new Dictionary { { "espPhase", "FinalizingSetup" }, { "autoDetected", true }, { "triggeredBy", reason }, - { "previousPhase", "AccountSetup" } + { "previousPhase", _lastEspPhase ?? "unknown" }, + { "desktopArrivedBackup", _desktopArrived && !string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase) } } }); @@ -670,11 +809,16 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } else { - // DeviceSetup phase exiting - this is just transition to AccountSetup, not final - _logger.Info($"EnrollmentTracker: ESP phase exiting from '{_lastEspPhase ?? "unknown"}' - intermediate transition, not starting Hello wait timer"); + // DeviceSetup phase exiting without desktop — intermediate transition (Device→Account) or device-only ESP + _logger.Info($"EnrollmentTracker: ESP phase exiting from '{_lastEspPhase ?? "unknown"}' - intermediate transition, starting device-only ESP detection timer ({DeviceOnlyEspTimerMinutes}min)"); - // Don't emit FinalizingSetup event yet, this is not the final exit - // The regular esp_phase_changed event will be emitted when we detect AccountSetup phase + // Start device-only ESP detection timer + _deviceOnlyEspTimer?.Dispose(); + _deviceOnlyEspTimer = new Timer( + OnDeviceOnlyEspTimerExpired, + null, + TimeSpan.FromMinutes(DeviceOnlyEspTimerMinutes), + TimeSpan.FromMilliseconds(-1)); } } else if (reason == "hello_wizard_started") @@ -703,6 +847,245 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } } + // ===== State Persistence ===== + + private void LoadState() + { + var loaded = _statePersistence.Load(); + if (loaded == null) + return; + + _espEverSeen = loaded.EspEverSeen; + _espFinalExitSeen = loaded.EspFinalExitSeen; + _desktopArrived = loaded.DesktopArrived; + _lastEspPhase = loaded.LastEspPhase; + _isWaitingForHello = loaded.IsWaitingForHello; + _enrollmentCompleteEmitted = loaded.EnrollmentCompleteEmitted; + _enrollmentType = loaded.EnrollmentType ?? _enrollmentType; + _stateData = loaded; + + _logger.Info($"EnrollmentTracker: state restored — espEverSeen={_espEverSeen}, espFinalExitSeen={_espFinalExitSeen}, desktopArrived={_desktopArrived}, lastEspPhase={_lastEspPhase}, enrollmentCompleteEmitted={_enrollmentCompleteEmitted}"); + + // Restart Hello wait timer if needed after crash recovery + if ((_desktopArrived || _espFinalExitSeen) && _espAndHelloTracker != null && !_espAndHelloTracker.IsHelloCompleted) + { + _logger.Info("EnrollmentTracker: restarting Hello wait timer after state recovery"); + _espAndHelloTracker.StartHelloWaitTimer(); + } + } + + private void RecordSignal(string signal) + { + if (!_stateData.SignalsSeen.Contains(signal)) + _stateData.SignalsSeen.Add(signal); + _stateDirty = true; + } + + // ===== Unified Completion Logic ===== + + /// + /// Central guard method for enrollment_complete emission. All completion paths route through here. + /// An _enrollmentCompleteEmitted flag prevents double emission. + /// Emits a throttled completion_check event on every call for observability. + /// + private void TryEmitEnrollmentComplete(string source) + { + if (_enrollmentCompleteEmitted) + { + _logger.Debug($"EnrollmentTracker: TryEmitEnrollmentComplete('{source}') — already emitted, skipping"); + return; + } + + if (string.IsNullOrEmpty(source)) + return; + + // Hello-Check: Hello must be resolved before we can complete + bool helloResolved = _espAndHelloTracker == null + || _espAndHelloTracker.IsHelloCompleted + || !_espAndHelloTracker.IsPolicyConfigured; + + if (!helloResolved) + { + _logger.Info($"EnrollmentTracker: Completion source '{source}' ready but Hello still pending — not completing yet"); + EmitCompletionCheck(source, "hello_pending", "hello_not_resolved"); + return; + } + + // Desktop-Arrival Gate: Only allow desktop_arrival when ESP is NOT actively running + // WDP v2 has no ESP — skip the gate entirely + if (source == "desktop_arrival" && _enrollmentType != "v2" && _espEverSeen && !_espFinalExitSeen) + { + _logger.Info("EnrollmentTracker: Desktop arrived but ESP still active — not completing yet"); + EmitCompletionCheck(source, "blocked", "esp_active"); + return; + } + + _enrollmentCompleteEmitted = true; + _stateData.EnrollmentCompleteEmitted = true; + + // Stop summary timer + _summaryTimer?.Change(Timeout.Infinite, Timeout.Infinite); + _summaryTimerActive = false; + + var helloOutcome = _espAndHelloTracker?.HelloOutcome ?? "unknown"; + + var signalTimestamps = new Dictionary(); + if (_stateData.EspFirstSeenUtc.HasValue) + signalTimestamps["espFirstSeen"] = _stateData.EspFirstSeenUtc.Value.ToString("o"); + if (_stateData.DesktopArrivedUtc.HasValue) + signalTimestamps["desktopArrived"] = _stateData.DesktopArrivedUtc.Value.ToString("o"); + if (_stateData.EspFinalExitUtc.HasValue) + signalTimestamps["espFinalExit"] = _stateData.EspFinalExitUtc.Value.ToString("o"); + if (_stateData.HelloResolvedUtc.HasValue) + signalTimestamps["helloResolved"] = _stateData.HelloResolvedUtc.Value.ToString("o"); + if (_stateData.ImePatternSeenUtc.HasValue) + signalTimestamps["imePatternSeen"] = _stateData.ImePatternSeenUtc.Value.ToString("o"); + + _emitEvent(new EnrollmentEvent + { + SessionId = _sessionId, + TenantId = _tenantId, + EventType = "enrollment_complete", + Severity = EventSeverity.Info, + Source = "EnrollmentTracker", + Phase = EnrollmentPhase.Complete, + Message = $"Autopilot enrollment completed successfully (source: {source})", + Data = new Dictionary + { + { "completionSource", source }, + { "helloOutcome", helloOutcome }, + { "signalsSeen", _stateData.SignalsSeen }, + { "signalTimestamps", signalTimestamps }, + { "agentUptimeSeconds", (DateTime.UtcNow - _agentStartTimeUtc).TotalSeconds } + } + }); + + // Write enrollment complete marker for cleanup retry detection + WriteEnrollmentCompleteMarker(); + + // Clean up persisted tracker state so next enrollment starts fresh + _imeLogTracker?.DeleteState(); + _statePersistence.Delete(); + } + + /// + /// Emits a throttled completion_check event for observability. + /// Max 1 event per minute per source to avoid flooding. + /// + private void EmitCompletionCheck(string source, string result, string reason) + { + // Throttle: max 1x per minute per source + var now = DateTime.UtcNow; + if (_lastCompletionCheckBySource.TryGetValue(source, out var lastEmit) && (now - lastEmit).TotalSeconds < 60) + return; + _lastCompletionCheckBySource[source] = now; + + _emitEvent(new EnrollmentEvent + { + SessionId = _sessionId, + TenantId = _tenantId, + EventType = "completion_check", + Severity = EventSeverity.Info, + Source = "EnrollmentTracker", + Phase = EnrollmentPhase.Unknown, + Message = $"Completion source '{source}' evaluated — {result}", + Data = new Dictionary + { + { "source", source }, + { "result", result }, + { "reason", reason }, + { "espEverSeen", _espEverSeen }, + { "espFinalExitSeen", _espFinalExitSeen }, + { "desktopArrived", _desktopArrived }, + { "helloResolved", _espAndHelloTracker?.IsHelloCompleted ?? false }, + { "helloPolicyConfigured", _espAndHelloTracker?.IsPolicyConfigured ?? false }, + { "enrollmentType", _enrollmentType }, + { "lastEspPhase", _lastEspPhase ?? "none" } + } + }); + } + + /// + /// Called by MonitoringService when Desktop Arrival is detected (explorer.exe under a real user). + /// Corrects phase if needed, starts Hello wait timer in no-ESP scenarios, and attempts completion. + /// + public void NotifyDesktopArrived() + { + if (_desktopArrived) + return; + + _desktopArrived = true; + _stateData.DesktopArrived = true; + _stateData.DesktopArrivedUtc = DateTime.UtcNow; + RecordSignal("desktop_arrived"); + _logger.Info("EnrollmentTracker: Desktop arrival notified"); + + // Phase correction: If ESP was seen but AccountSetup was never detected by IME log, + // correct the phase and emit an event for the timeline + if (_espEverSeen && !string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase)) + { + var previousPhase = _lastEspPhase ?? "unknown"; + _lastEspPhase = "AccountSetup"; + _logger.Info($"EnrollmentTracker: Desktop arrival confirmed AccountSetup phase (was: {previousPhase}) — phase corrected on timeline"); + + _emitEvent(new EnrollmentEvent + { + SessionId = _sessionId, + TenantId = _tenantId, + EventType = "esp_phase_changed", + Severity = EventSeverity.Info, + Source = "DesktopArrivalDetector", + Phase = EnrollmentPhase.AccountSetup, + Message = $"ESP phase: AccountSetup (auto-detected from desktop arrival, was: {previousPhase})", + Data = new Dictionary + { + { "espPhase", "AccountSetup" }, + { "autoDetected", true }, + { "correctedBy", "desktop_arrival" }, + { "previousPhase", previousPhase } + } + }); + } + + // Start Hello wait timer in no-ESP or post-ESP scenarios + // Without this, Hello would never timeout-resolve in no-ESP scenarios (WDP v2, ESP disabled) + if (_espAndHelloTracker != null && !_espAndHelloTracker.IsHelloCompleted) + { + _logger.Info("EnrollmentTracker: Desktop arrived with Hello pending — starting Hello wait timer"); + _espAndHelloTracker.StartHelloWaitTimer(); + } + + TryEmitEnrollmentComplete("desktop_arrival"); + } + + /// + /// Called when the device-only ESP timer expires. If no AccountSetup phase started + /// and desktop is available, classify as device-only ESP and mark final exit. + /// + private void OnDeviceOnlyEspTimerExpired(object state) + { + // AccountSetup started meanwhile? Timer is obsolete + if (string.Equals(_lastEspPhase, "AccountSetup", StringComparison.OrdinalIgnoreCase)) + { + _logger.Debug("EnrollmentTracker: Device-only ESP timer expired but AccountSetup detected — ignoring"); + return; + } + + if (_desktopArrived) + { + _logger.Info($"EnrollmentTracker: No AccountSetup phase after {DeviceOnlyEspTimerMinutes}min — classified as device-only ESP, desktop is active"); + _espFinalExitSeen = true; + _stateData.EspFinalExitSeen = true; + _stateData.EspFinalExitUtc = DateTime.UtcNow; + RecordSignal("device_only_esp_final_exit"); + _espAndHelloTracker?.StartHelloWaitTimer(); + } + else + { + _logger.Info($"EnrollmentTracker: No AccountSetup phase after {DeviceOnlyEspTimerMinutes}min and no desktop yet — waiting for Desktop Arrival or Lifetime Timer"); + } + } + private void CollectDeviceInfoAtFinalizingSetup(string triggerReason) { if (_finalDeviceInfoCollected) @@ -720,6 +1103,13 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking { // Only emit if state-breakdown counters changed since last emission (backstop for missed events) EmitAppTrackingSummaryIfChanged(); + + // Periodic state save (piggybacks on the existing 30s timer) + if (_stateDirty) + { + _stateDirty = false; + _statePersistence.Save(_stateData); + } } /// @@ -786,14 +1176,17 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking { Stop(); - // Unsubscribe from HelloDetector events + // Unsubscribe from EspAndHelloTracker events if (_espAndHelloTracker != null) { _espAndHelloTracker.HelloCompleted -= OnHelloCompleted; _espAndHelloTracker.FinalizingSetupPhaseTriggered -= OnFinalizingSetupPhaseTriggered; _espAndHelloTracker.WhiteGloveCompleted -= OnWhiteGloveCompleted; + _espAndHelloTracker.EspFailureDetected -= OnEspFailureDetected; } + _espFailureTimer?.Dispose(); + _deviceOnlyEspTimer?.Dispose(); _summaryTimer?.Dispose(); _imeLogTracker?.Dispose(); } diff --git a/src/Backend/AutopilotMonitor.Functions/Functions/DailyMaintenanceFunction.cs b/src/Backend/AutopilotMonitor.Functions/Functions/DailyMaintenanceFunction.cs index f3a68f75..859a393c 100644 --- a/src/Backend/AutopilotMonitor.Functions/Functions/DailyMaintenanceFunction.cs +++ b/src/Backend/AutopilotMonitor.Functions/Functions/DailyMaintenanceFunction.cs @@ -23,11 +23,13 @@ namespace AutopilotMonitor.Functions.Functions } /// - /// Timer trigger: Runs daily at 2:00 AM UTC + /// Timer trigger: Runs every 2 hours /// NCRONTAB format: {second} {minute} {hour} {day} {month} {day-of-week} + /// Reduced from daily (2:00 UTC) to every 2 hours to catch stalled sessions faster. + /// MarkStalledSessionsAsTimedOutAsync is idempotent (terminal states not overwritten). /// [Function("DailyMaintenance")] - public async Task Run([TimerTrigger("0 0 2 * * *")] object timer) + public async Task Run([TimerTrigger("0 0 */2 * * *")] object timer) { _logger.LogInformation("DailyMaintenance timer trigger fired"); await _maintenanceService.RunAllAsync(); diff --git a/src/Backend/AutopilotMonitor.Functions/Functions/GetAgentConfigFunction.cs b/src/Backend/AutopilotMonitor.Functions/Functions/GetAgentConfigFunction.cs index cbc19c42..f7994d16 100644 --- a/src/Backend/AutopilotMonitor.Functions/Functions/GetAgentConfigFunction.cs +++ b/src/Backend/AutopilotMonitor.Functions/Functions/GetAgentConfigFunction.cs @@ -94,7 +94,8 @@ namespace AutopilotMonitor.Functions.Functions EnablePerformanceCollector = tenantConfig.EnablePerformanceCollector, PerformanceIntervalSeconds = tenantConfig.PerformanceCollectorIntervalSeconds, CollectorIdleTimeoutMinutes = adminConfig.CollectorIdleTimeoutMinutes, - HelloWaitTimeoutSeconds = tenantConfig.HelloWaitTimeoutSeconds + HelloWaitTimeoutSeconds = tenantConfig.HelloWaitTimeoutSeconds, + AgentMaxLifetimeMinutes = tenantConfig.AgentMaxLifetimeMinutes ?? 360 }; // Get active gather rules for this tenant (user-defined ad-hoc only) @@ -111,7 +112,7 @@ namespace AutopilotMonitor.Functions.Functions var response = req.CreateResponse(HttpStatusCode.OK); await response.WriteAsJsonAsync(new AgentConfigResponse { - ConfigVersion = 12, // collector idle timeout: replaced MaxCollectorDurationHours with activity-aware CollectorIdleTimeoutMinutes + ConfigVersion = 13, // session lifecycle: agent max lifetime, esp_failure → enrollment_failed, desktop arrival, multi-signal completion UploadIntervalSeconds = 30, SelfDestructOnComplete = tenantConfig.SelfDestructOnComplete ?? true, KeepLogFile = tenantConfig.KeepLogFile ?? false, diff --git a/src/Backend/AutopilotMonitor.Functions/Functions/IngestEventsFunction.cs b/src/Backend/AutopilotMonitor.Functions/Functions/IngestEventsFunction.cs index 45223a75..09e92fe9 100644 --- a/src/Backend/AutopilotMonitor.Functions/Functions/IngestEventsFunction.cs +++ b/src/Backend/AutopilotMonitor.Functions/Functions/IngestEventsFunction.cs @@ -412,6 +412,17 @@ namespace AutopilotMonitor.Functions.Functions // Retrieve updated session data to include in SignalR messages var updatedSession = await _storageService.GetSessionAsync(request.TenantId, request.SessionId); + // Session age warning: log if session >4h old and still InProgress (observability only) + if (updatedSession != null && updatedSession.Status == SessionStatus.InProgress) + { + var sessionAge = DateTime.UtcNow - updatedSession.StartedAt; + if (sessionAge.TotalHours > 4) + { + _logger.LogWarning("Session {SessionId} (tenant {TenantId}) still InProgress after {Hours:F1}h — may be stuck", + request.SessionId, request.TenantId, sessionAge.TotalHours); + } + } + // Log warning if WhiteGlove status update was not persisted despite retries and fallback. // Events are already stored (idempotent UpsertReplace). Do NOT return 500 here: // the agent retries the same batch containing whiteglove_complete, hitting the same diff --git a/src/Shared/AutopilotMonitor.Shared/Constants.cs b/src/Shared/AutopilotMonitor.Shared/Constants.cs index 4f2424b6..5c99f3a7 100644 --- a/src/Shared/AutopilotMonitor.Shared/Constants.cs +++ b/src/Shared/AutopilotMonitor.Shared/Constants.cs @@ -105,6 +105,10 @@ namespace AutopilotMonitor.Shared public const string EspUiState = "esp_ui_state"; public const string GatherResult = "gather_result"; public const string WhiteGloveComplete = "whiteglove_complete"; + public const string EnrollmentComplete = "enrollment_complete"; + public const string EnrollmentFailed = "enrollment_failed"; + public const string DesktopArrived = "desktop_arrived"; + public const string CompletionCheck = "completion_check"; } // ----------------------------------------------------------------------- diff --git a/src/Shared/AutopilotMonitor.Shared/Models/AgentConfigResponse.cs b/src/Shared/AutopilotMonitor.Shared/Models/AgentConfigResponse.cs index 1a0870b0..d650ddca 100644 --- a/src/Shared/AutopilotMonitor.Shared/Models/AgentConfigResponse.cs +++ b/src/Shared/AutopilotMonitor.Shared/Models/AgentConfigResponse.cs @@ -162,6 +162,12 @@ namespace AutopilotMonitor.Shared.Models /// public int HelloWaitTimeoutSeconds { get; set; } = 30; + /// + /// Maximum agent lifetime in minutes. Safety net to prevent zombie agents. + /// 0 = disabled (no lifetime limit). Default: 360 (6 hours). + /// + public int AgentMaxLifetimeMinutes { get; set; } = 360; + /// /// Creates default collector configuration /// diff --git a/src/Shared/AutopilotMonitor.Shared/Models/TenantConfiguration.cs b/src/Shared/AutopilotMonitor.Shared/Models/TenantConfiguration.cs index 33d8911f..da389a5e 100644 --- a/src/Shared/AutopilotMonitor.Shared/Models/TenantConfiguration.cs +++ b/src/Shared/AutopilotMonitor.Shared/Models/TenantConfiguration.cs @@ -166,6 +166,12 @@ namespace AutopilotMonitor.Shared.Models /// public int? AuthFailureTimeoutMinutes { get; set; } + /// + /// Maximum agent lifetime in minutes. Safety net to prevent zombie agents. + /// null = use default (360 = 6 hours). 0 = disabled (no lifetime limit). + /// + public int? AgentMaxLifetimeMinutes { get; set; } + // ===== AGENT BEHAVIOR OVERRIDES ===== ///