From 70934e75624163399401f73b69ed420733098d1a Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?S=C3=B8ren=20Eggert=20Lundsteen=20Olsen?= <seo@seosoft.dk>
Date: Fri, 2 Oct 2026 11:31:00 +0200
Subject: [PATCH] Review 1.2: error log entries are no longer counted again

The default trace was filtered on whole seconds only, so the newest entry
read (ReadUntil) came back at every collection until a newer one was
written: one 824 became a new event every 5 minutes. Entries at or before
ReadUntil are now left out, as for xp_readerrorlog.

The ring buffer's times were computed to whole seconds from the clock at
each read and moved by up to a second between reads, so the newest entry
could be counted twice. They are now computed to the millisecond with a
small tolerance.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
---
 .../Instance/ErrorLogCollector.cs             | 20 ++++++++++++++-----
 1 file changed, 15 insertions(+), 5 deletions(-)

diff --git a/src/SQLInsight.Collectors/Instance/ErrorLogCollector.cs b/src/SQLInsight.Collectors/Instance/ErrorLogCollector.cs
index 77848e2..410448a 100644
--- a/src/SQLInsight.Collectors/Instance/ErrorLogCollector.cs
+++ b/src/SQLInsight.Collectors/Instance/ErrorLogCollector.cs
@@ -16,14 +16,19 @@ public sealed class ErrorLogCollector(int loginFailureBurst = 20) : Collector<Er
     /// <summary>On the first collection, this far back.</summary>
     public static readonly TimeSpan FirstLookBack = TimeSpan.FromHours(1);
 
+    /// <summary>How much the ring buffer's computed times can move between two reads.</summary>
+    internal static readonly TimeSpan RingBufferClockTolerance = TimeSpan.FromMilliseconds(50);
+
     internal const string CanReadErrorLogSql = """
         SELECT CASE WHEN IS_SRVROLEMEMBER(N'securityadmin') = 1 OR IS_SRVROLEMEMBER(N'sysadmin') = 1 THEN 1 ELSE 0 END,
                DATEDIFF(minute, GETUTCDATE(), GETDATE()), GETUTCDATE()
         """;
 
     // The exception ring buffer: every exception raised, with number and severity. ms_ticks is the clock it counts in.
+    // The time is computed to the millisecond: rounded to whole seconds it moved by up to a second between collections,
+    // so the newest entry could be read (and counted) again.
     internal const string RingBufferSql = """
-        SELECT DATEADD(second, -CAST((i.ms_ticks - rb.timestamp) / 1000 AS int), GETUTCDATE()),
+        SELECT DATEADD(millisecond, -CAST((i.ms_ticks - rb.timestamp) % 1000 AS int), DATEADD(second, -CAST((i.ms_ticks - rb.timestamp) / 1000 AS int), GETUTCDATE())),
                rb.x.value('(//Exception/Error)[1]', 'int'), rb.x.value('(//Exception/Severity)[1]', 'int')
         FROM (SELECT timestamp, CAST(record AS xml) AS x FROM sys.dm_os_ring_buffers WHERE ring_buffer_type = N'RING_BUFFER_EXCEPTION') rb
         CROSS JOIN sys.dm_os_sys_info i
@@ -31,7 +36,7 @@ public sealed class ErrorLogCollector(int loginFailureBurst = 20) : Collector<Er
 
     // Failed logins in the connectivity ring buffer (SQL Server 2008+): error 18456 with its state and client address.
     internal const string ConnectivitySql = """
-        SELECT DATEADD(second, -CAST((i.ms_ticks - rb.timestamp) / 1000 AS int), GETUTCDATE()),
+        SELECT DATEADD(millisecond, -CAST((i.ms_ticks - rb.timestamp) % 1000 AS int), DATEADD(second, -CAST((i.ms_ticks - rb.timestamp) / 1000 AS int), GETUTCDATE())),
                rb.x.value('(//SniConsumerError)[1]', 'int'), rb.x.value('(//State)[1]', 'int'), rb.x.value('(//RemoteHost)[1]', 'nvarchar(128)')
         FROM (SELECT timestamp, CAST(record AS xml) AS x FROM sys.dm_os_ring_buffers
               WHERE ring_buffer_type = N'RING_BUFFER_CONNECTIVITY' AND record LIKE N'%<SniConsumerError>18456</SniConsumerError>%') rb
@@ -74,12 +79,15 @@ public sealed class ErrorLogCollector(int loginFailureBurst = 20) : Collector<Er
         }
         else
         {
+            // The ring buffer's times are derived from the server's clock at each read and can differ by a few
+            // milliseconds between reads (datetime precision), so the newest entry read last time must not be read again.
+            var after = since + RingBufferClockTolerance;
             entries = (await Db.QueryAsync(connection, RingBufferSql, r => new ErrorLogEntry(Utc(r.DateTime(0)), r.NullableInt(1), r.NullableInt(2), null), ct)
-                .ConfigureAwait(false)).Where(e => e.At > since).ToList();
+                .ConfigureAwait(false)).Where(e => e.At > after).ToList();
             if (context.Instance.Version.Major >= 10)
             {
                 entries.AddRange((await Db.QueryAsync(connection, ConnectivitySql, r => new ErrorLogEntry(Utc(r.DateTime(0)), 18456, 14,
-                    $"Login failed (state {r.NullableInt(2)}) [CLIENT: {r.NullableString(3)}]"), ct).ConfigureAwait(false)).Where(e => e.At > since));
+                    $"Login failed (state {r.NullableInt(2)}) [CLIENT: {r.NullableString(3)}]"), ct).ConfigureAwait(false)).Where(e => e.At > after));
             }
 
             (source, coverage) = (ErrorLogSource.RingBuffer, RingBufferCoverage);
@@ -154,7 +162,9 @@ public sealed class ErrorLogCollector(int loginFailureBurst = 20) : Collector<Er
                 }
             }
 
-            return entries;
+            // StartTime is compared to whole seconds above, so the entries of that second that were read last time
+            // (the newest of them is ReadUntil) come back; leave them out, or they are counted again every collection.
+            return [.. entries.Where(e => e.At > since)];
         }
         catch (DbException)
         {