Merge pull request #42 from okieselbach/claude/add-event-backfill-0cjfb

This commit is contained in:
Oliver Kieselbach
2026-04-12 18:33:49 +02:00
committed by GitHub
4 changed files with 323 additions and 86 deletions
@@ -1,25 +1,30 @@
using System;
using System.Collections.Generic;
using System.Diagnostics.Eventing.Reader;
using System.IO;
using AutopilotMonitor.Shared;
using AutopilotMonitor.Shared.Models;
using Newtonsoft.Json;
namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
{
/// <summary>
/// Partial: ModernDeployment-Diagnostics-Provider event log handling (Ebene 1 — live capture).
/// Partial: ModernDeployment-Diagnostics-Provider event log handling (Ebene 1 — live capture + backfill).
///
/// Subscribes to two Windows event channels that Microsoft uses to log Autopilot and ESP events:
/// - Microsoft-Windows-ModernDeployment-Diagnostics-Provider/Autopilot
/// - Microsoft-Windows-ModernDeployment-Diagnostics-Provider/ManagementService
///
/// Current mode is **live-capture only**: every event at Level ≤ ModernDeploymentLogLevelMax
/// Current mode is **live-capture + targeted backfill**: every event at Level ≤ ModernDeploymentLogLevelMax
/// (default 3 = Warning, Error, Critical) is forwarded to the backend as a
/// <see cref="Constants.EventTypes.ModernDeploymentLog"/>/<see cref="Constants.EventTypes.ModernDeploymentWarning"/>/
/// <see cref="Constants.EventTypes.ModernDeploymentError"/> event. We intentionally do NOT
/// classify failures locally or fire <c>EspFailureDetected</c> from this code yet — we first
/// want to gather real EventIDs from production devices and then iterate on classification rules
/// via backend config without agent rollout.
/// <see cref="Constants.EventTypes.ModernDeploymentError"/> event. Targeted events (e.g. Event 509)
/// are additionally backfilled from the event log on startup to catch events that were written
/// before the agent started (e.g. WhiteGlove initiation during OOBE before MDM enroll).
///
/// We intentionally do NOT classify failures locally or fire <c>EspFailureDetected</c> from this
/// code yet — we first want to gather real EventIDs from production devices and then iterate on
/// classification rules via backend config without agent rollout.
///
/// Timing: Watchers stay subscribed for the entire agent lifetime (not stopped by idle timeout).
/// They are push-based (kernel-driven delivery) — zero-cost when no events are written.
@@ -52,6 +57,12 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
private System.Diagnostics.Eventing.Reader.EventLogWatcher _modernDeploymentAutopilotWatcher;
private System.Diagnostics.Eventing.Reader.EventLogWatcher _modernDeploymentManagementWatcher;
/// <summary>
/// File name for persisting WhiteGlove backfill state across agent restarts.
/// Written to the stateDirectory passed via the constructor.
/// </summary>
private const string WhiteGloveBackfillStateFileName = "whiteglove-backfill.json";
private void StartModernDeploymentEventLogWatchers()
{
_modernDeploymentAutopilotWatcher = TryStartModernDeploymentWatcher(
@@ -134,6 +145,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
}
}
// -----------------------------------------------------------------------
// Live event handler (EventLogWatcher callback)
// -----------------------------------------------------------------------
private void OnModernDeploymentEventRecordWritten(EventRecordWrittenEventArgs e, string shortName, string channelName)
{
if (e.EventRecord == null)
@@ -141,80 +156,7 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
try
{
var record = e.EventRecord;
// Targeted event dispatch: WhiteGlove start (Event 509, Level 4).
// Captured via the combined XPath filter — handle before the generic level switch.
if (record.Id == EventId_ManagementService_WhiteGloveStart
&& shortName == "ManagementService")
{
HandleWhiteGloveStartEvent(record);
return;
}
// Determine severity based on Windows event level:
// 1 = Critical, 2 = Error, 3 = Warning, 4 = Information, 5 = Verbose
var level = record.Level ?? 4;
string eventType;
EventSeverity severity;
switch (level)
{
case 1:
case 2:
eventType = Constants.EventTypes.ModernDeploymentError;
severity = EventSeverity.Error;
break;
case 3:
eventType = Constants.EventTypes.ModernDeploymentWarning;
severity = EventSeverity.Warning;
break;
default:
eventType = Constants.EventTypes.ModernDeploymentLog;
severity = EventSeverity.Info;
break;
}
// Downgrade known harmless warnings to Debug.
// EventID 100 Level 3 = "Autopilot policy not found" — fires when optional
// ESP sync policies are not configured; no real impact on enrollment.
if (level == 3 && record.Id == 100)
{
eventType = Constants.EventTypes.ModernDeploymentLog;
severity = EventSeverity.Debug;
}
string description = null;
try { description = record.FormatDescription(); }
catch { /* some events lack formatting resources */ }
if (string.IsNullOrEmpty(description))
description = $"Event ID {record.Id} (no formatted description)";
// Trim the message body to keep the event payload small.
var truncated = description.Length > 1000 ? description.Substring(0, 1000) + "…" : description;
var data = new Dictionary<string, object>
{
{ "channel", shortName },
{ "channelFullName", channelName },
{ "eventId", record.Id },
{ "level", level },
{ "levelName", record.LevelDisplayName ?? string.Empty },
{ "providerName", record.ProviderName ?? string.Empty },
{ "timeCreated", record.TimeCreated?.ToUniversalTime().ToString("o") ?? string.Empty }
};
_onEventCollected(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
EventType = eventType,
Severity = severity,
Source = "ModernDeploymentWatcher",
Phase = EnrollmentPhase.Unknown,
Message = $"[{shortName}] EventID {record.Id}: {truncated}",
Data = data
});
ProcessModernDeploymentRecord(e.EventRecord, shortName, channelName, isBackfill: false);
}
catch (Exception ex)
{
@@ -222,12 +164,103 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
}
}
// -----------------------------------------------------------------------
// Shared event processing (used by both live watcher and backfill reader)
// -----------------------------------------------------------------------
/// <summary>
/// Processes a single ModernDeployment event record. Called from both the live
/// EventLogWatcher callback and the startup backfill reader. The <paramref name="isBackfill"/>
/// flag is included in the emitted event data for trace analysis.
/// </summary>
private void ProcessModernDeploymentRecord(EventRecord record, string shortName, string channelName, bool isBackfill)
{
// Targeted event dispatch: WhiteGlove start (Event 509, Level 4).
// Captured via the combined XPath filter — handle before the generic level switch.
if (record.Id == EventId_ManagementService_WhiteGloveStart
&& shortName == "ManagementService")
{
HandleWhiteGloveStartEvent(record, isBackfill);
return;
}
// Determine severity based on Windows event level:
// 1 = Critical, 2 = Error, 3 = Warning, 4 = Information, 5 = Verbose
var level = record.Level ?? 4;
string eventType;
EventSeverity severity;
switch (level)
{
case 1:
case 2:
eventType = Constants.EventTypes.ModernDeploymentError;
severity = EventSeverity.Error;
break;
case 3:
eventType = Constants.EventTypes.ModernDeploymentWarning;
severity = EventSeverity.Warning;
break;
default:
eventType = Constants.EventTypes.ModernDeploymentLog;
severity = EventSeverity.Info;
break;
}
// Downgrade known harmless warnings to Debug.
// EventID 100 Level 3 = "Autopilot policy not found" — fires when optional
// ESP sync policies are not configured; no real impact on enrollment.
if (level == 3 && record.Id == 100)
{
eventType = Constants.EventTypes.ModernDeploymentLog;
severity = EventSeverity.Debug;
}
string description = null;
try { description = record.FormatDescription(); }
catch { /* some events lack formatting resources */ }
if (string.IsNullOrEmpty(description))
description = $"Event ID {record.Id} (no formatted description)";
// Trim the message body to keep the event payload small.
var truncated = description.Length > 1000 ? description.Substring(0, 1000) + "…" : description;
var data = new Dictionary<string, object>
{
{ "channel", shortName },
{ "channelFullName", channelName },
{ "eventId", record.Id },
{ "level", level },
{ "levelName", record.LevelDisplayName ?? string.Empty },
{ "providerName", record.ProviderName ?? string.Empty },
{ "timeCreated", record.TimeCreated?.ToUniversalTime().ToString("o") ?? string.Empty },
{ "backfilled", isBackfill }
};
_onEventCollected(new EnrollmentEvent
{
SessionId = _sessionId,
TenantId = _tenantId,
EventType = eventType,
Severity = severity,
Source = "ModernDeploymentWatcher",
Phase = EnrollmentPhase.Unknown,
Message = $"[{shortName}] EventID {record.Id}: {truncated}",
Data = data
});
}
// -----------------------------------------------------------------------
// WhiteGlove start detection (Event 509)
// -----------------------------------------------------------------------
/// <summary>
/// Handles ManagementService Event 509 (WhiteGlove start indicator).
/// Called from the shared OnModernDeploymentEventRecordWritten handler when a targeted
/// Called from <see cref="ProcessModernDeploymentRecord"/> when a targeted
/// event ID matches. Emits a whiteglove_started event for monitoring — no actions derived.
/// Persists the detection to disk so subsequent agent restarts skip the backfill scan.
/// </summary>
private void HandleWhiteGloveStartEvent(EventRecord record)
private void HandleWhiteGloveStartEvent(EventRecord record, bool isBackfill)
{
string description = null;
try { description = record.FormatDescription(); }
@@ -251,7 +284,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
_whiteGloveStartDetected = true;
}
_logger.Info($"WhiteGlove start detected via ManagementService Event 509: {description}");
_logger.Info($"WhiteGlove start detected via ManagementService Event 509 (backfill={isBackfill}): {description}");
// Persist across restarts — subsequent agent launches skip the backfill scan.
PersistWhiteGloveBackfillState(record.TimeCreated?.ToUniversalTime());
var truncated = description.Length > 500 ? description.Substring(0, 500) + "…" : description;
@@ -271,10 +307,174 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
{ "eventId", record.Id },
{ "level", record.Level ?? 4 },
{ "description", truncated },
{ "timeCreated", record.TimeCreated?.ToUniversalTime().ToString("o") ?? string.Empty }
{ "timeCreated", record.TimeCreated?.ToUniversalTime().ToString("o") ?? string.Empty },
{ "backfilled", isBackfill }
},
ImmediateUpload = true
});
}
// -----------------------------------------------------------------------
// Targeted backfill (runs once on startup)
// -----------------------------------------------------------------------
/// <summary>
/// Scans the ManagementService event log for targeted events (e.g. Event 509) that may
/// have been written before the agent started. This covers the timing gap during OOBE where
/// WhiteGlove initiation (Event 509) fires before MDM enrollment completes and the agent
/// starts monitoring.
///
/// <para>Flow:</para>
/// <list type="number">
/// <item>Check persisted state — if WhiteGlove was already seen in a prior run, skip the scan
/// and set the in-memory guard to suppress live duplicates.</item>
/// <item>If not persisted, query the event log with a time-bounded XPath filter for the
/// configured lookback window (default: 30 minutes).</item>
/// <item>Process each matching event through <see cref="ProcessModernDeploymentRecord"/> with
/// <c>isBackfill=true</c>. The existing fire-once guard in
/// <see cref="HandleWhiteGloveStartEvent"/> prevents duplicate emissions.</item>
/// </list>
/// </summary>
private void BackfillTargetedModernDeploymentEvents()
{
if (!_modernDeploymentBackfillEnabled)
{
_logger.Info("ModernDeployment backfill disabled by config");
return;
}
if (TargetedManagementServiceEventIds.Count == 0)
return;
// Check persisted state from a prior agent run — if WhiteGlove was already detected,
// skip the event log scan entirely and set the in-memory guard.
var persistedState = LoadWhiteGloveBackfillState();
if (persistedState != null && persistedState.WhiteGloveStartSeen)
{
_logger.Info($"WhiteGlove start already persisted from prior run (seen at {persistedState.SeenUtc:O}) — skipping backfill");
lock (_stateLock) { _whiteGloveStartDetected = true; }
return;
}
try
{
var lookbackMs = _modernDeploymentBackfillLookbackMinutes * 60 * 1000;
var idClauses = string.Join(" or ",
System.Linq.Enumerable.Select(TargetedManagementServiceEventIds, id => $"EventID={id}"));
var xpath = $"*[System[({idClauses}) and TimeCreated[timediff(@SystemTime) <= {lookbackMs}]]]";
_logger.Info($"ModernDeployment backfill: scanning {ModernDeploymentManagementChannel} " +
$"(lookback={_modernDeploymentBackfillLookbackMinutes}min, targetedIds={TargetedManagementServiceEventIds.Count})");
var query = new EventLogQuery(ModernDeploymentManagementChannel, PathType.LogName, xpath)
{
ReverseDirection = true // newest first — fire-once guard takes only the first match
};
int found = 0;
using (var reader = new EventLogReader(query))
{
EventRecord record;
while ((record = reader.ReadEvent()) != null)
{
using (record)
{
found++;
_logger.Info($"Backfill found ManagementService Event {record.Id} at {record.TimeCreated:O}");
ProcessModernDeploymentRecord(record, "ManagementService", ModernDeploymentManagementChannel, isBackfill: true);
}
}
}
if (found == 0)
_logger.Debug($"ModernDeployment backfill: no targeted events found in last {_modernDeploymentBackfillLookbackMinutes} minutes");
else
_logger.Info($"ModernDeployment backfill: processed {found} event(s)");
}
catch (EventLogNotFoundException)
{
_logger.Warning($"ModernDeployment event log not found during backfill: {ModernDeploymentManagementChannel} (normal on non-Windows 10/11 test environments)");
}
catch (UnauthorizedAccessException ex)
{
_logger.Warning($"ModernDeployment backfill access denied: {ex.Message}");
}
catch (Exception ex)
{
_logger.Warning($"ModernDeployment backfill failed: {ex.Message}");
}
}
// -----------------------------------------------------------------------
// Backfill state persistence (small JSON file for cross-restart dedup)
// -----------------------------------------------------------------------
/// <summary>
/// Persists the WhiteGlove detection flag to disk so the next agent start can skip
/// the backfill scan. Uses atomic write (temp file + copy) to avoid partial writes.
/// </summary>
private void PersistWhiteGloveBackfillState(DateTime? eventTimeUtc)
{
if (string.IsNullOrEmpty(_stateDirectory))
return;
try
{
Directory.CreateDirectory(_stateDirectory);
var filePath = Path.Combine(_stateDirectory, WhiteGloveBackfillStateFileName);
var state = new WhiteGloveBackfillState
{
WhiteGloveStartSeen = true,
SeenUtc = eventTimeUtc ?? DateTime.UtcNow,
PersistedUtc = DateTime.UtcNow
};
var json = JsonConvert.SerializeObject(state, Formatting.Indented);
var tempPath = filePath + ".tmp";
File.WriteAllText(tempPath, json);
File.Copy(tempPath, filePath, overwrite: true);
try { File.Delete(tempPath); } catch { }
_logger.Info($"WhiteGlove backfill state persisted to {filePath}");
}
catch (Exception ex)
{
_logger.Warning($"Failed to persist WhiteGlove backfill state: {ex.Message}");
}
}
/// <summary>
/// Loads the persisted WhiteGlove backfill state from disk.
/// Returns null if no state file exists or on error.
/// </summary>
private WhiteGloveBackfillState LoadWhiteGloveBackfillState()
{
if (string.IsNullOrEmpty(_stateDirectory))
return null;
var filePath = Path.Combine(_stateDirectory, WhiteGloveBackfillStateFileName);
if (!File.Exists(filePath))
return null;
try
{
var json = File.ReadAllText(filePath);
return JsonConvert.DeserializeObject<WhiteGloveBackfillState>(json);
}
catch (Exception ex)
{
_logger.Warning($"Failed to load WhiteGlove backfill state: {ex.Message}");
return null;
}
}
/// <summary>
/// Minimal DTO for the WhiteGlove backfill state file.
/// Persisted as <c>whiteglove-backfill.json</c> in the agent state directory.
/// </summary>
private class WhiteGloveBackfillState
{
public bool WhiteGloveStartSeen { get; set; }
public DateTime SeenUtc { get; set; }
public DateTime PersistedUtc { get; set; }
}
}
}
@@ -59,6 +59,9 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
private readonly int _helloWaitTimeoutSeconds;
private readonly bool _modernDeploymentWatcherEnabled;
private readonly int _modernDeploymentLogLevelMax;
private readonly bool _modernDeploymentBackfillEnabled;
private readonly int _modernDeploymentBackfillLookbackMinutes;
private readonly string _stateDirectory;
private const int HelloCompletionTimeoutSeconds = 300;
private const int BackfillLookbackMinutes = 5;
@@ -155,7 +158,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
AgentLogger logger,
int helloWaitTimeoutSeconds = 30,
bool modernDeploymentWatcherEnabled = true,
int modernDeploymentLogLevelMax = 3)
int modernDeploymentLogLevelMax = 3,
bool modernDeploymentBackfillEnabled = true,
int modernDeploymentBackfillLookbackMinutes = 30,
string stateDirectory = null)
{
_sessionId = sessionId ?? throw new ArgumentNullException(nameof(sessionId));
_tenantId = tenantId ?? throw new ArgumentNullException(nameof(tenantId));
@@ -164,6 +170,9 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
_helloWaitTimeoutSeconds = helloWaitTimeoutSeconds;
_modernDeploymentWatcherEnabled = modernDeploymentWatcherEnabled;
_modernDeploymentLogLevelMax = modernDeploymentLogLevelMax;
_modernDeploymentBackfillEnabled = modernDeploymentBackfillEnabled;
_modernDeploymentBackfillLookbackMinutes = modernDeploymentBackfillLookbackMinutes;
_stateDirectory = stateDirectory != null ? Environment.ExpandEnvironmentVariables(stateDirectory) : null;
}
/// <summary>
@@ -229,6 +238,12 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Collectors
if (_modernDeploymentWatcherEnabled)
{
StartModernDeploymentEventLogWatchers();
// Backfill targeted events (e.g. Event 509 / WhiteGlove start) that may have been
// written before the agent started. Uses EventLogReader to scan the event log for
// recent occurrences. Must run AFTER watcher subscription so no gap exists between
// backfill scan and live capture. Fire-once guards prevent duplicate emissions.
BackfillTargetedModernDeploymentEvents();
}
// Safety net: backfill recent terminal events in case watcher started late or event delivery lagged.
@@ -528,6 +528,8 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core
?? _configuration.HelloWaitTimeoutSeconds;
var modernDeploymentEnabled = _remoteConfigService?.CurrentConfig?.Collectors?.ModernDeploymentWatcherEnabled ?? true;
var modernDeploymentLevelMax = _remoteConfigService?.CurrentConfig?.Collectors?.ModernDeploymentLogLevelMax ?? 3;
var modernDeploymentBackfillEnabled = _remoteConfigService?.CurrentConfig?.Collectors?.ModernDeploymentBackfillEnabled ?? true;
var modernDeploymentBackfillLookbackMinutes = _remoteConfigService?.CurrentConfig?.Collectors?.ModernDeploymentBackfillLookbackMinutes ?? 30;
_espAndHelloTracker = new EspAndHelloTracker(
_configuration.SessionId,
_configuration.TenantId,
@@ -535,7 +537,10 @@ namespace AutopilotMonitor.Agent.Core.Monitoring.Core
_logger,
helloTimeout,
modernDeploymentWatcherEnabled: modernDeploymentEnabled,
modernDeploymentLogLevelMax: modernDeploymentLevelMax
modernDeploymentLogLevelMax: modernDeploymentLevelMax,
modernDeploymentBackfillEnabled: modernDeploymentBackfillEnabled,
modernDeploymentBackfillLookbackMinutes: modernDeploymentBackfillLookbackMinutes,
stateDirectory: @"%ProgramData%\AutopilotMonitor\State"
);
_espAndHelloTracker.Start();
@@ -323,6 +323,23 @@ namespace AutopilotMonitor.Shared.Models
/// </summary>
public int ModernDeploymentLogLevelMax { get; set; } = 3;
/// <summary>
/// Enable backfill for targeted ModernDeployment events (e.g. Event 509 / WhiteGlove start)
/// that may have been written before the agent started during OOBE.
/// Uses EventLogReader to scan the event log for recent occurrences on startup.
/// Default: true
/// </summary>
public bool ModernDeploymentBackfillEnabled { get; set; } = true;
/// <summary>
/// Lookback window in minutes for the ModernDeployment backfill scan.
/// Only events within this window are considered. Set generously because the
/// gap between WhiteGlove initiation and MDM enroll (when the agent starts)
/// can be 5–15 minutes depending on TPM attestation and disk encryption setup.
/// Default: 30 minutes.
/// </summary>
public int ModernDeploymentBackfillLookbackMinutes { get; set; } = 30;
/// <summary>
/// Creates default collector configuration
/// </summary>