sqlinsight-pro/src/SQLInsight.Agent/Servers/ServerMonitoringService.cs
Søren Eggert Lundsteen Olsen 6d8a5d9ad7 Review 1.5: a Windows server that hangs no longer holds up the agent; reads are bounded and backed off
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) <noreply@anthropic.com>
2026-10-02 16:02:17 +02:00

231 lines
10 KiB
C#

using Microsoft.Extensions.Options;
using SQLInsight.Core.Servers;
using SQLInsight.Notifications;
using SQLInsight.Repository;
using SQLInsight.Servers;
namespace SQLInsight.Agent.Servers;
/// <summary>
/// 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 and check results hourly (also when only the
/// synthetic checks are on).
/// </summary>
public sealed partial class ServerMonitoringService(
IOptions<ServerOptions> options,
IOptions<SyntheticCheckOptions> checkOptions,
IWindowsServerSource source,
InsightRepository repository,
TimeProvider time,
ILoggerFactory loggerFactory,
NotificationDispatcher notifications,
IOptions<NotificationOptions> notificationOptions,
IOptions<AgentOptions> agentOptions,
Configuration.RepositoryReadiness readiness) : BackgroundService
{
public static readonly TimeSpan RefreshInterval = TimeSpan.FromMinutes(1);
public static readonly TimeSpan MaintenanceInterval = TimeSpan.FromHours(1);
private readonly ILogger _logger = loggerFactory.CreateLogger<ServerMonitoringService>();
protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
var settings = options.Value;
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<int, ServerMonitor>();
var running = new Dictionary<int, Task>();
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);
try
{
do
{
var now = time.GetUtcNow();
try
{
if (now >= nextRefresh)
{
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))
{
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);
}
}
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);
}
/// <summary>Servers off, synthetic checks on: only the hourly maintenance.</summary>
private async Task MaintainOnlyAsync(ServerOptions settings, CancellationToken stoppingToken)
{
try
{
await readiness.Ready.WaitAsync(stoppingToken).ConfigureAwait(false);
using var timer = new PeriodicTimer(MaintenanceInterval, time);
do
{
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.
}
}
/// <summary>Deletes what is past retention, in small batches; every period is at least a day (see <see cref="ServerOptions.Normalize"/>).</summary>
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);
/// <summary>
/// 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.
/// </summary>
internal static async Task WaitQuietlyAsync(IEnumerable<Task> tasks)
{
foreach (var task in tasks)
{
try
{
await task.ConfigureAwait(false);
}
catch (Exception ex) when (ex is OperationCanceledException or System.Data.Common.DbException)
{
// Stopping.
}
}
}
/// <summary>The SQL Server hosts first, then the servers to look at (not paused).</summary>
private async Task RefreshAsync(Dictionary<int, ServerMonitor> monitors, ServerOptions settings, DateTimeOffset now, CancellationToken cancellationToken)
{
if (settings.IncludeSqlHosts)
{
var hosts = (await repository.GetConfiguredInstancesAsync(cancellationToken).ConfigureAwait(false))
.Select(i => ServerHost.FromDataSource(i.DataSource, Environment.MachineName).Host)
.OfType<string>()
.Distinct(StringComparer.OrdinalIgnoreCase)
.Select(h => (h, ServerHost.ShortName(h)))
.ToList();
await repository.SyncSqlHostServersAsync(hosts, now, cancellationToken).ConfigureAwait(false);
}
var servers = (await repository.GetWindowsServersAsync(cancellationToken).ConfigureAwait(false)).Where(s => !s.Paused).ToList();
foreach (var row in servers)
{
if (monitors.TryGetValue(row.ServerId, out var monitor) && string.Equals(monitor.Server.Host, row.Host, StringComparison.OrdinalIgnoreCase))
{
monitor.Update(row);
continue;
}
monitors[row.ServerId] = new ServerMonitor(row, source, repository, settings, loggerFactory.CreateLogger($"SQLInsight.Server.{row.Name}"), notifications,
notificationOptions.Value.WebUrl);
LogStarted(_logger, row.Name, row.Host);
}
foreach (var gone in monitors.Keys.Where(id => servers.All(s => s.ServerId != id)).ToList())
{
LogStopped(_logger, monitors[gone].Server.Name);
monitors.Remove(gone);
}
}
/// <summary>
/// One server's cycle when a slot is free, with the time taken then (not when it was queued). The cycle bounds
/// itself (<see cref="ServerOptions.CycleTimeout"/>), so a hung server gives its slot back.
/// </summary>
private async Task RunThrottledAsync(ServerMonitor monitor, SemaphoreSlim throttle, CancellationToken cancellationToken)
{
await throttle.WaitAsync(cancellationToken).ConfigureAwait(false);
try
{
await monitor.RunCycleAsync(time.GetUtcNow(), cancellationToken).ConfigureAwait(false);
}
catch (Exception ex) when (!cancellationToken.IsCancellationRequested)
{
LogCycleFailed(_logger, ex, monitor.Server.Name);
}
finally
{
throttle.Release();
}
}
[LoggerMessage(Level = LogLevel.Information, Message = "Windows servers are not monitored (SQLInsight:Servers:Enabled is false).")]
private static partial void LogDisabled(ILogger logger);
[LoggerMessage(Level = LogLevel.Information, Message = "Windows server {Server} ({Host}): monitoring started")]
private static partial void LogStarted(ILogger logger, string server, string host);
[LoggerMessage(Level = LogLevel.Information, Message = "Windows server {Server}: monitoring stopped (paused or removed)")]
private static partial void LogStopped(ILogger logger, string server);
[LoggerMessage(Level = LogLevel.Error, Message = "Windows server {Server}: cycle failed")]
private static partial void LogCycleFailed(ILogger logger, Exception exception, string server);
[LoggerMessage(Level = LogLevel.Error, Message = "Monitoring Windows servers failed this round; retrying.")]
private static partial void LogRoundFailed(ILogger logger, Exception exception);
}