From 6d8a5d9ad78e6ddffadd4ebedfa67946cc380ee3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B8ren=20Eggert=20Lundsteen=20Olsen?= Date: Fri, 2 Oct 2026 15:57:46 +0200 Subject: [PATCH] Review 1.5: a Windows server that hangs no longer holds up the agent; reads are bounded and backed off MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Deadlines - Event log over RPC (MS-EVEN6): the whole read has a deadline (OperationTimeout per log); the token cancels the EventLogSession's operations and is checked before each FormatDescription, and the agent stops waiting even if the native call ignores it. Reported as ServerAccessProblem.Timeout ("svarede ikke i tide over hændelsesloggens protokol (RPC) inden for N sekunder"). - Every CIM call runs on the thread pool and is awaited with the caller's token; a call that ignores cancellation is abandoned and the CIM session is closed once it returns. - Each server cycle has a deadline (new SQLInsight:Servers:CycleTimeout, default 5 min, 1-30 min, at least 2 x OperationTimeout): the areas not read by then are "ikke målbar" ("Serveren svarede ikke inden for N minutter, så indsamlingen blev afbrudt; …"), logged once, and the slot is freed. - Scheduled tasks: run information is read within a time budget (CycleTimeout / 3); the rest keep their state without the last run, and the coverage note says so. - "Test server" has an overall deadline (WindowsServerTester, default 2 min); areas not done in time are reported as not answered, so the result is always stored. Backoff and memory - A server that does not answer (Unreachable/Timeout, or a timed-out cycle) is backed off 1, 2, 5, 10, then 15 minutes, reset when it answers. - Protocol Auto: the protocol that worked (e.g. DCOM after WS-Man was refused, also for access denied) is tried first for an hour, then WS-Man is tried again; a server whose event log RPC failed is read over CIM for an hour. - Over WS-Man with read-only WinRM rights Task Scheduler's GetInfoByName is denied: with Auto the tasks are read over DCOM instead (remembered for the server); with WSMan forced the reason says to choose Auto or DCOM. The advice "winrm configSDDL default" (broader WinRM rights) is gone; texts follow the grant script (-WinRM read right, -EnableFirewall -AgentAddress), not Remote Management Users. Events - Each log continues from its own mark (ServerEventSnapshot.LogReadUntil, a small additive field in Core): a truncated System log no longer loses the events between its last read event and the newest Application event. - CIM fallback: Win32_NTLogEvent is streamed and only the oldest max per log are kept (memory bounded, deterministic order), consistent with the RPC read and the coverage text, which now names the logs that had more. Other - CimInstances (and method results) are mapped to SQLInsight's types and disposed at once. - Options are clamped when bound (ServerOptions/SyntheticCheckOptions.Normalize): OperationTimeout 5 s-5 min, MaxEventsPerCollection 10-10000, MaxWatched 1-200, MaxParallelServers/Checks 1-32, retention days >= 1, ForecastHistoryDays 1-365, FailuresBeforeFinding/SlowRunsBeforeFinding 1-99. - Shutdown: the timer's cancellation is caught, running cycles are awaited before the throttle is disposed; a cycle's time is taken when it gets its slot; a TaskCanceledException that is not shutdown no longer ends the service. - Retention maintenance also runs (hourly) when SQLInsight:Servers:Enabled is false but synthetic checks are on. - LocalCimTests run alone (collection without parallelization), share one warmed-up session, use the same 2 min operation timeout and a 5 min deadline per test, a smaller workload, and report timings in assertion messages. Co-Authored-By: Claude Opus 5.5 (1M context) --- src/SQLInsight.Agent/Servers/ServerMonitor.cs | 143 +++- .../Servers/ServerMonitoringService.cs | 151 ++-- src/SQLInsight.Agent/Servers/ServerOptions.cs | 63 +- .../Servers/ServerServices.cs | 4 +- src/SQLInsight.Core/Servers/ServerEvents.cs | 3 + .../CimWindowsServerSource.cs | 644 +++++++++++++----- src/SQLInsight.Servers/ServerErrors.cs | 8 +- src/SQLInsight.Servers/ServerHostMemory.cs | 49 ++ src/SQLInsight.Servers/WindowsServerAccess.cs | 31 +- src/SQLInsight.Servers/WindowsServerTester.cs | 42 +- .../ServerAgentOptionsTests.cs | 114 ++++ .../ServerAgentTests.cs | 48 +- .../SQLInsight.Servers.Tests/LocalCimTests.cs | 160 +++-- .../ServerAccessTests.cs | 5 +- .../ServerDeadlineTests.cs | 124 ++++ 15 files changed, 1302 insertions(+), 287 deletions(-) create mode 100644 src/SQLInsight.Servers/ServerHostMemory.cs create mode 100644 tests/SQLInsight.Agent.Tests/ServerAgentOptionsTests.cs create mode 100644 tests/SQLInsight.Servers.Tests/ServerDeadlineTests.cs diff --git a/src/SQLInsight.Agent/Servers/ServerMonitor.cs b/src/SQLInsight.Agent/Servers/ServerMonitor.cs index 348196e..dff4a90 100644 --- a/src/SQLInsight.Agent/Servers/ServerMonitor.cs +++ b/src/SQLInsight.Agent/Servers/ServerMonitor.cs @@ -37,18 +37,42 @@ public sealed partial class ServerMonitor( private DateTimeOffset _nextEvaluation = DateTimeOffset.MinValue; private bool _seeded; private bool? _wasReachable; + private int _failures; + private DateTimeOffset _retryAt = DateTimeOffset.MinValue; public WindowsServerRow Server { get; private set; } = server; public int ServerId => Server.ServerId; + /// A server that did not answer is not tried again before this (backing off: 1, 2, 5, 10, then every 15 minutes). + public DateTimeOffset RetryAt => _retryAt; + /// The configuration changed in SQLInsight Web (role, watch lists): used from the next cycle. public void Update(WindowsServerRow row) => Server = row; - public bool IsDue(DateTimeOffset now) => ServerArea.All.Any(a => !_nextDue.TryGetValue(a, out var due) || due <= now); + public bool IsDue(DateTimeOffset now) => now >= _retryAt && ServerArea.All.Any(a => !_nextDue.TryGetValue(a, out var due) || due <= now); + /// How long to wait after the th failure in a row to reach a server. + public static TimeSpan Backoff(int failures) => TimeSpan.FromMinutes(failures switch + { + <= 1 => 1, + 2 => 2, + 3 => 5, + 4 => 10, + _ => 15, + }); + + /// + /// Reads the due areas over one session, within : what is not done by then is + /// "ikke målbar" this time (logged once), and the server is backed off like one that does not answer. + /// public async Task RunCycleAsync(DateTimeOffset now, CancellationToken cancellationToken) { + if (now < _retryAt) + { + return; + } + var due = ServerArea.All.Where(a => !_nextDue.TryGetValue(a, out var at) || at <= now).ToList(); if (due.Count == 0) { @@ -60,6 +84,22 @@ public sealed partial class ServerMonitor( _nextDue[area] = now + options.IntervalOf(area); } + using var deadline = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + deadline.CancelAfter(options.CycleTimeout); + var pending = new List(due); + try + { + await RunDueAsync(due, pending, now, deadline.Token).ConfigureAwait(false); + } + catch (Exception) when (deadline.IsCancellationRequested && !cancellationToken.IsCancellationRequested) + { + // The deadline, not the agent stopping (the repository may also report it as its own error). + await CycleTimedOutAsync(pending, now, cancellationToken).ConfigureAwait(false); + } + } + + private async Task RunDueAsync(IReadOnlyList due, List pending, DateTimeOffset now, CancellationToken cancellationToken) + { if (!_seeded) { await SeedAsync(now, cancellationToken).ConfigureAwait(false); @@ -73,12 +113,15 @@ public sealed partial class ServerMonitor( } catch (ServerAccessException ex) { + pending.Clear(); await NotReachableAsync(ex, due, now, cancellationToken).ConfigureAwait(false); return; } using (session) { + _failures = 0; + _retryAt = DateTimeOffset.MinValue; if (_wasReachable == false) { await NotifyAsync([NotificationFactory.Recovered(Server.Name, webUrl, now) with { Url = ServerNotifications.ServerPage(webUrl, ServerId) }], cancellationToken) @@ -90,8 +133,10 @@ public sealed partial class ServerMonitor( foreach (var area in due) { await CollectAsync(session, area, now, cancellationToken).ConfigureAwait(false); + pending.Remove(area); } + _reported.Remove("cycle"); if (due.Any(a => a != ServerArea.Performance) || now >= _nextEvaluation) { _nextEvaluation = now + EvaluationInterval; @@ -100,7 +145,38 @@ public sealed partial class ServerMonitor( } } - /// Unreachable: recorded and notified once. Refused by rights at the door: every area is "ikke målbar" with the reason. + /// The round ran out of time: the areas not read are "ikke målbar" with the reason, and the server is backed off. + private async Task CycleTimedOutAsync(List pending, DateTimeOffset now, CancellationToken cancellationToken) + { + var minutes = options.CycleTimeout.TotalMinutes.ToString("0.#", System.Globalization.CultureInfo.GetCultureInfo("da-DK")); + var reason = $"Serveren svarede ikke inden for {minutes} minutter, så indsamlingen blev afbrudt; området læses igen ved næste indsamling."; + if (Report("cycle", reason + string.Join(",", pending))) + { + LogCycleTimedOut(logger, Server.Name, options.CycleTimeout, string.Join(", ", pending)); + } + + if (pending.Count == 0) + { + return; + } + + Failed(now); + foreach (var area in pending) + { + Unavailable(area, reason); + } + + _nextEvaluation = now + EvaluationInterval; + await EvaluateAsync(now, cancellationToken).ConfigureAwait(false); + } + + private void Failed(DateTimeOffset now) + { + _failures++; + _retryAt = now + Backoff(_failures); + } + + /// Unreachable: recorded and notified once, and backed off. Refused by rights at the door: every area is "ikke målbar" with the reason. private async Task NotReachableAsync(ServerAccessException ex, IReadOnlyList due, DateTimeOffset now, CancellationToken cancellationToken) { if (Report("connect", ex.Message)) @@ -108,6 +184,12 @@ public sealed partial class ServerMonitor( LogNotReachable(logger, Server.Name, ex.Message); } + if (ex.Problem is ServerAccessProblem.Unreachable or ServerAccessProblem.Timeout) + { + // A server that does not answer costs a timeout per protocol: not every minute. + Failed(now); + } + await repository.RecordServerErrorAsync(ServerId, ex.Message, now, cancellationToken).ConfigureAwait(false); if (ex.Problem is ServerAccessProblem.AccessDenied or ServerAccessProblem.NotSupported) { @@ -259,44 +341,74 @@ public sealed partial class ServerMonitor( return $"{services.Count} tjenester"; } - /// The first time, the last day is read, so recent problems show at once; then from where the last read stopped. + /// + /// The first time, the last day is read, so recent problems show at once; then each log from where its last read + /// stopped, so a log that had more than could be read loses nothing while the other log keeps up. + /// public async Task CollectEventsAsync(IWindowsServerSession session, DateTimeOffset now, CancellationToken cancellationToken) { ArgumentNullException.ThrowIfNull(session); - var since = _events?.ReadUntil ?? now - ServerEventAnalysis.RecentWindow; - var read = await session.GetEventsAsync(since, Math.Max(10, options.EventLog.MaxEventsPerCollection), cancellationToken).ConfigureAwait(false); + var max = Math.Max(10, options.EventLog.MaxEventsPerCollection); + var since = ServerEventAnalysis.Logs.ToDictionary(log => log, log => EventsReadUntil(_events, log, now), StringComparer.OrdinalIgnoreCase); + var read = await session.GetEventsAsync(since, max, cancellationToken).ConfigureAwait(false); var (groups, ignored) = ServerEventAnalysis.Group(read.Entries, ServerEventAnalysis.DefaultIgnore.Concat(options.EventLog.Ignore)); + var logReadUntil = NextReadUntil(read, since, now); + var truncated = ServerEventAnalysis.Logs.Where(read.IsTruncated).ToList(); + var coverage = new List(); + if (truncated.Count > 0) + { + coverage.Add($"Der var flere end {max} hændelser i {string.Join(" og ", truncated)} siden sidst; resten læses ved næste indsamling."); + } + + if (read.Note is { } note) + { + coverage.Add(note); + } - // Strictly after the newest event read; without events, keep ten minutes' margin for events written late. - var readUntil = read.Entries.Count > 0 ? read.Entries.Max(e => e.At) : Max(since, now.AddMinutes(-10)); var snapshot = new ServerEventSnapshot { CapturedAt = now, - ReadUntil = readUntil, + ReadUntil = logReadUntil.Values.Min(), + LogReadUntil = logReadUntil, Method = read.Method, Groups = groups, Recent = ServerEventAnalysis.Recent(_events?.Recent ?? [], groups, now), Ignored = ignored, - Coverage = read.Truncated - ? $"Der var flere end {options.EventLog.MaxEventsPerCollection} hændelser i en log siden sidst; resten læses ved næste indsamling." - : read.Note, + Coverage = coverage.Count == 0 ? null : string.Join(" ", coverage), }; _events = snapshot; _data.Set(snapshot); await repository.SaveServerEventsAsync(ServerId, snapshot, cancellationToken).ConfigureAwait(false); await repository.SaveServerSnapshotAsync(ServerId, ServerArea.Events, snapshot with { Groups = [] }, now, cancellationToken).ConfigureAwait(false); return $"{read.Entries.Count} hændelser ({read.Method})"; - - static DateTimeOffset Max(DateTimeOffset a, DateTimeOffset b) => a > b ? a : b; } + /// Where a log's next read starts: its own mark, else the snapshot's (from before per-log marks), else a day back. + public static DateTimeOffset EventsReadUntil(ServerEventSnapshot? previous, string log, DateTimeOffset now) => + previous?.LogReadUntil?.FirstOrDefault(m => string.Equals(m.Key, log, StringComparison.OrdinalIgnoreCase)) is { Key: not null } mark ? mark.Value + : previous?.ReadUntil ?? now - ServerEventAnalysis.RecentWindow; + + /// + /// Per log: strictly after the newest event read (for a log that had more, that is where its rest starts); without + /// events, ten minutes' margin for events written late. + /// + public static Dictionary NextReadUntil(ServerEventRead read, IReadOnlyDictionary since, DateTimeOffset now) => + ServerEventAnalysis.Logs.ToDictionary(log => log, log => + { + var from = since[log]; + var newest = read.Entries.Where(e => string.Equals(e.Log, log, StringComparison.OrdinalIgnoreCase)).Select(e => (DateTimeOffset?)e.At).Max(); + return newest is { } at ? Max(at, from) : Max(from, now.AddMinutes(-10)); + }, StringComparer.Ordinal); + + private static DateTimeOffset Max(DateTimeOffset a, DateTimeOffset b) => a > b ? a : b; + public async Task CollectTasksAsync(IWindowsServerSession session, DateTimeOffset now, CancellationToken cancellationToken) { ArgumentNullException.ThrowIfNull(session); var tasks = options.Tasks; var read = await session.GetTasksAsync( tasks.Watches, - Math.Max(1, tasks.MaxWatched), cancellationToken).ConfigureAwait(false); + Math.Max(1, tasks.MaxWatched), options.TaskBudget, cancellationToken).ConfigureAwait(false); var snapshot = new ServerTaskSnapshot { CapturedAt = now, Tasks = read.Watched, Visible = read.Visible, Coverage = read.Note }; _data.Set(snapshot); await repository.SaveServerSnapshotAsync(ServerId, ServerArea.Tasks, snapshot, now, cancellationToken).ConfigureAwait(false); @@ -338,6 +450,9 @@ public sealed partial class ServerMonitor( } } + [LoggerMessage(Level = LogLevel.Warning, Message = "Windows server {Server} did not finish within {Timeout}; not read this time: {Areas}")] + private static partial void LogCycleTimedOut(ILogger logger, string server, TimeSpan timeout, string areas); + [LoggerMessage(Level = LogLevel.Warning, Message = "Windows server {Server} cannot be read: {Reason}")] private static partial void LogNotReachable(ILogger logger, string server, string reason); diff --git a/src/SQLInsight.Agent/Servers/ServerMonitoringService.cs b/src/SQLInsight.Agent/Servers/ServerMonitoringService.cs index b3f6fa4..7d3d8a4 100644 --- a/src/SQLInsight.Agent/Servers/ServerMonitoringService.cs +++ b/src/SQLInsight.Agent/Servers/ServerMonitoringService.cs @@ -9,7 +9,8 @@ namespace SQLInsight.Agent.Servers; /// /// The agent's loop for Windows servers: keeps the SQL Server hosts in step with the monitored instances, reads the /// configured servers (changes in SQLInsight Web apply within a minute, without a restart), runs each server's due -/// areas with a limit on how many at once, and deletes old samples hourly. +/// areas with a limit on how many at once, and deletes old samples and check results hourly (also when only the +/// synthetic checks are on). /// public sealed partial class ServerMonitoringService( IOptions options, @@ -25,6 +26,8 @@ public sealed partial class ServerMonitoringService( { public static readonly TimeSpan RefreshInterval = TimeSpan.FromMinutes(1); + public static readonly TimeSpan MaintenanceInterval = TimeSpan.FromHours(1); + private readonly ILogger _logger = loggerFactory.CreateLogger(); protected override async Task ExecuteAsync(CancellationToken stoppingToken) @@ -33,64 +36,126 @@ public sealed partial class ServerMonitoringService( if (!settings.Enabled) { LogDisabled(_logger); + if (checkOptions.Value.Enabled) + { + // The synthetic checks keep writing results: their retention still applies. + await MaintainOnlyAsync(settings, stoppingToken).ConfigureAwait(false); + } + return; } await readiness.Ready.WaitAsync(stoppingToken).ConfigureAwait(false); var monitors = new Dictionary(); var running = new Dictionary(); - using var throttle = new SemaphoreSlim(Math.Max(1, settings.MaxParallelServers)); + using var throttle = new SemaphoreSlim(Math.Clamp(settings.MaxParallelServers, 1, 32)); var nextRefresh = DateTimeOffset.MinValue; var nextMaintenance = time.GetUtcNow().AddMinutes(5); using var timer = new PeriodicTimer(agentOptions.Value.Tick, time); - do + try { - var now = time.GetUtcNow(); - try + do { - if (now >= nextRefresh) + var now = time.GetUtcNow(); + try { - nextRefresh = now + RefreshInterval; - await RefreshAsync(monitors, settings, now, stoppingToken).ConfigureAwait(false); - } - - foreach (var (id, monitor) in monitors) - { - if (running.TryGetValue(id, out var task) && !task.IsCompleted || !monitor.IsDue(now)) + if (now >= nextRefresh) { - continue; + nextRefresh = now + RefreshInterval; + await RefreshAsync(monitors, settings, now, stoppingToken).ConfigureAwait(false); } - running[id] = RunThrottledAsync(monitor, now, throttle, stoppingToken); - } - - foreach (var done in running.Where(r => r.Value.IsCompleted && !monitors.ContainsKey(r.Key)).Select(r => r.Key).ToList()) - { - running.Remove(done); - } - - if (now >= nextMaintenance) - { - nextMaintenance = now.AddHours(1); - await repository.RunServerMaintenanceAsync(new ServerRetention + foreach (var (id, monitor) in monitors) { - SampleDays = settings.SampleDays, - DiskHistoryDays = Math.Max(settings.DiskHistoryDays, settings.Disks.ForecastHistoryDays + 1), - EventDays = settings.EventDays, - CheckResultDays = checkOptions.Value.ResultDays, - ResolvedFindingDays = agentOptions.Value.Retention.ResolvedFindingDays, - }, now, stoppingToken).ConfigureAwait(false); + if (running.TryGetValue(id, out var task) && !task.IsCompleted || !monitor.IsDue(now)) + { + continue; + } + + running[id] = RunThrottledAsync(monitor, throttle, stoppingToken); + } + + foreach (var done in running.Where(r => r.Value.IsCompleted && !monitors.ContainsKey(r.Key)).Select(r => r.Key).ToList()) + { + running.Remove(done); + } + + if (now >= nextMaintenance) + { + nextMaintenance = now + MaintenanceInterval; + await MaintainAsync(settings, now, stoppingToken).ConfigureAwait(false); + } + } + catch (Exception ex) when (!stoppingToken.IsCancellationRequested) + { + // Typically the repository is unreachable. Try again next round. + LogRoundFailed(_logger, ex); } } - catch (Exception ex) when (ex is not OperationCanceledException) + while (await timer.WaitForNextTickAsync(stoppingToken).ConfigureAwait(false)); + } + catch (OperationCanceledException) when (stoppingToken.IsCancellationRequested) + { + // Stopping: the running cycles end below, before the throttle they release is disposed. + } + + await WaitQuietlyAsync(running.Values).ConfigureAwait(false); + } + + /// Servers off, synthetic checks on: only the hourly maintenance. + private async Task MaintainOnlyAsync(ServerOptions settings, CancellationToken stoppingToken) + { + try + { + await readiness.Ready.WaitAsync(stoppingToken).ConfigureAwait(false); + using var timer = new PeriodicTimer(MaintenanceInterval, time); + do { - // Typically the repository is unreachable. Try again next round. - LogRoundFailed(_logger, ex); + try + { + await MaintainAsync(settings, time.GetUtcNow(), stoppingToken).ConfigureAwait(false); + } + catch (Exception ex) when (!stoppingToken.IsCancellationRequested) + { + LogRoundFailed(_logger, ex); + } + } + while (await timer.WaitForNextTickAsync(stoppingToken).ConfigureAwait(false)); + } + catch (OperationCanceledException) when (stoppingToken.IsCancellationRequested) + { + // Stopping. + } + } + + /// Deletes what is past retention, in small batches; every period is at least a day (see ). + private Task MaintainAsync(ServerOptions settings, DateTimeOffset now, CancellationToken cancellationToken) => + repository.RunServerMaintenanceAsync(new ServerRetention + { + SampleDays = Math.Max(1, settings.SampleDays), + DiskHistoryDays = Math.Max(Math.Max(1, settings.DiskHistoryDays), settings.Disks.ForecastHistoryDays + 1), + EventDays = Math.Max(1, settings.EventDays), + CheckResultDays = Math.Max(1, checkOptions.Value.ResultDays), + ResolvedFindingDays = Math.Max(1, agentOptions.Value.Retention.ResolvedFindingDays), + }, now, cancellationToken); + + /// + /// Waits, when the agent stops, for tasks that end with it: a cancellation (or the error a cancelled database call + /// reports instead) is how they end, not news. + /// + internal static async Task WaitQuietlyAsync(IEnumerable tasks) + { + foreach (var task in tasks) + { + try + { + await task.ConfigureAwait(false); + } + catch (Exception ex) when (ex is OperationCanceledException or System.Data.Common.DbException) + { + // Stopping. } } - while (await timer.WaitForNextTickAsync(stoppingToken).ConfigureAwait(false)); - - await Task.WhenAll(running.Values).ConfigureAwait(false); } /// The SQL Server hosts first, then the servers to look at (not paused). @@ -128,14 +193,18 @@ public sealed partial class ServerMonitoringService( } } - private async Task RunThrottledAsync(ServerMonitor monitor, DateTimeOffset now, SemaphoreSlim throttle, CancellationToken cancellationToken) + /// + /// One server's cycle when a slot is free, with the time taken then (not when it was queued). The cycle bounds + /// itself (), so a hung server gives its slot back. + /// + private async Task RunThrottledAsync(ServerMonitor monitor, SemaphoreSlim throttle, CancellationToken cancellationToken) { await throttle.WaitAsync(cancellationToken).ConfigureAwait(false); try { - await monitor.RunCycleAsync(now, cancellationToken).ConfigureAwait(false); + await monitor.RunCycleAsync(time.GetUtcNow(), cancellationToken).ConfigureAwait(false); } - catch (Exception ex) when (ex is not OperationCanceledException) + catch (Exception ex) when (!cancellationToken.IsCancellationRequested) { LogCycleFailed(_logger, ex, monitor.Server.Name); } diff --git a/src/SQLInsight.Agent/Servers/ServerOptions.cs b/src/SQLInsight.Agent/Servers/ServerOptions.cs index 393197b..c64fca7 100644 --- a/src/SQLInsight.Agent/Servers/ServerOptions.cs +++ b/src/SQLInsight.Agent/Servers/ServerOptions.cs @@ -1,4 +1,5 @@ using SQLInsight.Core.Servers; +using SQLInsight.Core.SyntheticChecks; using SQLInsight.Notifications; using SQLInsight.Repository; using SQLInsight.Rules.Servers; @@ -11,40 +12,71 @@ public sealed class ServerOptions : ServerRuleSettings { public const string SectionName = "SQLInsight:Servers"; + public static readonly TimeSpan MinCycleTimeout = TimeSpan.FromMinutes(1); + public static readonly TimeSpan MaxCycleTimeout = TimeSpan.FromMinutes(30); + /// Look at Windows servers at all. public bool Enabled { get; set; } = true; /// The computers behind the monitored SQL Server instances are Windows servers too, without being added. public bool IncludeSqlHosts { get; set; } = true; - /// How many servers are read at the same time. + /// How many servers are read at the same time (1 to 32). public int MaxParallelServers { get; set; } = 4; /// Auto (WS-Man, then DCOM), WSMan or DCOM. public string Protocol { get; set; } = "Auto"; - /// How long one CIM operation may take. + /// How long one CIM operation may take (5 seconds to 5 minutes). public TimeSpan OperationTimeout { get; set; } = TimeSpan.FromSeconds(30); + /// + /// How long one server's round may take at most (1 to 30 minutes, at least twice ): what is + /// not read by then is "ikke målbar" until the next round, so a server that hangs never holds up the others. + /// + public TimeSpan CycleTimeout { get; set; } = TimeSpan.FromMinutes(5); + /// Read event logs with the Event Log service's own protocol (filters on the server); off: CIM only. public bool EventLogRpc { get; set; } = true; /// Overrides of the collection intervals by area: performance, disks, services, events, tasks. public IDictionary Intervals { get; } = new Dictionary(StringComparer.OrdinalIgnoreCase); - /// Per-minute CPU and memory samples. + /// Per-minute CPU and memory samples (at least 1 day). public int SampleDays { get; set; } = 14; /// Free space per volume: at least the forecast's history. public int DiskHistoryDays { get; set; } = 35; - /// Grouped Windows events. + /// Grouped Windows events (at least 1 day). public int EventDays { get; set; } = 90; + /// The share of the scheduled tasks' run information may take; the rest is read next time. + public TimeSpan TaskBudget => CycleTimeout / 3; + public TimeSpan IntervalOf(string area) => Intervals.TryGetValue(area, out var interval) && interval >= TimeSpan.FromSeconds(30) ? interval : ServerArea.DefaultInterval(area); public ServerConnectionOptions Connection => new() { Protocol = Protocol, OperationTimeout = OperationTimeout, EventLogRpc = EventLogRpc }; + + /// + /// Keeps the settings within what works: a timeout of 0 or hours, retention of 0 days (maintenance would delete + /// everything) or unbounded parallelism are moved to the nearest sensible value. Applied when the options are bound. + /// + public ServerOptions Normalize() + { + MaxParallelServers = Math.Clamp(MaxParallelServers, 1, 32); + OperationTimeout = ServerConnectionOptions.BoundTimeout(OperationTimeout); + var cycle = CycleTimeout < OperationTimeout * 2 ? OperationTimeout * 2 : CycleTimeout; + CycleTimeout = cycle < MinCycleTimeout ? MinCycleTimeout : cycle > MaxCycleTimeout ? MaxCycleTimeout : cycle; + SampleDays = Math.Max(1, SampleDays); + DiskHistoryDays = Math.Max(1, DiskHistoryDays); + EventDays = Math.Max(1, EventDays); + Disks.ForecastHistoryDays = Math.Clamp(Disks.ForecastHistoryDays, 1, 365); + EventLog.MaxEventsPerCollection = Math.Clamp(EventLog.MaxEventsPerCollection, 10, 10000); + Tasks.MaxWatched = Math.Clamp(Tasks.MaxWatched, 1, 200); + return this; + } } /// Synthetic checks (SQLInsight:SyntheticChecks): how many run at once, how long results are kept, and the rules' thresholds. @@ -52,15 +84,36 @@ public sealed class SyntheticCheckOptions : SyntheticCheckRuleSettings { public const string SectionName = "SQLInsight:SyntheticChecks"; + /// The most recent results the rules look at: enough for "fejlet i træk", never unbounded. + public const int MaxRecentResults = 100; + public bool Enabled { get; set; } = true; + /// How many checks run at the same time (1 to 32). public int MaxParallelChecks { get; set; } = 4; - /// Every run's result. + /// Every run's result (at least 1 day). public int ResultDays { get; set; } = 14; /// Where the Dynamics AX .NET Business Connector is, when not where the AX installer puts it. public string? BusinessConnectorPath { get; set; } + + /// How many recent results the rules are given: more than they need to count failures or slow runs in a row. + public int RecentResults => Math.Clamp(Math.Max(10, Math.Max(FailuresBeforeFinding, SlowRunsBeforeFinding)) + 1, 11, MaxRecentResults); + + /// Keeps the settings within what works (see ). Applied when the options are bound. + public SyntheticCheckOptions Normalize() + { + MaxParallelChecks = Math.Clamp(MaxParallelChecks, 1, 32); + ResultDays = Math.Max(1, ResultDays); + FailuresBeforeFinding = Math.Clamp(FailuresBeforeFinding, 1, MaxRecentResults - 1); + SlowRunsBeforeFinding = Math.Clamp(SlowRunsBeforeFinding, 1, MaxRecentResults - 1); + return this; + } + + /// A check's interval as the agent runs it: never more often than . + public static TimeSpan IntervalOf(int intervalSeconds) => + TimeSpan.FromSeconds(Math.Clamp(intervalSeconds, SyntheticCheckLimits.MinIntervalSeconds, SyntheticCheckLimits.MaxIntervalSeconds)); } /// Notifications about Windows servers and synthetic checks, with links to their pages in the web UI. diff --git a/src/SQLInsight.Agent/Servers/ServerServices.cs b/src/SQLInsight.Agent/Servers/ServerServices.cs index 7c155d9..ff16688 100644 --- a/src/SQLInsight.Agent/Servers/ServerServices.cs +++ b/src/SQLInsight.Agent/Servers/ServerServices.cs @@ -14,8 +14,10 @@ public static class ServerServices ArgumentNullException.ThrowIfNull(configuration); services.Configure(configuration.GetSection(ServerOptions.SectionName)); services.Configure(configuration.GetSection(SyntheticCheckOptions.SectionName)); + services.PostConfigure(o => o.Normalize()); + services.PostConfigure(o => o.Normalize()); services.AddSingleton(sp => OperatingSystem.IsWindows() - ? new CimWindowsServerSource(sp.GetRequiredService>().Value.Connection) + ? new CimWindowsServerSource(sp.GetRequiredService>().Value.Connection, sp.GetRequiredService()) : new UnsupportedWindowsServerSource()); services.AddSingleton(sp => new BusinessConnectorLocator(sp.GetRequiredService>().Value.BusinessConnectorPath)); services.AddSingleton(); diff --git a/src/SQLInsight.Core/Servers/ServerEvents.cs b/src/SQLInsight.Core/Servers/ServerEvents.cs index be31c36..81a8e38 100644 --- a/src/SQLInsight.Core/Servers/ServerEvents.cs +++ b/src/SQLInsight.Core/Servers/ServerEvents.cs @@ -53,6 +53,9 @@ public sealed record ServerEventSnapshot /// The newest event read; the next collection continues after it. public required DateTimeOffset ReadUntil { get; init; } + /// Per log, where the next collection continues (a log that had more than could be read continues from its own last event). + public IReadOnlyDictionary? LogReadUntil { get; init; } + /// How the log was read: "Event Log (RPC)" or "CIM (Win32_NTLogEvent)". public string? Method { get; init; } diff --git a/src/SQLInsight.Servers/CimWindowsServerSource.cs b/src/SQLInsight.Servers/CimWindowsServerSource.cs index cd2cfdc..7537264 100644 --- a/src/SQLInsight.Servers/CimWindowsServerSource.cs +++ b/src/SQLInsight.Servers/CimWindowsServerSource.cs @@ -12,31 +12,80 @@ namespace SQLInsight.Servers; /// How the agent connects to Windows servers (SQLInsight:Servers in the agent's appsettings.json). public sealed class ServerConnectionOptions { + public static readonly TimeSpan MinOperationTimeout = TimeSpan.FromSeconds(5); + public static readonly TimeSpan MaxOperationTimeout = TimeSpan.FromMinutes(5); + /// Auto (WS-Man, then DCOM), WSMan or DCOM. public string Protocol { get; set; } = "Auto"; - /// How long one CIM operation may take. + /// How long one CIM operation may take (5 seconds to 5 minutes). public TimeSpan OperationTimeout { get; set; } = TimeSpan.FromSeconds(30); /// Read event logs with the Event Log service's own protocol (MS-EVEN6), which filters on the server; CIM (Win32_NTLogEvent) is the fallback. public bool EventLogRpc { get; set; } = true; + + /// within 5 seconds and 5 minutes: 0, negative or hours would fail or hang every read. + public static TimeSpan BoundTimeout(TimeSpan timeout) => + timeout < MinOperationTimeout ? MinOperationTimeout : timeout > MaxOperationTimeout ? MaxOperationTimeout : timeout; } /// /// Reads Windows servers with CIM: WS-Man (WinRM, TCP 5985) first, DCOM (RPC, TCP 135 + dynamic ports) if that fails, /// as the agent's own Windows identity. Only queries (and Task Scheduler's GetInfo) are used: nothing is changed. +/// What worked for a server (DCOM instead of WS-Man, CIM instead of the event log's RPC protocol) is remembered for an +/// hour, so a refused protocol is not tried again every cycle. /// [SupportedOSPlatform("windows")] -public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IWindowsServerSource +public sealed class CimWindowsServerSource : IWindowsServerSource { + public const string WsMan = "WS-Man"; + public const string Dcom = "DCOM"; + + private const string ProtocolFact = "protocol"; + private const string EventLogRpcFact = "eventlog-rpc"; + private const string TasksOverDcomFact = "tasks-dcom"; + + private readonly ServerConnectionOptions _options; + private readonly string[] _protocols; + private readonly TimeProvider _time; + + public CimWindowsServerSource(ServerConnectionOptions options, TimeProvider? time = null) + { + ArgumentNullException.ThrowIfNull(options); + _options = new ServerConnectionOptions + { + Protocol = options.Protocol, + OperationTimeout = ServerConnectionOptions.BoundTimeout(options.OperationTimeout), + EventLogRpc = options.EventLogRpc, + }; + _protocols = (options.Protocol ?? "Auto").ToUpperInvariant() switch + { + "WSMAN" or "WS-MAN" => [WsMan], + "DCOM" => [Dcom], + _ => [WsMan, Dcom], + }; + _time = time ?? TimeProvider.System; + Memory = new ServerHostMemory(_time, ServerHostMemory.DefaultFor); + } + + /// What was learned per server (the protocol that works, a blocked event log protocol). + public ServerHostMemory Memory { get; } + + /// Both protocols may be used (Protocol Auto). + private bool Auto => _protocols.Length > 1; + + /// The longest one read of the event logs may take: one operation per log. + private TimeSpan EventReadTimeout => _options.OperationTimeout * ServerEventAnalysis.Logs.Count; + + private sealed record WorkingProtocol(string Protocol, string? Note); + public async Task ConnectAsync(string host, CancellationToken cancellationToken) { ArgumentException.ThrowIfNullOrWhiteSpace(host); var account = AgentAccount(host); if (ServerHost.IsLocal(host, Environment.MachineName)) { - var local = CimSession.Create(null); - var session = new Session(local, host, "lokal", null, account, options); + var session = new Session(this, CimSession.Create(null), host, "lokal", null, account); try { await session.ProbeAsync(cancellationToken).ConfigureAwait(false); @@ -49,23 +98,28 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW } } - var protocols = options.Protocol.ToUpperInvariant() switch - { - "WSMAN" or "WS-MAN" => new[] { "WS-Man" }, - "DCOM" => ["DCOM"], - _ => ["WS-Man", "DCOM"], - }; + // The protocol that worked last time first (for an hour), so a refused WS-Man is not waited on every cycle. + var remembered = Auto ? Memory.Recall(host, ProtocolFact) : null; + var protocols = remembered is null ? _protocols : [remembered.Protocol, .. _protocols.Where(p => p != remembered.Protocol)]; var failures = new List(); foreach (var protocol in protocols) { - CimSessionOptions sessionOptions = protocol == "WS-Man" - ? new WSManSessionOptions { Timeout = options.OperationTimeout } - : new DComSessionOptions { Timeout = options.OperationTimeout, PacketPrivacy = true, PacketIntegrity = true }; - var note = failures.Count == 0 ? null : $"{failures[0].Message} Agenten bruger derfor {protocol}."; - var session = new Session(CimSession.Create(host, sessionOptions), host, protocol, note, account, options); + var note = failures.Count > 0 ? $"{failures[0].Message} Agenten bruger derfor {protocol}." + : protocol == remembered?.Protocol ? remembered.Note + : null; + var session = new Session(this, CreateSession(host, protocol), host, protocol, note, account); try { await session.ProbeAsync(cancellationToken).ConfigureAwait(false); + if (Auto && protocol == _protocols[0]) + { + Memory.Forget(host, ProtocolFact); + } + else if (Auto && failures.Count > 0) + { + Memory.Remember(host, ProtocolFact, new WorkingProtocol(protocol, note)); + } + return session; } catch (ServerAccessException ex) @@ -73,6 +127,11 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW session.Dispose(); failures.Add(ex); } + catch + { + session.Dispose(); + throw; + } } // Access denied says more than "does not answer": report that one first. @@ -81,6 +140,14 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW throw new ServerAccessException(best.Problem, string.Join(" ", others.Prepend(best.Message)), best) { Code = best.Code }; } + private CimSession CreateSession(string host, string protocol) + { + using CimSessionOptions sessionOptions = protocol == WsMan + ? new WSManSessionOptions { Timeout = _options.OperationTimeout } + : new DComSessionOptions { Timeout = _options.OperationTimeout, PacketPrivacy = true, PacketIntegrity = true }; + return CimSession.Create(host, sessionOptions); + } + /// The account the agent arrives as on (the computer account for a virtual service account). public static string AgentAccount(string host) => ServerGrantScript.AccountFor(WindowsIdentity.GetCurrent().Name, host, Environment.MachineName, Environment.UserDomainName); @@ -104,75 +171,171 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW internal static string? Text(CimInstance instance, string name) => instance.CimInstanceProperties[name]?.Value?.ToString(); - private sealed class Session(CimSession session, string host, string protocol, string? note, string account, ServerConnectionOptions options) : IWindowsServerSession + /// + /// One server. Every CIM instance is mapped to SQLInsight's own types while it is read, and disposed at once. Native + /// calls run on the thread pool and are awaited with the caller's token, so a server that hangs costs the caller its + /// deadline, never more; the CIM session is closed once such a call has returned. + /// + private sealed class Session(CimWindowsServerSource source, CimSession session, string host, string protocol, string? note, string account) : IWindowsServerSession { + private readonly Lock _lock = new(); + private readonly List _abandoned = []; + private CimSession? _taskSession; + private bool _disposed; + public string Protocol => protocol; public string? ProtocolNote => note; - public void Dispose() => session.Dispose(); + private TimeSpan Timeout => source._options.OperationTimeout; + + public void Dispose() + { + Task[] pending; + lock (_lock) + { + if (_disposed) + { + return; + } + + _disposed = true; + pending = [.. _abandoned.Where(t => !t.IsCompleted)]; + } + + if (pending.Length == 0) + { + Close(); + } + else + { + // A call that ignored its cancellation still uses the session: closing it now could block on the call. + _ = Task.WhenAll(pending).ContinueWith(_ => Close(), CancellationToken.None, TaskContinuationOptions.None, TaskScheduler.Default); + } + + void Close() + { + session.Dispose(); + _taskSession?.Dispose(); + } + } + + /// Runs a blocking native call on the thread pool; stops waiting when is cancelled, even if the call does not. + private async Task RunAsync(Func work, CancellationToken cancellationToken) + { + var task = Task.Run(work, cancellationToken); + try + { + return await task.WaitAsync(cancellationToken).ConfigureAwait(false); + } + catch (OperationCanceledException) when (!task.IsCompleted) + { + Abandon(task); + throw; + } + } + + /// A call no longer waited for: its end is observed (a late error is not left unobserved) and the session outlives it. + private void Abandon(Task task) + { + _ = task.ContinueWith(static t => _ = t.Exception, CancellationToken.None, TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously, + TaskScheduler.Default); + lock (_lock) + { + _abandoned.Add(task); + } + } /// The cheapest query that proves the connection (and the right to root\cimv2). public async Task ProbeAsync(CancellationToken cancellationToken) => - await QueryAsync(CimV2, "SELECT CSName FROM Win32_OperatingSystem", null, cancellationToken).ConfigureAwait(false); + await QueryAsync(CimV2, "SELECT CSName FROM Win32_OperatingSystem", null, _ => true, cancellationToken, limit: 1).ConfigureAwait(false); - private CimOperationOptions Options(CancellationToken cancellationToken) => new() { Timeout = options.OperationTimeout, CancellationToken = cancellationToken }; + private CimOperationOptions Options(CancellationToken cancellationToken) => new() { Timeout = Timeout, CancellationToken = cancellationToken }; - private Task> QueryAsync(string ns, string query, string? area, CancellationToken cancellationToken) => - Task.Run(() => + /// The query's instances mapped by ; at most are read. + private Task> QueryAsync(string ns, string query, string? area, Func map, CancellationToken cancellationToken, int? limit = null) => + RunAsync(() => { - try + var list = new List(); + Read(ns, query, area, instance => { - return session.QueryInstances(ns, "WQL", query, Options(cancellationToken)).ToList(); - } - catch (CimException ex) - { - throw Describe(ex, area); - } - catch (UnauthorizedAccessException ex) - { - throw ServerErrors.Describe(ServerErrors.AccessDenied, "AccessDenied", ex.Message, area, host, account, protocol); - } + list.Add(map(instance)); + return limit is not { } max || list.Count < max; + }, cancellationToken); + return list; }, cancellationToken); - private ServerAccessException Describe(CimException ex, string? area) + /// Streams a query: each instance is handed to (false: stop) and disposed. Blocking. + private void Read(string ns, string query, string? area, Func each, CancellationToken cancellationToken) + { + try + { + using var operation = Options(cancellationToken); + foreach (var instance in session.QueryInstances(ns, "WQL", query, operation)) + { + using (instance) + { + if (!each(instance)) + { + break; + } + } + } + } + catch (CimException ex) + { + throw Describe(ex, area, protocol); + } + catch (UnauthorizedAccessException ex) + { + throw ServerErrors.Describe(ServerErrors.AccessDenied, "AccessDenied", ex.Message, area, host, account, protocol); + } + } + + private ServerAccessException Describe(CimException ex, string? area, string over) { uint? code = ex.ErrorData?.CimInstanceProperties["error_Code"]?.Value is IConvertible c ? Convert.ToUInt32(c, CultureInfo.InvariantCulture) : null; - var error = ServerErrors.Describe(code, ex.NativeErrorCode.ToString(), ex.Message, area, host, account, protocol); + var error = ServerErrors.Describe(code, ex.NativeErrorCode.ToString(), ex.Message, area, host, account, over); return new ServerAccessException(error.Problem, error.Message, ex) { Code = error.Code }; } public async Task GetOperatingSystemAsync(CancellationToken cancellationToken) { - var os = (await QueryAsync(CimV2, OperatingSystemQuery, ServerArea.Performance, cancellationToken).ConfigureAwait(false)).FirstOrDefault() + var os = (await QueryAsync(CimV2, OperatingSystemQuery, ServerArea.Performance, i => new ServerOsInfo + { + Caption = Text(i, "Caption")?.Trim(), + Version = Text(i, "Version"), + BuildNumber = Text(i, "BuildNumber"), + LastBootUpTime = ToOffset(i.CimInstanceProperties["LastBootUpTime"]?.Value), + TotalMemoryMb = UInt64(i, "TotalVisibleMemorySize") is { } kb ? kb / 1024d : null, + ComputerName = Text(i, "CSName"), + }, cancellationToken, limit: 1).ConfigureAwait(false)).FirstOrDefault() ?? throw new ServerAccessException(ServerAccessProblem.Other, $"{host} returnerede intet styresystem (Win32_OperatingSystem)."); int? processors = null; try { - processors = (await QueryAsync(CimV2, ComputerSystemQuery, ServerArea.Performance, cancellationToken).ConfigureAwait(false)) - .Select(i => (int?)UInt64(i, "NumberOfLogicalProcessors")).FirstOrDefault(); + processors = (await QueryAsync(CimV2, ComputerSystemQuery, ServerArea.Performance, i => (int?)UInt64(i, "NumberOfLogicalProcessors"), cancellationToken, limit: 1) + .ConfigureAwait(false)).FirstOrDefault(); } catch (ServerAccessException) { // The number of processors is a detail; the rest still counts. } - return new ServerOsInfo - { - Caption = Text(os, "Caption")?.Trim(), - Version = Text(os, "Version"), - BuildNumber = Text(os, "BuildNumber"), - LastBootUpTime = ToOffset(os.CimInstanceProperties["LastBootUpTime"]?.Value), - TotalMemoryMb = UInt64(os, "TotalVisibleMemorySize") is { } kb ? kb / 1024d : null, - LogicalProcessors = processors, - ComputerName = Text(os, "CSName"), - }; + return os with { LogicalProcessors = processors }; } + private sealed record ProcessorCounters(ulong? Idle, ulong? Timestamp); + + private sealed record MemoryCounters(ulong? Pages, ulong? PerfTime, ulong? PerfFrequency, ulong? AvailableMb, ulong? Committed, ulong? CommitLimit); + public async Task GetPerformanceAsync(DateTimeOffset now, CancellationToken cancellationToken) { - var processor = (await QueryAsync(CimV2, ProcessorQuery, ServerArea.Performance, cancellationToken).ConfigureAwait(false)).FirstOrDefault(); - var memory = (await QueryAsync(CimV2, MemoryQuery, ServerArea.Performance, cancellationToken).ConfigureAwait(false)).FirstOrDefault(); + var processor = (await QueryAsync(CimV2, ProcessorQuery, ServerArea.Performance, + i => new ProcessorCounters(UInt64(i, "PercentProcessorTime"), UInt64(i, "Timestamp_Sys100NS")), cancellationToken, limit: 1).ConfigureAwait(false)).FirstOrDefault(); + var memory = (await QueryAsync(CimV2, MemoryQuery, ServerArea.Performance, + i => new MemoryCounters(UInt64(i, "PagesPersec"), UInt64(i, "Timestamp_PerfTime"), UInt64(i, "Frequency_PerfTime"), UInt64(i, "AvailableMBytes"), + UInt64(i, "CommittedBytes"), UInt64(i, "CommitLimit")), cancellationToken, limit: 1).ConfigureAwait(false)).FirstOrDefault(); if (processor is null && memory is null) { // Performance counters come back empty, rather than denied, without Performance Monitor Users. @@ -183,58 +346,57 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW return new ServerPerformanceRaw { CapturedAt = now, - ProcessorIdle100Ns = processor is null ? null : UInt64(processor, "PercentProcessorTime"), - ProcessorTimestamp100Ns = processor is null ? null : UInt64(processor, "Timestamp_Sys100NS"), - Pages = memory is null ? null : UInt64(memory, "PagesPersec"), - MemoryPerfTime = memory is null ? null : UInt64(memory, "Timestamp_PerfTime"), - MemoryPerfFrequency = memory is null ? null : UInt64(memory, "Frequency_PerfTime"), - AvailableMb = memory is not null && UInt64(memory, "AvailableMBytes") is { } available ? available : null, - CommittedBytes = memory is not null && UInt64(memory, "CommittedBytes") is { } committed ? committed : null, - CommitLimit = memory is not null && UInt64(memory, "CommitLimit") is { } limit ? limit : null, + ProcessorIdle100Ns = processor?.Idle, + ProcessorTimestamp100Ns = processor?.Timestamp, + Pages = memory?.Pages, + MemoryPerfTime = memory?.PerfTime, + MemoryPerfFrequency = memory?.PerfFrequency, + AvailableMb = memory?.AvailableMb, + CommittedBytes = memory?.Committed, + CommitLimit = memory?.CommitLimit, }; } public async Task> GetDisksAsync(CancellationToken cancellationToken) { - List volumes; + List disks; try { - volumes = await QueryAsync(CimV2, VolumeQuery, ServerArea.Disks, cancellationToken).ConfigureAwait(false); + disks = (await QueryAsync(CimV2, VolumeQuery, ServerArea.Disks, + v => new ServerDisk(Text(v, "Name") ?? string.Empty, Text(v, "Label"), Text(v, "FileSystem"), Gb(UInt64(v, "Capacity")), Gb(UInt64(v, "FreeSpace"))), + cancellationToken).ConfigureAwait(false)) + .Where(d => d.Volume.Length > 0 && !d.Volume.StartsWith(@"\\?\", StringComparison.Ordinal)) // no drive letter or mount point: system/recovery partitions + .ToList(); } catch (ServerAccessException ex) when (ex.Problem is ServerAccessProblem.AccessDenied or ServerAccessProblem.NotAvailable) { - volumes = []; + disks = []; } - var disks = volumes - .Select(v => (Name: Text(v, "Name") ?? string.Empty, Volume: v)) - .Where(v => v.Name.Length > 0 && !v.Name.StartsWith(@"\\?\", StringComparison.Ordinal)) // no drive letter or mount point: system/recovery partitions - .Select(v => new ServerDisk(v.Name, Text(v.Volume, "Label"), Text(v.Volume, "FileSystem"), Gb(UInt64(v.Volume, "Capacity")), Gb(UInt64(v.Volume, "FreeSpace")))) - .ToList(); if (disks.Count > 0) { return disks; } // Older or locked-down servers: the logical disks (drive letters only). - return (await QueryAsync(CimV2, LogicalDiskQuery, ServerArea.Disks, cancellationToken).ConfigureAwait(false)) - .Select(d => new ServerDisk((Text(d, "DeviceID") ?? "?") + "\\", Text(d, "VolumeName"), Text(d, "FileSystem"), Gb(UInt64(d, "Size")), Gb(UInt64(d, "FreeSpace")))) - .ToList(); + return await QueryAsync(CimV2, LogicalDiskQuery, ServerArea.Disks, + d => new ServerDisk((Text(d, "DeviceID") ?? "?") + "\\", Text(d, "VolumeName"), Text(d, "FileSystem"), Gb(UInt64(d, "Size")), Gb(UInt64(d, "FreeSpace"))), + cancellationToken).ConfigureAwait(false); static double Gb(ulong? bytes) => bytes is { } b ? b / 1073741824d : 0; } public async Task> GetServicesAsync(CancellationToken cancellationToken) { - List services; + List services; try { - services = await QueryAsync(CimV2, ServiceQuery, ServerArea.Services, cancellationToken).ConfigureAwait(false); + services = await QueryAsync(CimV2, ServiceQuery, ServerArea.Services, Service, cancellationToken).ConfigureAwait(false); } catch (ServerAccessException ex) when (ex.Problem == ServerAccessProblem.Other) { // Windows before Server 2012 has no DelayedAutoStart property. - services = await QueryAsync(CimV2, ServiceQueryWithoutDelayed, ServerArea.Services, cancellationToken).ConfigureAwait(false); + services = await QueryAsync(CimV2, ServiceQueryWithoutDelayed, ServerArea.Services, Service, cancellationToken).ConfigureAwait(false); } if (services.Count == 0) @@ -244,13 +406,13 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW + "Service Control Manager. Kør tildelingsscriptet på serveren."); } - return services.Select(Service).ToList(); + return services; } public async Task GetServiceAsync(string name, CancellationToken cancellationToken) { ArgumentException.ThrowIfNullOrWhiteSpace(name); - return (await QueryAsync(CimV2, SingleServiceQuery(name), ServerArea.Services, cancellationToken).ConfigureAwait(false)).Select(Service).FirstOrDefault(); + return (await QueryAsync(CimV2, SingleServiceQuery(name), ServerArea.Services, Service, cancellationToken, limit: 1).ConfigureAwait(false)).FirstOrDefault(); } private static ServerService Service(CimInstance s) => new( @@ -261,121 +423,278 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW s.CimInstanceProperties["DelayedAutoStart"]?.Value is true, UInt64(s, "ExitCode") is { } code ? (int)Math.Min(code, int.MaxValue) : null); - public async Task GetEventsAsync(DateTimeOffset since, int max, CancellationToken cancellationToken) + public async Task GetEventsAsync(IReadOnlyDictionary since, int max, CancellationToken cancellationToken) { + ArgumentNullException.ThrowIfNull(since); + ArgumentOutOfRangeException.ThrowIfLessThan(max, 1); string? note = null; - if (options.EventLogRpc) + if (source._options.EventLogRpc) { - try + // A server whose event log protocol was blocked within the hour is read over CIM at once. + note = source.Memory.Recall(host, EventLogRpcFact); + if (note is null) { - return await Task.Run(() => ReadWithEventLogService(since, max, cancellationToken), cancellationToken).ConfigureAwait(false); - } - catch (UnauthorizedAccessException ex) - { - throw ServerErrors.Describe(ServerErrors.AccessDenied, "AccessDenied", ex.Message, ServerArea.Events, host, account, protocol); - } - catch (EventLogException ex) - { - note = $"Hændelsesloggens egen protokol (RPC) virkede ikke ({ex.Message.Trim()}); loggen læses over CIM i stedet, hvilket er langsommere."; + try + { + return await ReadWithEventLogServiceAsync(since, max, cancellationToken).ConfigureAwait(false); + } + catch (UnauthorizedAccessException ex) + { + throw ServerErrors.Describe(ServerErrors.AccessDenied, "AccessDenied", ex.Message, ServerArea.Events, host, account, protocol); + } + catch (EventLogException ex) + { + note = $"Hændelsesloggens egen protokol (RPC) virkede ikke ({ex.Message.Trim()}); loggen læses over CIM i stedet, hvilket er langsommere."; + source.Memory.Remember(host, EventLogRpcFact, note); + } } } var entries = new List(); - var truncated = false; + var truncated = new List(); foreach (var log in ServerEventAnalysis.Logs) { - var rows = await QueryAsync(CimV2, EventQuery(log, since), ServerArea.Events, cancellationToken).ConfigureAwait(false); - truncated |= rows.Count > max; - entries.AddRange(rows.Take(max).Select(e => new ServerEventEntry( - Text(e, "Logfile") ?? log, - Text(e, "SourceName") ?? string.Empty, - (long)(UInt64(e, "EventCode") ?? 0), - 2, - ToOffset(e.CimInstanceProperties["TimeGenerated"]?.Value) ?? since, - Text(e, "Message"), - (long?)UInt64(e, "RecordNumber")))); + var from = Since(since, log); + + // Win32_NTLogEvent cannot be ordered: the oldest max are kept while streaming (memory stays bounded), as the RPC read does. + var (oldest, more) = await RunAsync(() => + { + var kept = new PriorityQueue(Comparer<(DateTimeOffset, long)>.Create((a, b) => b.CompareTo(a))); + var seen = 0; + Read(CimV2, EventQuery(log, from), ServerArea.Events, e => + { + var entry = new ServerEventEntry( + Text(e, "Logfile") ?? log, + Text(e, "SourceName") ?? string.Empty, + (long)(UInt64(e, "EventCode") ?? 0), + 2, + ToOffset(e.CimInstanceProperties["TimeGenerated"]?.Value) ?? from, + Text(e, "Message"), + (long?)UInt64(e, "RecordNumber")); + var key = (entry.At, entry.RecordId ?? 0); + seen++; + if (kept.Count < max) + { + kept.Enqueue(entry, key); + } + else if (kept.TryPeek(out _, out var newest) && key.CompareTo(newest) < 0) + { + kept.EnqueueDequeue(entry, key); + } + + return true; + }, cancellationToken); + return (kept.UnorderedItems.Select(i => i.Element).ToList(), seen > max); + }, cancellationToken).ConfigureAwait(false); + entries.AddRange(oldest); + if (more) + { + truncated.Add(log); + } } - return new ServerEventRead(entries.OrderBy(e => e.At).ToList(), "CIM (Win32_NTLogEvent)", truncated, note); + return new ServerEventRead(Ordered(entries), "CIM (Win32_NTLogEvent)", truncated.Count > 0, note, truncated); } - private ServerEventRead ReadWithEventLogService(DateTimeOffset since, int max, CancellationToken cancellationToken) + private static DateTimeOffset Since(IReadOnlyDictionary since, string log) => + since.TryGetValue(log, out var from) ? from : since.Count > 0 ? since.Values.Min() : DateTimeOffset.UtcNow - ServerEventAnalysis.RecentWindow; + + private static List Ordered(IEnumerable entries) => + entries.OrderBy(e => e.At).ThenBy(e => e.Log, StringComparer.Ordinal).ThenBy(e => e.RecordId).ToList(); + + /// + /// The event log's own protocol, with a deadline for the whole read: a server that does not answer cancels the + /// session's operations, and the agent stops waiting even if the native call ignores that. + /// + private async Task ReadWithEventLogServiceAsync(IReadOnlyDictionary since, int max, CancellationToken cancellationToken) + { + var deadline = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + deadline.CancelAfter(source.EventReadTimeout); + var token = deadline.Token; + var read = Task.Run(() => ReadWithEventLogService(since, max, token), token); + try + { + return await read.WaitAsync(token).ConfigureAwait(false); + } + catch (Exception ex) when (ex is OperationCanceledException or EventLogException && token.IsCancellationRequested && !cancellationToken.IsCancellationRequested) + { + throw ServerErrors.Describe(ServerErrors.MiTimeout, "Timeout", string.Empty, ServerArea.Events, host, account, + $"hændelsesloggens protokol (RPC) inden for {source.EventReadTimeout.TotalSeconds.ToString("0", CultureInfo.InvariantCulture)} sekunder"); + } + finally + { + if (read.IsCompleted) + { + deadline.Dispose(); + } + else + { + _ = read.ContinueWith(_ => deadline.Dispose(), CancellationToken.None, TaskContinuationOptions.ExecuteSynchronously, TaskScheduler.Default); + Abandon(read); + } + } + } + + private ServerEventRead ReadWithEventLogService(IReadOnlyDictionary since, int max, CancellationToken cancellationToken) { using var logSession = protocol == "lokal" ? new EventLogSession() : new EventLogSession(host); + using var cancel = cancellationToken.Register(logSession.CancelCurrentOperations); var entries = new List(); - var truncated = false; + var truncated = new List(); foreach (var log in ServerEventAnalysis.Logs) { - var query = new EventLogQuery(log, PathType.LogName, EventXPath(since)) { Session = logSession }; + cancellationToken.ThrowIfCancellationRequested(); + var from = Since(since, log); + var query = new EventLogQuery(log, PathType.LogName, EventXPath(from)) { Session = logSession }; using var reader = new EventLogReader(query); var newest = new Dictionary<(string, int), EventRecord>(); var read = new List<(EventRecord Record, ServerEventEntry Entry)>(); - var count = 0; - for (var record = reader.ReadEvent(); record is not null; record = reader.ReadEvent()) + try { - cancellationToken.ThrowIfCancellationRequested(); - if (++count > max) + var count = 0; + for (var record = reader.ReadEvent(); record is not null; record = reader.ReadEvent()) + { + if (++count > max) + { + record.Dispose(); + truncated.Add(log); + break; + } + + var entry = new ServerEventEntry(log, record.ProviderName ?? string.Empty, record.Id, record.Level ?? 2, + record.TimeCreated is { } created ? new DateTimeOffset(created.ToUniversalTime(), TimeSpan.Zero) : from, null, record.RecordId); + read.Add((record, entry)); + newest[(entry.Source, record.Id)] = record; + cancellationToken.ThrowIfCancellationRequested(); + } + + // The text is only needed once per source and id (the sample): formatting asks the server for the publisher's messages. + foreach (var (record, entry) in read) + { + string? message = null; + if (newest.TryGetValue((entry.Source, record.Id), out var sample) && ReferenceEquals(sample, record)) + { + cancellationToken.ThrowIfCancellationRequested(); + try + { + message = record.FormatDescription(); + } + catch (EventLogException) + { + message = null; + } + } + + entries.Add(entry with { Message = message }); + } + } + finally + { + foreach (var (record, _) in read) { record.Dispose(); - truncated = true; - break; } - - var entry = new ServerEventEntry(log, record.ProviderName ?? string.Empty, record.Id, record.Level ?? 2, - record.TimeCreated is { } created ? new DateTimeOffset(created.ToUniversalTime(), TimeSpan.Zero) : since, null, record.RecordId); - read.Add((record, entry)); - newest[(entry.Source, record.Id)] = record; - } - - // The text is only needed once per source and id (the sample): formatting asks the server for the publisher's messages. - foreach (var (record, entry) in read) - { - string? message = null; - if (newest.TryGetValue((entry.Source, record.Id), out var sample) && ReferenceEquals(sample, record)) - { - try - { - message = record.FormatDescription(); - } - catch (EventLogException) - { - message = null; - } - } - - entries.Add(entry with { Message = message }); - record.Dispose(); } } - return new ServerEventRead(entries.OrderBy(e => e.At).ToList(), "Event Log (RPC)", truncated); + return new ServerEventRead(Ordered(entries), "Event Log (RPC)", truncated.Count > 0, null, truncated); } - public async Task GetTasksAsync(Func watch, int maxWatched, CancellationToken cancellationToken) + public async Task GetTasksAsync(Func watch, int maxWatched, TimeSpan budget, CancellationToken cancellationToken) { ArgumentNullException.ThrowIfNull(watch); - var all = (await QueryAsync(TaskSchedulerNamespace, TaskQuery, ServerArea.Tasks, cancellationToken).ConfigureAwait(false)) - .Select(t => new ServerTask - { - Path = Text(t, "TaskPath") ?? "\\", - Name = Text(t, "TaskName") ?? string.Empty, - State = (UInt64(t, "State") ?? 0) switch { 1 => "Disabled", 2 => "Queued", 3 => "Ready", 4 => "Running", _ => "Unknown" }, - }) - .ToList(); + var all = await QueryAsync(TaskSchedulerNamespace, TaskQuery, ServerArea.Tasks, t => new ServerTask + { + Path = Text(t, "TaskPath") ?? "\\", + Name = Text(t, "TaskName") ?? string.Empty, + State = (UInt64(t, "State") ?? 0) switch { 1 => "Disabled", 2 => "Queued", 3 => "Ready", 4 => "Running", _ => "Unknown" }, + }, cancellationToken).ConfigureAwait(false); var watched = all.Where(t => watch(t.FullName)).ToList(); - var note = watched.Count > maxWatched ? $"Kun de første {maxWatched} af {watched.Count} opgaver overvåges." : null; + var notes = new List(); + if (watched.Count > maxWatched) + { + notes.Add($"Kun de første {maxWatched} af {watched.Count} opgaver overvåges."); + } + + var started = source._time.GetTimestamp(); var result = new List(); + var unread = 0; foreach (var task in watched.Take(maxWatched)) { + if (source._time.GetElapsedTime(started) >= budget) + { + // The time for the tasks is spent: the rest keep their state, without the last run, until next time. + result.Add(task); + unread++; + continue; + } + result.Add(await GetInfoAsync(task, cancellationToken).ConfigureAwait(false)); } - return new ServerTaskRead(result, all.Count, note); + if (unread > 0) + { + notes.Add($"Seneste kørsel blev ikke læst for {unread} af {result.Count} opgaver: tiden til opgaverne " + + $"({budget.TotalSeconds.ToString("0", CultureInfo.InvariantCulture)} sekunder) var brugt. De læses ved næste indsamling."); + } + + return new ServerTaskRead(result, all.Count, notes.Count == 0 ? null : string.Join(" ", notes)); } - /// Last and next run of a task: Task Scheduler's GetInfo, which only reads (as Get-ScheduledTaskInfo). - private Task GetInfoAsync(ServerTask task, CancellationToken cancellationToken) => - Task.Run(() => + /// + /// Last and next run of a task. Over WS-Man an account with read-only WinRM rights may not call Task Scheduler's + /// GetInfo; with Protocol Auto the tasks are then read over DCOM (and that is remembered for the server). + /// + private async Task GetInfoAsync(ServerTask task, CancellationToken cancellationToken) + { + if (_taskSession is null && protocol == WsMan && source.Auto && source.Memory.Recall(host, TasksOverDcomFact) is not null) + { + _taskSession = source.CreateSession(host, Dcom); + } + + if (_taskSession is not null) + { + try + { + return await GetInfoAsync(_taskSession, Dcom, task, cancellationToken).ConfigureAwait(false); + } + catch (ServerAccessException) + { + source.Memory.Forget(host, TasksOverDcomFact); + throw; + } + } + + try + { + return await GetInfoAsync(session, protocol, task, cancellationToken).ConfigureAwait(false); + } + catch (ServerAccessException ex) when (ex.Problem == ServerAccessProblem.AccessDenied && protocol == WsMan) + { + const string why = " Opgavernes seneste resultat læses med Task Schedulers GetInfo, et CIM-metodekald, og over WinRM må agentens konto kun læse."; + if (!source.Auto) + { + throw new ServerAccessException(ServerAccessProblem.AccessDenied, + ex.Message + why + " Vælg protokollen Auto eller DCOM (SQLInsight:Servers:Protocol), så læses opgaverne over DCOM.", ex) + { Code = ex.Code }; + } + + _taskSession = source.CreateSession(host, Dcom); + try + { + var info = await GetInfoAsync(_taskSession, Dcom, task, cancellationToken).ConfigureAwait(false); + source.Memory.Remember(host, TasksOverDcomFact, Dcom); + return info; + } + catch (ServerAccessException dcom) + { + throw new ServerAccessException(dcom.Problem, ex.Message + why + " Agenten prøvede derfor DCOM: " + dcom.Message, dcom) { Code = dcom.Code }; + } + } + } + + private Task GetInfoAsync(CimSession over, string overProtocol, ServerTask task, CancellationToken cancellationToken) => + RunAsync(() => { try { @@ -384,32 +703,31 @@ public sealed class CimWindowsServerSource(ServerConnectionOptions options) : IW CimMethodParameter.Create("TaskName", task.Name, CimType.String, CimFlags.In), CimMethodParameter.Create("TaskPath", task.Path, CimType.String, CimFlags.In), }; - var result = session.InvokeMethod(TaskSchedulerNamespace, "PS_ScheduledTask", "GetInfoByName", parameters, Options(cancellationToken)); + using var operation = Options(cancellationToken); + using var result = over.InvokeMethod(TaskSchedulerNamespace, "PS_ScheduledTask", "GetInfoByName", parameters, operation); if (result.OutParameters["cmdletOutput"]?.Value is not CimInstance info) { return task; } - return task with + using (info) { - LastRunTime = ToOffset(info.CimInstanceProperties["LastRunTime"]?.Value), - LastTaskResult = UInt64(info, "LastTaskResult") is { } r ? (uint)r : null, - NextRunTime = ToOffset(info.CimInstanceProperties["NextRunTime"]?.Value), - MissedRuns = (int)(UInt64(info, "NumberOfMissedRuns") ?? 0), - }; + return task with + { + LastRunTime = ToOffset(info.CimInstanceProperties["LastRunTime"]?.Value), + LastTaskResult = UInt64(info, "LastTaskResult") is { } r ? (uint)r : null, + NextRunTime = ToOffset(info.CimInstanceProperties["NextRunTime"]?.Value), + MissedRuns = (int)(UInt64(info, "NumberOfMissedRuns") ?? 0), + }; + } } catch (CimException ex) { - var error = Describe(ex, ServerArea.Tasks); - if (error.Problem == ServerAccessProblem.AccessDenied && protocol == "WS-Man") - { - throw new ServerAccessException(ServerAccessProblem.AccessDenied, - error.Message + " Opgavernes seneste resultat læses med Task Schedulers GetInfo (et CIM-metodekald), som WinRM kun tillader for kontoen, " - + "når den også har Execute-ret i WinRM. Uden den: vælg DCOM (SQLInsight:Servers:Protocol), eller giv kontoen ret med winrm configSDDL default.", ex) - { Code = error.Code }; - } - - throw error; + throw Describe(ex, ServerArea.Tasks, overProtocol); + } + catch (UnauthorizedAccessException ex) + { + throw ServerErrors.Describe(ServerErrors.AccessDenied, "AccessDenied", ex.Message, ServerArea.Tasks, host, account, overProtocol); } }, cancellationToken); } diff --git a/src/SQLInsight.Servers/ServerErrors.cs b/src/SQLInsight.Servers/ServerErrors.cs index 2bbfc92..6770a8f 100644 --- a/src/SQLInsight.Servers/ServerErrors.cs +++ b/src/SQLInsight.Servers/ServerErrors.cs @@ -40,7 +40,9 @@ public static class ServerErrors || message.Contains("Adgang nægtet", StringComparison.OrdinalIgnoreCase)) { var right = area is null - ? (protocol == "WS-Man" ? "Remote Management Users og WMI Remote Enable på root\\cimv2" : "Distributed COM Users og WMI Remote Enable på root\\cimv2") + ? (protocol == "WS-Man" + ? "læseret i WinRM (grant-windows-server.ps1 -WinRM) og WMI Remote Enable på root\\cimv2; uden WinRM-retten bruges DCOM (SQLInsight:Servers:Protocol Auto eller DCOM)" + : "Distributed COM Users og WMI Remote Enable på root\\cimv2") : ServerArea.Right(area); return new ServerAccessException(ServerAccessProblem.AccessDenied, $"Adgang nægtet til {what} på {host} over {protocol}: {who} mangler {right}. Kør tildelingsscriptet (grant-windows-server.ps1) som administrator på serveren, " @@ -67,14 +69,14 @@ public static class ServerErrors { return new ServerAccessException(ServerAccessProblem.Unreachable, $"{host} svarer ikke på RPC/DCOM: serveren er slukket, navnet findes ikke, eller firewallen blokerer TCP 135 og de dynamiske RPC-porte " - + "(reglerne \"Windows Management Instrumentation (WMI)\" og for hændelsesloggen \"Remote Event Log Management\")." + windows) + + "fra agentens server. Tildelingsscriptet kan oprette regler kun for agentens adresse (-EnableFirewall -AgentAddress …)." + windows) { Code = code }; } if (code is WinRmCannotConnect || message.Contains("WinRM", StringComparison.OrdinalIgnoreCase) || message.Contains("WS-Management", StringComparison.OrdinalIgnoreCase)) { return new ServerAccessException(ServerAccessProblem.Unreachable, - $"{host} svarer ikke på WinRM (WS-Man, TCP 5985): tjenesten Windows Remote Management kører ikke, eller firewallen blokerer porten." + windows) + $"{host} svarer ikke på WinRM (WS-Man, TCP 5985): tjenesten Windows Remote Management kører ikke, eller firewallen blokerer porten. Agenten kan bruge DCOM i stedet (SQLInsight:Servers:Protocol Auto)." + windows) { Code = code }; } diff --git a/src/SQLInsight.Servers/ServerHostMemory.cs b/src/SQLInsight.Servers/ServerHostMemory.cs new file mode 100644 index 0000000..0791fe2 --- /dev/null +++ b/src/SQLInsight.Servers/ServerHostMemory.cs @@ -0,0 +1,49 @@ +using System.Collections.Concurrent; + +namespace SQLInsight.Servers; + +/// +/// What the agent learned about a server for a while (e.g. "WS-Man is refused, DCOM works", "the event log's RPC protocol +/// is blocked"), so it is not tried again every cycle; it is forgotten after , so it is tried again then. +/// Thread-safe. +/// +public sealed class ServerHostMemory(TimeProvider time, TimeSpan remember) +{ + public static readonly TimeSpan DefaultFor = TimeSpan.FromHours(1); + + private readonly ConcurrentDictionary<(string Host, string Key), (object Value, DateTimeOffset Until)> _facts = new(); + + public TimeSpan For => remember; + + public void Remember(string host, string key, object value) + { + ArgumentNullException.ThrowIfNull(host); + ArgumentNullException.ThrowIfNull(value); + _facts[(host.ToUpperInvariant(), key)] = (value, time.GetUtcNow() + remember); + } + + public T? Recall(string host, string key) + where T : class + { + ArgumentNullException.ThrowIfNull(host); + var id = (host.ToUpperInvariant(), key); + if (!_facts.TryGetValue(id, out var fact)) + { + return null; + } + + if (fact.Until <= time.GetUtcNow()) + { + _facts.TryRemove(id, out _); + return null; + } + + return fact.Value as T; + } + + public void Forget(string host, string key) + { + ArgumentNullException.ThrowIfNull(host); + _facts.TryRemove((host.ToUpperInvariant(), key), out _); + } +} diff --git a/src/SQLInsight.Servers/WindowsServerAccess.cs b/src/SQLInsight.Servers/WindowsServerAccess.cs index 106c5ee..eecadb0 100644 --- a/src/SQLInsight.Servers/WindowsServerAccess.cs +++ b/src/SQLInsight.Servers/WindowsServerAccess.cs @@ -33,16 +33,35 @@ public interface IWindowsServerSession : IDisposable /// One service, or null when it does not exist (or cannot be seen). Task GetServiceAsync(string name, CancellationToken cancellationToken); - /// Errors and critical events in the System and Application logs since , oldest first. - Task GetEventsAsync(DateTimeOffset since, int max, CancellationToken cancellationToken); + /// + /// Errors and critical events in the System and Application logs, each log after its own time in + /// (a log not in it: after the earliest), oldest first; at most per log, the oldest ones. + /// + Task GetEventsAsync(IReadOnlyDictionary since, int max, CancellationToken cancellationToken); - /// Scheduled tasks; run information only for the ones selects (at most ). - Task GetTasksAsync(Func watch, int maxWatched, CancellationToken cancellationToken); + /// Errors and critical events in the System and Application logs since , oldest first. + Task GetEventsAsync(DateTimeOffset since, int max, CancellationToken cancellationToken) => + GetEventsAsync(ServerEventAnalysis.Logs.ToDictionary(l => l, _ => since, StringComparer.OrdinalIgnoreCase), max, cancellationToken); + + /// + /// Scheduled tasks; run information only for the ones selects (at most ), + /// read one at a time until is spent: the rest come without run information, and the note says so. + /// + Task GetTasksAsync(Func watch, int maxWatched, TimeSpan budget, CancellationToken cancellationToken); + + /// Scheduled tasks, without a time budget. + Task GetTasksAsync(Func watch, int maxWatched, CancellationToken cancellationToken) => + GetTasksAsync(watch, maxWatched, TimeSpan.MaxValue, cancellationToken); } /// How the logs were read: "Event Log (RPC)" or "CIM (Win32_NTLogEvent)". -/// More events than max: the rest is read next time. -public sealed record ServerEventRead(IReadOnlyList Entries, string Method, bool Truncated, string? Note = null); +/// More events than max in a log: the rest is read next time. +/// The logs that had more (null while : every log). +public sealed record ServerEventRead(IReadOnlyList Entries, string Method, bool Truncated, string? Note = null, IReadOnlyList? TruncatedLogs = null) +{ + /// Whether had more events than were read. + public bool IsTruncated(string log) => Truncated && (TruncatedLogs is null || TruncatedLogs.Contains(log, StringComparer.OrdinalIgnoreCase)); +} /// Every task the agent could see. public sealed record ServerTaskRead(IReadOnlyList Watched, int Visible, string? Note = null); diff --git a/src/SQLInsight.Servers/WindowsServerTester.cs b/src/SQLInsight.Servers/WindowsServerTester.cs index f65ce8c..171910c 100644 --- a/src/SQLInsight.Servers/WindowsServerTester.cs +++ b/src/SQLInsight.Servers/WindowsServerTester.cs @@ -1,3 +1,4 @@ +using System.Globalization; using SQLInsight.Core.Servers; namespace SQLInsight.Servers; @@ -8,19 +9,36 @@ namespace SQLInsight.Servers; /// public static class WindowsServerTester { - public static async Task TestAsync(IWindowsServerSource source, string host, string? account, DateTimeOffset now, CancellationToken cancellationToken) + /// How long a whole test may take by default: a server that does not answer is a result, in time to be stored. + public static readonly TimeSpan DefaultTimeout = TimeSpan.FromMinutes(2); + + public static Task TestAsync(IWindowsServerSource source, string host, string? account, DateTimeOffset now, CancellationToken cancellationToken) => + TestAsync(source, host, account, now, DefaultTimeout, cancellationToken); + + /// For the whole test: what is not done by then is reported as not answered in time. + public static async Task TestAsync(IWindowsServerSource source, string host, string? account, DateTimeOffset now, TimeSpan timeout, + CancellationToken cancellationToken) { ArgumentNullException.ThrowIfNull(source); ArgumentException.ThrowIfNullOrWhiteSpace(host); + using var deadline = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + deadline.CancelAfter(timeout); + var token = deadline.Token; + var late = $"{host} svarede ikke inden for {timeout.TotalSeconds.ToString("0", CultureInfo.InvariantCulture)} sekunder, så testen blev afbrudt. " + + "Serveren kan være overbelastet, eller en firewall taber pakkerne."; IWindowsServerSession session; try { - session = await source.ConnectAsync(host, cancellationToken).ConfigureAwait(false); + session = await source.ConnectAsync(host, token).ConfigureAwait(false); } catch (ServerAccessException ex) { return new WindowsServerTestResult { Reachable = false, Error = ex.Message, Hint = Hint(ex.Problem), Account = account }; } + catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested) + { + return new WindowsServerTestResult { Reachable = false, Error = late, Hint = Hint(ServerAccessProblem.Timeout), Account = account }; + } using (session) { @@ -34,20 +52,20 @@ public static class WindowsServerTester ServerOsInfo? os = null; await TryAsync(ServerArea.Performance, async () => { - os = await session.GetOperatingSystemAsync(cancellationToken).ConfigureAwait(false); - await session.GetPerformanceAsync(now, cancellationToken).ConfigureAwait(false); + os = await session.GetOperatingSystemAsync(token).ConfigureAwait(false); + await session.GetPerformanceAsync(now, token).ConfigureAwait(false); return null; }).ConfigureAwait(false); await TryAsync(ServerArea.Disks, async () => { - var disks = await session.GetDisksAsync(cancellationToken).ConfigureAwait(false); + var disks = await session.GetDisksAsync(token).ConfigureAwait(false); return disks.Count == 0 ? "Ingen lokale diske fundet." : $"{disks.Count} drev: " + string.Join(", ", disks.Select(d => d.Volume)); }).ConfigureAwait(false); await TryAsync(ServerArea.Services, async () => - $"{(await session.GetServicesAsync(cancellationToken).ConfigureAwait(false)).Count} tjenester synlige.").ConfigureAwait(false); + $"{(await session.GetServicesAsync(token).ConfigureAwait(false)).Count} tjenester synlige.").ConfigureAwait(false); await TryAsync(ServerArea.Events, async () => { - var read = await session.GetEventsAsync(now.AddHours(-24), 500, cancellationToken).ConfigureAwait(false); + var read = await session.GetEventsAsync(now.AddHours(-24), 500, token).ConfigureAwait(false); if (read.Note is { } eventNote) { notes.Add(eventNote); @@ -57,7 +75,7 @@ public static class WindowsServerTester }).ConfigureAwait(false); await TryAsync(ServerArea.Tasks, async () => { - var tasks = await session.GetTasksAsync(name => !TaskResults.IsMicrosoftTask(name), 1, cancellationToken).ConfigureAwait(false); + var tasks = await session.GetTasksAsync(name => !TaskResults.IsMicrosoftTask(name), 1, token).ConfigureAwait(false); return $"{tasks.Visible} opgaver synlige."; }).ConfigureAwait(false); @@ -78,12 +96,17 @@ public static class WindowsServerTester { try { + token.ThrowIfCancellationRequested(); areas.Add(new ServerAreaStatus(area, true, await read().ConfigureAwait(false), ServerArea.Right(area))); } catch (ServerAccessException ex) { areas.Add(new ServerAreaStatus(area, false, ex.Message, ServerArea.Right(area))); } + catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested) + { + areas.Add(new ServerAreaStatus(area, false, late, ServerArea.Right(area))); + } } } } @@ -92,7 +115,8 @@ public static class WindowsServerTester { ServerAccessProblem.AccessDenied => "Kør tildelingsscriptet nedenfor som administrator på serveren, og test igen.", ServerAccessProblem.Unreachable or ServerAccessProblem.Timeout => - "Tjek navnet, at serveren kører, og firewallen fra agentens server: WinRM (TCP 5985) eller DCOM/RPC (TCP 135 og dynamiske porte). Tildelingsscriptet kan slå Windows' egne regler til (-EnableFirewall).", + "Tjek navnet, at serveren kører, og firewallen fra agentens server: DCOM/RPC (TCP 135 og dynamiske porte) eller WinRM (TCP 5985). " + + "Tildelingsscriptet kan oprette regler kun for agentens adresse (-EnableFirewall -AgentAddress …).", ServerAccessProblem.NotSupported => UnsupportedWindowsServerSource.Reason, _ => "Se fejlteksten. Forbindelsen blev forsøgt fra agentens server som agentens konto.", }; diff --git a/tests/SQLInsight.Agent.Tests/ServerAgentOptionsTests.cs b/tests/SQLInsight.Agent.Tests/ServerAgentOptionsTests.cs new file mode 100644 index 0000000..29d2ce1 --- /dev/null +++ b/tests/SQLInsight.Agent.Tests/ServerAgentOptionsTests.cs @@ -0,0 +1,114 @@ +using SQLInsight.Agent.Servers; +using SQLInsight.Core.Servers; +using SQLInsight.Core.SyntheticChecks; +using SQLInsight.Servers; + +namespace SQLInsight.Agent.Tests; + +public class ServerAgentOptionsTests +{ + [Fact] + public void Server_options_are_kept_within_what_works() + { + var wild = new ServerOptions + { + MaxParallelServers = 0, OperationTimeout = TimeSpan.Zero, CycleTimeout = TimeSpan.FromHours(5), SampleDays = 0, DiskHistoryDays = -3, EventDays = 0, + }; + wild.EventLog.MaxEventsPerCollection = 1_000_000; + wild.Tasks.MaxWatched = 0; + wild.Disks.ForecastHistoryDays = 0; + + wild.Normalize(); + + Assert.Equal(1, wild.MaxParallelServers); + Assert.Equal(TimeSpan.FromSeconds(5), wild.OperationTimeout); + Assert.Equal(TimeSpan.FromMinutes(30), wild.CycleTimeout); + Assert.Equal((1, 1, 1), (wild.SampleDays, wild.DiskHistoryDays, wild.EventDays)); // 0 days would make maintenance delete everything + Assert.Equal(10000, wild.EventLog.MaxEventsPerCollection); + Assert.Equal(1, wild.Tasks.MaxWatched); + Assert.Equal(1, wild.Disks.ForecastHistoryDays); + + var other = new ServerOptions { MaxParallelServers = 500, OperationTimeout = TimeSpan.FromHours(2), CycleTimeout = TimeSpan.FromSeconds(1) }; + other.EventLog.MaxEventsPerCollection = 1; + other.Tasks.MaxWatched = 10_000; + other.Normalize(); + + Assert.Equal(32, other.MaxParallelServers); + Assert.Equal(TimeSpan.FromMinutes(5), other.OperationTimeout); + Assert.Equal(TimeSpan.FromMinutes(10), other.CycleTimeout); // at least two operations + Assert.Equal(10, other.EventLog.MaxEventsPerCollection); + Assert.Equal(200, other.Tasks.MaxWatched); + Assert.Equal(other.CycleTimeout / 3, other.TaskBudget); + } + + [Fact] + public void Defaults_are_unchanged_by_normalizing() + { + var defaults = new ServerOptions().Normalize(); + + Assert.Equal((4, TimeSpan.FromSeconds(30), TimeSpan.FromMinutes(5)), (defaults.MaxParallelServers, defaults.OperationTimeout, defaults.CycleTimeout)); + Assert.Equal((14, 35, 90), (defaults.SampleDays, defaults.DiskHistoryDays, defaults.EventDays)); + Assert.Equal((2000, 50), (defaults.EventLog.MaxEventsPerCollection, defaults.Tasks.MaxWatched)); + Assert.Equal(TimeSpan.FromSeconds(30), ServerConnectionOptions.BoundTimeout(TimeSpan.FromSeconds(30))); + } + + [Fact] + public void Synthetic_check_options_are_kept_within_what_works() + { + var wild = new SyntheticCheckOptions { MaxParallelChecks = -1, ResultDays = 0, FailuresBeforeFinding = 30, SlowRunsBeforeFinding = 0 }.Normalize(); + + Assert.Equal(1, wild.MaxParallelChecks); + Assert.Equal(1, wild.ResultDays); + Assert.Equal(1, wild.SlowRunsBeforeFinding); + Assert.Equal(31, wild.RecentResults); // enough to count 30 failures in a row + Assert.Equal(11, new SyntheticCheckOptions().RecentResults); + Assert.Equal(100, new SyntheticCheckOptions { FailuresBeforeFinding = 5000 }.Normalize().RecentResults); + Assert.Equal(32, new SyntheticCheckOptions { MaxParallelChecks = 1000 }.Normalize().MaxParallelChecks); + } + + [Fact] + public void A_check_never_runs_more_often_than_the_minimum_interval() + { + Assert.Equal(TimeSpan.FromSeconds(SyntheticCheckLimits.MinIntervalSeconds), SyntheticCheckOptions.IntervalOf(0)); + Assert.Equal(TimeSpan.FromSeconds(SyntheticCheckLimits.MinIntervalSeconds), SyntheticCheckOptions.IntervalOf(5)); + Assert.Equal(TimeSpan.FromMinutes(5), SyntheticCheckOptions.IntervalOf(300)); + Assert.Equal(TimeSpan.FromSeconds(SyntheticCheckLimits.MaxIntervalSeconds), SyntheticCheckOptions.IntervalOf(int.MaxValue)); + } + + [Fact] + public void An_unreachable_server_is_backed_off_1_2_5_10_then_15_minutes() + { + var waits = Enumerable.Range(1, 7).Select(ServerMonitor.Backoff).Select(t => (int)t.TotalMinutes); + + Assert.Equal([1, 2, 5, 10, 15, 15, 15], waits); + } + + [Fact] + public void Each_event_log_continues_from_its_own_mark() + { + var now = new DateTimeOffset(2026, 10, 2, 12, 0, 0, TimeSpan.Zero); + var since = new Dictionary { ["System"] = now.AddHours(-24), ["Application"] = now.AddHours(-24) }; + + // System had more than could be read (up to 08:00); Application was read to 11:59. + var read = new ServerEventRead( + [ + new ServerEventEntry("System", "disk", 153, 2, now.AddHours(-6)), + new ServerEventEntry("System", "disk", 153, 2, now.AddHours(-4)), + new ServerEventEntry("Application", "app", 1000, 2, now.AddMinutes(-1)), + ], "Event Log (RPC)", true, null, ["System"]); + + var marks = ServerMonitor.NextReadUntil(read, since, now); + + Assert.Equal(now.AddHours(-4), marks["System"]); // the rest of System is read next time, not skipped + Assert.Equal(now.AddMinutes(-1), marks["Application"]); + var snapshot = new ServerEventSnapshot { CapturedAt = now, ReadUntil = marks.Values.Min(), LogReadUntil = marks }; + Assert.Equal(now.AddHours(-4), ServerMonitor.EventsReadUntil(snapshot, "System", now)); + Assert.Equal(now.AddMinutes(-1), ServerMonitor.EventsReadUntil(snapshot, "application", now)); + + // A log without events keeps ten minutes' margin; a snapshot from before per-log marks continues from its single mark. + var quiet = ServerMonitor.NextReadUntil(new ServerEventRead([], "Event Log (RPC)", false), since, now); + Assert.Equal(now.AddMinutes(-10), quiet["System"]); + Assert.Equal(now.AddHours(-2), ServerMonitor.EventsReadUntil(new ServerEventSnapshot { CapturedAt = now, ReadUntil = now.AddHours(-2) }, "System", now)); + Assert.Equal(now - ServerEventAnalysis.RecentWindow, ServerMonitor.EventsReadUntil(null, "System", now)); + } +} diff --git a/tests/SQLInsight.IntegrationTests/ServerAgentTests.cs b/tests/SQLInsight.IntegrationTests/ServerAgentTests.cs index 73625fd..1975934 100644 --- a/tests/SQLInsight.IntegrationTests/ServerAgentTests.cs +++ b/tests/SQLInsight.IntegrationTests/ServerAgentTests.cs @@ -101,8 +101,18 @@ public sealed class ServerAgentTests(SqlServerFixture sql) : IAsyncLifetime }); } - public Task> GetDisksAsync(CancellationToken cancellationToken) => - Task.FromResult>([new ServerDisk(@"C:\", "System", "NTFS", 100, 40), new ServerDisk(@"D:\", "Data", "NTFS", 100, FreeGb)]); + /// The disks never answer: only the cycle's deadline ends the wait. + public bool DisksHang { get; set; } + + public async Task> GetDisksAsync(CancellationToken cancellationToken) + { + if (DisksHang) + { + await Task.Delay(Timeout.Infinite, cancellationToken); + } + + return [new ServerDisk(@"C:\", "System", "NTFS", 100, 40), new ServerDisk(@"D:\", "Data", "NTFS", 100, FreeGb)]; + } public Task> GetServicesAsync(CancellationToken cancellationToken) => ServicesError is { } error ? throw error @@ -111,11 +121,11 @@ public sealed class ServerAgentTests(SqlServerFixture sql) : IAsyncLifetime public Task GetServiceAsync(string name, CancellationToken cancellationToken) => Task.FromResult(new ServerService(name, name, AosState, "Auto")); - public Task GetEventsAsync(DateTimeOffset since, int max, CancellationToken cancellationToken) => Task.FromResult(new ServerEventRead( + public Task GetEventsAsync(IReadOnlyDictionary since, int max, CancellationToken cancellationToken) => Task.FromResult(new ServerEventRead( [new ServerEventEntry("System", "disk", 153, 2, DateTimeOffset.UtcNow.AddMinutes(-1), @"The IO operation at logical block address 0x1 for Disk 1 was retried.")], "Event Log (RPC)", false)); - public Task GetTasksAsync(Func watch, int maxWatched, CancellationToken cancellationToken) => Task.FromResult(new ServerTaskRead( + public Task GetTasksAsync(Func watch, int maxWatched, TimeSpan budget, CancellationToken cancellationToken) => Task.FromResult(new ServerTaskRead( [new ServerTask { Path = @"\", Name = "AX export", State = "Ready", LastTaskResult = 1, LastRunTime = DateTimeOffset.UtcNow.AddHours(-1) }], 140)); public void Dispose() @@ -215,9 +225,9 @@ public sealed class ServerAgentTests(SqlServerFixture sql) : IAsyncLifetime Assert.True(stored.Reachable); } - private SyntheticCheckService Checks(FakeServer server, IBusinessConnectorLocator? locator = null) => new( + private SyntheticCheckService Checks(FakeServer server, IBusinessConnectorLocator? locator = null, ISqlConnectionFactory? sql = null) => new( Options.Create(new SyntheticCheckOptions()), - new SyntheticCheckRunner(new SqlConnectionFactory(), locator ?? new NoBusinessConnector(), new ProcessRunner(), TimeProvider.System), + new SyntheticCheckRunner(sql ?? new SqlConnectionFactory(), locator ?? new NoBusinessConnector(), new ProcessRunner(), TimeProvider.System), server, _repository, _key, TimeProvider.System, NullLogger.Instance, Dispatcher(), Options.Create(new NotificationOptions { WebUrl = WebUrl }), Options.Create(new AgentOptions()), new RepositoryReadiness()); @@ -226,6 +236,32 @@ public sealed class ServerAgentTests(SqlServerFixture sql) : IAsyncLifetime public BusinessConnectorInstallation? Find() => null; } + [Fact] + public async Task A_server_that_hangs_is_cut_off_at_the_cycle_deadline_and_backed_off() + { + var row = await AddServerAsync(); + var server = new FakeServer { DisksHang = true }; + var monitor = new ServerMonitor(row, server, _repository, new ServerOptions { CycleTimeout = TimeSpan.FromSeconds(5) }, NullLogger.Instance, Dispatcher(), WebUrl); + var now = DateTimeOffset.UtcNow; + + var cycle = monitor.RunCycleAsync(now, CancellationToken.None); + Assert.Same(cycle, await Task.WhenAny(cycle, Task.Delay(TimeSpan.FromMinutes(1)))); + await cycle; + + var areas = (await _repository.GetWindowsServerAsync(row.ServerId))!.Areas; + Assert.True(areas.Single(a => a.Area == ServerArea.Performance).Ok); // read before the deadline + Assert.All(areas.Where(a => a.Area != ServerArea.Performance), a => Assert.False(a.Ok)); + Assert.All(areas.Where(a => a.Area != ServerArea.Performance), a => Assert.Contains("svarede ikke inden for", a.Detail, StringComparison.Ordinal)); + Assert.Equal(now + ServerMonitor.Backoff(1), monitor.RetryAt); + Assert.False(monitor.IsDue(now.AddSeconds(30))); + + // Once it answers again, everything is read and the backoff is gone. + server.DisksHang = false; + await monitor.RunCycleAsync(now.AddMinutes(16), CancellationToken.None); + Assert.All((await _repository.GetWindowsServerAsync(row.ServerId))!.Areas, a => Assert.True(a.Ok, a.Detail)); + Assert.Equal(DateTimeOffset.MinValue, monitor.RetryAt); + } + private static int ClosedPort() { using var probe = new TcpListener(IPAddress.Loopback, 0); diff --git a/tests/SQLInsight.Servers.Tests/LocalCimTests.cs b/tests/SQLInsight.Servers.Tests/LocalCimTests.cs index ff304de..c840519 100644 --- a/tests/SQLInsight.Servers.Tests/LocalCimTests.cs +++ b/tests/SQLInsight.Servers.Tests/LocalCimTests.cs @@ -1,80 +1,163 @@ +using System.Diagnostics; +using System.Runtime.Versioning; using SQLInsight.Core.Servers; using SQLInsight.Servers; namespace SQLInsight.Servers.Tests; +/// The local CIM tests run alone: WMI on a busy test machine (SQL Server containers, every test assembly at once) is slow enough already. +[CollectionDefinition(Name, DisableParallelization = true)] +public sealed class LocalCimGroup +{ + public const string Name = "Local CIM"; +} + +/// +/// One local session for the class, with WMI warmed up once: the first query of a class can take long on a cold or busy +/// machine (the provider loads), which is not what the tests are about. +/// +[SupportedOSPlatform("windows")] +public sealed class LocalCimFixture : IAsyncLifetime +{ + /// Generous: the whole test suite (with SQL Server containers) may run at the same time. + public static readonly ServerConnectionOptions Options = new() { OperationTimeout = TimeSpan.FromMinutes(2) }; + + public CimWindowsServerSource? Source { get; private set; } + + public IWindowsServerSession? Session { get; private set; } + + /// How long the warm-up took, for the assertion messages. + public string WarmUp { get; private set; } = "no warm-up"; + + public async Task InitializeAsync() + { + if (!OperatingSystem.IsWindows()) + { + return; + } + + using var stop = new CancellationTokenSource(TimeSpan.FromMinutes(5)); + var watch = Stopwatch.StartNew(); + var source = new CimWindowsServerSource(Options); + var session = await Once(() => source.ConnectAsync(Environment.MachineName, stop.Token)); + Source = source; + Session = session; + + // One read of every class the tests use; a timeout is retried once (a cold provider), anything else fails the tests. + await Once(() => session.GetOperatingSystemAsync(stop.Token)); + await Once(() => session.GetPerformanceAsync(DateTimeOffset.UtcNow, stop.Token)); + await Once(() => session.GetDisksAsync(stop.Token)); + await Once(() => session.GetServiceAsync("EventLog", stop.Token)); + await Once(() => session.GetEventsAsync(DateTimeOffset.UtcNow.AddMinutes(-5), 1, stop.Token)); + await Once(() => session.GetTasksAsync(_ => false, 1, stop.Token)); + WarmUp = $"warm-up {watch.Elapsed.TotalSeconds:0.0} s"; + + static async Task Once(Func> read) + { + try + { + return await read(); + } + catch (ServerAccessException ex) when (ex.Problem == ServerAccessProblem.Timeout) + { + return await read(); + } + } + } + + public Task DisposeAsync() + { + Session?.Dispose(); + return Task.CompletedTask; + } +} + /// /// The CIM implementation against this computer (a local CIM session, as for the agent's own server). Remote access over /// WS-Man/DCOM with least privilege cannot be tested here; it needs a domain with a second server. /// [Trait("Category", "Windows")] -[System.Runtime.Versioning.SupportedOSPlatform("windows")] -public class LocalCimTests +[Collection(LocalCimGroup.Name)] +[SupportedOSPlatform("windows")] +public sealed class LocalCimTests(LocalCimFixture cim) : IClassFixture { - private static async Task ConnectAsync() - { - if (!OperatingSystem.IsWindows()) - { - return null; - } + /// Every call in a test shares this: a hang is a failure within minutes, never a stuck test run. + private static readonly TimeSpan TestDeadline = TimeSpan.FromMinutes(5); - // Generous: the whole test suite (with SQL Server containers) may run at the same time. - return await new CimWindowsServerSource(new ServerConnectionOptions { OperationTimeout = TimeSpan.FromMinutes(2) }).ConnectAsync(Environment.MachineName, CancellationToken.None); + private readonly List _timings = []; + + private string Timings => cim.WarmUp + "; " + string.Join(", ", _timings); + + private async Task Timed(string what, Func> read) + { + var watch = Stopwatch.StartNew(); + try + { + return await read(); + } + finally + { + _timings.Add($"{what} {watch.Elapsed.TotalSeconds:0.0} s"); + } } [Fact] public async Task Reads_os_performance_disks_services_events_and_tasks() { - using var session = await ConnectAsync(); - if (session is null) + if (cim.Session is not { } session) { return; } - var os = await session.GetOperatingSystemAsync(CancellationToken.None); - var first = await session.GetPerformanceAsync(DateTimeOffset.UtcNow, CancellationToken.None); - await Task.Delay(1500); - var second = await session.GetPerformanceAsync(DateTimeOffset.UtcNow, CancellationToken.None); + using var stop = new CancellationTokenSource(TestDeadline); + var os = await Timed("os", () => session.GetOperatingSystemAsync(stop.Token)); + var first = await Timed("performance", () => session.GetPerformanceAsync(DateTimeOffset.UtcNow, stop.Token)); + await Task.Delay(1500, stop.Token); + var second = await Timed("performance", () => session.GetPerformanceAsync(DateTimeOffset.UtcNow, stop.Token)); var sample = ServerPerformanceMath.Sample(first, second, os); - var disks = await session.GetDisksAsync(CancellationToken.None); - var services = await session.GetServicesAsync(CancellationToken.None); - var service = await session.GetServiceAsync(services[0].Name, CancellationToken.None); - var events = await session.GetEventsAsync(DateTimeOffset.UtcNow.AddDays(-1), 200, CancellationToken.None); - var tasks = await session.GetTasksAsync(name => !TaskResults.IsMicrosoftTask(name), 3, CancellationToken.None); + var disks = await Timed("disks", () => session.GetDisksAsync(stop.Token)); + var services = await Timed("services", () => session.GetServicesAsync(stop.Token)); + var service = await Timed("service", () => session.GetServiceAsync(services[0].Name, stop.Token)); + var missing = await Timed("missing service", () => session.GetServiceAsync("SQLInsight-findes-ikke", stop.Token)); + var events = await Timed("events", () => session.GetEventsAsync(DateTimeOffset.UtcNow.AddHours(-1), 50, stop.Token)); + var tasks = await Timed("tasks", () => session.GetTasksAsync(name => !TaskResults.IsMicrosoftTask(name), 1, stop.Token)); - Assert.Equal("lokal", session.Protocol); + Assert.True(session.Protocol == "lokal", Timings); Assert.Contains("Windows", os.Caption, StringComparison.OrdinalIgnoreCase); - Assert.True(os.LastBootUpTime < DateTimeOffset.UtcNow); - Assert.True(os.TotalMemoryMb > 0); - Assert.True(os.LogicalProcessors > 0); + Assert.True(os.LastBootUpTime < DateTimeOffset.UtcNow, Timings); + Assert.True(os.TotalMemoryMb > 0, Timings); + Assert.True(os.LogicalProcessors > 0, Timings); Assert.InRange(sample.CpuPercent!.Value, 0, 100); - Assert.True(sample.AvailableMb > 0); + Assert.True(sample.AvailableMb > 0, Timings); Assert.InRange(sample.CommitPercent!.Value, 0, 100); - Assert.NotEmpty(disks); + Assert.True(disks.Count > 0, Timings); Assert.All(disks, d => Assert.False(d.Volume.StartsWith(@"\\?\", StringComparison.Ordinal))); Assert.All(disks, d => Assert.InRange(d.FreeGb, 0, d.SizeGb)); - Assert.Contains(services, s => s.IsRunning && s.IsAutomatic); - Assert.Equal(services[0].Name, service!.Name); - Assert.Null(await session.GetServiceAsync("SQLInsight-findes-ikke", CancellationToken.None)); - Assert.Equal("Event Log (RPC)", events.Method); + Assert.True(services.Any(s => s.IsRunning && s.IsAutomatic), Timings); + Assert.True(services[0].Name == service?.Name, Timings); + Assert.True(missing is null, Timings); + Assert.True(events.Method == "Event Log (RPC)", $"{events.Method} {events.Note}; {Timings}"); + Assert.True(events.Entries.Count <= 2 * 50, Timings); Assert.All(events.Entries, e => Assert.InRange(e.Level, 1, 2)); - Assert.True(tasks.Visible > 0); + Assert.True(tasks.Visible > 0, Timings); + Assert.True(tasks.Watched.Count <= 1, Timings); Assert.All(tasks.Watched, t => Assert.False(TaskResults.IsMicrosoftTask(t.FullName))); } [Fact] public async Task The_test_reports_every_area() { - if (!OperatingSystem.IsWindows()) + if (cim.Source is not { } source) { return; } - var result = await WindowsServerTester.TestAsync(new CimWindowsServerSource(new ServerConnectionOptions()), "localhost", "test", DateTimeOffset.UtcNow, CancellationToken.None); + using var stop = new CancellationTokenSource(TestDeadline); + var result = await Timed("test", () => WindowsServerTester.TestAsync(source, "localhost", "test", DateTimeOffset.UtcNow, TestDeadline, stop.Token)); - Assert.True(result.Reachable, result.Error); + Assert.True(result.Reachable, $"{result.Error}; {Timings}"); Assert.Equal(ServerArea.All, result.Areas.Select(a => a.Area)); - Assert.All(result.Areas, a => Assert.True(a.Ok, a.Detail)); + Assert.All(result.Areas, a => Assert.True(a.Ok, $"{a.Area}: {a.Detail}; {Timings}")); } [Fact] @@ -85,10 +168,11 @@ public class LocalCimTests return; } + using var stop = new CancellationTokenSource(TestDeadline); var source = new CimWindowsServerSource(new ServerConnectionOptions { OperationTimeout = TimeSpan.FromSeconds(5) }); - var error = await Assert.ThrowsAsync(() => source.ConnectAsync("sqlinsight-findes-ikke.invalid", CancellationToken.None)); + var error = await Assert.ThrowsAsync(() => Timed("connect", () => source.ConnectAsync("sqlinsight-findes-ikke.invalid", stop.Token))); - Assert.True(error.Problem is ServerAccessProblem.Unreachable or ServerAccessProblem.Timeout, error.Message); + Assert.True(error.Problem is ServerAccessProblem.Unreachable or ServerAccessProblem.Timeout, $"{error.Message}; {Timings}"); Assert.Contains("sqlinsight-findes-ikke.invalid", error.Message, StringComparison.Ordinal); } } diff --git a/tests/SQLInsight.Servers.Tests/ServerAccessTests.cs b/tests/SQLInsight.Servers.Tests/ServerAccessTests.cs index cc1caf7..14017ac 100644 --- a/tests/SQLInsight.Servers.Tests/ServerAccessTests.cs +++ b/tests/SQLInsight.Servers.Tests/ServerAccessTests.cs @@ -22,7 +22,10 @@ public class ServerErrorTests Assert.Contains("0x80070005", error.Message, StringComparison.Ordinal); Assert.Contains("Event Log Readers", Describe(ServerErrors.WbemAccessDenied, area: ServerArea.Events).Message, StringComparison.Ordinal); Assert.Contains("Distributed COM Users", Describe(null, "AccessDenied", area: null, protocol: "DCOM").Message, StringComparison.Ordinal); - Assert.Contains("Remote Management Users", Describe(null, "AccessDenied", area: null, protocol: "WS-Man").Message, StringComparison.Ordinal); + var wsman = Describe(null, "AccessDenied", area: null, protocol: "WS-Man").Message; + Assert.Contains("læseret i WinRM (grant-windows-server.ps1 -WinRM)", wsman, StringComparison.Ordinal); + Assert.DoesNotContain("Remote Management Users", wsman, StringComparison.Ordinal); // that group may also run PowerShell remotely + Assert.DoesNotContain("configSDDL", wsman, StringComparison.Ordinal); } [Fact] diff --git a/tests/SQLInsight.Servers.Tests/ServerDeadlineTests.cs b/tests/SQLInsight.Servers.Tests/ServerDeadlineTests.cs new file mode 100644 index 0000000..6aecbad --- /dev/null +++ b/tests/SQLInsight.Servers.Tests/ServerDeadlineTests.cs @@ -0,0 +1,124 @@ +using System.Diagnostics; +using SQLInsight.Core.Servers; + +namespace SQLInsight.Servers.Tests; + +/// What the agent remembers per server, and that a server that does not answer never holds the agent longer than its deadline. +public class ServerDeadlineTests +{ + private sealed class Clock(DateTimeOffset now) : TimeProvider + { + public DateTimeOffset Now { get; set; } = now; + + public override DateTimeOffset GetUtcNow() => Now; + } + + [Fact] + public void A_fact_about_a_server_is_remembered_for_a_while_then_tried_again() + { + var clock = new Clock(new DateTimeOffset(2026, 10, 2, 12, 0, 0, TimeSpan.Zero)); + var memory = new ServerHostMemory(clock, TimeSpan.FromHours(1)); + + memory.Remember("aos01.firma.local", "protocol", "DCOM"); + clock.Now = clock.Now.AddMinutes(59); + Assert.Equal("DCOM", memory.Recall("AOS01.firma.local", "protocol")); + Assert.Null(memory.Recall("aos01.firma.local", "eventlog-rpc")); + + clock.Now = clock.Now.AddMinutes(1); + Assert.Null(memory.Recall("aos01.firma.local", "protocol")); + + memory.Remember("aos01", "protocol", "DCOM"); + memory.Forget("aos01", "protocol"); + Assert.Null(memory.Recall("aos01", "protocol")); + } + + [Fact] + public void Operation_timeouts_are_bounded() + { + Assert.Equal(TimeSpan.FromSeconds(5), ServerConnectionOptions.BoundTimeout(TimeSpan.Zero)); + Assert.Equal(TimeSpan.FromSeconds(5), ServerConnectionOptions.BoundTimeout(TimeSpan.FromSeconds(-1))); + Assert.Equal(TimeSpan.FromMinutes(5), ServerConnectionOptions.BoundTimeout(TimeSpan.FromHours(3))); + Assert.Equal(TimeSpan.FromSeconds(45), ServerConnectionOptions.BoundTimeout(TimeSpan.FromSeconds(45))); + } + + /// A server that accepts the connection, then never answers any area (it honours cancellation, as the CIM source makes sure it is). + private sealed class HungServer(bool hangOnConnect = false) : IWindowsServerSource, IWindowsServerSession + { + public string Protocol => "DCOM"; + + public string? ProtocolNote => null; + + public async Task ConnectAsync(string host, CancellationToken cancellationToken) + { + if (hangOnConnect) + { + await Hang(cancellationToken); + } + + return this; + } + + private static Task Hang(CancellationToken cancellationToken) => Task.Delay(Timeout.Infinite, cancellationToken); + + public async Task GetOperatingSystemAsync(CancellationToken cancellationToken) + { + await Hang(cancellationToken); + throw new UnreachableException(); + } + + public Task GetPerformanceAsync(DateTimeOffset now, CancellationToken cancellationToken) => throw new UnreachableException(); + + public Task> GetDisksAsync(CancellationToken cancellationToken) => + Task.FromResult>([new ServerDisk(@"C:\", null, "NTFS", 100, 50)]); + + public async Task> GetServicesAsync(CancellationToken cancellationToken) + { + await Hang(cancellationToken); + throw new UnreachableException(); + } + + public Task GetServiceAsync(string name, CancellationToken cancellationToken) => throw new UnreachableException(); + + public async Task GetEventsAsync(IReadOnlyDictionary since, int max, CancellationToken cancellationToken) + { + await Hang(cancellationToken); + throw new UnreachableException(); + } + + public async Task GetTasksAsync(Func watch, int maxWatched, TimeSpan budget, CancellationToken cancellationToken) + { + await Hang(cancellationToken); + throw new UnreachableException(); + } + + public void Dispose() + { + } + } + + [Fact] + public async Task A_test_of_a_server_that_hangs_ends_at_its_deadline_with_every_area_said() + { + var watch = Stopwatch.StartNew(); + var result = await WindowsServerTester.TestAsync(new HungServer(), "aos01", null, DateTimeOffset.UtcNow, TimeSpan.FromMilliseconds(300), CancellationToken.None); + var hungAtConnect = await WindowsServerTester.TestAsync(new HungServer(hangOnConnect: true), "aos01", null, DateTimeOffset.UtcNow, TimeSpan.FromMilliseconds(300), + CancellationToken.None); + + Assert.True(watch.Elapsed < TimeSpan.FromSeconds(30), $"took {watch.Elapsed}"); + Assert.True(result.Reachable); + Assert.Equal(ServerArea.All, result.Areas.Select(a => a.Area)); + Assert.All(result.Areas, a => Assert.False(a.Ok)); + Assert.All(result.Areas, a => Assert.Contains("svarede ikke inden for", a.Detail, StringComparison.Ordinal)); + Assert.False(hungAtConnect.Reachable); + Assert.Contains("svarede ikke inden for", hungAtConnect.Error, StringComparison.Ordinal); + } + + [Fact] + public async Task Stopping_the_agent_still_cancels_a_test() + { + using var stop = new CancellationTokenSource(TimeSpan.FromMilliseconds(200)); + + await Assert.ThrowsAnyAsync(() => + WindowsServerTester.TestAsync(new HungServer(hangOnConnect: true), "aos01", null, DateTimeOffset.UtcNow, TimeSpan.FromMinutes(5), stop.Token)); + } +}