From c2ee8a8ffd04a58d7b4dff04b8f95e952d7dedae Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Tue, 17 Mar 2026 20:09:59 +0100 Subject: [PATCH] more robust completion logic in device phase only path --- .../EnrollmentTracker.CompletionLogic.cs | 61 +++++++++++++++++-- .../Tracking/EnrollmentTracker.Diagnostics.cs | 1 + .../Monitoring/Tracking/EnrollmentTracker.cs | 4 ++ .../AutopilotMonitor.Agent/buildcounter.txt | 2 +- 4 files changed, 62 insertions(+), 6 deletions(-) diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.CompletionLogic.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.CompletionLogic.cs index ba0cb9fd..b1270fc8 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.CompletionLogic.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.CompletionLogic.cs @@ -109,7 +109,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } }); - CollectDeviceInfoAtFinalizingSetup("self_deploying_provisioning_complete"); + try { CollectDeviceInfoAtFinalizingSetup("self_deploying_provisioning_complete"); } + catch (Exception ex) { _logger.Warning($"EnrollmentTracker: final device info collection failed (self_deploying): {ex.Message}"); } // Attempt completion — Hello guard is bypassed for Self-Deploying (IsSelfDeploying) TryEmitEnrollmentComplete("self_deploying_provisioning_complete"); @@ -230,6 +231,36 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking TryEmitEnrollmentComplete("ime_hello_safety_timeout"); } + /// + /// Safety-net callback for device-only ESP (SkipUserStatusPage=true) completion. + /// If the normal Hello timer chain (30s wait + 300s completion) failed for any reason + /// (exception, timer disposal, race condition), this forces enrollment_complete instead + /// of waiting for the 6h max lifetime timer. + /// + private void OnDeviceOnlyCompletionSafetyTimeout(object state) + { + if (_enrollmentCompleteEmitted) + { + _logger.Debug("EnrollmentTracker: device-only completion safety timeout fired but enrollment already completed — ignoring"); + return; + } + + _logger.Warning($"EnrollmentTracker: device-only ESP completion safety timeout ({DeviceOnlyCompletionSafetyTimeoutSeconds}s) expired — forcing completion"); + + // Force-resolve Hello if still pending so the Hello guard in TryEmitEnrollmentComplete passes + if (_espAndHelloTracker != null && !_espAndHelloTracker.IsHelloCompleted) + { + _espAndHelloTracker.ForceMarkHelloCompleted("device_only_safety_timeout"); + } + + TryEmitEnrollmentComplete("device_only_esp_safety_timeout"); + + if (!_enrollmentCompleteEmitted) + { + _logger.Error("EnrollmentTracker: device-only ESP safety timeout — TryEmitEnrollmentComplete still did not fire (unexpected guard block)"); + } + } + /// /// Emits an enrollment_failed event. The MonitoringService handles shutdown identically to enrollment_complete. /// @@ -313,7 +344,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } }); - CollectDeviceInfoAtFinalizingSetup(reason); + try { CollectDeviceInfoAtFinalizingSetup(reason); } + catch (Exception ex) { _logger.Warning($"EnrollmentTracker: final device info collection failed (esp_final_exit): {ex.Message}"); } // Start Hello wait timer (waits for Hello wizard to start or timeout) _espAndHelloTracker?.StartHelloWaitTimer(); @@ -351,9 +383,25 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } }); - CollectDeviceInfoAtFinalizingSetup("device_only_esp_registry"); + try { CollectDeviceInfoAtFinalizingSetup("device_only_esp_registry"); } + catch (Exception ex) { _logger.Warning($"EnrollmentTracker: final device info collection failed (device_only_esp_registry): {ex.Message}"); } + _espAndHelloTracker?.StartHelloWaitTimer(); TryEmitEnrollmentComplete("device_only_esp_registry"); + + // Safety net: if enrollment_complete didn't fire immediately (Hello pending), + // start a safety timer to force completion. Without this, a failed Hello timer + // chain would leave the session hanging until the 6h max lifetime timer. + if (!_enrollmentCompleteEmitted) + { + _logger.Info($"EnrollmentTracker: device-only ESP completion pending — starting safety timer ({DeviceOnlyCompletionSafetyTimeoutSeconds}s)"); + _deviceOnlyCompletionSafetyTimer?.Dispose(); + _deviceOnlyCompletionSafetyTimer = new Timer( + OnDeviceOnlyCompletionSafetyTimeout, + null, + TimeSpan.FromSeconds(DeviceOnlyCompletionSafetyTimeoutSeconds), + TimeSpan.FromMilliseconds(-1)); + } } else { @@ -392,7 +440,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } }); - CollectDeviceInfoAtFinalizingSetup(reason); + try { CollectDeviceInfoAtFinalizingSetup(reason); } + catch (Exception ex) { _logger.Warning($"EnrollmentTracker: final device info collection failed (hello_wizard_started): {ex.Message}"); } } } @@ -516,6 +565,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking _summaryTimerActive = false; _debugStateTimer?.Change(Timeout.Infinite, Timeout.Infinite); _debugStateTimerActive = false; + _deviceOnlyCompletionSafetyTimer?.Change(Timeout.Infinite, Timeout.Infinite); var helloOutcome = _espAndHelloTracker?.HelloOutcome ?? "unknown"; @@ -661,7 +711,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking } }); - CollectDeviceInfoAtFinalizingSetup("desktop_arrived_skip_user"); + try { CollectDeviceInfoAtFinalizingSetup("desktop_arrived_skip_user"); } + catch (Exception ex) { _logger.Warning($"EnrollmentTracker: final device info collection failed (desktop_arrived_skip_user): {ex.Message}"); } } else { diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.Diagnostics.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.Diagnostics.cs index 65252c86..0fb89660 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.Diagnostics.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.Diagnostics.cs @@ -173,6 +173,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking _espFailureTimer?.Dispose(); _deviceOnlyEspTimer?.Dispose(); _waitingForHelloSafetyTimer?.Dispose(); + _deviceOnlyCompletionSafetyTimer?.Dispose(); _summaryTimer?.Dispose(); _debugStateTimer?.Dispose(); _imeLogTracker?.Dispose(); diff --git a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs index 471f3b15..30b57154 100644 --- a/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.Core/Monitoring/Tracking/EnrollmentTracker.cs @@ -74,6 +74,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Tracking private Timer _waitingForHelloSafetyTimer; private const int WaitingForHelloSafetyTimeoutSeconds = 420; // 7 min — longer than Hello chain (330s) + // Safety-net timer for device-only ESP completion (SkipUserStatusPage=true) + private Timer _deviceOnlyCompletionSafetyTimer; + private const int DeviceOnlyCompletionSafetyTimeoutSeconds = 420; // 7 min — same as Hello safety + // State persistence for crash recovery private readonly EnrollmentStatePersistence _statePersistence; private EnrollmentStateData _stateData = new EnrollmentStateData(); diff --git a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt index 3bb8a497..f27d46f4 100644 --- a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt +++ b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt @@ -1 +1 @@ -464 +466