diff --git a/Check-ExcessDrift.ps1 b/Check-ExcessDrift.ps1
new file mode 100644
index 0000000..3bac2c2
--- /dev/null
+++ b/Check-ExcessDrift.ps1
@@ -0,0 +1,48 @@
+#!/usr/bin/env pwsh
+param(
+ [string] $LogFolder = 'C:\Octopus\TimeService',
+ [double] $DurationHours = 12,
+ [double] $SleepMinutes = 30
+)
+
+$ErrorActionPreference = 'Stop'
+
+$markerFileName = 'EXCESS_DRIFT'
+$markerPath = Join-Path $LogFolder $markerFileName
+
+function Write-Log {
+ param([string] $Message)
+ $stamp = (Get-Date).ToString('yyyy-MM-ddTHH:mm:ssK')
+ Write-Host "[$stamp] $Message"
+ # TeamCity service message: surfaces the line prominently in the build log.
+ $escaped = $Message -replace "\|", "||" -replace "'", "|'" -replace "\[", "|[" -replace "\]", "|]" -replace "\r", "" -replace "\n", "|n"
+ Write-Host "##teamcity[message text='$escaped' status='WARNING']"
+}
+
+Write-Log "Checking for excess-drift marker at '$markerPath'."
+
+if (-not (Test-Path -LiteralPath $markerPath -PathType Leaf)) {
+ Write-Log "No EXCESS_DRIFT marker found. Clock drift is within tolerance; nothing to do."
+ exit 0
+}
+
+$deadline = (Get-Date).AddHours($DurationHours)
+$sleep = [TimeSpan]::FromMinutes($SleepMinutes)
+
+Write-Log "EXCESS_DRIFT marker found. Holding for $DurationHours hour(s), logging every $SleepMinutes minute(s). Will finish at $($deadline.ToString('yyyy-MM-ddTHH:mm:ssK'))."
+
+while ($true) {
+ $remaining = $deadline - (Get-Date)
+ if ($remaining -le [TimeSpan]::Zero) { break }
+
+ Write-Log "Excess clock drift detected by OctopusTimeService (marker: '$markerPath'). $([int]$remaining.TotalMinutes) minute(s) remaining."
+
+ # Don't overshoot the 12-hour deadline on the final iteration.
+ $thisSleep = if ($remaining -lt $sleep) { $remaining } else { $sleep }
+ if ($thisSleep -gt [TimeSpan]::Zero) {
+ Start-Sleep -Seconds ([int]$thisSleep.TotalSeconds)
+ }
+}
+
+Write-Log "Excess-drift hold complete after $DurationHours hour(s)."
+exit 0
diff --git a/src/OctopusTimeService/Logging/ExcessDriftMonitor.cs b/src/OctopusTimeService/Logging/ExcessDriftMonitor.cs
new file mode 100644
index 0000000..ab0bb3f
--- /dev/null
+++ b/src/OctopusTimeService/Logging/ExcessDriftMonitor.cs
@@ -0,0 +1,82 @@
+namespace TimeService.Logging;
+
+///
+/// Watches successive NTP drift measurements and raises a one-time alert when the clock has been
+/// excessively wrong for several consecutive measurements. "Excessive" means the absolute drift
+/// (server ahead of, or behind, the local clock) exceeds ; the alert
+/// fires once the streak of excessive measurements reaches
+/// in a row. A single within-threshold measurement resets the streak.
+///
+/// When tripped it logs (EventId 1500) and drops an
+/// empty EXCESS_DRIFT marker file into the log folder. The alert fires at most once per process
+/// lifetime. State is held in memory, which suits this long-running service. Thread-safe.
+///
+public sealed class ExcessDriftMonitor
+{
+ public const string MarkerFileName = "EXCESS_DRIFT";
+ public const int DefaultConsecutiveThreshold = 3;
+ public static readonly TimeSpan DefaultThreshold = TimeSpan.FromSeconds(60);
+
+ private readonly ILogger logger;
+ private readonly string directory;
+ private readonly TimeSpan threshold;
+ private readonly int consecutiveThreshold;
+ private readonly Lock gate = new();
+
+ private int consecutiveExcessCount;
+ private bool alerted;
+
+ public ExcessDriftMonitor(ILogger logger, string directory)
+ : this(logger, directory, DefaultThreshold, DefaultConsecutiveThreshold)
+ {
+ }
+
+ public ExcessDriftMonitor(
+ ILogger logger,
+ string directory,
+ TimeSpan threshold,
+ int consecutiveThreshold)
+ {
+ this.logger = logger;
+ this.directory = directory;
+ this.threshold = threshold;
+ this.consecutiveThreshold = consecutiveThreshold;
+ }
+
+ ///
+ /// Records one drift measurement, updating the consecutive-excess streak and firing the
+ /// one-time alert if the streak reaches the configured threshold. Drift may be positive or
+ /// negative; only its magnitude relative to the threshold matters.
+ ///
+ public void Record(TimeSpan drift)
+ {
+ lock (gate)
+ {
+ var excess = drift.Duration() > threshold;
+ consecutiveExcessCount = excess ? consecutiveExcessCount + 1 : 0;
+
+ if (alerted || consecutiveExcessCount < consecutiveThreshold)
+ return;
+
+ alerted = true;
+ Log.ExcessDriftDetected(logger);
+ WriteMarkerFile();
+ }
+ }
+
+ private void WriteMarkerFile()
+ {
+ var path = Path.Combine(directory, MarkerFileName);
+ try
+ {
+ Directory.CreateDirectory(directory);
+ // Empty placeholder. OpenOrCreate leaves any existing marker untouched — a marker
+ // already on disk (e.g. left by a prior run) is expected, not an error.
+ using var _ = File.Open(path, FileMode.OpenOrCreate, FileAccess.Write, FileShare.ReadWrite);
+ }
+ catch (Exception ex)
+ {
+ Log.ExcessDriftMarkerWriteFailed(logger, path, ex);
+ }
+ }
+}
diff --git a/src/OctopusTimeService/Logging/Log.cs b/src/OctopusTimeService/Logging/Log.cs
index c24db93..e56ce7d 100644
--- a/src/OctopusTimeService/Logging/Log.cs
+++ b/src/OctopusTimeService/Logging/Log.cs
@@ -5,8 +5,8 @@ namespace TimeService.Logging;
///
/// Source-generated logging for the service. Each entry has a stable EventId so individual
/// events are identifiable in the Windows Event Log.
-/// Ranges: 1000-1099 Worker, 2000-2099 StartupSequence, 3000-3099 WindowsServiceOps,
-/// 4000-4099 ScheduledTaskOps.
+/// Ranges: 1000-1099 Worker, 1500-1599 drift monitoring, 2000-2099 StartupSequence,
+/// 3000-3099 WindowsServiceOps, 4000-4099 ScheduledTaskOps.
///
internal static partial class Log
{
@@ -44,6 +44,16 @@ internal static partial class Log
Message = "Failed to write drift measurement to CSV log at {Path}")]
public static partial void DriftCsvWriteFailed(ILogger logger, string path, Exception ex);
+ // -------- Drift monitoring (1500-1599) --------
+
+ [LoggerMessage(EventId = 1500, Level = LogLevel.Error,
+ Message = "Excess Drift Detected")]
+ public static partial void ExcessDriftDetected(ILogger logger);
+
+ [LoggerMessage(EventId = 1501, Level = LogLevel.Warning,
+ Message = "Failed to write EXCESS_DRIFT marker file at {Path}")]
+ public static partial void ExcessDriftMarkerWriteFailed(ILogger logger, string path, Exception ex);
+
// -------- StartupSequence (2000-2099) --------
[LoggerMessage(EventId = 2001, Level = LogLevel.Information,
diff --git a/src/OctopusTimeService/Program.cs b/src/OctopusTimeService/Program.cs
index e84408a..684efc7 100644
--- a/src/OctopusTimeService/Program.cs
+++ b/src/OctopusTimeService/Program.cs
@@ -52,6 +52,9 @@ static int RunAsService(string[] forwardedArgs)
builder.Services.AddSingleton(sp => new DriftCsvLog(
sp.GetRequiredService>(),
RegistrySettings.ReadLogFolder(ServiceDefaults.ServiceName)));
+ builder.Services.AddSingleton(sp => new ExcessDriftMonitor(
+ sp.GetRequiredService>(),
+ RegistrySettings.ReadLogFolder(ServiceDefaults.ServiceName)));
builder.Services.AddSingleton(sp => new StartupSequence(
sp.GetRequiredService>(),
sp.GetRequiredService(),
@@ -69,6 +72,9 @@ static int RunAsConsole(string[] forwardedArgs)
builder.Services.AddSingleton(sp => new DriftCsvLog(
sp.GetRequiredService>(),
RegistrySettings.ReadLogFolder(ServiceDefaults.ServiceName)));
+ builder.Services.AddSingleton(sp => new ExcessDriftMonitor(
+ sp.GetRequiredService>(),
+ RegistrySettings.ReadLogFolder(ServiceDefaults.ServiceName)));
builder.Services.AddSingleton(sp => new StartupSequence(
sp.GetRequiredService>(),
sp.GetRequiredService(),
diff --git a/src/OctopusTimeService/Worker.cs b/src/OctopusTimeService/Worker.cs
index 8f28dd6..4147008 100644
--- a/src/OctopusTimeService/Worker.cs
+++ b/src/OctopusTimeService/Worker.cs
@@ -8,7 +8,8 @@ public class Worker(
ILogger logger,
NtpClient ntpClient,
StartupSequence startupSequence,
- DriftCsvLog driftCsvLog) : BackgroundService
+ DriftCsvLog driftCsvLog,
+ ExcessDriftMonitor excessDriftMonitor) : BackgroundService
{
private readonly TimeSpan measurementInterval = TimeSpan.FromSeconds(
RegistrySettings.ReadNtpCheckIntervalSeconds(ServiceDefaults.ServiceName));
@@ -38,7 +39,7 @@ protected override async Task ExecuteAsync(CancellationToken stoppingToken)
using var timer = new PeriodicTimer(measurementInterval);
while (!stoppingToken.IsCancellationRequested && await timer.WaitForNextTickAsync(stoppingToken))
{
- await MeasureAndLogDriftAsync(logger, ntpClient, driftCsvLog, "steady-state", stoppingToken);
+ await MeasureAndLogDriftAsync(logger, ntpClient, driftCsvLog, "steady-state", stoppingToken, excessDriftMonitor);
}
}
@@ -47,14 +48,17 @@ protected override async Task ExecuteAsync(CancellationToken stoppingToken)
/// on-disk CSV log. Shared by the steady-state loop and so every
/// measurement, whatever its origin, lands in both sinks identically.
/// labels the measurement in the event log (e.g. "steady-state", "pre-resync", "post-resync").
- /// Measurement failures are logged and swallowed; host cancellation is propagated.
+ /// When an is supplied, each successful measurement is fed
+ /// to it so it can track consecutive excess-drift streaks. Measurement failures are logged and
+ /// swallowed (and do not touch the monitor); host cancellation is propagated.
///
public static async Task MeasureAndLogDriftAsync(
ILogger logger,
NtpClient ntpClient,
DriftCsvLog driftCsvLog,
string phase,
- CancellationToken cancellationToken)
+ CancellationToken cancellationToken,
+ ExcessDriftMonitor? excessDriftMonitor = null)
{
try
{
@@ -63,6 +67,7 @@ public static async Task MeasureAndLogDriftAsync(
var ntpTime = localTime + result.Drift;
Log.ClockDrift(logger, phase, ntpClient.Server, result.Drift, result.MarginOfError);
driftCsvLog.Append(localTime, ntpTime, result.Drift, result.MarginOfError);
+ excessDriftMonitor?.Record(result.Drift);
}
catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested)
{
diff --git a/tests/TimeService.Tests/Logging/ExcessDriftMonitorTests.cs b/tests/TimeService.Tests/Logging/ExcessDriftMonitorTests.cs
new file mode 100644
index 0000000..e18465e
--- /dev/null
+++ b/tests/TimeService.Tests/Logging/ExcessDriftMonitorTests.cs
@@ -0,0 +1,162 @@
+using Microsoft.Extensions.Logging;
+using TimeService.Logging;
+
+namespace TimeService.Tests.Logging;
+
+public class ExcessDriftMonitorTests
+{
+ private const int ExcessDriftEventId = 1500;
+ private static readonly TimeSpan Threshold = TimeSpan.FromSeconds(60);
+
+ // Excess = strictly more than 60s away, positive or negative.
+ private static readonly TimeSpan Excess = TimeSpan.FromSeconds(61);
+ private static readonly TimeSpan ExcessNegative = TimeSpan.FromSeconds(-61);
+ private static readonly TimeSpan Good = TimeSpan.FromSeconds(10);
+
+ [Fact]
+ public void Does_not_trip_before_three_consecutive_excess_measurements()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+
+ Assert.Equal(0, logger.CountOf(ExcessDriftEventId));
+ Assert.False(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void Trips_on_third_consecutive_excess_measurement()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+
+ Assert.Equal(1, logger.CountOf(ExcessDriftEventId));
+ Assert.True(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void A_good_measurement_resets_the_streak()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ // Two excess, then a good one resets, so the following two are not enough.
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+ monitor.Record(Good);
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+
+ Assert.Equal(0, logger.CountOf(ExcessDriftEventId));
+ Assert.False(MarkerExists(dir));
+
+ // A third consecutive excess after the reset finally trips it.
+ monitor.Record(Excess);
+
+ Assert.Equal(1, logger.CountOf(ExcessDriftEventId));
+ Assert.True(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void Negative_drift_counts_as_excess()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ monitor.Record(ExcessNegative);
+ monitor.Record(ExcessNegative);
+ monitor.Record(ExcessNegative);
+
+ Assert.Equal(1, logger.CountOf(ExcessDriftEventId));
+ Assert.True(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void Drift_exactly_at_the_threshold_is_not_excess()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ // Exactly 60s is "more than 60s away"? No — the rule is strictly greater than 60s.
+ monitor.Record(Threshold);
+ monitor.Record(Threshold);
+ monitor.Record(Threshold);
+
+ Assert.Equal(0, logger.CountOf(ExcessDriftEventId));
+ Assert.False(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void Alert_fires_only_once_even_with_further_excess_measurements()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+
+ for (var i = 0; i < 10; i++)
+ monitor.Record(Excess);
+
+ Assert.Equal(1, logger.CountOf(ExcessDriftEventId));
+ Assert.True(MarkerExists(dir));
+ }
+
+ [Fact]
+ public void An_existing_marker_file_is_not_an_error()
+ {
+ var (monitor, logger, dir) = NewMonitor();
+ Directory.CreateDirectory(dir);
+ var markerPath = Path.Combine(dir, ExcessDriftMonitor.MarkerFileName);
+ File.WriteAllText(markerPath, "left over from a prior run");
+
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+
+ Assert.Equal(1, logger.CountOf(ExcessDriftEventId));
+ Assert.True(File.Exists(markerPath));
+ }
+
+ [Fact]
+ public void Marker_file_is_created_empty()
+ {
+ var (monitor, _, dir) = NewMonitor();
+
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+ monitor.Record(Excess);
+
+ var markerPath = Path.Combine(dir, ExcessDriftMonitor.MarkerFileName);
+ Assert.True(File.Exists(markerPath));
+ Assert.Equal(0, new FileInfo(markerPath).Length);
+ }
+
+ private static (ExcessDriftMonitor Monitor, RecordingLogger Logger, string Directory) NewMonitor()
+ {
+ var dir = Path.Combine(Path.GetTempPath(), $"octopus-timeservice-tests-{Guid.NewGuid():N}");
+ var logger = new RecordingLogger();
+ var monitor = new ExcessDriftMonitor(
+ logger, dir, Threshold, ExcessDriftMonitor.DefaultConsecutiveThreshold);
+ return (monitor, logger, dir);
+ }
+
+ private static bool MarkerExists(string directory) =>
+ File.Exists(Path.Combine(directory, ExcessDriftMonitor.MarkerFileName));
+
+ /// Minimal that counts how many times each EventId was logged.
+ private sealed class RecordingLogger : ILogger
+ {
+ private readonly Dictionary countsByEventId = new();
+
+ public int CountOf(int eventId) => countsByEventId.GetValueOrDefault(eventId);
+
+ public void Log(
+ LogLevel logLevel, EventId eventId, TState state, Exception? exception,
+ Func formatter)
+ {
+ countsByEventId[eventId.Id] = CountOf(eventId.Id) + 1;
+ }
+
+ public bool IsEnabled(LogLevel logLevel) => true;
+
+ public IDisposable? BeginScope(TState state) where TState : notnull => null;
+ }
+}