State the tail-overlap condition where the recovery claim is made, and pin it to the cadence

Lite.Tests/LogTailOverlapThresholdPinTests.cs

@@ -0,0 +1,183 @@
+/*
+ * Copyright (c) 2026 Erik Darling, Darling Data LLC
+ *
+ * This file is part of the SQL Server Performance Monitor Lite.
+ *
+ * Licensed under the MIT License. See LICENSE file in the project root for full license information.
+ */
+
+using System;
+using System.Collections.Generic;
+using System.Globalization;
+using System.IO;
+using System.Linq;
+using System.Text.RegularExpressions;
+using PerformanceMonitor.Collectors;
+using Xunit;
+
+namespace Lite.Tests;
+
+/// <summary>
+/// The two server-log collectors read the same file the same way — a fixed byte tail via
+/// <c>pg_read_file</c>, no resume marker — and their doc comments explain truncation recovery in terms of
+/// consecutive reads OVERLAPPING. That only happens while the log grows by less than one tail between
+/// cycles, so the threshold is <c>TailBytes / interval</c> and it is a different number for each of them:
+/// <c>pg_deadlocks</c> runs every five minutes and <c>pg_plan_capture</c> every sixty.
+///
+/// <para>Those numbers are written into four prose comments, which makes them exactly the thing that goes
+/// stale when somebody changes a cadence or the tail and reads the comment as still true. So the threshold
+/// is DERIVED here from <see cref="CollectorScheduleDefaults"/> and the collectors' own constants, and the
+/// figure each comment states is parsed back out and compared. Changing either input fails this.</para>
+///
+/// <para>Every assertion is floored on the population it matched, because the failure mode being guarded
+/// is a claim nobody checks — a regex that silently matches nothing would "pass" while proving nothing,
+/// which is the same shape as the drift itself.</para>
+/// </summary>
+public sealed class LogTailOverlapThresholdPinTests
+{
+    private static string RepoFile(string relativePath)
+    {
+        var dir = AppContext.BaseDirectory;
+        for (int i = 0; i < 10 && dir is not null; i++)
+        {
+            var candidate = Path.Combine(dir, relativePath);
+            if (File.Exists(candidate))
+            {
+                return candidate;
+            }
+            dir = Path.GetDirectoryName(dir);
+        }
+        throw new FileNotFoundException($"Could not locate {relativePath} from {AppContext.BaseDirectory}");
+    }
+
+    private static string Collectors(string fileName) =>
+        File.ReadAllText(RepoFile(Path.Combine("PerformanceMonitor.Collectors", fileName)));
+
+    /* The literal spliced into each collector's SQL. Read from source rather than referenced, because
+       both are private consts - and reading them is the point: the pin is that the two agree. */
+    private static int TailBytesIn(string fileName)
+    {
+        var source = Collectors(fileName);
+        var match = Regex.Match(source, @"TailBytesLiteral\s*=\s*""(\d+)""");
+        Assert.True(match.Success, $"No TailBytesLiteral found in {fileName} — the tail is no longer spelled the way this pin reads it, so its arithmetic is unverified rather than satisfied.");
+        return int.Parse(match.Groups[1].Value, CultureInfo.InvariantCulture);
+    }
+
+    /// <summary>
+    /// KB/s of log growth at which consecutive tail reads stop overlapping: one tail spread over one
+    /// interval.
+    /// </summary>
+    private static double ThresholdKbPerSecond(int tailBytes, int intervalMinutes) =>
+        tailBytes / (intervalMinutes * 60.0) / 1024.0;
+
+    [Fact]
+    public void BothLogTailCollectors_ReadTheSameTail()
+    {
+        var deadlocks = TailBytesIn("PgDeadlocksCollector.cs");
+        var plans = TailBytesIn("PgPlanCaptureCollector.cs");
+
+        Assert.Equal(4 * 1024 * 1024, deadlocks);
+        Assert.Equal(deadlocks, plans);
+    }
+
+    [Fact]
+    public void TheTwoCadences_AreNotEqual_AndNoCommentClaimsTheyAre()
+    {
+        var deadlockMinutes = CollectorScheduleDefaults.All["pg_deadlocks"].FrequencyMinutes;
+        var planMinutes = CollectorScheduleDefaults.All["pg_plan_capture"].FrequencyMinutes;
+
+        /* Not an accident and not interchangeable: a deadlock is an event that has to still be inside the
+           window when the read comes round, and the plan collector's hourly interval was chosen for the
+           consume-once RDS transport that shares its schedule key. If these are ever equalised the prose
+           below has to change with them, which is why this asserts the relationship rather than either
+           number alone. */
+        Assert.NotEqual(deadlockMinutes, planMinutes);
+        Assert.True(deadlockMinutes < planMinutes, $"pg_deadlocks ({deadlockMinutes}m) is expected to run more often than pg_plan_capture ({planMinutes}m).");
+
+        /* The specific false claim this pin exists to prevent recurring: the schedule table describing one
+           of these cadences as matching the other. Anchored to the two collector names appearing in a
+           claim of sameness rather than to one phrasing, and the control below proves it can fire. */
+        var schedule = Collectors("CollectorScheduleDefaults.cs");
+        foreach (var phrase in ClaimsOfParity(schedule))
+        {
+            Assert.Fail($"CollectorScheduleDefaults claims a cadence match between the two log-tail collectors, but they run {deadlockMinutes}m and {planMinutes}m apart: \"{phrase.Trim()}\"");
+        }
+    }
+
+    private static IEnumerable<string> ClaimsOfParity(string source) =>
+        Regex.Matches(source, @"[^.\r\n]*\b(?:matching|matches|same as|identical to)\s+pg_plan_capture\b[^.\r\n]*")
+             .Select(m => m.Value)
+             .Concat(Regex.Matches(source, @"[^.\r\n]*\b(?:matching|matches|same as|identical to)\s+pg_deadlocks\b[^.\r\n]*")
+                          .Select(m => m.Value));
+
+    [Fact]
+    public void TheParityDetector_FiresOnTheClaimItGuardsAgainst()
+    {
+        /* Without this, the assertion above passes on any source that simply never says the word - and it
+           would have passed on a file where the claim was reworded. Both directions, because the schedule
+           table could name either collector as the one being matched. */
+        Assert.Single(ClaimsOfParity("Every 5 minutes against a 4 MB tail, matching pg_plan_capture: the two read the same file."));
+        Assert.Single(ClaimsOfParity("Hourly, same as pg_deadlocks, because both read a log."));
+        Assert.Empty(ClaimsOfParity("Every 5 minutes against the same 4 MB tail pg_plan_capture reads, at a TWELFTH of its interval."));
+    }
+
+    /* One file legitimately states BOTH thresholds - the schedule table explains both cadences - so this
+       cannot assert that every figure in a file matches one collector. It asserts two things instead: the
+       collector's OWN threshold appears in the file that explains it, and every figure stated anywhere is
+       one of the two the arithmetic produces. A third number, or a stale one after a cadence change, fails
+       the second; a comment that quietly dropped its threshold fails the first. */
+    [Theory]
+    [InlineData("pg_deadlocks", "CollectorScheduleDefaults.cs")]
+    [InlineData("pg_deadlocks", "PgDeadlockLogParser.cs")]
+    [InlineData("pg_plan_capture", "CollectorScheduleDefaults.cs")]
+    [InlineData("pg_plan_capture", "PgPlanCaptureCollector.cs")]
+    [InlineData("pg_plan_capture", "PgPlanLogParser.cs")]
+    public void EveryStatedOverlapThreshold_MatchesTheCadenceAndTailItIsDerivedFrom(string collectorName, string fileName)
+    {
+        var own = ThresholdFor(collectorName);
+        var everyKnown = new[] { ThresholdFor("pg_deadlocks"), ThresholdFor("pg_plan_capture") };
+
+        var stated = StatedThresholds(fileName);
+
+        /* The floor. A comment that stopped stating its threshold would otherwise satisfy this by having
+           nothing to check, which is the drift being guarded rather than a state to accept. */
+        Assert.True(stated.Length > 0, $"{fileName} states no KB/s overlap threshold, so the cadence it explains is unverified. Expected roughly {own:0.0} KB/s for {collectorName}.");
+
+        Assert.True(
+            stated.Any(v => Math.Abs(v - own) <= Tolerance),
+            $"{fileName} explains {collectorName} but states no figure near {own:0.00} KB/s (the {CollectorScheduleDefaults.All[collectorName].FrequencyMinutes}-minute cadence against its tail). Stated: {string.Join(", ", stated)}.");
+
+        foreach (var value in stated)
+        {
+            Assert.True(
+                everyKnown.Any(k => Math.Abs(value - k) <= Tolerance),
+                $"{fileName} states {value} KB/s, which is neither collector's overlap threshold ({string.Join(" or ", everyKnown.Select(k => k.ToString("0.00", CultureInfo.InvariantCulture)))} KB/s). A cadence or tail change has to move the prose with it.");
+        }
+    }
+
+    /* Rounded prose against derived arithmetic: wide enough for "about 14" and "1.2", far too narrow to
+       survive a cadence change, which moves these by 12x. */
+    private const double Tolerance = 0.5;
+
+    private static double ThresholdFor(string collectorName)
+    {
+        var tail = TailBytesIn(collectorName == "pg_deadlocks" ? "PgDeadlocksCollector.cs" : "PgPlanCaptureCollector.cs");
+        return ThresholdKbPerSecond(tail, CollectorScheduleDefaults.All[collectorName].FrequencyMinutes);
+    }
+
+    private static double[] StatedThresholds(string fileName) =>
+        Regex.Matches(Collectors(fileName), @"(\d+(?:\.\d+)?)\s*KB/s")
+             .Select(m => double.Parse(m.Groups[1].Value, CultureInfo.InvariantCulture))
+             .ToArray();
+
+    [Fact]
+    public void TheThresholdArithmetic_IsTheOneTheCommentsDescribe()
+    {
+        /* Guards the helper itself rather than the prose: a tail spread over its interval, so halving the
+           interval doubles the rate the window can absorb. Fixed numbers, so a refactor of the expression
+           above cannot quietly redefine what "threshold" means. */
+        Assert.Equal(13.65, ThresholdKbPerSecond(4 * 1024 * 1024, 5), 2);
+        Assert.Equal(1.14, ThresholdKbPerSecond(4 * 1024 * 1024, 60), 2);
+        Assert.Equal(2 * ThresholdKbPerSecond(4 * 1024 * 1024, 60), ThresholdKbPerSecond(4 * 1024 * 1024, 30), 6);
+    }
+}

PerformanceMonitor.Collectors/CollectorScheduleDefaults.cs

@@ -148,11 +148,25 @@ almost always asked long after the fact — "this got slow sometime last quarter
            rows are small, and the changes read only ever looks at consecutive snapshots. */
         ["pg_server_config"] = new(60, 365),
 
-        /* Every 5 minutes against a 4 MB tail, matching pg_plan_capture: the two read the same file the
-           same way, and a deadlock is an EVENT rather than a level, so the cadence has to be short enough
-           that a report is still inside the window when the read comes round. 90 days because deadlocks
-           are asked about in retrospect - "we had a spike last month" - and a shorter horizon answers that
-           with silence. The overlapping window is deliberate and the hash is what makes it free. */
+        /* Every 5 minutes against the same 4 MB tail pg_plan_capture reads, of the same file, by the same
+           pg_read_file call - and at a TWELFTH of its interval. The two are not on a shared cadence and
+           the difference is the point: a deadlock is an EVENT rather than a level, so the cadence has to
+           be short enough that a report is still inside the window when the read comes round.
+
+           The 5 is also what makes the overlap real on the self-hosted route, and that is arithmetic
+           rather than intent. The tail is a fixed 4 MB read from the END of the file, so consecutive reads
+           overlap only while the log grows by less than 4 MB between them - under about 14 KB/s here.
+           Past that the reads no longer touch, and the bytes between them are seen by nobody: whole
+           reports lost rather than merely cut, and the loss is silent because a report nobody read looks
+           exactly like a deadlock that did not happen. PgDeadlockLogParser states the condition at the
+           claim it qualifies. Nothing in either collector measures the log's write rate, so neither can
+           tell a quiet server from a truncated view of a busy one; an operator whose target logs harder
+           than that lowers this number per server rather than relying on the default.
+
+           90 days because deadlocks are asked about in retrospect - "we had a spike last month" - and a
+           shorter horizon answers that with silence. Repeats are expected and cheap: the hash carries the
+           identity and every read groups on it, so a report seen in six consecutive tails is one row to
+           every consumer. */
         ["pg_deadlocks"] = new(5, 90),
 
         /* Per-minute, unlike its wraparound sibling: an xmin holder is the FAST-moving leading
@@ -266,11 +280,29 @@ pg_stat_statements get installed" and "when did this extension get upgraded" are
            managed target they can only ever record a non-fatal skip, and at a five-minute cadence that
            is roughly 900 skip rows per target per day saying the same thing.
 
-           Hourly costs nothing where they DO work: every one of these reads a CUMULATIVE counter
-           (pg_wait_sampling_profile, pg_stat_kcache, pg_qualstats) or an append-only log, so a longer
-           interval loses no events - it only widens the window each delta covers. That is the opposite
-           of a sampled collector like pg_blocking, where the cadence IS the resolution and stretching
-           it genuinely loses sightings. */
+           Hourly costs nothing for THREE of them: pg_wait_sampling_profile, pg_stat_kcache and
+           pg_qualstats are cumulative COUNTERS, so a longer interval loses no events - it only widens the
+           window each delta covers. That is the opposite of a sampled collector like pg_blocking, where
+           the cadence IS the resolution and stretching it genuinely loses sightings.
+
+           pg_plan_capture is the fourth and it is neither. It reads a LOG, and "append-only" is not the
+           property that matters - the property that matters is how much of it a read can see. Its two
+           transports fail in opposite directions at this cadence, and one schedule number serves both:
+
+             - Aurora and RDS reach the table through the log API, which is consume-once and keeps a resume
+               marker per (instance, file). An hour there batches more text per call and loses nothing,
+               which is the case this 60 was chosen for.
+             - A self-hosted target is read with pg_read_file as a fixed 4 MB tail with NO marker, so an
+               hour holds only the last 4 MB whatever was written before it - about 1.2 KB/s before the
+               window stops covering the interval. That is a low bar; a server doing nothing but logging
+               connections can clear it. Plans past it are not re-read later, they are never read, and
+               that reads downstream as a target with no slow queries.
+
+           Growing the tail does not fix it and is not the pending change: #2565 measured 772 MB of log in
+           twenty seconds at capture-everything, so no fixed number bounds the worst case - it only moves
+           the threshold. What is missing is that the collector cannot SAY it happened, and it already
+           selects the file's size, so a stored previous size would make the skipped span a measurement
+           instead of an absence. Until then a self-hosted operator lowers this per server. */
         ["pg_wait_sampling"] = new(60, 30),
         ["pg_kernel_stats"] = new(60, 30),
         ["pg_predicate_stats"] = new(60, 30),

PerformanceMonitor.Collectors/PgDeadlockLogParser.cs

@@ -144,9 +144,14 @@ sharing a prefix with a zero one (+0030) cannot match part of itself and pass. *
     /// every cycle.</para>
     ///
     /// <para><b>Whether that skip is ever recovered depends on the transport, and on the managed one it is
-    /// not (#3009).</b> <see cref="PgDeadlocksCollector"/>'s <c>pg_read_file</c> route re-reads an
-    /// overlapping byte-window tail every cycle, so a report cut at one read's edge arrives whole in the
-    /// next and skipping it costs nothing. The RDS log-API route is CONSUME-ONCE: <c>RdsLogSource</c>
+    /// not (#3009).</b> <see cref="PgDeadlocksCollector"/>'s <c>pg_read_file</c> route re-reads a
+    /// byte-window tail every cycle that overlaps the previous one <b>while the log grows by less than
+    /// that tail between cycles</b>, and a report cut at one read's edge arrives whole in the next only
+    /// inside that condition. The tail is 4 MB and the cadence is five minutes, so the condition is a
+    /// write rate under roughly 14 KB/s. Above it consecutive reads stop touching and the bytes between
+    /// them are read by nobody — reports lost entire rather than cut, which is a different outcome from
+    /// the one this paragraph is about and is not recovered by anything. Neither collector measures the
+    /// write rate, so neither can distinguish a quiet server from a truncated view of a loud one. The RDS log-API route is CONSUME-ONCE: <c>RdsLogSource</c>
     /// holds a resume marker per (instance, file) and <c>DownloadDBLogFilePortion</c> starts the next call
     /// where the last one stopped, so there is no overlap and no next pass, and a report straddling a
     /// chunk boundary is not completed for the life of that marker. The paragraph above is not a recovery

PerformanceMonitor.Collectors/PgPlanCaptureCollector.cs

@@ -74,6 +74,22 @@ public readonly record struct Row(
     /// How much of the log tail to read per cycle. Bounded because the file can reach hundreds of megabytes
     /// — #2565 measured 772 MB in twenty seconds at capture-everything — and reading it whole would turn a
     /// monitoring collector into the server's biggest reader.
+    ///
+    /// <para><b>It is a window, not a resume marker, and that is what decides coverage.</b> The read is
+    /// always the last <c>TailBytes</c> of the current file, so consecutive cycles see overlapping text
+    /// only while the log grows by less than this between them. At the <c>pg_plan_capture</c> default of
+    /// sixty minutes that threshold is about 1.2 KB/s. Above it the two windows do not meet and the span
+    /// between them is read by no cycle: those plans are lost, not deferred, and the result reads
+    /// downstream as a target with nothing slow on it. The measurement quoted above is exactly a rate that
+    /// clears the threshold by four orders of magnitude, so this is the ordinary case on a target with
+    /// <c>auto_explain.log_min_duration</c> set low rather than a pathological one.</para>
+    ///
+    /// <para>Raising this number moves the threshold without establishing one, which is why it has not
+    /// been raised: at 772 MB in twenty seconds no fixed tail covers an hour. The gap is that nothing
+    /// reports the shortfall — the query already selects the file's <c>size</c>, so comparing it against
+    /// the previous cycle's would turn a silent skip into a number. An operator on a busy self-hosted
+    /// target lowers the interval for that server in the meantime; the managed route reaches this table
+    /// through the RDS log API instead, which keeps a resume marker and has no equivalent exposure.</para>
     /// </summary>
     private const int TailBytes = 4 * 1024 * 1024;