From 8b5fdf0d73e8535e4af14b962d381e73a93aca05 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 15:16:34 -0400 Subject: [PATCH 1/7] Darling: per-collection procedure totals, written with each procedure_stats batch (part of #5638) --- .../ProcedureStatsTotalsTests.cs | 194 +++++++++ .../ProcedureStatsTotalsWriterLiveTests.cs | 391 ++++++++++++++++++ .../DarlingCollectorRunner.cs | 20 +- .../DarlingRetention.cs | 25 ++ .../Mcp/DarlingMcpTrendTools.cs | 18 +- .../PgMigrations.cs | 14 + .../ProcedureStatsTotals.cs | 110 +++++ .../ProcedureStatsTotalsWriter.cs | 64 +++ .../StorageVersion.cs | 2 +- .../ViewerDataService.cs | 16 +- 10 files changed, 847 insertions(+), 7 deletions(-) create mode 100644 Darling/Darling.Tests/ProcedureStatsTotalsTests.cs create mode 100644 Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs create mode 100644 Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs create mode 100644 Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs new file mode 100644 index 0000000000..b7bfa7e313 --- /dev/null +++ b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs @@ -0,0 +1,194 @@ +/* + * Copyright (c) 2026 Erik Darling, Darling Data LLC + * + * This file is part of the SQL Server Performance Monitor. + * + * Licensed under the MIT License. See LICENSE file in the project root for full license information. + */ + +using System; +using System.Linq; +using PerformanceMonitor.Darling.Service; +using PerformanceMonitor.Darling.Service.Mcp; +using PerformanceMonitor.Darling.Storage; +using Xunit; + +namespace Darling.Tests; + +/// +/// Pins for the per-collection procedure totals (#5638, V176) that need no store: the rung and its text, the upsert statement, the +/// runner's call site, the retention registration, and the MCP duration trends' tier clock. The live behavior is in +/// . +/// +public sealed class ProcedureStatsTotalsTests +{ + private static string Normalize(string text) => text.Replace("\r\n", "\n", StringComparison.Ordinal); + + [Fact] + public void TheRung_IsV176_AndEmbedsTheCreateText() + { + Assert.Equal(176, ProcedureStatsTotals.RungVersion); + Assert.True(StorageVersion.SchemaVersion >= ProcedureStatsTotals.RungVersion); + + var migrations = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Storage", "PgMigrations.cs"); + Assert.Contains("new Migration(176, \"procedure-stats-totals\", V176Sql)", migrations, StringComparison.Ordinal); + Assert.Contains("private const string V176Sql = ProcedureStatsTotals.CreateSql;", migrations, StringComparison.Ordinal); + } + + [Fact] + public void TheCreateText_PinsTheShape_NoBackfill_AndTheNullsNotDistinctKey() + { + var sql = Normalize(ProcedureStatsTotals.CreateSql); + + Assert.Contains("CREATE TABLE IF NOT EXISTS collect.procedure_stats_totals", sql, StringComparison.Ordinal); + Assert.Contains("server_id integer NOT NULL,", sql, StringComparison.Ordinal); + Assert.Contains("collection_time timestamp NOT NULL,", sql, StringComparison.Ordinal); + Assert.Contains("database_name text,", sql, StringComparison.Ordinal); + Assert.Contains("total_elapsed_time bigint,", sql, StringComparison.Ordinal); + Assert.Contains("total_execution_count bigint,", sql, StringComparison.Ordinal); + Assert.Contains("row_count bigint NOT NULL,", sql, StringComparison.Ordinal); + Assert.Contains("max_sample_interval_seconds integer", sql, StringComparison.Ordinal); + Assert.Contains( + "CREATE UNIQUE INDEX IF NOT EXISTS ux_procedure_stats_totals ON collect.procedure_stats_totals (server_id, collection_time, database_name) NULLS NOT DISTINCT;", + sql, StringComparison.Ordinal); + + /* No backfill: the rung moves no existing row. */ + Assert.DoesNotContain("INSERT", sql, StringComparison.OrdinalIgnoreCase); + Assert.DoesNotContain("UPDATE", sql, StringComparison.OrdinalIgnoreCase); + Assert.DoesNotContain("create_hypertable", sql, StringComparison.OrdinalIgnoreCase); + } + + [Fact] + public void TheUpsert_ReadsBackTheStoredRows_AndRecomputesEveryMeasureOnConflict() + { + var sql = Normalize(ProcedureStatsTotals.UpsertSql); + + Assert.Contains("FROM collect.procedure_stats\nWHERE server_id = $1::integer\nAND collection_time = $2::timestamp\nGROUP BY server_id, collection_time, database_name", sql, StringComparison.Ordinal); + Assert.Contains("SUM(delta_elapsed_time)::bigint,", sql, StringComparison.Ordinal); + Assert.Contains("SUM(delta_execution_count)::bigint,", sql, StringComparison.Ordinal); + Assert.Contains("COUNT(*),", sql, StringComparison.Ordinal); + Assert.Contains("MAX(sample_interval_seconds)", sql, StringComparison.Ordinal); + Assert.Contains("ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET", sql, StringComparison.Ordinal); + + /* Recompute, never add: every measure is set from EXCLUDED, and no measure is added to its old value. */ + foreach (var measure in new[] { "total_elapsed_time", "total_execution_count", "row_count", "max_sample_interval_seconds" }) + { + Assert.Contains($"{measure} = EXCLUDED.{measure}", sql, StringComparison.Ordinal); + } + + Assert.DoesNotContain("t.row_count +", sql, StringComparison.Ordinal); + Assert.DoesNotContain("COALESCE(", sql, StringComparison.Ordinal); + } + + [Fact] + public void TheRunner_WritesTheTotalsOnTheCopysTransaction_AfterTheCopy_BeforeTheCommit() + { + var runner = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "DarlingCollectorRunner.cs")); + var start = runner.IndexOf("private async Task CopyBatchOnceAsync(", StringComparison.Ordinal); + Assert.True(start > 0); + var body = runner[start..]; + + var call = body.IndexOf("ProcedureStatsTotalsWriter.UpsertBatchAsync(", StringComparison.Ordinal); + var commit = body.IndexOf("await transaction.CommitAsync(cancellationToken);", StringComparison.Ordinal); + var ledger = body.IndexOf("QueryStatsHourLedgerWriter.AddBatchAsync(", StringComparison.Ordinal); + Assert.True(ledger > 0 && call > ledger && commit > call, "the totals upsert sits after the COPY block and before the commit"); + + /* On the COPY's transaction, for procedure_stats batches only, with no savepoint or catch around it. */ + Assert.Contains("pgConnection, transaction, server.ServerId, storedCollectionTime,\n rowsWritten", body, StringComparison.Ordinal); + Assert.Contains("var totalsBatch = string.Equals(definition.TargetTable, ProcedureStatsCollector.Instance.TargetTable", body, StringComparison.Ordinal); + Assert.Contains("|| ledgerBatch || totalsBatch", body, StringComparison.Ordinal); + var between = body[(call - 400)..call]; + Assert.DoesNotContain("catch", between, StringComparison.Ordinal); + Assert.DoesNotContain("SAVEPOINT", between, StringComparison.OrdinalIgnoreCase); + + /* collect.procedure_stats has exactly one writer: the runner's COPY. */ + foreach (var file in new[] { "DarlingWorker.cs", "DarlingRetention.cs" }) + { + var text = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", file); + Assert.DoesNotContain("INSERT INTO collect.procedure_stats ", text, StringComparison.Ordinal); + } + } + + [Fact] + public void Retention_PurgesTheTotals_AtProcedureStatsDays_NeverBeforeTheRawRows() + { + var retention = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "DarlingRetention.cs")); + + Assert.Contains("TimeSlicedDeleteSql(ProcedureStatsTotals.Table, \"collection_time\", ProcedureStatsTotals.PrunePredicate)", retention, StringComparison.Ordinal); + Assert.Contains("EffectivePurgeRetentionDays(\n \"procedure_stats\",", retention, StringComparison.Ordinal); + + var delete = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); + Assert.StartsWith("DELETE FROM collect.procedure_stats_totals WHERE collection_time < $1 AND collection_time < COALESCE((SELECT min(collection_time) FROM collect.procedure_stats), $1)", delete, StringComparison.Ordinal); + + /* The totals table is a plain table outside the collector catalog: no hypertable conversion, no collector schedule entry. */ + Assert.DoesNotContain(CollectorCatalogTables(), t => string.Equals(t, "procedure_stats_totals", StringComparison.Ordinal)); + } + + private static string[] CollectorCatalogTables() => + PerformanceMonitor.Collectors.CollectorCatalog.All.Select(c => c.TargetTable).ToArray(); + + /* ---- the MCP duration trends' tier clock (#5638) ---- */ + + private static readonly DateTime Now = new(2026, 10, 12, 12, 0, 0, DateTimeKind.Utc); + + [Fact] + public void TierClock_WithNoAsOf_IsTheWindowEndItself() + { + Assert.Equal(Now, DarlingMcpTrendTools.TierClock(null, Now, () => Now.AddMinutes(5))); + Assert.Equal(Now, DarlingMcpTrendTools.TierClock(" ", Now, () => Now.AddMinutes(5))); + } + + [Fact] + public void TierClock_WithAnAsOf_IsOneWallClockReading_NeverTheAnchor() + { + var anchor = Now.AddDays(-30); + var wall = Now.AddSeconds(3); + var reads = 0; + + var clock = DarlingMcpTrendTools.TierClock("2026-09-12T12:00:00Z", anchor, () => { reads++; return wall; }); + + Assert.Equal(wall, clock); + Assert.NotEqual(anchor, clock); + Assert.Equal(1, reads); + } + + /// + /// The regression: a 95 h window (start exactly on the raw boundary, 96 h less the 1 h margin) with no as_of routes Raw every time + /// when the tier is decided against the instant the window was computed. Deciding it against a clock read a few milliseconds LATER + /// (the old default) flips it to the hourly tier. Both procedure and query routes. + /// + [Theory] + [InlineData(0)] + [InlineData(1)] + [InlineData(7)] + [InlineData(250)] + public void A95HourWindowWithNoAsOf_RoutesRawEveryTime(int millisecondsLater) + { + var windowEnd = Now; + var start = windowEnd.AddHours(-95); + var coverage = RollupCoverage.Unknown; + + Assert.Equal(TimescaleSupport.RawRetentionSpan - DarlingTrendReader.RawTierMargin, TimeSpan.FromHours(95)); + + var pinned = DarlingMcpTrendTools.TierClock(null, windowEnd, () => windowEnd.AddMilliseconds(millisecondsLater)); + Assert.Equal(RetentionTier.Raw, DarlingTrendReader.ResolveProcedureDurationTrendRoute(start, RollupAvailability.All, coverage, nowUtc: pinned, windowEndUtc: windowEnd).Tier); + Assert.Equal(RetentionTier.Raw, DarlingTrendReader.ResolveQueryDurationTrendRoute(start, RollupAvailability.All, coverage, nowUtc: pinned, windowEndUtc: windowEnd).Tier); + + /* The old behaviour, for contrast: a clock read after the window flips the same window to the hourly tier. */ + if (millisecondsLater > 0) + { + var late = windowEnd.AddMilliseconds(millisecondsLater); + Assert.Equal(RetentionTier.Hourly, DarlingTrendReader.ResolveProcedureDurationTrendRoute(start, RollupAvailability.All, coverage, nowUtc: late, windowEndUtc: windowEnd).Tier); + } + } + + [Fact] + public void TheDurationTrendTools_PassTheirOwnClock_ToBothRoutes() + { + var tools = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "Mcp", "DarlingMcpTrendTools.cs")); + + Assert.Contains("ResolveQueryDurationTrendRoute(startUtc, rollups, coverage, nowUtc: TierClock(as_of, now), windowEndUtc: now)", tools, StringComparison.Ordinal); + Assert.Contains("ResolveProcedureDurationTrendRoute(startUtc, rollups, coverage, nowUtc: TierClock(as_of, now), windowEndUtc: now)", tools, StringComparison.Ordinal); + Assert.DoesNotContain("coverage, windowEndUtc: now)", tools, StringComparison.Ordinal); + } +} diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs new file mode 100644 index 0000000000..4a35a15b17 --- /dev/null +++ b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs @@ -0,0 +1,391 @@ +/* + * Copyright (c) 2026 Erik Darling, Darling Data LLC + * + * This file is part of the SQL Server Performance Monitor. + * + * 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.Reflection; +using System.Threading; +using System.Threading.Tasks; +using Npgsql; +using PerformanceMonitor.Collectors; +using PerformanceMonitor.Darling.Service; +using PerformanceMonitor.Darling.Storage; +using Xunit; + +namespace Darling.Tests; + +/// +/// Live pins for the per-collection procedure totals (#5638, V176): the procedure_stats batch's totals are written inside +/// the COPY's own transaction by DarlingCollectorRunner.CopyBatchOnceAsync, read back from the stored rows, so rows and +/// totals commit together or not at all. Every batch goes through the product's own WriteBatchAsync with +/// deltas, so the rows carry exactly the deltas and intervals a fact +/// names (a restart collection is interval 0 everywhere). The oracle in every fact is a GROUP BY over the stored rows, the +/// aggregate the trend's CTE takes. +/// +/// #1776 own-store: every test here creates and drops its own scratch database through +/// , so it is not in the live-postgres collection. +/// +public sealed class ProcedureStatsTotalsWriterLiveTests +{ + private static string? BaseConnectionString => Environment.GetEnvironmentVariable("DARLING_TEST_PG"); + + private const string SkipReason = "Set DARLING_TEST_PG to run the procedure totals writer's live pins (each mints its own scratch database)."; + + private static readonly DateTime T0 = new(2026, 1, 5, 10, 0, 0, DateTimeKind.Unspecified); + + private static readonly MethodInfo WriteBatchMethod = typeof(DarlingCollectorRunner) + .GetMethod("WriteBatchAsync", BindingFlags.NonPublic | BindingFlags.Instance)!; + + private sealed class Rig : IAsyncDisposable + { + public required ScratchPostgres Scratch { get; init; } + + public required NpgsqlDataSource DataSource { get; init; } + + public required NpgsqlConnection Connection { get; init; } + + public required DarlingCollectorRunner Runner { get; init; } + + public required CollectorDeltaCalculator Deltas { get; init; } + + public required ServerRuntime Server { get; init; } + + public static async Task OpenAsync(int serverId, string serverName, CancellationToken ct) + { + var scratch = await ScratchPostgres.CreateAsync(BaseConnectionString!, ct); + var connection = new NpgsqlConnection(scratch.ConnectionString); + await connection.OpenAsync(ct); + await PgMigrations.MigrateAsync(connection, ct); + var deltas = new CollectorDeltaCalculator(); + var dataSource = NpgsqlDataSource.Create(scratch.ConnectionString); + return new Rig + { + Scratch = scratch, + DataSource = dataSource, + Connection = connection, + Deltas = deltas, + Runner = new DarlingCollectorRunner(dataSource, deltas), + Server = new ServerRuntime + { + Config = new MonitoredServer { Name = serverName, Host = serverName }, + ConnectionString = "Server=" + serverName, + Target = new CollectorTargetInfo { SqlMajorVersion = 16 }, + StorageName = serverName, + ServerId = serverId, + EngineEdition = 3, + }, + }; + } + + /// One batch through the product's WriteBatchAsync; a fault surfaces as the store's own exception. + public async Task WriteAsync(DateTime collectionTime, List rows, CancellationToken ct) + { + var context = new CollectorContext + { + ServerId = Server.ServerId, + ServerName = Server.StorageName, + CollectionTime = collectionTime, + Deltas = Deltas, + Target = Server.Target, + }; + + var task = (Task)WriteBatchMethod.MakeGenericMethod(typeof(ProcedureStatsCollector.Row)).Invoke( + Runner, + new object?[] { Connection, ProcedureStatsCollector.Instance, rows, Server, collectionTime, context, ct })!; + await task; + return (int)task.GetType().GetProperty("Result")!.GetValue(task)!; + } + + public async ValueTask DisposeAsync() + { + await Connection.DisposeAsync(); + await DataSource.DisposeAsync(); + await Scratch.DisposeAsync(); + } + } + + /// One procedure row whose deltas are given, so the interval (0 = restart) is the fact's, not the calculator's. + private static ProcedureStatsCollector.Row Row(string database, string name, long elapsed, long executions, int interval) => new( + database, "dbo", name, "P ", T0, T0, executions, elapsed, elapsed, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, + "0x" + name, "0xP" + name, null, null) + { + Precomputed = new ProcedureStatsCollector.ReadTimeDeltas(executions, elapsed, elapsed, 1, 1, 1, 0, interval), + }; + + private static async Task ScalarAsync(NpgsqlConnection connection, string sql, CancellationToken ct) + { + await using var command = new NpgsqlCommand(sql, connection); + return await command.ExecuteScalarAsync(ct); + } + + private static async Task ExecAsync(NpgsqlConnection connection, string sql, CancellationToken ct) + { + await using var command = new NpgsqlCommand(sql, connection); + await command.ExecuteNonQueryAsync(ct); + } + + private static string Stamp(DateTime value) => "'" + value.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + "'::timestamp"; + + /// + /// The totals of one collection as text, one line per database in database order (NULL last), and the same text from a GROUP BY over + /// the stored rows. The two strings are equal when the totals equal the rows' own aggregate, NULL group and NULL measures included. + /// + private static async Task<(string Totals, string Raw)> CompareAsync(NpgsqlConnection connection, int serverId, DateTime collectionTime, CancellationToken ct) + { + var where = "server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time = " + Stamp(collectionTime); + const string cols = "COALESCE(database_name, ''), total_elapsed_time, total_execution_count, row_count, max_sample_interval_seconds"; + var totals = await ScalarAsync( + connection, + "SELECT COALESCE(string_agg(concat_ws('|', " + cols + "), ';' ORDER BY database_name NULLS LAST), '') FROM collect.procedure_stats_totals WHERE " + where, ct); + var raw = await ScalarAsync( + connection, + "SELECT COALESCE(string_agg(concat_ws('|', COALESCE(database_name, ''), e, x, n, i), ';' ORDER BY database_name NULLS LAST), '') FROM (" + + "SELECT database_name, SUM(delta_elapsed_time) AS e, SUM(delta_execution_count) AS x, COUNT(*) AS n, MAX(sample_interval_seconds) AS i " + + "FROM collect.procedure_stats WHERE " + where + " GROUP BY database_name) g", ct); + return ((string)totals!, (string)raw!); + } + + /// A measured two-database batch, then a restart collection (interval 0 on every row), through the real write path. + [Fact] + public async Task TheTotalsEqualAGroupByOverTheRows_ForAMeasuredBatchAndARestartCollection() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945301; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals\\INST", ct); + + var bodySucceeded = false; + try + { + var measured = new List + { + Row("DbA", "p1", 1_000_001, 3, 60), Row("DbA", "p2", 2_000_003, 5, 60), Row("DbA", "p3", 7, 1, 60), + Row("DbB", "p1", 5_000_000, 9, 60), Row("DbB", "p2", 11, 2, 60), + }; + Assert.Equal(5, await rig.WriteAsync(T0.AddMinutes(1), measured, ct)); + + var (totals, raw) = await CompareAsync(rig.Connection, serverId, T0.AddMinutes(1), ct); + Assert.Equal(raw, totals); + Assert.Equal("DbA|3000011|9|3|60;DbB|5000011|11|2|60", totals); + + /* A restart collection: no delta was knowable, so every row's interval is 0 and its deltas are 0. The totals keep the + rows (row_count) and the 0 interval, so the read's three-state contract (0 = restart) is intact. */ + var restart = new List + { + Row("DbA", "p1", 0, 0, 0), Row("DbA", "p2", 0, 0, 0), Row("DbB", "p1", 0, 0, 0), + }; + Assert.Equal(3, await rig.WriteAsync(T0.AddMinutes(2), restart, ct)); + var (restartTotals, restartRaw) = await CompareAsync(rig.Connection, serverId, T0.AddMinutes(2), ct); + Assert.Equal(restartRaw, restartTotals); + Assert.Equal("DbA|0|0|2|0;DbB|0|0|1|0", restartTotals); + + /* One collection is one row-group per database, and nothing was written for a collection that stored no rows. */ + Assert.Equal(0, await rig.WriteAsync(T0.AddMinutes(3), new List(), ct)); + Assert.Equal(0L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE collection_time = " + Stamp(T0.AddMinutes(3)), ct))); + Assert.Equal(4L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// A second batch at the SAME collection_time recomputes from all the stored rows rather than adding, a re-run of the upsert on its + /// own is a no-op, and a row whose interval is NULL (stored before the column existed) and a row with a NULL database_name are + /// kept exactly as the rows have them: the NULL interval stays NULL when every interval is NULL, and the NULL database is one group. + /// + [Fact] + public async Task ASecondBatchAtTheSameCollectionTime_Recomputes_AndNullIntervalsAndANullDatabaseKeepTheRowsShape() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945302; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals2", ct); + + var bodySucceeded = false; + try + { + var at = T0.AddMinutes(5); + Assert.Equal(2, await rig.WriteAsync(at, new List { Row("DbA", "p1", 100, 1, 60), Row("DbA", "p2", 200, 2, 30) }, ct)); + Assert.Equal("DbA|300|3|2|60", (await CompareAsync(rig.Connection, serverId, at, ct)).Totals); + + /* The same collection arrives in a second batch (a fan-out chunk): the totals are the whole collection, not the second batch. */ + Assert.Equal(2, await rig.WriteAsync(at, new List { Row("DbA", "p3", 400, 4, 10), Row("DbB", "p1", 800, 8, 45) }, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, at, ct); + Assert.Equal(raw, totals); + Assert.Equal("DbA|700|7|3|60;DbB|800|8|1|45", totals); + + /* An upsert that runs again (a re-attempt) changes nothing. */ + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + Assert.Equal(2, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 4, 30, ct)); + await tx.CommitAsync(ct); + } + + Assert.Equal(raw, (await CompareAsync(rig.Connection, serverId, at, ct)).Totals); + + /* Rows stored without an interval (NULL) and without a database (NULL), the shape of rows written before the columns existed. */ + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats SET sample_interval_seconds = NULL, database_name = NULL WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time = " + Stamp(at) + " AND database_name = 'DbB'", ct); + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats SET sample_interval_seconds = NULL WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time = " + Stamp(at) + " AND object_name IN ('p1', 'p2') AND database_name = 'DbA'", ct); + /* The UPDATE above moved a stored group to NULL, which a real store never does; the stale DbB totals row is cleared by hand. */ + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE database_name = 'DbB'", ct); + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, ct); + await tx.CommitAsync(ct); + } + + var (nullTotals, nullRaw) = await CompareAsync(rig.Connection, serverId, at, ct); + Assert.Equal(nullRaw, nullTotals); + + /* DbA keeps its measured 10 (p3); the NULL database is its own group, its NULL interval stays NULL (concat_ws drops it). */ + Assert.Equal("DbA|700|7|3|10;|800|8|1", nullTotals); + + /* And a second upsert still leaves one NULL-database row (the key treats NULL as one group, so it conflicts). */ + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, ct); + await tx.CommitAsync(ct); + } + + Assert.Equal(1L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE database_name IS NULL", ct))); + Assert.True((bool)(await ScalarAsync(rig.Connection, "SELECT max_sample_interval_seconds IS NULL FROM collect.procedure_stats_totals WHERE database_name IS NULL", ct))!); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// A fault in the totals statement aborts the whole batch: there is no savepoint, so the COPY's rows roll back with it. A trigger + /// that refuses every totals write stands in for the fault; once it clears, the next batch writes rows and totals together. + /// + [Fact] + public async Task AFailedTotalsUpsert_AbortsTheBatch_SoRowsAndTotalsAreBothUnchanged() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945303; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals3", ct); + + var bodySucceeded = false; + try + { + Assert.Equal(2, await rig.WriteAsync(T0.AddMinutes(1), new List { Row("DbA", "p1", 10, 1, 60), Row("DbA", "p2", 20, 2, 60) }, ct)); + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats", ct))); + + await ExecAsync( + rig.Connection, + "CREATE FUNCTION collect.proc_totals_refuse() RETURNS trigger LANGUAGE plpgsql AS $$ BEGIN RAISE EXCEPTION 'totals write refused' USING ERRCODE = 'P0001'; END $$;" + + "CREATE TRIGGER trg_proc_totals_refuse BEFORE INSERT OR UPDATE ON collect.procedure_stats_totals FOR EACH ROW EXECUTE FUNCTION collect.proc_totals_refuse();", + ct); + + var fault = await Assert.ThrowsAsync( + () => rig.WriteAsync(T0.AddMinutes(2), new List { Row("DbA", "p1", 30, 3, 60) }, ct)); + Assert.Equal("P0001", fault.SqlState); + + /* The COPY ran inside the same transaction: its row is gone, and no totals row exists for that collection. */ + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats", ct))); + Assert.Equal(1L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + await ExecAsync(rig.Connection, "DROP TRIGGER trg_proc_totals_refuse ON collect.procedure_stats_totals; DROP FUNCTION collect.proc_totals_refuse();", ct); + + Assert.Equal(1, await rig.WriteAsync(T0.AddMinutes(3), new List { Row("DbA", "p1", 40, 4, 60) }, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, T0.AddMinutes(3), ct); + Assert.Equal(raw, totals); + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// The read-back is served by an index on server_id + collection_time of procedure_stats (functional check only; no timing is claimed), + /// and the retention predicate never deletes a totals row at or after the oldest raw row, whatever the cutoff, while it does delete the + /// rows older than both. The statement is the sweep's own TimeSlicedDeleteSql with . + /// + [Fact] + public async Task TheReadBackUsesAnIndex_AndRetentionNeverPurgesTotalsBeforeTheRawRowsOfTheirAge() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945304; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals4", ct); + + var bodySucceeded = false; + try + { + /* Collections at day 0 (oldest raw), day 1 and day 2; raw is later trimmed so day 0's rows are gone but day 1 stays. */ + for (var day = 0; day < 3; day++) + { + Assert.Equal(1, await rig.WriteAsync(T0.AddDays(day), new List { Row("DbA", "p1", 10 + day, 1, 60) }, ct)); + } + + await ExecAsync(rig.Connection, "SET enable_seqscan = off", ct); + var plan = new System.Text.StringBuilder(); + await using (var explain = new NpgsqlCommand( + "EXPLAIN SELECT database_name, SUM(delta_elapsed_time) FROM collect.procedure_stats WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + + " AND collection_time = " + Stamp(T0) + " GROUP BY database_name", rig.Connection)) + await using (var reader = await explain.ExecuteReaderAsync(ct)) + { + while (await reader.ReadAsync(ct)) + { + plan.AppendLine(reader.GetString(0)); + } + } + + Assert.Contains("Index", plan.ToString(), StringComparison.Ordinal); + Assert.DoesNotContain("Seq Scan on procedure_stats", plan.ToString(), StringComparison.Ordinal); + await ExecAsync(rig.Connection, "RESET enable_seqscan", ct); + + var sliced = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); + + /* Cutoff after day 1 while every raw row is still held: raw holds day 0, so no totals row may go. */ + await using (var held = new NpgsqlCommand(sliced, rig.Connection)) + { + held.Parameters.AddWithValue(NpgsqlTypes.NpgsqlDbType.Timestamp, T0.AddDays(1).AddHours(1)); + Assert.Equal(0, await held.ExecuteNonQueryAsync(ct)); + } + + Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + /* Raw loses day 0 (its purge ran). Now day 0's totals row is older than both the cutoff and the oldest raw row. */ + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats WHERE collection_time < " + Stamp(T0.AddDays(1)), ct); + await using (var purge = new NpgsqlCommand(sliced, rig.Connection)) + { + purge.Parameters.AddWithValue(NpgsqlTypes.NpgsqlDbType.Timestamp, T0.AddDays(2).AddHours(1)); + Assert.Equal(1, await purge.ExecuteNonQueryAsync(ct)); + } + + /* Day 1's totals row is the oldest raw row's age, so it stays even though the cutoff is past it; day 2 is newer than the cutoff. */ + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + Assert.Equal(T0.AddDays(1), (DateTime)(await ScalarAsync(rig.Connection, "SELECT min(collection_time) FROM collect.procedure_stats_totals", ct))!); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } +} diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs index aa0136d04e..ad3857fd3a 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs @@ -4481,6 +4481,11 @@ before the COPY completes catches any other overload. */ writer.CountNonZeroAt(QueryStatsHourLedgerWriter.IntervalPayloadIndex(definition)); } + /* #5638: a procedure_stats batch also brings the per-collection totals up to date (ProcedureStatsTotalsWriter), in + the COPY's own transaction below. Like the ledger, it is chosen by the table this COPY writes, so a definition aimed + at procedure_stats that is not the catalog's ProcedureStatsCollector (an import or backfill) writes its totals too. */ + var totalsBatch = string.Equals(definition.TargetTable, ProcedureStatsCollector.Instance.TargetTable, StringComparison.OrdinalIgnoreCase); + /* #3953: a Query Store batch also maintains the latest-snapshot-per-interval table, in the COPY's own transaction behind a savepoint (QueryStoreIntervalLatest). Its two wider reads, the coverage row's creation and the hourly gap check, run HERE, before the transaction, so nothing inside it reads raw @@ -4517,7 +4522,7 @@ connection and the backfill are all covered here and nowhere else. */ transaction; everything else keeps the pre-#1767 single-COPY commit and pays nothing. query_stats diverts its text and plans today, so the ledger term does not add a transaction; it is named so that the ledger upsert can never be left without the transaction its atomicity with the COPY depends on. */ - await using var transaction = diversionPlan.Count > 0 || queryStoreDatabases is not null || ledgerBatch + await using var transaction = diversionPlan.Count > 0 || queryStoreDatabases is not null || ledgerBatch || totalsBatch ? await pgConnection.BeginTransactionAsync(cancellationToken) : null; @@ -4676,6 +4681,19 @@ await QueryStatsHourLedgerWriter.AddBatchAsync( writer.NonZeroCounted, ServiceCommandDeadlines.CollectionSweepSeconds, cancellationToken); } + /* #5638: the collection's per-database totals, read back from the rows the store now holds for this + collection_time and upserted, on THIS transaction after the COPY and before the commit, so rows and totals + commit together or not at all. No savepoint and no catch, like the ledger above: a fault throws out of the + batch, the transaction rolls back and the rows are not stored, because rows the totals never saw would make a + read of the totals disagree with the rows. Recomputed, never added, so a second batch at this collection_time or + a re-attempt is exact. A batch of 0 rows writes nothing: the read keeps its collection_log axis for an idle run. */ + if (totalsBatch) + { + await ProcedureStatsTotalsWriter.UpsertBatchAsync( + pgConnection, transaction, server.ServerId, storedCollectionTime, + rowsWritten, ServiceCommandDeadlines.CollectionSweepSeconds, cancellationToken); + } + /* #3953: after the COPY and the dimension flush, in the unstamped region (#3095): a fault here is not the COPY's and is never re-attempted. The apply cannot fail the batch: it rolls back to its own savepoint and records the batch for replay, so raw commits either way. */ diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs index 25436d5af2..52f7f4d948 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs @@ -1003,6 +1003,31 @@ the same constant just bounds the table there. { tablesFailed++; } + /* collect.procedure_stats_totals (#5638, V176): the per-collection totals of procedure_stats. NOT in CollectorCatalog.All + (the collector runner's COPY transaction writes it), so the loop above skips it. It ages with the raw collector it + summarises: the same resolved days as procedure_stats (EffectivePurgeRetentionDays, so a per-collector override moves both), + and a row is never purged before the procedure_stats rows of its age (ProcedureStatsTotals.PrunePredicate also keeps every + totals row at or after the oldest raw row, because on TimescaleDB the raw chunks leave through the gated purge, which can + hold them past the horizon). A plain table with a plain time-sliced DELETE on both store kinds; about one row per database + per collection, so a slice is a small fraction of a raw slice. Failure-isolated like every sibling. */ + var procedureTotalsDays = EffectivePurgeRetentionDays( + "procedure_stats", + retentionDaysFor?.Invoke("procedure_stats") + ?? (CollectorScheduleDefaults.All.TryGetValue("procedure_stats", out var procedureSchedule) ? procedureSchedule.RetentionDays : DataRetentionBaseDays)); + var procedureTotalsDeleted = await PurgeOneAsync( + postgres, ProcedureStatsTotals.Table, + TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate), + utcNow.AddDays(-procedureTotalsDays), logger, cancellationToken, + pacer: walPacer); + if (procedureTotalsDeleted is not null) + { + tablesPurged++; + totalRowsDeleted += procedureTotalsDeleted.Value; + } + else + { + tablesFailed++; + } /* collect.oversized_plan_backlog (#3392) purges on last_seen_at at OversizedPlanBacklogRetentionDays. NOT in CollectorCatalog.All (it is written by the collector runner's post-write hook and by the backlog sweep, not by a collector definition), so the loop diff --git a/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpTrendTools.cs b/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpTrendTools.cs index 63cfd7c8dd..1db3e938d8 100644 --- a/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpTrendTools.cs +++ b/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpTrendTools.cs @@ -94,6 +94,20 @@ namespace PerformanceMonitor.Darling.Service.Mcp; [McpServerToolType] public sealed class DarlingMcpTrendTools { + /// + /// The wall clock the duration-trend tools hand to the tier decision (#5638), captured ONCE per call. With no + /// the window ends at the instant + /// took, so that instant IS the wall clock and the tier is decided against the very instant the window was computed. Without + /// it, ResolveDurationTrendRoute defaulted its clock to a second DateTime.UtcNow read a few milliseconds LATER, and + /// a window whose start sits exactly on the raw boundary ( less + /// , 95 h) fell just past it and flipped to the hourly tier on a read that should + /// always be raw. With an the window's end is an anchor in the past and is NEVER the clock: + /// (#2353) measures against the wall clock because retention drops by age, + /// so the clock is one reading (the real clock unless a test passes one). + /// + internal static DateTime TierClock(string? asOf, DateTime windowEndUtc, Func? wallClock = null) => + string.IsNullOrWhiteSpace(asOf) ? windowEndUtc : (wallClock?.Invoke() ?? DateTime.UtcNow); + [McpServerTool(Name = "get_memory_trend"), Description("Gets memory usage over time in time buckets: total server, target, buffer pool and plan cache memory, with granted memory from the memory-grant series joined per bucket. total_granted_mb is null where that series has no snapshot (granted_note says why); use get_memory_grants for grant detail." + BaselineDiscontinuities.DescriptionSentence)] public static Task GetMemoryTrend( NpgsqlDataSource postgres, @@ -552,7 +566,7 @@ nothing survived the empty branch called the window "genuinely quiet" and advise as_of anchor decides the window, not how old its rows are. */ var (rollups, coverage) = await ComposeStoreAvailability.GetRollupsAsync(postgres, cancellationToken); - var route = DarlingTrendReader.ResolveQueryDurationTrendRoute(startUtc, rollups, coverage, windowEndUtc: now); + var route = DarlingTrendReader.ResolveQueryDurationTrendRoute(startUtc, rollups, coverage, nowUtc: TierClock(as_of, now), windowEndUtc: now); /* #3897: the hourly rollup's points are whole hours, so a width it cannot serve is refused rather than quietly answered at another, and an automatic width is never finer than the rollup's hour. */ @@ -639,7 +653,7 @@ internal static async Task GetProcedureDurationTrend( /* #3541 A2 — the same routing as get_query_duration_trend, over the procedure pair, and #3897 the same width rule on the hourly tier. */ var (rollups, coverage) = await ComposeStoreAvailability.GetRollupsAsync(postgres, cancellationToken); - var route = DarlingTrendReader.ResolveProcedureDurationTrendRoute(startUtc, rollups, coverage, windowEndUtc: now); + var route = DarlingTrendReader.ResolveProcedureDurationTrendRoute(startUtc, rollups, coverage, nowUtc: TierClock(as_of, now), windowEndUtc: now); if (route.Tier == RetentionTier.Hourly) { var hourlyError = TrendBuckets.RequireWholeHours(bucket_minutes, RawRetentionDays); diff --git a/Darling/PerformanceMonitor.Darling.Storage/PgMigrations.cs b/Darling/PerformanceMonitor.Darling.Storage/PgMigrations.cs index 6350a7c2c3..20488e1678 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/PgMigrations.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/PgMigrations.cs @@ -992,6 +992,19 @@ FROM information_schema.columns END $$;"; + /// + /// V176 (#5638) - collect.procedure_stats_totals: the per-collection totals of collect.procedure_stats that the raw + /// procedure duration trend reads instead of every row of every collection (about 560 to 1,060 rows per collection since #5463). + /// The collector writes it on the COPY's own transaction (ProcedureStatsTotalsWriter); the grain, the measures, the + /// NULL database handling and the retention are on , which the rung embeds. + /// + /// Empty when created, no backfill (the data-moving census therefore has nothing to declare): a collection written + /// before the rung has no totals row and the read keeps reading its rows. A plain table, not a collector, so no catalog, hypertable or + /// grant change; the collect schema's blanket SELECT and owner default privileges cover it. No Lite twin: Lite's store is + /// DuckDB with its own procedure trend. + /// + private const string V176Sql = ProcedureStatsTotals.CreateSql; + /// /// The text of V171 and V172 (#5571). Plain literal DDL after token substitution, not dynamic SQL, so the data-moving /// census can read the shipped text. Every statement is catalog-only; see . @@ -1279,6 +1292,7 @@ holds the ordering. */ new Migration(173, "query-store-compose-stamp", V173Sql), new Migration(174, "service-version", V174Sql), new Migration(175, "plan-regression-daily-rowcount", V175Sql), + new Migration(176, "procedure-stats-totals", V176Sql), }; /// diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs new file mode 100644 index 0000000000..42e338c2f8 --- /dev/null +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs @@ -0,0 +1,110 @@ +/* + * Copyright (c) 2026 Erik Darling, Darling Data LLC + * + * This file is part of the SQL Server Performance Monitor. + * + * Licensed under the MIT License. See LICENSE file in the project root for full license information. + */ + +namespace PerformanceMonitor.Darling.Storage; + +/// +/// The per-collection totals of collect.procedure_stats (#5638, V176): one row per (server, collection, database) +/// holding what the raw procedure duration trend sums from every row of that collection. Since #5463 a collection stores +/// about 560 to 1,060 rows per server, and the trend's per-collection CTE read all of them (about 60 K heap pages for one +/// 24 h read). The collector now writes the totals in the same transaction as the rows () +/// and the read (a later part of #5638) reads them in place of the rows. This class is the storage half: the table, the upsert +/// and the retention predicate. +/// +/// Grain and measures. (server_id, collection_time, database_name). Per database because the Viewer's +/// database filter sums only the chosen databases of a collection. Every measure is the aggregate the trend's CTE takes over +/// the same rows, with the same column types and no unit conversion (PostgreSQL keeps the microseconds, so every value is +/// exact): total_elapsed_time = SUM(delta_elapsed_time), total_execution_count = SUM(delta_execution_count), +/// row_count = COUNT(*) (the filtered trend's matched_rows), max_sample_interval_seconds = +/// MAX(sample_interval_seconds). The two sums and the max are NULL when every row's value is NULL, as SUM and MAX are over the +/// rows, so the three-state interval contract (#3540: 0 = restart, NULL = unknown, positive = measured) reads the same from here. +/// +/// NULL database_name. procedure_stats.database_name is a nullable text, so the key is a unique +/// index NULLS NOT DISTINCT (the form V170 uses; PostgreSQL 15 is the supported floor): the NULL database is one group, as +/// GROUP BY makes it, and the writer's conflict target matches that index. The table keeps the NULL group exactly as the raw rows +/// have it, so a database filter (database_name = ANY(...)) treats it the same here as on the rows. +/// +/// No backfill. The table is empty when created. A collection written before the rung has no totals row, and the +/// read keeps reading the rows for it (stitched at the server's floor, MIN(collection_time) of this table). +/// +/// A plain table, on both store kinds. About one row per database per collection against a thousand raw rows, so +/// the table is a small fraction of procedure_stats. Like the hour ledger (V164) and the PostgreSQL I/O rollup (V170) it is +/// not a collector, is absent from CollectorCatalog.All and is not a hypertable. It sits in the collect schema, so the +/// blanket SELECT and the owner's default privileges cover it, and the collector writes as the owner. Retention is +/// . +/// +public static class ProcedureStatsTotals +{ + /// The store schema version of the rung that creates the table (V176). A store below it has no table. + public const int RungVersion = 176; + + /// The totals table. + public const string Table = "collect.procedure_stats_totals"; + + /// The unique key's index name. + public const string KeyIndexName = "ux_procedure_stats_totals"; + + /// + /// The table, its unique key and the time index, as the V176 rung runs them. Idempotent, and empty when created. Editing this text + /// edits a shipped rung: add a new rung instead (ProcedureStatsTotalsTests pins the shape). + /// + public const string CreateSql = """ +CREATE TABLE IF NOT EXISTS collect.procedure_stats_totals +( + server_id integer NOT NULL, + collection_time timestamp NOT NULL, + database_name text, + total_elapsed_time bigint, + total_execution_count bigint, + row_count bigint NOT NULL, + max_sample_interval_seconds integer +); +CREATE UNIQUE INDEX IF NOT EXISTS ux_procedure_stats_totals ON collect.procedure_stats_totals (server_id, collection_time, database_name) NULLS NOT DISTINCT; +CREATE INDEX IF NOT EXISTS ix_procedure_stats_totals_time ON collect.procedure_stats_totals (collection_time); +"""; + + /// + /// Writes the totals of one collection: $1 is the server id and $2 the collection's collection_time (naive UTC + /// timestamp). It READS BACK the rows the store holds for that collection and upserts one row per database, so it is exact + /// and idempotent when one collection spans several batches or a batch is attempted again: the second run recomputes the same + /// values from the rows and never adds to them. The sums are cast to bigint (SUM of a bigint is numeric); a sum past bigint + /// would fail the statement, which is 292,000 years of elapsed time in one collection. Run it on the COPY's own transaction, after + /// the COPY and before the commit. + /// + public const string UpsertSql = """ +INSERT INTO collect.procedure_stats_totals AS t + (server_id, collection_time, database_name, total_elapsed_time, total_execution_count, row_count, max_sample_interval_seconds) +SELECT + server_id, + collection_time, + database_name, + SUM(delta_elapsed_time)::bigint, + SUM(delta_execution_count)::bigint, + COUNT(*), + MAX(sample_interval_seconds) +FROM collect.procedure_stats +WHERE server_id = $1::integer +AND collection_time = $2::timestamp +GROUP BY server_id, collection_time, database_name +ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET + total_elapsed_time = EXCLUDED.total_elapsed_time, + total_execution_count = EXCLUDED.total_execution_count, + row_count = EXCLUDED.row_count, + max_sample_interval_seconds = EXCLUDED.max_sample_interval_seconds; +"""; + + /// + /// The extra predicate the retention sweep adds to its one-day-slice DELETE (DarlingRetention.TimeSlicedDeleteSql; $1 + /// is the cutoff): a totals row is never purged before the procedure_stats rows of the same age. The cutoff is the raw + /// collector's own retention, so on a plain store the two purge together. On TimescaleDB raw chunks leave through a gated purge that + /// can hold them past the horizon, so the predicate also keeps every totals row at or after the oldest raw row. With no raw rows left + /// the oldest is NULL and the cutoff alone decides. + /// + public const string PrunePredicate = + "collection_time < COALESCE((SELECT min(collection_time) FROM collect.procedure_stats), $1)"; +} diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs new file mode 100644 index 0000000000..39b1074f41 --- /dev/null +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs @@ -0,0 +1,64 @@ +/* + * Copyright (c) 2026 Erik Darling, Darling Data LLC + * + * This file is part of the SQL Server Performance Monitor. + * + * Licensed under the MIT License. See LICENSE file in the project root for full license information. + */ + +using System; +using System.Threading; +using System.Threading.Tasks; +using Npgsql; +using NpgsqlTypes; + +namespace PerformanceMonitor.Darling.Storage; + +/// +/// The write half of the per-collection procedure totals (#5638): the one statement that brings +/// up to date after a collect.procedure_stats batch. The caller is +/// DarlingCollectorRunner.CopyBatchOnceAsync, the only code that writes collect.procedure_stats. +/// +/// Atomic with the COPY, and fatal to it. runs on the COPY's own transaction, after the COPY +/// and the dimension flush and before the commit, with no savepoint and no catch (the hour ledger's shape, #4605): a fault throws out of +/// the batch, the transaction rolls back and the batch's raw rows are not stored. Rows and totals therefore commit together or not at all, +/// and the read can trust a totals row to equal its collection's rows. The cost of a fault is the batch's sample, which +/// StoreWriteReattempt declines to re-run because the delta baselines have moved. +/// +/// Exact when a collection spans batches. The statement recomputes from the rows the store holds for the collection +/// (those of earlier committed batches and this batch's, visible on this transaction), so it never adds, and a second batch at the +/// same collection_time or a re-attempt writes the same totals. A batch that wrote no rows writes no totals: the read keeps +/// its collection_log axis for a run that stored nothing. +/// +public static class ProcedureStatsTotalsWriter +{ + /// + /// Upserts the totals of the collection stamped for on the COPY's + /// transaction (). A of 0 or less writes nothing and costs + /// no round trip. Returns the totals rows the statement wrote (one per database in the collection). + /// + public static async Task UpsertBatchAsync( + NpgsqlConnection connection, + NpgsqlTransaction transaction, + int serverId, + DateTime collectionTime, + int rowsWritten, + int commandTimeoutSeconds, + CancellationToken cancellationToken) + { + ArgumentNullException.ThrowIfNull(connection); + ArgumentNullException.ThrowIfNull(transaction); + + if (rowsWritten <= 0) + { + return 0; + } + + await using var command = new NpgsqlCommand(ProcedureStatsTotals.UpsertSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }; + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + + /* Naive-UTC storage: Npgsql 6+ rejects Kind=Utc against `timestamp` - see PgCollectorRowWriter. */ + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified) }); + return await command.ExecuteNonQueryAsync(cancellationToken); + } +} diff --git a/Darling/PerformanceMonitor.Darling.Storage/StorageVersion.cs b/Darling/PerformanceMonitor.Darling.Storage/StorageVersion.cs index 51b087247b..671225cb43 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/StorageVersion.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/StorageVersion.cs @@ -16,5 +16,5 @@ namespace PerformanceMonitor.Darling.Storage; /// public static class StorageVersion { - public const int SchemaVersion = 175; + public const int SchemaVersion = 176; } diff --git a/Darling/PerformanceMonitor.Darling.Viewer/ViewerDataService.cs b/Darling/PerformanceMonitor.Darling.Viewer/ViewerDataService.cs index 8d70859e15..8ece93e834 100644 --- a/Darling/PerformanceMonitor.Darling.Viewer/ViewerDataService.cs +++ b/Darling/PerformanceMonitor.Darling.Viewer/ViewerDataService.cs @@ -1146,7 +1146,10 @@ in the catalog so the answer does not depend on the connecting role's privileges /* V175 (#5631) adds the per-day rows-per-call sum to the daily plan regression totals. That column is the sentinel, found by catalog so the answer does not depend on the connecting role's privileges. Named only in this probe line, never in prose, per the V71 finding. */ - EXISTS (SELECT 1 FROM pg_attribute WHERE attrelid = to_regclass('collect.plan_regression_daily') AND attname = 'rowcount_sum' AND NOT attisdropped)"; + EXISTS (SELECT 1 FROM pg_attribute WHERE attrelid = to_regclass('collect.plan_regression_daily') AND attname = 'rowcount_sum' AND NOT attisdropped), + /* V176 (#5638) adds the per-collection procedure totals table. That table is the sentinel, found by name in the catalog so the answer does not + depend on the connecting role's privileges on it. Named only in this probe line, never in prose, per the V71 finding. */ + EXISTS (SELECT 1 WHERE to_regclass('collect.procedure_stats_totals') IS NOT NULL)"; /// The store schema version this viewer build requires — the highest migration it knows /// (). The connect-time gate blocks a store below this. @@ -1168,7 +1171,7 @@ per the V71 finding. */ await using var reader = await command.ExecuteReaderAsync(cancellationToken); if (await reader.ReadAsync(cancellationToken)) { - return MapProbedSchemaVersion(reader.GetBoolean(0), reader.GetBoolean(1), reader.GetBoolean(2), reader.GetBoolean(3), reader.GetBoolean(4), reader.GetBoolean(5), reader.GetBoolean(6), reader.GetBoolean(7), reader.GetBoolean(8), reader.GetBoolean(9), reader.GetBoolean(10), reader.GetBoolean(11), reader.GetBoolean(12), reader.GetBoolean(13), reader.GetBoolean(14), reader.GetBoolean(15), reader.GetBoolean(16), reader.GetBoolean(17), reader.GetBoolean(18), reader.GetBoolean(19), reader.GetBoolean(20), reader.GetBoolean(21), reader.GetBoolean(22), reader.GetBoolean(23), reader.GetBoolean(24), reader.GetBoolean(25), reader.GetBoolean(26), reader.GetBoolean(27), reader.GetBoolean(28), reader.GetBoolean(29), reader.GetBoolean(30), reader.GetBoolean(31), reader.GetBoolean(32), reader.GetBoolean(33), reader.GetBoolean(34), reader.GetBoolean(35), reader.GetBoolean(36), reader.GetBoolean(37), reader.GetBoolean(38), reader.GetBoolean(39), reader.GetBoolean(40), reader.GetBoolean(41), reader.GetBoolean(42), reader.GetBoolean(43), reader.GetBoolean(44), reader.GetBoolean(45), reader.GetBoolean(46), reader.GetBoolean(47), reader.GetBoolean(48), reader.GetBoolean(49), reader.GetBoolean(50), reader.GetBoolean(51), reader.GetBoolean(52), reader.GetBoolean(53), reader.GetBoolean(54), reader.GetBoolean(55), reader.GetBoolean(56), reader.GetBoolean(57), reader.GetBoolean(58), reader.GetBoolean(59), reader.GetBoolean(60), reader.GetBoolean(61), reader.GetBoolean(62), reader.GetBoolean(63), reader.GetBoolean(64), reader.GetBoolean(65), reader.GetBoolean(66), reader.GetBoolean(67), reader.GetBoolean(68), reader.GetBoolean(69), reader.GetBoolean(70), reader.GetBoolean(71), reader.GetBoolean(72), reader.GetBoolean(73), reader.GetBoolean(74), reader.GetBoolean(75), reader.GetBoolean(76), reader.GetBoolean(77), reader.GetBoolean(78), reader.GetBoolean(79), reader.GetBoolean(80), reader.GetBoolean(81), reader.GetBoolean(82), reader.GetBoolean(83), reader.GetBoolean(84), reader.GetBoolean(85), reader.GetBoolean(86), reader.GetBoolean(87), reader.GetBoolean(88), reader.GetBoolean(89), reader.GetBoolean(90), reader.GetBoolean(91), reader.GetBoolean(92), reader.GetBoolean(93), reader.GetBoolean(94), reader.GetBoolean(95), reader.GetBoolean(96), reader.GetBoolean(97), reader.GetBoolean(98), reader.GetBoolean(99), reader.GetBoolean(100), reader.GetBoolean(101), reader.GetBoolean(102), reader.GetBoolean(103), reader.GetBoolean(104), reader.GetBoolean(105), reader.GetBoolean(106), reader.GetBoolean(107), reader.GetBoolean(108), reader.GetBoolean(109), reader.GetBoolean(110), reader.GetBoolean(111), reader.GetBoolean(112), reader.GetBoolean(113), reader.GetBoolean(114), reader.GetBoolean(115), reader.GetBoolean(116), reader.GetBoolean(117), reader.GetBoolean(118), reader.GetBoolean(119), reader.GetBoolean(120), reader.GetBoolean(121), reader.GetBoolean(122), reader.GetBoolean(123), reader.GetBoolean(124), reader.GetBoolean(125), reader.GetBoolean(126), reader.GetBoolean(127), reader.GetBoolean(128), reader.GetBoolean(129), reader.GetBoolean(130), reader.GetBoolean(131), reader.GetBoolean(132), reader.GetBoolean(133), reader.GetBoolean(134), reader.GetBoolean(135), reader.GetBoolean(136), reader.GetBoolean(137), reader.GetBoolean(138), reader.GetBoolean(139), reader.GetBoolean(140), reader.GetBoolean(141), reader.GetBoolean(142), reader.GetBoolean(143), reader.GetBoolean(144), reader.GetBoolean(145), reader.GetBoolean(146), reader.GetBoolean(147), reader.GetBoolean(148), reader.GetBoolean(149), reader.GetBoolean(150)); + return MapProbedSchemaVersion(reader.GetBoolean(0), reader.GetBoolean(1), reader.GetBoolean(2), reader.GetBoolean(3), reader.GetBoolean(4), reader.GetBoolean(5), reader.GetBoolean(6), reader.GetBoolean(7), reader.GetBoolean(8), reader.GetBoolean(9), reader.GetBoolean(10), reader.GetBoolean(11), reader.GetBoolean(12), reader.GetBoolean(13), reader.GetBoolean(14), reader.GetBoolean(15), reader.GetBoolean(16), reader.GetBoolean(17), reader.GetBoolean(18), reader.GetBoolean(19), reader.GetBoolean(20), reader.GetBoolean(21), reader.GetBoolean(22), reader.GetBoolean(23), reader.GetBoolean(24), reader.GetBoolean(25), reader.GetBoolean(26), reader.GetBoolean(27), reader.GetBoolean(28), reader.GetBoolean(29), reader.GetBoolean(30), reader.GetBoolean(31), reader.GetBoolean(32), reader.GetBoolean(33), reader.GetBoolean(34), reader.GetBoolean(35), reader.GetBoolean(36), reader.GetBoolean(37), reader.GetBoolean(38), reader.GetBoolean(39), reader.GetBoolean(40), reader.GetBoolean(41), reader.GetBoolean(42), reader.GetBoolean(43), reader.GetBoolean(44), reader.GetBoolean(45), reader.GetBoolean(46), reader.GetBoolean(47), reader.GetBoolean(48), reader.GetBoolean(49), reader.GetBoolean(50), reader.GetBoolean(51), reader.GetBoolean(52), reader.GetBoolean(53), reader.GetBoolean(54), reader.GetBoolean(55), reader.GetBoolean(56), reader.GetBoolean(57), reader.GetBoolean(58), reader.GetBoolean(59), reader.GetBoolean(60), reader.GetBoolean(61), reader.GetBoolean(62), reader.GetBoolean(63), reader.GetBoolean(64), reader.GetBoolean(65), reader.GetBoolean(66), reader.GetBoolean(67), reader.GetBoolean(68), reader.GetBoolean(69), reader.GetBoolean(70), reader.GetBoolean(71), reader.GetBoolean(72), reader.GetBoolean(73), reader.GetBoolean(74), reader.GetBoolean(75), reader.GetBoolean(76), reader.GetBoolean(77), reader.GetBoolean(78), reader.GetBoolean(79), reader.GetBoolean(80), reader.GetBoolean(81), reader.GetBoolean(82), reader.GetBoolean(83), reader.GetBoolean(84), reader.GetBoolean(85), reader.GetBoolean(86), reader.GetBoolean(87), reader.GetBoolean(88), reader.GetBoolean(89), reader.GetBoolean(90), reader.GetBoolean(91), reader.GetBoolean(92), reader.GetBoolean(93), reader.GetBoolean(94), reader.GetBoolean(95), reader.GetBoolean(96), reader.GetBoolean(97), reader.GetBoolean(98), reader.GetBoolean(99), reader.GetBoolean(100), reader.GetBoolean(101), reader.GetBoolean(102), reader.GetBoolean(103), reader.GetBoolean(104), reader.GetBoolean(105), reader.GetBoolean(106), reader.GetBoolean(107), reader.GetBoolean(108), reader.GetBoolean(109), reader.GetBoolean(110), reader.GetBoolean(111), reader.GetBoolean(112), reader.GetBoolean(113), reader.GetBoolean(114), reader.GetBoolean(115), reader.GetBoolean(116), reader.GetBoolean(117), reader.GetBoolean(118), reader.GetBoolean(119), reader.GetBoolean(120), reader.GetBoolean(121), reader.GetBoolean(122), reader.GetBoolean(123), reader.GetBoolean(124), reader.GetBoolean(125), reader.GetBoolean(126), reader.GetBoolean(127), reader.GetBoolean(128), reader.GetBoolean(129), reader.GetBoolean(130), reader.GetBoolean(131), reader.GetBoolean(132), reader.GetBoolean(133), reader.GetBoolean(134), reader.GetBoolean(135), reader.GetBoolean(136), reader.GetBoolean(137), reader.GetBoolean(138), reader.GetBoolean(139), reader.GetBoolean(140), reader.GetBoolean(141), reader.GetBoolean(142), reader.GetBoolean(143), reader.GetBoolean(144), reader.GetBoolean(145), reader.GetBoolean(146), reader.GetBoolean(147), reader.GetBoolean(148), reader.GetBoolean(149), reader.GetBoolean(150), reader.GetBoolean(151)); } return null; @@ -1193,7 +1196,7 @@ per the V71 finding. */ /// is unit-tested without a live store; any schema bump past the newest arm trips the pinning test that keeps /// this in step with . /// - internal static int MapProbedSchemaVersion(bool hasConfigControlPlane, bool hasAlertDeliveryOverride, bool hasAnalysisState, bool hasAlertTuningKnobs, bool hasDefaultTraceEvents, bool hasIndexObjectStatsLatestIndex, bool hasCollectionLogHypertableOrPlainPg, bool hasJobHistory, bool hasAgentStatus, bool hasGenericWebhook, bool hasDeadlocksDatabaseName, bool hasQueryStoreReplicaRole, bool hasLongQueryCompletions, bool hasWebDashboardConfig, bool hasCustomViews, bool hasServerTags, bool hasConnectionRefireKnobs = false, bool hasAgCollectors = false, bool hasAgAlertKnobs = false, bool hasAgLatencyColumns = false, bool hasAgDisconnectRefire = false, bool hasPayloadDimensions = false, bool hasDimFloorIndexes = false, bool hasBlockingWaitThreshold = false, bool hasQueryStoreIntervalIdentity = false, bool hasPagerDutyWebhook = false, bool hasPagerDutyProxy = false, bool hasCollectorState = false, bool hasPlanCorrection = false, bool hasPvsStats = false, bool hasPvsPressureKnobs = false, bool hasDatabaseStateAlert = false, bool hasServerTagColour = false, bool hasQueryStatsHostObject = false, bool hasFindingDrillDown = false, bool hasStoreMetrics = false, bool hasPlanDimGzip = false, bool hasSelfAlertKnobs = false, bool hasJobMetricsColumns = false, bool hasJobCadenceKnob = false, bool hasBackfillSwitch = false, bool hasCollectorMemoryKnobs = false, bool hasDatabaseStateEdgeMemory = false, bool hasIncidentOccurrences = false, bool hasPlanXmlCompressionKnob = false, bool hasMonitoredServerEngine = false, bool hasPgBlockingEdges = false, bool hasQueryStorePlanMap = false, bool hasPgStatementText = false, bool hasQueryStoreText = false, bool hasPlanContentRetentionKnob = false, bool hasQueryStoreHealth = false, bool hasQueryStoreTextHash = false, bool hasComposeTimeoutKnob = false, bool hasFileGrowthAlert = false, bool hasCollectionLogFanoutRollup = false, bool hasTempDbMaxSize = false, bool hasServerEngineKind = false, bool hasPgDatabaseStats = false, bool hasPgIndexUsageStats = false, bool hasPgTableBloatStats = false, bool hasPgSessionStates = false, bool hasPgPlanCaptureReadiness = false, bool hasPgWriteStats = false, bool hasPgExtensionAvailability = false, bool hasPgLockStats = false, bool hasPgColumnStats = false, bool hasPgReplicationStats = false, bool hasPgBufferUsage = false, bool hasPgIndexBloat = false, bool hasPgPerDatabaseAttribution = false, bool hasPgWaitSampling = false, bool hasPgKernelStats = false, bool hasPgPredicateStats = false, bool hasPgPlanCapture = false, bool hasPgMajorVersion = false, bool hasPg18IoBytes = false, bool hasPgServerConfig = false, bool hasPgDeadlocks = false, bool hasPgDeadlockIdentity = false, bool hasCollectorCost = false, bool hasPgCpuUtilization = false, bool hasPlanForceActions = false, bool hasCollectionLogPhaseSplit = false, bool hasCollectionLogDrainForensics = false, bool hasCollectionLogFetchPhaseSums = false, bool hasStoreLogSelfMonitoring = false, bool hasCollectorStallProbes = false, bool hasRemediationCredentialAndActor = false, bool hasPgIndexBloatEstimate = false, bool hasPgCpuCapacityHeadroom = false, bool hasCustomAlertCore = false, bool hasMuteRuleReloadBeacon = false, bool hasBuiltinAlertPersistence = false, bool hasRetentionHoldRatioKnobs = false, bool hasDeadlockRateBandKnobs = false, bool hasOversizedPlanBacklog = false, bool hasPgAlertCountKnobs = false, bool hasFleetSweepState = false, bool hasFleetSweepCadenceKnobs = false, bool hasCollectorScheduleDatabases = false, bool hasSelfDiskWarnGbFloor = false, bool hasDeltaFamilyIntervalColumns = false, bool hasDeltaFamilyIntervalCompletion = false, bool hasPgLogEvents = false, bool hasPgLogEventMetrics = false, bool hasNotificationRoutes = false, bool hasPerfmonCounterType = false, bool hasPgNumbackendsAndSampledMs = false, bool hasTimeHonesty = false, bool hasLrqExclusionKnob = false, bool hasPgDatabaseSizeStatsAndHostMemory = false, bool hasQsCaptureModeRouteKnobToast = false, bool hasPgServerConfigDatabaseRoleOverrides = false, bool hasPostmasterStartTime = false, bool hasCheckpointsTimed = false, bool hasCollectionCaveats = false, bool hasIndexObjectStatsServerTimeIndex = false, bool hasQueryStoreIntervalLatest = false, bool hasRawChunkIntervalRungHistory = false, bool hasQueryStoreIntervalWide = false, bool hasManagedConfVerdicts = false, bool hasComposeTimeoutSixty = false, bool hasReadLatency = false, bool hasHotLivenessTouch = false, bool hasCollectionLogWatermarkAndJobHistoryIndexes = false, bool hasAgGroupId = false, bool hasCaggGroupIndexDrop = false, bool hasIntervalFirstExecIndexes = false, bool hasIntervalWideFirstExecIndex = false, bool hasQueryStoreIntervalEnd = false, bool hasCheckpointLongestSync = false, bool hasMuteRuleServerId = false, bool hasInstallId = false, bool hasInstallIdTableOid = false, bool hasCollectorRunAt = false, bool hasQueryStoreTopDaily = false, bool hasSlowReads = false, bool hasStoreStatementHistory = false, bool hasQueryStatsHourLedger = false, bool hasPasswordKey = false, bool hasPagerDutyAutoResolve = false, bool hasLegacyPinCandidates = false, bool hasPlanRegressionDaily = false, bool hasAwsRole = false, bool hasPgIoStatsHourly = false, bool hasQueryStoreIntervalWidePartitioned = false, bool hasQueryStoreIntervalLatestPartitioned = false, bool hasQueryStoreComposeStamp = false, bool hasServiceVersion = false, bool hasPlanRegressionDailyRowcount = false) + internal static int MapProbedSchemaVersion(bool hasConfigControlPlane, bool hasAlertDeliveryOverride, bool hasAnalysisState, bool hasAlertTuningKnobs, bool hasDefaultTraceEvents, bool hasIndexObjectStatsLatestIndex, bool hasCollectionLogHypertableOrPlainPg, bool hasJobHistory, bool hasAgentStatus, bool hasGenericWebhook, bool hasDeadlocksDatabaseName, bool hasQueryStoreReplicaRole, bool hasLongQueryCompletions, bool hasWebDashboardConfig, bool hasCustomViews, bool hasServerTags, bool hasConnectionRefireKnobs = false, bool hasAgCollectors = false, bool hasAgAlertKnobs = false, bool hasAgLatencyColumns = false, bool hasAgDisconnectRefire = false, bool hasPayloadDimensions = false, bool hasDimFloorIndexes = false, bool hasBlockingWaitThreshold = false, bool hasQueryStoreIntervalIdentity = false, bool hasPagerDutyWebhook = false, bool hasPagerDutyProxy = false, bool hasCollectorState = false, bool hasPlanCorrection = false, bool hasPvsStats = false, bool hasPvsPressureKnobs = false, bool hasDatabaseStateAlert = false, bool hasServerTagColour = false, bool hasQueryStatsHostObject = false, bool hasFindingDrillDown = false, bool hasStoreMetrics = false, bool hasPlanDimGzip = false, bool hasSelfAlertKnobs = false, bool hasJobMetricsColumns = false, bool hasJobCadenceKnob = false, bool hasBackfillSwitch = false, bool hasCollectorMemoryKnobs = false, bool hasDatabaseStateEdgeMemory = false, bool hasIncidentOccurrences = false, bool hasPlanXmlCompressionKnob = false, bool hasMonitoredServerEngine = false, bool hasPgBlockingEdges = false, bool hasQueryStorePlanMap = false, bool hasPgStatementText = false, bool hasQueryStoreText = false, bool hasPlanContentRetentionKnob = false, bool hasQueryStoreHealth = false, bool hasQueryStoreTextHash = false, bool hasComposeTimeoutKnob = false, bool hasFileGrowthAlert = false, bool hasCollectionLogFanoutRollup = false, bool hasTempDbMaxSize = false, bool hasServerEngineKind = false, bool hasPgDatabaseStats = false, bool hasPgIndexUsageStats = false, bool hasPgTableBloatStats = false, bool hasPgSessionStates = false, bool hasPgPlanCaptureReadiness = false, bool hasPgWriteStats = false, bool hasPgExtensionAvailability = false, bool hasPgLockStats = false, bool hasPgColumnStats = false, bool hasPgReplicationStats = false, bool hasPgBufferUsage = false, bool hasPgIndexBloat = false, bool hasPgPerDatabaseAttribution = false, bool hasPgWaitSampling = false, bool hasPgKernelStats = false, bool hasPgPredicateStats = false, bool hasPgPlanCapture = false, bool hasPgMajorVersion = false, bool hasPg18IoBytes = false, bool hasPgServerConfig = false, bool hasPgDeadlocks = false, bool hasPgDeadlockIdentity = false, bool hasCollectorCost = false, bool hasPgCpuUtilization = false, bool hasPlanForceActions = false, bool hasCollectionLogPhaseSplit = false, bool hasCollectionLogDrainForensics = false, bool hasCollectionLogFetchPhaseSums = false, bool hasStoreLogSelfMonitoring = false, bool hasCollectorStallProbes = false, bool hasRemediationCredentialAndActor = false, bool hasPgIndexBloatEstimate = false, bool hasPgCpuCapacityHeadroom = false, bool hasCustomAlertCore = false, bool hasMuteRuleReloadBeacon = false, bool hasBuiltinAlertPersistence = false, bool hasRetentionHoldRatioKnobs = false, bool hasDeadlockRateBandKnobs = false, bool hasOversizedPlanBacklog = false, bool hasPgAlertCountKnobs = false, bool hasFleetSweepState = false, bool hasFleetSweepCadenceKnobs = false, bool hasCollectorScheduleDatabases = false, bool hasSelfDiskWarnGbFloor = false, bool hasDeltaFamilyIntervalColumns = false, bool hasDeltaFamilyIntervalCompletion = false, bool hasPgLogEvents = false, bool hasPgLogEventMetrics = false, bool hasNotificationRoutes = false, bool hasPerfmonCounterType = false, bool hasPgNumbackendsAndSampledMs = false, bool hasTimeHonesty = false, bool hasLrqExclusionKnob = false, bool hasPgDatabaseSizeStatsAndHostMemory = false, bool hasQsCaptureModeRouteKnobToast = false, bool hasPgServerConfigDatabaseRoleOverrides = false, bool hasPostmasterStartTime = false, bool hasCheckpointsTimed = false, bool hasCollectionCaveats = false, bool hasIndexObjectStatsServerTimeIndex = false, bool hasQueryStoreIntervalLatest = false, bool hasRawChunkIntervalRungHistory = false, bool hasQueryStoreIntervalWide = false, bool hasManagedConfVerdicts = false, bool hasComposeTimeoutSixty = false, bool hasReadLatency = false, bool hasHotLivenessTouch = false, bool hasCollectionLogWatermarkAndJobHistoryIndexes = false, bool hasAgGroupId = false, bool hasCaggGroupIndexDrop = false, bool hasIntervalFirstExecIndexes = false, bool hasIntervalWideFirstExecIndex = false, bool hasQueryStoreIntervalEnd = false, bool hasCheckpointLongestSync = false, bool hasMuteRuleServerId = false, bool hasInstallId = false, bool hasInstallIdTableOid = false, bool hasCollectorRunAt = false, bool hasQueryStoreTopDaily = false, bool hasSlowReads = false, bool hasStoreStatementHistory = false, bool hasQueryStatsHourLedger = false, bool hasPasswordKey = false, bool hasPagerDutyAutoResolve = false, bool hasLegacyPinCandidates = false, bool hasPlanRegressionDaily = false, bool hasAwsRole = false, bool hasPgIoStatsHourly = false, bool hasQueryStoreIntervalWidePartitioned = false, bool hasQueryStoreIntervalLatestPartitioned = false, bool hasQueryStoreComposeStamp = false, bool hasServiceVersion = false, bool hasPlanRegressionDailyRowcount = false, bool hasProcedureStatsTotals = false) { /* V71 (the PostgreSQL blocking-edges rung): a table-existence sentinel and now the newest-first arm. A collector table would ordinarily get no arm at all — see the V63-V69 note below — but the TOP @@ -1394,6 +1397,13 @@ StorageVersion.SchemaVersion rather than falling through to 171 and showing a sp and the TOP rung, so a fully-migrated store maps to EXACTLY StorageVersion.SchemaVersion rather than falling through to 173 and showing a spurious upgrade banner on a store that is current. Named only in the probe line, not this prose, per the V71 finding. */ + /* V176 (#5638): the per-collection procedure totals table. Table-existence sentinel, newest-first, and the TOP rung, so a + fully-migrated store maps to EXACTLY StorageVersion.SchemaVersion rather than falling through to 175 and showing a spurious + upgrade banner on a store that is current. Named only in the probe line, not this prose, per the V71 finding. */ + if (hasProcedureStatsTotals) + { + return 176; + } /* V175 (#5631): the rows-per-call column of the daily plan regression totals. Column-existence sentinel, newest-first, and the TOP rung, so a fully-migrated store maps to EXACTLY StorageVersion.SchemaVersion rather than falling through to 174 and showing a spurious upgrade banner on a store that is current. Named only in the probe line, not this prose, per the V71 From 519f6fabf083a2d2a238f2d6255d83f087828285 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 15:39:11 -0400 Subject: [PATCH 2/7] Darling: V176 follow-through - probe ordinals, rung ladders and the totals artifact in the older-rung tests (part of #5638) --- .../AwsPerServerRoleRungTests.cs | 5 ++-- .../CaggGroupIndexDropLiveTests.cs | 7 +++++ .../LegacyPinCandidateRungTests.cs | 5 ++-- .../PlanRegressionDailyRungTests.cs | 5 ++-- .../PlanRegressionRowcountRungTests.cs | 11 +++++-- .../QueryStatsHourLedgerWriterTests.cs | 2 +- .../QueryStoreIntervalPartitionRungTests.cs | 30 ++++++++++--------- .../Darling.Tests/ServiceVersionRungTests.cs | 3 +- 8 files changed, 43 insertions(+), 25 deletions(-) diff --git a/Darling/Darling.Tests/AwsPerServerRoleRungTests.cs b/Darling/Darling.Tests/AwsPerServerRoleRungTests.cs index 887f79281f..8a9caffffb 100644 --- a/Darling/Darling.Tests/AwsPerServerRoleRungTests.cs +++ b/Darling/Darling.Tests/AwsPerServerRoleRungTests.cs @@ -107,7 +107,8 @@ public void TheProbeMapsAFullyMigratedStoreToThisTopRung() Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 4})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 5})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 6})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 7})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 7})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 8})", viewer, StringComparison.Ordinal); Assert.Equal(StorageVersion.SchemaVersion, ViewerDataService.RequiredStoreSchemaVersion); @@ -115,7 +116,7 @@ public void TheProbeMapsAFullyMigratedStoreToThisTopRung() var arity = method.GetParameters().Length; /* A newer rung's sentinel (V175's, #5631) is the last argument. */ - Assert.Equal(ProbeOrdinal + 6, arity - 1); + Assert.Equal(ProbeOrdinal + 7, arity - 1); var all = Enumerable.Repeat((object)true, arity).ToArray(); Assert.Equal(StorageVersion.SchemaVersion, (int)method.Invoke(null, all)!); diff --git a/Darling/Darling.Tests/CaggGroupIndexDropLiveTests.cs b/Darling/Darling.Tests/CaggGroupIndexDropLiveTests.cs index 7a07dc30e6..948950ae90 100644 --- a/Darling/Darling.Tests/CaggGroupIndexDropLiveTests.cs +++ b/Darling/Darling.Tests/CaggGroupIndexDropLiveTests.cs @@ -318,6 +318,13 @@ the group index still present — the same fixture shape CaggGroupIndexDropUpgra /// A future rung that adds a new probe sentinel must add its artifact's removal here. private static async Task DropArtifactsOfLaterRungsAsync(NpgsqlConnection connection, int simulatedVersion, CancellationToken ct) { + if (simulatedVersion < ProcedureStatsTotals.RungVersion) + { + /* V176 (#5638) - the per-collection procedure totals table is the probe's sentinel. */ + await using var dropTotals = new NpgsqlCommand("DROP TABLE IF EXISTS collect.procedure_stats_totals", connection); + await dropTotals.ExecuteNonQueryAsync(ct); + } + if (simulatedVersion < 175) { /* V175 (#5631) - the rows-per-call column of the daily plan regression totals is the probe's sentinel. */ diff --git a/Darling/Darling.Tests/LegacyPinCandidateRungTests.cs b/Darling/Darling.Tests/LegacyPinCandidateRungTests.cs index 34d6458c4e..4fcec18a8d 100644 --- a/Darling/Darling.Tests/LegacyPinCandidateRungTests.cs +++ b/Darling/Darling.Tests/LegacyPinCandidateRungTests.cs @@ -138,11 +138,12 @@ public void TheProbeCarriesTheTable_AtItsOwnOrdinal() Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 6})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 7})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 8})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 9})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 9})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 10})", viewer, StringComparison.Ordinal); var method = typeof(ViewerDataService).GetMethod("MapProbedSchemaVersion", BindingFlags.NonPublic | BindingFlags.Static)!; var parameters = method.GetParameters(); - Assert.Equal(ProbeOrdinal + 8, parameters.Length - 1); + Assert.Equal(ProbeOrdinal + 9, parameters.Length - 1); Assert.Equal("hasLegacyPinCandidates", parameters[ProbeOrdinal].Name); Assert.Equal("hasPagerDutyAutoResolve", parameters[ProbeOrdinal - 1].Name); diff --git a/Darling/Darling.Tests/PlanRegressionDailyRungTests.cs b/Darling/Darling.Tests/PlanRegressionDailyRungTests.cs index acb131fe46..c9a523ffcd 100644 --- a/Darling/Darling.Tests/PlanRegressionDailyRungTests.cs +++ b/Darling/Darling.Tests/PlanRegressionDailyRungTests.cs @@ -336,7 +336,8 @@ public void TheProbeCarriesTheBuiltTableAtItsOwnOrdinal_AndMapsItsRung() Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 5})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 6})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 7})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 8})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 8})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 9})", viewer, StringComparison.Ordinal); Assert.Equal(StorageVersion.SchemaVersion, ViewerDataService.RequiredStoreSchemaVersion); @@ -344,7 +345,7 @@ public void TheProbeCarriesTheBuiltTableAtItsOwnOrdinal_AndMapsItsRung() var parameters = method.GetParameters(); /* A newer rung's sentinel (V175's, #5631) is the last argument. */ - Assert.Equal(ProbeOrdinal + 7, parameters.Length - 1); + Assert.Equal(ProbeOrdinal + 8, parameters.Length - 1); Assert.Equal("hasPlanRegressionDaily", parameters[ProbeOrdinal].Name); /* Every sentinel true is a fully-migrated store, which maps to exactly this build's version. */ diff --git a/Darling/Darling.Tests/PlanRegressionRowcountRungTests.cs b/Darling/Darling.Tests/PlanRegressionRowcountRungTests.cs index 9fbf04d60b..a71461bb3a 100644 --- a/Darling/Darling.Tests/PlanRegressionRowcountRungTests.cs +++ b/Darling/Darling.Tests/PlanRegressionRowcountRungTests.cs @@ -120,21 +120,26 @@ public void TheProbeNamesTheColumn_AndMapsAFullyMigratedStoreToThisTopRung() var viewer = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Viewer", "ViewerDataService.cs"); Assert.Contains($"reader.GetBoolean({ProbeOrdinal})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 1})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 1})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 2})", viewer, StringComparison.Ordinal); var method = typeof(ViewerDataService).GetMethod("MapProbedSchemaVersion", BindingFlags.NonPublic | BindingFlags.Static)!; var parameters = method.GetParameters(); Assert.Equal("hasPlanRegressionDailyRowcount", parameters[ProbeOrdinal].Name); Assert.Equal("hasServiceVersion", parameters[ProbeOrdinal - 1].Name); - Assert.Equal(ProbeOrdinal, parameters.Length - 1); + Assert.Equal(ProbeOrdinal + 1, parameters.Length - 1); /* Every sentinel present maps to exactly this build's version; this sentinel absent maps one rung back. */ var all = Enumerable.Repeat((object)true, parameters.Length).ToArray(); Assert.Equal(StorageVersion.SchemaVersion, (int)method.Invoke(null, all)!); - Assert.Equal(RungVersion, (int)method.Invoke(null, all)!); + /* V176 (#5638) sits above this rung: with only this sentinel and those below it the store maps to this rung. */ + var topAbsent = (object[])all.Clone(); + topAbsent[ProbeOrdinal + 1] = false; + Assert.Equal(RungVersion, (int)method.Invoke(null, topAbsent)!); var behind = (object[])all.Clone(); behind[ProbeOrdinal] = false; + behind[ProbeOrdinal + 1] = false; Assert.Equal(RungVersion - 1, (int)method.Invoke(null, behind)!); /* In the source the arm sits ABOVE V174's and returns this rung's version. */ diff --git a/Darling/Darling.Tests/QueryStatsHourLedgerWriterTests.cs b/Darling/Darling.Tests/QueryStatsHourLedgerWriterTests.cs index 0841682a22..93f68dc1a7 100644 --- a/Darling/Darling.Tests/QueryStatsHourLedgerWriterTests.cs +++ b/Darling/Darling.Tests/QueryStatsHourLedgerWriterTests.cs @@ -103,7 +103,7 @@ public void TheTally_StartsOnTheAttemptsOwnWriter_BeforeTheFirstRow_AndANamedTra Assert.Single(Regex.Matches(code, @"new PgCollectorRowWriter\(\)")); /* The ledger term keeps the transaction non-null for a ledger batch whatever the diversion plan says. */ - Assert.Matches(@"diversionPlan\.Count > 0 \|\| queryStoreDatabases is not null \|\| ledgerBatch\s*\?\s*await pgConnection\.BeginTransactionAsync", code); + Assert.Matches(@"diversionPlan\.Count > 0 \|\| queryStoreDatabases is not null \|\| ledgerBatch \|\| totalsBatch\s*\?\s*await pgConnection\.BeginTransactionAsync", code); /* A row that wrote the interval through another overload would be untallied: the batch fails before the COPY completes. The comparison lives in EnsureEveryRowTallied (its own test below fails without it), so this pins the CALL: it sits diff --git a/Darling/Darling.Tests/QueryStoreIntervalPartitionRungTests.cs b/Darling/Darling.Tests/QueryStoreIntervalPartitionRungTests.cs index 386f482a88..ec45701b55 100644 --- a/Darling/Darling.Tests/QueryStoreIntervalPartitionRungTests.cs +++ b/Darling/Darling.Tests/QueryStoreIntervalPartitionRungTests.cs @@ -66,13 +66,13 @@ FOR EACH ROW public void TheRungsAreRegistered_DenseAndTheTop_AndShareOneBuilder() { var versions = PgMigrations.Scripts.Select(s => s.Version).ToList(); - Assert.Equal(new[] { 170, 171, 172, 173, 174, 175 }, versions.OrderBy(v => v).TakeLast(6).ToArray()); + Assert.Equal(new[] { 170, 171, 172, 173, 174, 175, 176 }, versions.OrderBy(v => v).TakeLast(7).ToArray()); Assert.Equal("query-store-interval-wide-partitioned", WideRung.Name); Assert.Equal("query-store-interval-latest-partitioned", LatestRung.Name); /* No longer the top rung: the Query Store compose rollup rung (V173, #5582) and the service version rung (V174, #5655) landed above it. */ Assert.True(LatestRungVersion < StorageVersion.SchemaVersion); - Assert.Equal(LatestRungVersion, PgMigrations.Scripts[^4].Version); - Assert.Equal(WideRungVersion, PgMigrations.Scripts[^5].Version); + Assert.Equal(LatestRungVersion, PgMigrations.Scripts[^5].Version); + Assert.Equal(WideRungVersion, PgMigrations.Scripts[^6].Version); /* Every statement is catalog-only, in the shipped text: the indexes are ON ONLY, nothing copies rows, and the parent has no WITH clause (PostgreSQL refuses storage parameters on a partitioned table). */ @@ -112,7 +112,7 @@ public async Task TheRung_OnAStoreSeededAcrossFiveDays_PartitionsBothTablesAndKe Assert.Equal(RowsPerTable, latestBefore); Assert.Equal("r", await TextAsync(connection, "SELECT relkind::text FROM pg_class WHERE oid = 'collect." + Wide + "'::regclass", ct)); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); foreach (var table in new[] { Wide, Latest }) { @@ -219,7 +219,7 @@ INSERT INTO collect.qsp_ctl_child await migrator.OpenAsync(ct); migrator.Notice += (_, e) => notices.Add(e.Notice.MessageText); await ExecAsync(migrator, "SET client_min_messages = debug1", ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(migrator, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(migrator, ct)); await FlushStatsAsync(migrator, ct); } @@ -255,7 +255,7 @@ public async Task ReRunningTheRungs_ChangesNothing() try { await using var connection = await ArrangeV170StoreAsync(scratch, ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); var before = await CatalogSnapshotAsync(connection, ct); Assert.Contains("p:query_store_interval_wide", before, StringComparison.Ordinal); @@ -306,7 +306,7 @@ public async Task UpgradeFromV170_WithAnInvalidBtree_AMissingBrin_AndTheTrigger_ Assert.Equal(1, await CountAsync(connection, "pg_trigger WHERE tgrelid = 'collect.query_store_interval_latest'::regclass AND NOT tgisinternal", ct)); var triggerBefore = await TextAsync(connection, "SELECT pg_get_triggerdef(oid) FROM pg_trigger WHERE tgrelid = 'collect.query_store_interval_latest'::regclass AND NOT tgisinternal", ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); /* The INVALID btree is gone from both the legacy table and the parent; the missing BRIN was not built. */ Assert.Null(await ScalarAsync(connection, "SELECT to_regclass('collect.ix_query_store_interval_wide_server_first_exec')::text", ct)); @@ -351,7 +351,7 @@ public async Task UpgradeFromV170_WithAValidBtreeAndAValidBrin_AttachesBothWitho var filesBefore = await TextAsync(connection, "SELECT string_agg(relfilenode::text, ',' ORDER BY relname) FROM pg_class WHERE relname IN " + names, ct); Assert.Equal(4, filesBefore.Split(',').Length); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); foreach (var index in new[] { "ix_query_store_interval_wide_server_first_exec", "ix_query_store_interval_wide_collection_time_brin" }) { @@ -396,7 +396,7 @@ public async Task TheParent_HasTheLegacyTablesColumnsInTheSameOrder_AndTheSameNu legacyShape[table] = await ColumnShapeAsync(connection, "collect." + table, ct); } - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); foreach (var table in new[] { Wide, Latest }) { @@ -442,7 +442,7 @@ public async Task ReaderRoles_CanSelectTheNewParents() Assert.Equal(RowsPerTable, await CountAsync(connection, "collect." + Wide, ct)); await ExecAsync(connection, "RESET ROLE", ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); await ExecAsync(connection, "SET ROLE " + role, ct); foreach (var table in new[] { Wide, Latest }) @@ -491,7 +491,7 @@ public async Task TheWritersUpsert_InsertsThenUpdates_ThroughTheParent() try { await using var connection = await ArrangeV170StoreAsync(scratch, ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); Assert.True(await IndexIsValidAsync(connection, "ux_" + Wide, ct)); Assert.True(await IndexIsValidAsync(connection, "ux_" + Latest, ct)); @@ -567,7 +567,7 @@ public async Task TheLatestTablesTrigger_FiresForARowWrittenThroughTheParent() try { await using var connection = await ArrangeV170StoreAsync(scratch, ct); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); await ExecAsync(connection, "TRUNCATE collect.plan_regression_daily_built", ct); const string insert = @" @@ -601,7 +601,7 @@ public async Task TheViewerProbe_MapsAPartitionedStoreToTheTopRung_AndAStoreBehi { await using var connection = await ArrangeV170StoreAsync(scratch, ct); Assert.Equal(170, await ProbedVersionAsync(connection, ct)); - Assert.Equal(5, await PgMigrations.MigrateAsync(connection, ct)); + Assert.Equal(6, await PgMigrations.MigrateAsync(connection, ct)); Assert.Equal(StorageVersion.SchemaVersion, await ProbedVersionAsync(connection, ct)); bodySucceeded = true; } @@ -652,7 +652,9 @@ private static async Task RewindToV170Async(NpgsqlConnection connection, Cancell } /* V173 (#5582): the stamp-grain rollup and its triggers are above V170 too; RewindTableAsync dropped the triggers, the tables go here. */ - /* V175 (#5631): the daily plan regression rows-per-call column is above V170 too (the probe's newest sentinel). */ + /* V176 (#5638): the procedure totals table is above V170 too (the probe's newest sentinel). */ + await ExecAsync(connection, "DROP TABLE IF EXISTS collect.procedure_stats_totals", ct); + /* V175 (#5631): the daily plan regression rows-per-call column is above V170 too. */ await ExecAsync(connection, "ALTER TABLE IF EXISTS collect.plan_regression_daily DROP COLUMN IF EXISTS rowcount_sum", ct); /* V174 (#5655): the service version table is above V170 too. */ await ExecAsync(connection, "DROP TABLE IF EXISTS config.service_version", ct); diff --git a/Darling/Darling.Tests/ServiceVersionRungTests.cs b/Darling/Darling.Tests/ServiceVersionRungTests.cs index 658327192a..d6848de04c 100644 --- a/Darling/Darling.Tests/ServiceVersionRungTests.cs +++ b/Darling/Darling.Tests/ServiceVersionRungTests.cs @@ -85,7 +85,8 @@ public void TheProbeNamesTheTable_AndMapsAFullyMigratedStoreToThisTopRung() Assert.Contains($"reader.GetBoolean({ProbeOrdinal})", viewer, StringComparison.Ordinal); /* V175's sentinel (#5631) sits above this one; the probe's last ordinal is the newest rung's. */ Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 1})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 2})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 2})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 3})", viewer, StringComparison.Ordinal); var method = typeof(ViewerDataService).GetMethod("MapProbedSchemaVersion", BindingFlags.NonPublic | BindingFlags.Static)!; var parameters = method.GetParameters(); From df062e45435efe5efbeb4b2d6524675a1fa49286 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 16:16:45 -0400 Subject: [PATCH 3/7] Darling: the raw procedure duration trend reads per-collection totals from the server's floor, procedure_stats rows below it (fixes #5638) --- .../DarlingMcpTrendToolsTests.cs | 12 +- .../DurationTrendDatabaseFilterLiveTests.cs | 4 +- .../ProcedureTrendTotalsStitchLiveTests.cs | 523 ++++++++++++++++++ .../DurationTrendRouting.cs | 39 ++ .../ProcedureStatsTotals.cs | 2 +- 5 files changed, 574 insertions(+), 6 deletions(-) create mode 100644 Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs diff --git a/Darling/Darling.Tests/DarlingMcpTrendToolsTests.cs b/Darling/Darling.Tests/DarlingMcpTrendToolsTests.cs index ec90607516..505ef4037b 100644 --- a/Darling/Darling.Tests/DarlingMcpTrendToolsTests.cs +++ b/Darling/Darling.Tests/DarlingMcpTrendToolsTests.cs @@ -361,12 +361,14 @@ public void ProcedureDurationTrendSql_PrefersTheStoredInterval_NeverFabricatesZe Assert.Contains("CASE WHEN is_stored AND max_interval_seconds = 0 THEN NULL", sql, StringComparison.Ordinal); Assert.Contains($"CASE WHEN gap_seconds <= {CollectorDeltaCalculator.DefaultMaxGapSeconds} THEN gap_seconds END", sql, StringComparison.Ordinal); Assert.Contains("WHEN is_stored THEN NULLIF(max_interval_seconds, 0)", sql, StringComparison.Ordinal); - Assert.Equal(2, System.Text.RegularExpressions.Regex.Matches(sql, @"collection_time >= \$2 - INTERVAL '3600 seconds'").Count); + /* #5638: the stored collections come from two arms (the rows below the server's totals floor, the totals from it), each bounded + from $2 less the gap, and the runs are the third. */ + Assert.Equal(3, System.Text.RegularExpressions.Regex.Matches(sql, @"collection_time >= \$2 - INTERVAL '3600 seconds'").Count); Assert.Contains("FROM gapped\nWHERE collection_time >= $2", string.Join('\n', Lines(sql)), StringComparison.Ordinal); /* A run is logged after it finishes, so one that began inside the window can be logged just past its end: the runs are read - an hour past $3 (once), the stored rows and the final points stop at $3 (twice). */ + an hour past $3 (once), the stored rows, the stored totals and the final points stop at $3 (three times, #5638). */ Assert.Single(System.Text.RegularExpressions.Regex.Matches(sql, @"collection_time <= \$3 \+ INTERVAL '3600 seconds'")); - Assert.Equal(2, System.Text.RegularExpressions.Regex.Matches(sql, @"collection_time <= \$3\r?\n").Count); + Assert.Equal(3, System.Text.RegularExpressions.Regex.Matches(sql, @"collection_time <= \$3\r?\n").Count); Assert.DoesNotContain("COALESCE(MAX(", sql, StringComparison.Ordinal); Assert.DoesNotContain("series_first", sql, StringComparison.Ordinal); Assert.Contains("CASE WHEN interval_seconds > 0 THEN total_elapsed_ms / interval_seconds END AS elapsed_ms_per_second", sql, StringComparison.Ordinal); @@ -379,13 +381,15 @@ public void ProcedureDurationTrendSql_PrefersTheStoredInterval_NeverFabricatesZe carries NO database term, so the interval is the collection's), is the same text. */ static bool IsFilteredSumLine(string l) => l.Contains("delta_elapsed_time", StringComparison.Ordinal) || l.Contains("delta_execution_count", StringComparison.Ordinal) + || l.Contains("total_elapsed_time", StringComparison.Ordinal) || l.Contains("total_execution_count", StringComparison.Ordinal) || l.Contains("matched_rows", StringComparison.Ordinal); foreach (var cte in new[] { "stored AS\n(", "runs AS\n(", "events AS\n(", "sequenced AS\n(", "points AS\n(", "gapped AS\n(", "raw AS\n(" }) { var viewerCte = Cte(Lf(ViewerDataService.ProcedureDurationTrendSql), cte); if (cte == "stored AS\n(") { - Assert.Equal(3, viewerCte.Split('\n').Count(l => l.Contains("FILTER (WHERE $4::text[] IS NULL OR database_name = ANY($4))", StringComparison.Ordinal))); + /* #5638: three filtered sums on the rows arm and three on the totals arm. */ + Assert.Equal(6, viewerCte.Split('\n').Count(l => l.Contains("FILTER (WHERE $4::text[] IS NULL OR database_name = ANY($4))", StringComparison.Ordinal))); } var viewer = string.Join('\n', viewerCte.Split('\n').Where(l => !IsFilteredSumLine(l)).Select(l => l.Trim())); var mcp = string.Join('\n', Cte(Lf(sql), cte).Split('\n').Where(l => !IsFilteredSumLine(l)).Select(l => l.Trim())); diff --git a/Darling/Darling.Tests/DurationTrendDatabaseFilterLiveTests.cs b/Darling/Darling.Tests/DurationTrendDatabaseFilterLiveTests.cs index 8c57ccbe39..274099d63c 100644 --- a/Darling/Darling.Tests/DurationTrendDatabaseFilterLiveTests.cs +++ b/Darling/Darling.Tests/DurationTrendDatabaseFilterLiveTests.cs @@ -362,7 +362,9 @@ every database. */ /* Raw: the per-collection CTE, the filter at $4 and the bucket width at $5. */ Assert.Equal(3, Count(DarlingTrendReader.QueryDurationTrendFilteredSql, filterPredicate4)); - Assert.Equal(3, Count(DarlingTrendReader.ProcedureDurationTrendFilteredSql, filterPredicate4)); + /* #5638: the procedure statement's stored CTE has two arms, the rows below the totals floor and the per-database totals from + it, and each carries the three FILTERs (elapsed, executions, matched rows), so six. */ + Assert.Equal(6, Count(DarlingTrendReader.ProcedureDurationTrendFilteredSql, filterPredicate4)); Assert.Equal(0, Count(DarlingTrendReader.QueryDurationTrendFilteredSql, predicate4)); Assert.Equal(0, Count(DarlingTrendReader.ProcedureDurationTrendFilteredSql, predicate4)); /* #5414 round 2: empty is decided once for the whole window, never per bucket (a per-bucket HAVING dropped the diff --git a/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs new file mode 100644 index 0000000000..f6dc338e82 --- /dev/null +++ b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs @@ -0,0 +1,523 @@ +/* + * Copyright (c) 2026 Erik Darling, Darling Data LLC + * + * This file is part of the SQL Server Performance Monitor. + * + * 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.Linq; +using System.Reflection; +using System.Threading; +using System.Threading.Tasks; +using Npgsql; +using NpgsqlTypes; +using PerformanceMonitor.Collectors; +using PerformanceMonitor.Darling.Service; +using PerformanceMonitor.Darling.Storage; +using Xunit; + +namespace Darling.Tests; + +/// +/// The raw procedure duration trend reads the per-collection totals (#5638, V176) for the collections at or after a server's floor +/// (MIN(collection_time) of collect.procedure_stats_totals) and the procedure_stats rows below it. The ORACLE in +/// every comparison is the statement as it ran before the totals (the stored CTE summing every row of every collection, kept below as +/// and spliced into the new text), run on the same store. The new statement must return, column by column +/// and type by type, the buckets the old one returns, for the unfiltered and the database-filtered shapes, at the 1 and 60 minute +/// widths, for a window after the floor, one that straddles it, one before it, and for servers with no totals at all. +/// +/// The data: server 7 has 24 five-minute collections (10:00 to 11:55). The first twelve are rows only, written directly (a store +/// upgraded to V176 mid-stream); the rest go through the product's own WriteBatchAsync, so their totals are the real writer's. +/// They include a restart collection (interval 0 everywhere, before and after the floor), a collection whose intervals are all NULL, a +/// collection with a NULL database_name, a collection whose deltas are all NULL, a collection that stored one database only, and +/// collections that stored nothing (idle runs in collection_log, before and after the floor). Server 8 carries the same rows +/// and no totals at all (the floor is NULL: every collection reads the rows). +/// +/// #1776 own-store: the test creates and drops its own scratch database through , so it is +/// not in the live-postgres collection. +/// +public sealed class ProcedureTrendTotalsStitchLiveTests +{ + private static string? BaseConnectionString => Environment.GetEnvironmentVariable("DARLING_TEST_PG"); + + private const string SkipReason = "Set DARLING_TEST_PG to run the procedure trend totals stitch's live equivalence pins (each mints its own scratch database)."; + + private static readonly DateTime T0 = new(2026, 1, 5, 10, 0, 0, DateTimeKind.Unspecified); + + private const int FloorIndex = 12; + + private static readonly MethodInfo WriteBatchMethod = typeof(DarlingCollectorRunner) + .GetMethod("WriteBatchAsync", BindingFlags.NonPublic | BindingFlags.Instance)!; + + private static DateTime At(int index) => T0.AddMinutes(5 * index); + + /// The stored CTE as it ran before #5638: every row of every collection, summed per collection. + private static string OldStoredBlock(bool withDatabaseFilter) + { + const string match = "$4::text[] IS NULL OR database_name = ANY($4)"; + var maxGap = CollectorDeltaCalculator.DefaultMaxGapSeconds; + var sums = withDatabaseFilter + ? $"COALESCE(SUM(delta_elapsed_time) FILTER (WHERE {match}), 0) / 1000.0 AS total_elapsed_ms,\n" + + $" COALESCE(SUM(delta_execution_count) FILTER (WHERE {match}), 0) AS total_executions,\n" + + $" COUNT(*) FILTER (WHERE {match}) AS matched_rows," + : "SUM(delta_elapsed_time) / 1000.0 AS total_elapsed_ms,\n" + + " SUM(delta_execution_count) AS total_executions,"; + return $""" + stored AS + ( + SELECT + collection_time, + {sums} + MAX(sample_interval_seconds) AS max_interval_seconds + FROM procedure_stats + WHERE server_id = $1 + AND collection_time >= $2 - INTERVAL '{maxGap} seconds' + AND collection_time <= $3 + GROUP BY collection_time + ), + + """; + } + + /// The new statement with its stitched totals_floor + stored pair replaced by the pre-change stored. + private static string OldSql(bool withDatabaseFilter) + { + var text = DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", withDatabaseFilter); + var start = text.IndexOf("totals_floor AS", StringComparison.Ordinal); + var end = text.IndexOf("runs AS", StringComparison.Ordinal); + Assert.True(start > 0 && end > start, "the stitched pair is the text between totals_floor and runs"); + return text[..start] + OldStoredBlock(withDatabaseFilter).Replace("\r\n", "\n") + text[end..]; + } + + /// The stitched text names the totals table, takes the floor per server, and keeps the rows arm below it. + [Fact] + public void TheStatementReadsTheTotalsAtOrAfterTheFloorAndTheRowsBelowIt() + { + foreach (var filtered in new[] { false, true }) + { + var text = System.Text.RegularExpressions.Regex.Replace(DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", filtered), @"\s+", " "); + Assert.Contains("FROM collect.procedure_stats_totals WHERE server_id = $1", text, StringComparison.Ordinal); + Assert.Contains("COALESCE(MIN(collection_time), 'infinity'::timestamp) AS floor_time", text, StringComparison.Ordinal); + Assert.Contains("AND collection_time < (SELECT floor_time FROM totals_floor)", text, StringComparison.Ordinal); + Assert.Contains("MAX(max_sample_interval_seconds) AS max_interval_seconds", text, StringComparison.Ordinal); + Assert.Contains("SUM(total_elapsed_time)", text, StringComparison.Ordinal); + Assert.Equal(filtered, text.Contains("COALESCE(SUM(row_count) FILTER (WHERE $4::text[] IS NULL OR database_name = ANY($4)), 0)::bigint AS matched_rows", StringComparison.Ordinal)); + + /* The pre-change oracle really is a different text, so the equivalence below compares two statements. */ + Assert.NotEqual(DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", filtered), OldSql(filtered)); + Assert.DoesNotContain("procedure_stats_totals", OldSql(filtered), StringComparison.Ordinal); + } + } + + internal sealed record Spec(string? Database, string Procedure, long? Elapsed, long? Executions, int? Interval); + + /// The rows of collection , their final shape (NULLs included). An empty list stores nothing. + private static List Specs(int index) + { + if (index is 9 or 19) + { + return new List(); + } + + var specs = new List(); + var databases = index == 21 ? new[] { "B" } : index == 22 ? new[] { "A" } : new[] { "A", "B", "C" }; + for (var d = 0; d < databases.Length; d++) + { + var database = databases[d]; + for (var p = 1; p <= 3; p++) + { + long elapsed = 1000L * (index + 1) + p * 7 + d * 13; + long executions = 1 + (index % 4) + p; + int? interval = (index + p) % 5 == 0 ? 120 : 300; + if (index is 6 or 15) + { + elapsed = 0; + executions = 0; + interval = 0; + } + else if (index is 8 or 17) + { + interval = null; + } + + string? name = database; + if (index == 20 && database == "C") + { + name = null; + } + + long? e = elapsed; + long? x = executions; + if (index == 22) + { + e = null; + x = null; + } + + specs.Add(new Spec(name, $"{database}_p{p}", e, x, interval)); + } + } + + return specs; + } + + private static readonly int[] CollectionIndexes = BuildIndexes(); + + private static int[] BuildIndexes() + { + var all = new int[24]; + for (var i = 0; i < all.Length; i++) + { + all[i] = i; + } + + return all; + } + + private sealed class Rig : IAsyncDisposable + { + private int _directId; + private int _logId; + + public required ScratchPostgres Scratch { get; init; } + + public required NpgsqlDataSource DataSource { get; init; } + + public required NpgsqlConnection Connection { get; init; } + + public required DarlingCollectorRunner Runner { get; init; } + + public required CollectorDeltaCalculator Deltas { get; init; } + + public required ServerRuntime Server { get; init; } + + public static async Task OpenAsync(int serverId, CancellationToken ct) + { + var scratch = await ScratchPostgres.CreateAsync(BaseConnectionString!, ct); + var connection = new NpgsqlConnection(scratch.ConnectionString); + await connection.OpenAsync(ct); + await PgMigrations.MigrateAsync(connection, ct); + var deltas = new CollectorDeltaCalculator(); + var dataSource = NpgsqlDataSource.Create(scratch.ConnectionString); + return new Rig + { + Scratch = scratch, + DataSource = dataSource, + Connection = connection, + Deltas = deltas, + Runner = new DarlingCollectorRunner(dataSource, deltas), + Server = new ServerRuntime + { + Config = new MonitoredServer { Name = "Stitch\\INST", Host = "Stitch\\INST" }, + ConnectionString = "Server=Stitch", + Target = new CollectorTargetInfo { SqlMajorVersion = 16 }, + StorageName = "Stitch\\INST", + ServerId = serverId, + EngineEdition = 3, + }, + }; + } + + /// Sets a stored row to the spec's final shape (a NULL database, interval or deltas), the shape rows written before those columns carried. + public async Task ReshapeAsync(int serverId, DateTime at, Spec spec, CancellationToken ct) + { + await using var update = new NpgsqlCommand( + "UPDATE collect.procedure_stats SET database_name = $1, delta_elapsed_time = $2, delta_execution_count = $3, sample_interval_seconds = $4 " + + "WHERE server_id = $5 AND collection_time = $6 AND object_name = $7", + Connection); + update.Parameters.AddWithValue(NpgsqlDbType.Text, (object?)spec.Database ?? DBNull.Value); + update.Parameters.AddWithValue(NpgsqlDbType.Bigint, (object?)spec.Elapsed ?? DBNull.Value); + update.Parameters.AddWithValue(NpgsqlDbType.Bigint, (object?)spec.Executions ?? DBNull.Value); + update.Parameters.AddWithValue(NpgsqlDbType.Integer, (object?)spec.Interval ?? DBNull.Value); + update.Parameters.AddWithValue(serverId); + update.Parameters.AddWithValue(NpgsqlDbType.Timestamp, at); + update.Parameters.AddWithValue(spec.Procedure); + Assert.Equal(1, await update.ExecuteNonQueryAsync(ct)); + } + + /// One row stored directly (a store with no totals writer yet), NULLs as given. Ids are negative so they never meet the writer's. + public async Task DirectRowAsync(int serverId, DateTime at, Spec spec, CancellationToken ct) + { + await using var insert = new NpgsqlCommand(@" +INSERT INTO collect.procedure_stats + (collection_id, collection_time, server_id, server_name, database_name, schema_name, object_name, sql_handle, + delta_worker_time, delta_elapsed_time, delta_execution_count, sample_interval_seconds) +VALUES ($1, $2, $3, 'stitch', $4, 'dbo', $5, $5, 1, $6, $7, $8)", Connection); + insert.Parameters.AddWithValue(--_directId); + insert.Parameters.AddWithValue(NpgsqlDbType.Timestamp, at); + insert.Parameters.AddWithValue(serverId); + insert.Parameters.AddWithValue(NpgsqlDbType.Text, (object?)spec.Database ?? DBNull.Value); + insert.Parameters.AddWithValue(spec.Procedure); + insert.Parameters.AddWithValue(NpgsqlDbType.Bigint, (object?)spec.Elapsed ?? DBNull.Value); + insert.Parameters.AddWithValue(NpgsqlDbType.Bigint, (object?)spec.Executions ?? DBNull.Value); + insert.Parameters.AddWithValue(NpgsqlDbType.Integer, (object?)spec.Interval ?? DBNull.Value); + await insert.ExecuteNonQueryAsync(ct); + } + + public async Task RunAsync(int serverId, DateTime loggedAt, long durationMs, string status, CancellationToken ct) + { + await using var insert = new NpgsqlCommand(@" +INSERT INTO collect.collection_log (log_id, server_id, server_name, collector_name, collection_time, duration_ms, status, rows_collected) +VALUES ($1, $2, 'stitch', 'procedure_stats', $3, $4, $5, 0)", Connection); + insert.Parameters.AddWithValue(++_logId); + insert.Parameters.AddWithValue(serverId); + insert.Parameters.AddWithValue(NpgsqlDbType.Timestamp, loggedAt); + insert.Parameters.AddWithValue(durationMs); + insert.Parameters.AddWithValue(status); + await insert.ExecuteNonQueryAsync(ct); + } + + /// One batch through the product's WriteBatchAsync: the rows and their totals, in the COPY's own transaction. + public async Task WriteAsync(DateTime collectionTime, List rows, CancellationToken ct) + { + var context = new CollectorContext + { + ServerId = Server.ServerId, + ServerName = Server.StorageName, + CollectionTime = collectionTime, + Deltas = Deltas, + Target = Server.Target, + }; + + var task = (Task)WriteBatchMethod.MakeGenericMethod(typeof(ProcedureStatsCollector.Row)).Invoke( + Runner, + new object?[] { Connection, ProcedureStatsCollector.Instance, rows, Server, collectionTime, context, ct })!; + await task; + return (int)task.GetType().GetProperty("Result")!.GetValue(task)!; + } + + /// Recomputes one collection's totals from its rows with the product's own upsert, after the rows were reshaped to a NULL case. + public async Task RetotalAsync(int serverId, DateTime at, int rows, CancellationToken ct) + { + await using (var delete = new NpgsqlCommand("DELETE FROM collect.procedure_stats_totals WHERE server_id = $1 AND collection_time = $2", Connection)) + { + delete.Parameters.AddWithValue(serverId); + delete.Parameters.AddWithValue(NpgsqlDbType.Timestamp, at); + await delete.ExecuteNonQueryAsync(ct); + } + + await using var tx = await Connection.BeginTransactionAsync(ct); + await ProcedureStatsTotalsWriter.UpsertBatchAsync(Connection, tx, serverId, at, rows, 30, ct); + await tx.CommitAsync(ct); + } + + public async ValueTask DisposeAsync() + { + await Connection.DisposeAsync(); + await DataSource.DisposeAsync(); + await Scratch.DisposeAsync(); + } + } + + /// A row for the real writer. The placeholders (database, deltas, interval) are reshaped to the spec's NULLs afterwards. + private static ProcedureStatsCollector.Row WriterRow(Spec spec) => new( + spec.Database ?? "C", "dbo", spec.Procedure, "P ", T0, T0, spec.Executions ?? 0, spec.Elapsed ?? 0, spec.Elapsed ?? 0, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, + "0x" + spec.Procedure, "0xP" + spec.Procedure, null, null) + { + Precomputed = new ProcedureStatsCollector.ReadTimeDeltas(spec.Executions ?? 0, spec.Elapsed ?? 0, spec.Elapsed ?? 0, 1, 1, 1, 0, spec.Interval ?? 300), + }; + + /// Loads server 7 (rows below the floor, rows and real totals from it) and server 8 (rows only), and both servers' collection_log runs. + private static async Task LoadAsync(Rig rig, int totalsServer, int rowsOnlyServer, CancellationToken ct) + { + foreach (var i in CollectionIndexes) + { + var specs = Specs(i); + + foreach (var spec in specs) + { + await rig.DirectRowAsync(rowsOnlyServer, At(i), spec, ct); + } + + if (i < FloorIndex) + { + foreach (var spec in specs) + { + await rig.DirectRowAsync(totalsServer, At(i), spec, ct); + } + } + else if (specs.Count > 0) + { + Assert.Equal(specs.Count, await rig.WriteAsync(At(i), specs.ConvertAll(WriterRow), ct)); + var reshaped = false; + foreach (var spec in specs) + { + if (spec.Database is null || spec.Interval is null || spec.Elapsed is null) + { + reshaped = true; + await rig.ReshapeAsync(totalsServer, At(i), spec, ct); + } + } + + if (reshaped) + { + await rig.RetotalAsync(totalsServer, At(i), specs.Count, ct); + } + } + + /* Every cycle is a SUCCESS run logged 20 s after its stamp; a run that stored nothing is the idle point. */ + foreach (var server in new[] { totalsServer, rowsOnlyServer }) + { + await rig.RunAsync(server, At(i).AddSeconds(20), 1500, "SUCCESS", ct); + } + } + + /* A failed run is no point at all. */ + foreach (var server in new[] { totalsServer, rowsOnlyServer }) + { + await rig.RunAsync(server, At(24).AddSeconds(20), 900, "FAILED", ct); + } + } + + private static async Task<(string Types, List Rows)> ReadAsync( + NpgsqlDataSource dataSource, string sql, bool filtered, string[]? filter, int serverId, DateTime start, DateTime end, int width, CancellationToken ct) + { + await using var command = dataSource.CreateCommand(sql); + command.Parameters.AddWithValue(NpgsqlDbType.Integer, serverId); + command.Parameters.AddWithValue(NpgsqlDbType.Timestamp, start); + command.Parameters.AddWithValue(NpgsqlDbType.Timestamp, end); + if (filtered) + { + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Array | NpgsqlDbType.Text, Value = (object?)filter ?? DBNull.Value }); + } + + command.Parameters.AddWithValue(NpgsqlDbType.Integer, width); + var rows = new List(); + await using var reader = await command.ExecuteReaderAsync(ct); + var types = new string[reader.FieldCount]; + for (var c = 0; c < types.Length; c++) + { + types[c] = reader.GetName(c) + ":" + reader.GetDataTypeName(c); + } + + while (await reader.ReadAsync(ct)) + { + var cells = new string[reader.FieldCount]; + for (var c = 0; c < cells.Length; c++) + { + cells[c] = reader.IsDBNull(c) ? "" : Convert.ToString(reader.GetValue(c), CultureInfo.InvariantCulture) ?? ""; + } + + rows.Add(string.Join("|", cells)); + } + + return (string.Join(",", types), rows); + } + + [Fact] + public async Task TheStitchedStatementReturnsTheBucketsTheRowsOnlyStatementReturns() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int totalsServer = -945307; + const int rowsOnlyServer = -945308; + const int unknownServer = -945399; + + await using var rig = await Rig.OpenAsync(totalsServer, ct); + + var bodySucceeded = false; + try + { + await LoadAsync(rig, totalsServer, rowsOnlyServer, ct); + + /* The setup is what the test claims: the floor is the first writer collection, nothing is totalled below it, the idle + collection after it has no totals row, the NULL database is one totals group, and the rows-only server has no totals. */ + await using (var check = rig.DataSource.CreateCommand( + "SELECT (SELECT MIN(collection_time) FROM collect.procedure_stats_totals WHERE server_id = $1), " + + "(SELECT COUNT(*) FROM collect.procedure_stats_totals WHERE server_id = $1 AND collection_time < $2), " + + "(SELECT COUNT(*) FROM collect.procedure_stats_totals WHERE server_id = $1), " + + "(SELECT COUNT(*) FROM collect.procedure_stats_totals WHERE server_id = $3), " + + "(SELECT COUNT(*) FROM collect.procedure_stats_totals WHERE server_id = $1 AND collection_time = $4), " + + "(SELECT COUNT(*) FROM collect.procedure_stats_totals WHERE server_id = $1 AND database_name IS NULL)")) + { + check.Parameters.AddWithValue(NpgsqlDbType.Integer, totalsServer); + check.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(FloorIndex)); + check.Parameters.AddWithValue(NpgsqlDbType.Integer, rowsOnlyServer); + check.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(19)); + await using var reader = await check.ExecuteReaderAsync(ct); + Assert.True(await reader.ReadAsync(ct)); + Assert.Equal(At(FloorIndex), reader.GetDateTime(0)); + Assert.Equal(0L, reader.GetInt64(1)); + Assert.Equal(29L, reader.GetInt64(2)); + Assert.Equal(0L, reader.GetInt64(3)); + Assert.Equal(0L, reader.GetInt64(4)); + Assert.Equal(1L, reader.GetInt64(5)); + } + + var windows = new (string Name, DateTime Start, DateTime End)[] + { + ("after the floor", At(13), At(23)), + ("straddling the floor", At(6), At(18)), + ("before the floor", At(0), At(10)), + ("everything", At(0), At(24)), + }; + var filters = new (string Name, bool Filtered, string[]? Filter)[] + { + ("unfiltered", false, null), + ("filter NULL", true, null), + ("filter A", true, new[] { "A" }), + ("filter B,C", true, new[] { "B", "C" }), + ("filter with no rows", true, new[] { "NoSuchDb" }), + }; + + var mismatches = new List(); + var compared = 0; + var nonEmpty = 0; + var unrated = 0; + foreach (var server in new[] { totalsServer, rowsOnlyServer, unknownServer }) + { + foreach (var window in windows) + { + foreach (var filter in filters) + { + foreach (var width in new[] { 1, 60 }) + { + var expected = await ReadAsync(rig.DataSource, OldSql(filter.Filtered), filter.Filtered, filter.Filter, server, window.Start, window.End, width, ct); + var actual = await ReadAsync( + rig.DataSource, DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", filter.Filtered), filter.Filtered, filter.Filter, + server, window.Start, window.End, width, ct); + compared++; + if (expected.Rows.Count > 0) + { + nonEmpty++; + } + + if (expected.Rows.Exists(r => r.Contains("", StringComparison.Ordinal))) + { + unrated++; + } + + var label = $"server {server}, {window.Name}, {filter.Name}, width {width}"; + if (expected.Types != actual.Types) + { + mismatches.Add(label + ": column types " + expected.Types + " vs " + actual.Types); + } + else if (!expected.Rows.SequenceEqual(actual.Rows)) + { + mismatches.Add(label + ": " + expected.Rows.Count + " old rows vs " + actual.Rows.Count + " new rows; first old " + (expected.Rows.Count > 0 ? expected.Rows[0] : "-") + " first new " + (actual.Rows.Count > 0 ? actual.Rows[0] : "-")); + } + } + } + } + } + + Assert.Empty(mismatches); + + /* The comparison is not vacuous: most statements returned buckets, and the restart / NULL-interval collections left unrated points. */ + Assert.Equal(3 * windows.Length * filters.Length * 2, compared); + /* Two servers with rows x 4 windows x 4 filters that match (the no-rows filter and the unknown server return nothing) x 2 widths. */ + Assert.Equal(64, nonEmpty); + Assert.True(unrated > 0, "no unrated point was compared"); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } +} diff --git a/Darling/PerformanceMonitor.Darling.Storage/DurationTrendRouting.cs b/Darling/PerformanceMonitor.Darling.Storage/DurationTrendRouting.cs index 9b8c7a85ad..95fcaabc5a 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/DurationTrendRouting.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/DurationTrendRouting.cs @@ -397,6 +397,18 @@ GROUP BY collection_time /// stored collections per run.) A run that failed stores nothing and is no point: the next point's gap /// covers it. Without a log (imported or old data) the axis is the stored collections alone. /// + /// Where a stored collection's sums come from (#5638). The collector writes one row per (collection, database) to + /// in the same transaction as the procedure rows, so a collection's sums are the sums of a + /// handful of totals rows in place of about a thousand procedure_stats rows. The two sources are stitched at the server's + /// FLOOR, MIN(collection_time) of the totals table for $1 (totals_floor; infinity when the server has + /// none): a collection at or after it reads the totals, a collection before it (written before the upgrade, which backfills + /// nothing) reads the rows, so no collection is read from both. Each measure is the same aggregate of the same values (the sums of + /// the per-database sums, the max of the per-database maxes, matched_rows = the sum of row_count over the chosen + /// databases), NULL where every row's value was NULL, so the three-state interval contract reads the same from either source. The + /// floor is its own scalar CTE so the rows arm carries collection_time < floor as an index range (and TimescaleDB + /// excludes chunks past it) and reads nothing for a window after the floor. A store below the V176 rung has no table; the + /// Viewer's connect gate blocks it and the service migrates before it reads. + /// /// A point's seconds are the gap to the previous point, or NULL (an unrated point, counted by the bucket) when the /// gap passes , the collector's own limit: a longer outage is /// out of the bucket's seconds, and a shorter one sits in the next point's gap, whose deltas measured it. A stored @@ -424,10 +436,26 @@ private static string ProcedureCollectionsCte(bool withDatabaseFilter) + $" COUNT(*) FILTER (WHERE {match}) AS matched_rows," : "SUM(delta_elapsed_time) / 1000.0 AS total_elapsed_ms,\n" + " SUM(delta_execution_count) AS total_executions,"; + + // #5638: the same three measures from the per-collection totals table, one row per (collection, database). SUM of the per-database + // sums is the sum of the rows, and the filter picks the same databases (a NULL database never matches, here or on the rows). + // row_count is COUNT(*), so its filtered sum is matched_rows; SUM(bigint) is numeric, so it is cast back to the bigint COUNT(*) gives. + var totalsSums = withDatabaseFilter + ? $"COALESCE(SUM(total_elapsed_time) FILTER (WHERE {match}), 0) / 1000.0 AS total_elapsed_ms,\n" + + $" COALESCE(SUM(total_execution_count) FILTER (WHERE {match}), 0) AS total_executions,\n" + + $" COALESCE(SUM(row_count) FILTER (WHERE {match}), 0)::bigint AS matched_rows," + : "SUM(total_elapsed_time) / 1000.0 AS total_elapsed_ms,\n" + + " SUM(total_execution_count) AS total_executions,"; var matched = withDatabaseFilter ? ", matched_rows" : ""; var idleMatched = withDatabaseFilter ? ", CAST(0 AS bigint)" : ""; return $""" + totals_floor AS + ( + SELECT COALESCE(MIN(collection_time), 'infinity'::timestamp) AS floor_time + FROM {ProcedureStatsTotals.Table} + WHERE server_id = $1 + ), stored AS ( SELECT @@ -438,6 +466,17 @@ FROM procedure_stats WHERE server_id = $1 AND collection_time >= $2 - INTERVAL '{maxGap} seconds' AND collection_time <= $3 + AND collection_time < (SELECT floor_time FROM totals_floor) + GROUP BY collection_time + UNION ALL + SELECT + collection_time, + {totalsSums} + MAX(max_sample_interval_seconds) AS max_interval_seconds + FROM {ProcedureStatsTotals.Table} + WHERE server_id = $1 + AND collection_time >= $2 - INTERVAL '{maxGap} seconds' + AND collection_time <= $3 GROUP BY collection_time ), runs AS diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs index 42e338c2f8..cd64e0f728 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs @@ -13,7 +13,7 @@ namespace PerformanceMonitor.Darling.Storage; /// holding what the raw procedure duration trend sums from every row of that collection. Since #5463 a collection stores /// about 560 to 1,060 rows per server, and the trend's per-collection CTE read all of them (about 60 K heap pages for one /// 24 h read). The collector now writes the totals in the same transaction as the rows () -/// and the read (a later part of #5638) reads them in place of the rows. This class is the storage half: the table, the upsert +/// and the raw trend's per-collection CTE (DurationTrendRouting.BuildBucketedRawTrendSql) reads them in place of the rows. This class is the storage half: the table, the upsert /// and the retention predicate. /// /// Grain and measures. (server_id, collection_time, database_name). Per database because the Viewer's From 4e60c5be2e06de82cd4340d057fb0c5f8120043e Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 17:11:23 -0400 Subject: [PATCH 4/7] Darling: procedure totals review round 1 - retention floor measured once, read-back limited to the batch's databases, rollback gap totalled, retention tests on compressed chunks (part of #5638) --- .../ProcedureStatsTotalsTests.cs | 33 ++- .../ProcedureStatsTotalsWriterLiveTests.cs | 199 ++++++++++++++++-- .../ProcedureTrendTotalsStitchLiveTests.cs | 147 ++++++++++++- .../DarlingCollectorRunner.cs | 8 +- .../DarlingRetention.cs | 40 +++- .../ProcedureStatsTotals.cs | 102 ++++++++- .../ProcedureStatsTotalsWriter.cs | 29 ++- 7 files changed, 522 insertions(+), 36 deletions(-) diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs index b7bfa7e313..f8c1da0c12 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs @@ -24,6 +24,35 @@ public sealed class ProcedureStatsTotalsTests { private static string Normalize(string text) => text.Replace("\r\n", "\n", StringComparison.Ordinal); + /// Review of #5706: the gap fill is bounded by the server's newest earlier totals row and the batch, and recomputes like the upsert. + [Fact] + public void TheGapFill_TotalsTheCollectionsBetweenTheNewestEarlierTotalsAndTheBatch_AndRecomputes() + { + var sql = Normalize(ProcedureStatsTotals.GapFillSql); + + Assert.Contains("FROM collect.procedure_stats AS s\nWHERE s.server_id = $1::integer\nAND s.collection_time < $2::timestamp\nAND s.collection_time >\n(\n SELECT max(p.collection_time)\n FROM collect.procedure_stats_totals AS p\n WHERE p.server_id = $1::integer\n AND p.collection_time < $2::timestamp\n)", sql, StringComparison.Ordinal); + Assert.Contains("ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET", sql, StringComparison.Ordinal); + Assert.DoesNotContain("t.row_count +", sql, StringComparison.Ordinal); + } + + /// Review of #5706: the retention predicate carries the floor as a parameter and never scans procedure_stats itself (#1815). + [Fact] + public void ThePrunePredicate_TakesTheFloorAsAParameter_AndNeverScansProcedureStats() + { + Assert.DoesNotContain("procedure_stats", ProcedureStatsTotals.PrunePredicate.Replace("procedure_stats_totals", string.Empty, StringComparison.Ordinal), StringComparison.Ordinal); + Assert.Contains("$2", ProcedureStatsTotals.PrunePredicate, StringComparison.Ordinal); + + var delete = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); + Assert.DoesNotContain("FROM collect.procedure_stats)", delete, StringComparison.Ordinal); + Assert.DoesNotContain("FROM collect.procedure_stats ", delete, StringComparison.Ordinal); + + var retention = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "DarlingRetention.cs")); + var floor = retention.IndexOf("ProcedureStatsTotals.MeasureRawFloorAsync(", StringComparison.Ordinal); + var purge = retention.IndexOf("TimeSlicedDeleteSql(ProcedureStatsTotals.Table", StringComparison.Ordinal); + Assert.True(floor > 0 && purge > floor, "the floor is measured once, before the DELETE that binds it"); + Assert.Contains("secondParameter: new NpgsqlParameter", retention, StringComparison.Ordinal); + } + [Fact] public void TheRung_IsV176_AndEmbedsTheCreateText() { @@ -63,7 +92,7 @@ public void TheUpsert_ReadsBackTheStoredRows_AndRecomputesEveryMeasureOnConflict { var sql = Normalize(ProcedureStatsTotals.UpsertSql); - Assert.Contains("FROM collect.procedure_stats\nWHERE server_id = $1::integer\nAND collection_time = $2::timestamp\nGROUP BY server_id, collection_time, database_name", sql, StringComparison.Ordinal); + Assert.Contains("FROM collect.procedure_stats\nWHERE server_id = $1::integer\nAND collection_time = $2::timestamp\nAND ($3::text[] IS NULL OR database_name = ANY($3::text[]) OR ($4::boolean AND database_name IS NULL))\nGROUP BY server_id, collection_time, database_name", sql, StringComparison.Ordinal); Assert.Contains("SUM(delta_elapsed_time)::bigint,", sql, StringComparison.Ordinal); Assert.Contains("SUM(delta_execution_count)::bigint,", sql, StringComparison.Ordinal); Assert.Contains("COUNT(*),", sql, StringComparison.Ordinal); @@ -118,7 +147,7 @@ public void Retention_PurgesTheTotals_AtProcedureStatsDays_NeverBeforeTheRawRows Assert.Contains("EffectivePurgeRetentionDays(\n \"procedure_stats\",", retention, StringComparison.Ordinal); var delete = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); - Assert.StartsWith("DELETE FROM collect.procedure_stats_totals WHERE collection_time < $1 AND collection_time < COALESCE((SELECT min(collection_time) FROM collect.procedure_stats), $1)", delete, StringComparison.Ordinal); + Assert.StartsWith("DELETE FROM collect.procedure_stats_totals WHERE collection_time < $1 AND collection_time < COALESCE($2::timestamp, $1)", delete, StringComparison.Ordinal); /* The totals table is a plain table outside the collector catalog: no hypertable conversion, no collector schedule entry. */ Assert.DoesNotContain(CollectorCatalogTables(), t => string.Equals(t, "procedure_stats_totals", StringComparison.Ordinal)); diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs index 4a35a15b17..62e73d75c5 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs @@ -56,12 +56,21 @@ private sealed class Rig : IAsyncDisposable public required ServerRuntime Server { get; init; } - public static async Task OpenAsync(int serverId, string serverName, CancellationToken ct) + public static async Task OpenAsync(int serverId, string serverName, CancellationToken ct, bool timescale = false) { var scratch = await ScratchPostgres.CreateAsync(BaseConnectionString!, ct); var connection = new NpgsqlConnection(scratch.ConnectionString); await connection.OpenAsync(ct); await PgMigrations.MigrateAsync(connection, ct); + if (timescale) + { + /* TimescaleDB must be installed where this runs (CI's darling-pg job has it): the store's real hypertable conversion, then the + background jobs stopped so no policy compresses or drops a chunk under the test. */ + Assert.True(await LiveTimescaleProbe.TryEnableAsync(scratch.ConnectionString, ct), "TimescaleDB must be available for the compressed-chunk retention pin"); + await TimescaleSupport.ConvertToHypertablesAsync(connection, null, ct); + await ExecAsync(connection, "SELECT _timescaledb_functions.stop_background_workers()", ct); + } + var deltas = new CollectorDeltaCalculator(); var dataSource = NpgsqlDataSource.Create(scratch.ConnectionString); return new Rig @@ -130,6 +139,31 @@ private static async Task ExecAsync(NpgsqlConnection connection, string sql, Can await command.ExecuteNonQueryAsync(ct); } + /// + /// The sweep's own totals purge, as DarlingRetention runs it: the raw floor measured once () + /// and bound as $2 of the one-day-slice DELETE. Returns the rows the DELETE removed. + /// + private static async Task RetentionDeleteAsync(NpgsqlConnection connection, bool timescaleAvailable, DateTime cutoff, CancellationToken ct) + { + var floor = await ProcedureStatsTotals.MeasureRawFloorAsync(connection, timescaleAvailable, 60, ct); + var sliced = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); + await using var command = new NpgsqlCommand(sliced, connection); + command.Parameters.AddWithValue(NpgsqlTypes.NpgsqlDbType.Timestamp, cutoff); + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlTypes.NpgsqlDbType.Timestamp, Value = floor is { } value ? value : DBNull.Value }); + + /* Drained like the sweep's loop (a one-day slice per statement, repeated until a statement deletes nothing). */ + var total = 0; + int deleted; + do + { + deleted = await command.ExecuteNonQueryAsync(ct); + total += deleted; + } + while (deleted > 0); + + return total; + } + private static string Stamp(DateTime value) => "'" + value.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + "'::timestamp"; /// @@ -229,7 +263,7 @@ public async Task ASecondBatchAtTheSameCollectionTime_Recomputes_AndNullInterval /* An upsert that runs again (a re-attempt) changes nothing. */ await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) { - Assert.Equal(2, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 4, 30, ct)); + Assert.Equal(2, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 4, 30, null, ct)); await tx.CommitAsync(ct); } @@ -242,7 +276,7 @@ public async Task ASecondBatchAtTheSameCollectionTime_Recomputes_AndNullInterval await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE database_name = 'DbB'", ct); await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) { - await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, ct); + await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, null, ct); await tx.CommitAsync(ct); } @@ -255,7 +289,7 @@ public async Task ASecondBatchAtTheSameCollectionTime_Recomputes_AndNullInterval /* And a second upsert still leaves one NULL-database row (the key treats NULL as one group, so it conflicts). */ await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) { - await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, ct); + await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, null, ct); await tx.CommitAsync(ct); } @@ -358,29 +392,162 @@ public async Task TheReadBackUsesAnIndex_AndRetentionNeverPurgesTotalsBeforeTheR Assert.DoesNotContain("Seq Scan on procedure_stats", plan.ToString(), StringComparison.Ordinal); await ExecAsync(rig.Connection, "RESET enable_seqscan", ct); - var sliced = DarlingRetention.TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate); - /* Cutoff after day 1 while every raw row is still held: raw holds day 0, so no totals row may go. */ - await using (var held = new NpgsqlCommand(sliced, rig.Connection)) - { - held.Parameters.AddWithValue(NpgsqlTypes.NpgsqlDbType.Timestamp, T0.AddDays(1).AddHours(1)); - Assert.Equal(0, await held.ExecuteNonQueryAsync(ct)); - } + Assert.Equal(0, await RetentionDeleteAsync(rig.Connection, false, T0.AddDays(1).AddHours(1), ct)); Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); /* Raw loses day 0 (its purge ran). Now day 0's totals row is older than both the cutoff and the oldest raw row. */ await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats WHERE collection_time < " + Stamp(T0.AddDays(1)), ct); - await using (var purge = new NpgsqlCommand(sliced, rig.Connection)) - { - purge.Parameters.AddWithValue(NpgsqlTypes.NpgsqlDbType.Timestamp, T0.AddDays(2).AddHours(1)); - Assert.Equal(1, await purge.ExecuteNonQueryAsync(ct)); - } + Assert.Equal(1, await RetentionDeleteAsync(rig.Connection, false, T0.AddDays(2).AddHours(1), ct)); /* Day 1's totals row is the oldest raw row's age, so it stays even though the cutoff is past it; day 2 is newer than the cutoff. */ Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); Assert.Equal(T0.AddDays(1), (DateTime)(await ScalarAsync(rig.Connection, "SELECT min(collection_time) FROM collect.procedure_stats_totals", ct))!); + /* The plain-PostgreSQL floor is the table's exact oldest row (day 1), one min() measured before the DELETE. */ + Assert.Equal(T0.AddDays(1), await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, false, 60, ct)); + + /* Every raw row gone: the floor is NULL and the cutoff alone decides, so both remaining totals rows (older than the cutoff) go. */ + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats", ct); + Assert.Null(await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, false, 60, ct)); + Assert.Equal(2, await RetentionDeleteAsync(rig.Connection, false, T0.AddDays(2).AddHours(1), ct)); + Assert.Equal(0L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// Review of #5706, finding 2: on Azure SQL Database the collector writes one batch per database at one collection_time. Each batch + /// totals only its own databases, so the batches of the other databases are not read back (a sentinel written into DbA's totals survives + /// DbC's batch), and the result is still exact: a second DbA batch recomputes DbA from BOTH of its batches, and a NULL database name + /// matches its NULL rows through the writer's NULL flag. + /// + [Fact] + public async Task PerDatabaseBatchesAtOneCollectionTime_TotalOnlyTheirOwnDatabases_AndStayExact() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945311; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals5", ct); + + var bodySucceeded = false; + try + { + var at = T0.AddMinutes(5); + var id = serverId.ToString(CultureInfo.InvariantCulture); + Assert.Equal(2, await rig.WriteAsync(at, new List { Row("DbA", "p1", 100, 1, 60), Row("DbA", "p2", 200, 2, 30) }, ct)); + Assert.Equal(1, await rig.WriteAsync(at, new List { Row("DbB", "p1", 400, 4, 45) }, ct)); + Assert.Equal("DbA|300|3|2|60;DbB|400|4|1|45", (await CompareAsync(rig.Connection, serverId, at, ct)).Totals); + + /* DbA's totals row is spoiled by hand. A batch of DbC alone must not read DbA back, so the spoiled value survives it. */ + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats_totals SET total_elapsed_time = -1 WHERE database_name = 'DbA'", ct); + Assert.Equal(1, await rig.WriteAsync(at, new List { Row("DbC", "p1", 800, 8, 10) }, ct)); + Assert.Equal(-1L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT total_elapsed_time FROM collect.procedure_stats_totals WHERE database_name = 'DbA'", ct))); + Assert.Equal(400L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT total_elapsed_time FROM collect.procedure_stats_totals WHERE database_name = 'DbB'", ct))); + Assert.Equal(800L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT total_elapsed_time FROM collect.procedure_stats_totals WHERE database_name = 'DbC'", ct))); + + /* A later batch of DbA recomputes DbA from both of its batches (the rows of the earlier one included): exact. */ + Assert.Equal(1, await rig.WriteAsync(at, new List { Row("DbA", "p3", 50, 5, 20) }, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, at, ct); + Assert.Equal(raw, totals); + Assert.Equal("DbA|350|8|3|60;DbB|400|4|1|45;DbC|800|8|1|10", totals); + + /* The NULL database: DbC's rows lose their name (the shape of rows older than the column), and a batch that names only NULL + recomputes only the NULL group; DbA's spoiled row survives it, and a batch that names DbB and NULL leaves DbA alone too. */ + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats SET database_name = NULL WHERE server_id = " + id + " AND database_name = 'DbC'", ct); + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE database_name = 'DbC'", ct); + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats_totals SET total_elapsed_time = -1 WHERE database_name = 'DbA'", ct); + await UpsertAsync(rig, serverId, at, new string?[] { null }, ct); + Assert.Equal("DbA|-1|8|3|60;DbB|400|4|1|45;|800|8|1|10", (await CompareAsync(rig.Connection, serverId, at, ct)).Totals); + + await ExecAsync(rig.Connection, "UPDATE collect.procedure_stats_totals SET total_elapsed_time = -2 WHERE database_name = 'DbB'", ct); + await UpsertAsync(rig, serverId, at, new string?[] { "DbB", null }, ct); + Assert.Equal("DbA|-1|8|3|60;DbB|400|4|1|45;|800|8|1|10", (await CompareAsync(rig.Connection, serverId, at, ct)).Totals); + + /* No names at all (an import) reads the whole collection back. */ + await UpsertAsync(rig, serverId, at, null, ct); + var (allTotals, allRaw) = await CompareAsync(rig.Connection, serverId, at, ct); + Assert.Equal(allRaw, allTotals); + Assert.Equal("DbA|350|8|3|60;DbB|400|4|1|45;|800|8|1|10", allTotals); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + private static async Task UpsertAsync(Rig rig, int serverId, DateTime at, IReadOnlyCollection? names, CancellationToken ct) + { + await using var tx = await rig.Connection.BeginTransactionAsync(ct); + await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, at, 1, 30, names, ct); + await tx.CommitAsync(ct); + } + + /// + /// Review of #5706, finding 4 on a TimescaleDB store: procedure_stats is a hypertable whose oldest chunk is COMPRESSED (no btree + /// there, the case that timed out in the field, #1815). The floor the retention DELETE binds comes from the chunk catalog, is never later + /// than the oldest raw row, and the sweep's DELETE never removes a totals row at or after it, whatever the cutoff. When the oldest chunk + /// leaves, the floor moves up and the totals older than the new floor go. + /// + [Fact] + public async Task OnTimescaleDb_WithACompressedOldestChunk_TheFloorComesFromTheChunkCatalog_AndRetentionNeverPurgesTotalsAtOrAfterIt() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945312; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotals6", ct, timescale: true); + + var bodySucceeded = false; + try + { + /* Three collections ten days apart: three chunks. The first chunk is then compressed. */ + for (var i = 0; i < 3; i++) + { + Assert.Equal(1, await rig.WriteAsync(T0.AddDays(10 * i), new List { Row("DbA", "p1", 10 + i, 1, 60) }, ct)); + } + + Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM timescaledb_information.chunks WHERE hypertable_schema = 'collect' AND hypertable_name = 'procedure_stats'", ct))); + await ExecAsync(rig.Connection, "ALTER TABLE collect.procedure_stats SET (timescaledb.compress, timescaledb.compress_segmentby = 'server_id')", ct); + await ExecAsync(rig.Connection, "SELECT compress_chunk(c) FROM show_chunks('collect.procedure_stats', older_than => " + Stamp(T0.AddDays(5)) + ") c", ct); + Assert.True((bool)(await ScalarAsync(rig.Connection, + "SELECT bool_and(is_compressed) FROM timescaledb_information.chunks WHERE hypertable_schema = 'collect' AND hypertable_name = 'procedure_stats' AND range_start AT TIME ZONE 'UTC' < " + Stamp(T0.AddDays(5)), ct))!); + + /* The floor is the oldest chunk's range_start: not later than the oldest raw row (and, as the row is mid-chunk, earlier than it). */ + var floor = await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, true, 60, ct); + var chunkStart = (DateTime)(await ScalarAsync(rig.Connection, + "SELECT min(range_start AT TIME ZONE 'UTC') FROM timescaledb_information.chunks WHERE hypertable_schema = 'collect' AND hypertable_name = 'procedure_stats'", ct))!; + Assert.Equal(chunkStart, floor); + Assert.True(floor <= T0, "the chunk floor is never later than the oldest raw row"); + Assert.True(floor < T0, "the floor is the chunk's start, not the row's own time: it came from the catalog, not from min(collection_time)"); + + /* A cutoff far past every collection while the raw chunk is still held: nothing at or after the floor may go. */ + Assert.Equal(0, await RetentionDeleteAsync(rig.Connection, true, T0.AddDays(100), ct)); + Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + + /* The oldest chunk leaves (the raw purge ran). The floor moves to the next chunk, and the first collection's totals, now older + than every raw row, go; the other two sit at or after the oldest raw row and stay. */ + await ExecAsync(rig.Connection, "SELECT drop_chunks('collect.procedure_stats', older_than => " + Stamp(T0.AddDays(5)) + ")", ct); + var movedFloor = await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, true, 60, ct); + Assert.True(movedFloor > floor && movedFloor <= T0.AddDays(10)); + Assert.Equal(1, await RetentionDeleteAsync(rig.Connection, true, T0.AddDays(100), ct)); + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + Assert.Equal(T0.AddDays(10), (DateTime)(await ScalarAsync(rig.Connection, "SELECT min(collection_time) FROM collect.procedure_stats_totals", ct))!); + + /* Every raw row gone: no chunk and no row, so the floor is NULL and the cutoff alone decides (the empty-table behavior). */ + await ExecAsync(rig.Connection, "SELECT drop_chunks('collect.procedure_stats', older_than => " + Stamp(T0.AddDays(100)) + ")", ct); + Assert.Null(await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, true, 60, ct)); + Assert.Equal(2, await RetentionDeleteAsync(rig.Connection, true, T0.AddDays(100), ct)); + bodySucceeded = true; } finally diff --git a/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs index f6dc338e82..8d878daba9 100644 --- a/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs +++ b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs @@ -301,7 +301,7 @@ public async Task RetotalAsync(int serverId, DateTime at, int rows, Cancellation } await using var tx = await Connection.BeginTransactionAsync(ct); - await ProcedureStatsTotalsWriter.UpsertBatchAsync(Connection, tx, serverId, at, rows, 30, ct); + await ProcedureStatsTotalsWriter.UpsertBatchAsync(Connection, tx, serverId, at, rows, 30, null, ct); await tx.CommitAsync(ct); } @@ -520,4 +520,149 @@ public async Task TheStitchedStatementReturnsTheBucketsTheRowsOnlyStatementRetur await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); } } + + private static async Task ScalarAsync(NpgsqlConnection connection, string sql, CancellationToken ct) + { + await using var command = new NpgsqlCommand(sql, connection); + return await command.ExecuteScalarAsync(ct); + } + + private static async Task ExecAsync(NpgsqlConnection connection, string sql, CancellationToken ct) + { + await using var command = new NpgsqlCommand(sql, connection); + await command.ExecuteNonQueryAsync(ct); + } + + private static List GapRows(int salt) => new() + { + WriterRow(new Spec("A", "p1", 100 + salt, 1 + salt, 300)), + WriterRow(new Spec("B", "p2", 200 + salt, 2, 120)), + }; + + /// + /// Review of #5706, finding 3: a pre-V176 binary (a rollback) wrote collection t2 above the floor, after the server's totals at t1, so t2 has + /// raw rows and no totals and the stitched trend (rows only below the floor) would drop it. The next batch (t3) totals every collection + /// strictly between the server's newest earlier totals row and itself, and the trend then equals the rows-only oracle. + /// + [Fact] + public async Task ACollectionAnOlderBinaryWroteAboveTheFloor_IsTotalledByTheNextBatch_AndTheTrendEqualsTheOldStatement() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945310; + + await using var rig = await Rig.OpenAsync(serverId, ct); + + var bodySucceeded = false; + try + { + for (var i = 0; i < 3; i++) + { + await rig.RunAsync(serverId, At(i).AddSeconds(20), 1500, "SUCCESS", ct); + } + + Assert.Equal(2, await rig.WriteAsync(At(0), GapRows(0), ct)); + Assert.Equal(2, await rig.WriteAsync(At(1), GapRows(10), ct)); + + /* The older binary wrote t2: its rows are there, its totals row is not. */ + await using (var old = new NpgsqlCommand("DELETE FROM collect.procedure_stats_totals WHERE server_id = $1 AND collection_time = $2", rig.Connection)) + { + old.Parameters.AddWithValue(serverId); + old.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(1)); + Assert.Equal(2, await old.ExecuteNonQueryAsync(ct)); + } + + /* Not vacuous: before the next batch the stitched trend is missing t2 against the rows-only oracle. */ + var width = 1; + var windowStart = At(0); + var windowEnd = At(3); + var before = await ReadAsync(rig.DataSource, DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", false), false, null, serverId, windowStart, windowEnd, width, ct); + var oracleBefore = await ReadAsync(rig.DataSource, OldSql(false), false, null, serverId, windowStart, windowEnd, width, ct); + Assert.NotEqual(oracleBefore.Rows, before.Rows); + + Assert.Equal(2, await rig.WriteAsync(At(2), GapRows(20), ct)); + Assert.Equal(6L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture), ct))); + + foreach (var filtered in new[] { false, true }) + { + foreach (var w in new[] { 1, 60 }) + { + var expected = await ReadAsync(rig.DataSource, OldSql(filtered), filtered, null, serverId, windowStart, windowEnd, w, ct); + var actual = await ReadAsync(rig.DataSource, DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", filtered), filtered, null, serverId, windowStart, windowEnd, w, ct); + Assert.NotEmpty(expected.Rows); + Assert.Equal(expected.Types, actual.Types); + Assert.Equal(expected.Rows, actual.Rows); + } + } + + /* The probe is normally empty and indexed: with a totals row at every collection the range holds no raw row, and the plan reads no + procedure_stats heap beyond an index range. Functional only (no timing claimed). */ + await using (var set = new NpgsqlCommand("SET enable_seqscan = off", rig.Connection)) + { + await set.ExecuteNonQueryAsync(ct); + } + + var plan = new System.Text.StringBuilder(); + await using (var explain = new NpgsqlCommand("EXPLAIN (ANALYZE, BUFFERS) " + ProcedureStatsTotals.GapFillSql, rig.Connection)) + { + explain.Parameters.AddWithValue(NpgsqlDbType.Integer, serverId); + explain.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(2)); + await using var reader = await explain.ExecuteReaderAsync(ct); + while (await reader.ReadAsync(ct)) + { + plan.AppendLine(reader.GetString(0)); + } + } + + Assert.DoesNotContain("Seq Scan", plan.ToString(), StringComparison.Ordinal); + Assert.Contains("Index", plan.ToString(), StringComparison.Ordinal); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// Review of #5706, finding 3, the other side: a server with raw rows and no totals row at all needs nothing from the gap fill (its floor is + /// infinity, the rows arm reads it), so the first batch totals only itself and the trend still equals the rows-only oracle. + /// + [Fact] + public async Task AServerWithNoTotalsYet_IsNotBackfilledByTheFirstBatch_AndTheTrendStillEqualsTheOldStatement() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945313; + + await using var rig = await Rig.OpenAsync(serverId, ct); + + var bodySucceeded = false; + try + { + for (var i = 0; i < 3; i++) + { + await rig.RunAsync(serverId, At(i).AddSeconds(20), 1500, "SUCCESS", ct); + } + + /* Rows with no totals at all: what a store holds before the first V176 batch. */ + Assert.Equal(2, await rig.WriteAsync(At(0), GapRows(0), ct)); + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals", ct); + Assert.Equal(2, await rig.WriteAsync(At(1), GapRows(10), ct)); + Assert.Equal(2L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); + Assert.Equal(0L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE collection_time = '" + At(0).ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + "'", ct))); + + var expected = await ReadAsync(rig.DataSource, OldSql(false), false, null, serverId, At(0), At(3), 1, ct); + var actual = await ReadAsync(rig.DataSource, DurationTrendRouting.BuildBucketedRawTrendSql("procedure_stats", false), false, null, serverId, At(0), At(3), 1, ct); + Assert.NotEmpty(expected.Rows); + Assert.Equal(expected.Rows, actual.Rows); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } } diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs index ad3857fd3a..763495d939 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs @@ -4691,7 +4691,13 @@ await QueryStatsHourLedgerWriter.AddBatchAsync( { await ProcedureStatsTotalsWriter.UpsertBatchAsync( pgConnection, transaction, server.ServerId, storedCollectionTime, - rowsWritten, ServiceCommandDeadlines.CollectionSweepSeconds, cancellationToken); + rowsWritten, ServiceCommandDeadlines.CollectionSweepSeconds, + /* The databases THIS batch holds (one per batch on Azure SQL Database): the read-back is limited to them. Null + (rows of another type, an import) reads the whole collection. */ + (object)rows is List procedureRows + ? procedureRows.Select(static row => (string?)row.DatabaseName).Distinct().ToList() + : null, + cancellationToken); } /* #3953: after the COPY and the dimension flush, in the unstamped region (#3095): a fault here is not diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs index 52f7f4d948..cf0486a07d 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs @@ -16,6 +16,7 @@ using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using Npgsql; +using NpgsqlTypes; using PerformanceMonitor.Analysis.Baselines; using PerformanceMonitor.Collectors; using PerformanceMonitor.Darling.Storage; @@ -1014,11 +1015,33 @@ and a row is never purged before the procedure_stats rows of its age (ProcedureS "procedure_stats", retentionDaysFor?.Invoke("procedure_stats") ?? (CollectorScheduleDefaults.All.TryGetValue("procedure_stats", out var procedureSchedule) ? procedureSchedule.RetentionDays : DataRetentionBaseDays)); - var procedureTotalsDeleted = await PurgeOneAsync( - postgres, ProcedureStatsTotals.Table, - TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate), - utcNow.AddDays(-procedureTotalsDays), logger, cancellationToken, - pacer: walPacer); + /* The raw floor is measured ONCE here and bound as $2 (review of #5706, #1815): the predicate used to carry an unbounded + min() over procedure_stats that the slice statement expands three times, a whole-table scan each, and the chunk-catalog + form is how the digest floor above survives compressed chunks. A floor that cannot be measured skips this table's + purge for the cycle (counted failed): without the floor the guard against deleting totals the raw trend still reads + is unknown, and the totals only age out a sweep later. */ + DateTime? procedureRawFloor = null; + var procedureRawFloorMeasured = false; + try + { + await using var floorConnection = await postgres.OpenConnectionAsync(cancellationToken); + procedureRawFloor = await ProcedureStatsTotals.MeasureRawFloorAsync( + floorConnection, timescaleAvailable, DeleteTimeoutSeconds, cancellationToken); + procedureRawFloorMeasured = true; + } + catch (Exception ex) when (ex is not OperationCanceledException) + { + logger?.LogWarning("Retention purge: could not measure procedure_stats' floor for the totals purge: {Message}", ex.Message); + } + + var procedureTotalsDeleted = procedureRawFloorMeasured + ? await PurgeOneAsync( + postgres, ProcedureStatsTotals.Table, + TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate), + utcNow.AddDays(-procedureTotalsDays), logger, cancellationToken, + pacer: walPacer, + secondParameter: new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = procedureRawFloor is { } floorValue ? floorValue : DBNull.Value }) + : null; if (procedureTotalsDeleted is not null) { tablesPurged++; @@ -1839,7 +1862,8 @@ avoidable work on a path that already runs per table per day. */ CancellationToken cancellationToken, int batchSize = 1, string? adaptiveRowCapTimeColumn = null, - RetentionWalPacer? pacer = null) + RetentionWalPacer? pacer = null, + NpgsqlParameter? secondParameter = null) { /* #5592: a pass whose wall budget is already spent starts no further table: no connection, no statement. Every table's purge comes through here, so this is the one place that skips them. Nothing was deleted, @@ -1896,6 +1920,10 @@ reach the cap and the one execution is terminal. */ { using var command = new NpgsqlCommand(deleteSql, connection) { CommandTimeout = DeleteTimeoutSeconds }; command.Parameters.AddWithValue(cutoff); + if (secondParameter is not null) + { + command.Parameters.Add(secondParameter); + } drained = await DrainBatchesAsync( async ct => diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs index cd64e0f728..e619b618ce 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs @@ -6,6 +6,11 @@ * Licensed under the MIT License. See LICENSE file in the project root for full license information. */ +using System; +using System.Threading; +using System.Threading.Tasks; +using Npgsql; + namespace PerformanceMonitor.Darling.Storage; /// @@ -75,6 +80,13 @@ max_sample_interval_seconds integer /// values from the rows and never adds to them. The sums are cast to bigint (SUM of a bigint is numeric); a sum past bigint /// would fail the statement, which is 292,000 years of elapsed time in one collection. Run it on the COPY's own transaction, after /// the COPY and before the commit. + /// + /// Limited to the batch's databases (review of #5706). $3 is the text[] of the non-NULL database names the + /// batch wrote and $4 says whether the batch wrote a NULL database; a NULL $3 reads the whole collection. On Azure SQL + /// Database the collector writes one batch per database at one collection_time, and a read-back of the whole collection in + /// each made the work grow with the square of the database count. Totals are per database and a batch holds whole databases (the + /// read-back still counts rows of earlier batches of the same database), so the result is exact. The NULL database matches only + /// through $4, as = ANY never matches a NULL. /// public const string UpsertSql = """ INSERT INTO collect.procedure_stats_totals AS t @@ -90,7 +102,47 @@ INSERT INTO collect.procedure_stats_totals AS t FROM collect.procedure_stats WHERE server_id = $1::integer AND collection_time = $2::timestamp +AND ($3::text[] IS NULL OR database_name = ANY($3::text[]) OR ($4::boolean AND database_name IS NULL)) GROUP BY server_id, collection_time, database_name +ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET + total_elapsed_time = EXCLUDED.total_elapsed_time, + total_execution_count = EXCLUDED.total_execution_count, + row_count = EXCLUDED.row_count, + max_sample_interval_seconds = EXCLUDED.max_sample_interval_seconds; +"""; + + /// + /// Totals the collections a pre-V176 binary wrote after the floor (review of #5706): $1 is the server id and $2 the + /// batch's collection_time. PgMigrations lets an older binary write to a V176 store (a rollback), and the raw + /// trend reads procedure_stats only below the server's floor, so a collection that has rows, no totals and sits above the + /// floor would vanish from the trend. This totals every collection of the server that has rows strictly after the server's newest + /// totals row before the batch and strictly before the batch. A server with no totals row has nothing to total (its floor is + /// infinity and the raw arm reads it). Normally the range is empty and the statement is two index probes: a backward scan of the + /// totals key for the newest earlier row, then a range scan of procedure_stats (server_id, collection_time) from it that + /// finds no row. Same upsert target and recompute as , so it is idempotent and exact. + /// + public const string GapFillSql = """ +INSERT INTO collect.procedure_stats_totals AS t + (server_id, collection_time, database_name, total_elapsed_time, total_execution_count, row_count, max_sample_interval_seconds) +SELECT + s.server_id, + s.collection_time, + s.database_name, + SUM(s.delta_elapsed_time)::bigint, + SUM(s.delta_execution_count)::bigint, + COUNT(*), + MAX(s.sample_interval_seconds) +FROM collect.procedure_stats AS s +WHERE s.server_id = $1::integer +AND s.collection_time < $2::timestamp +AND s.collection_time > +( + SELECT max(p.collection_time) + FROM collect.procedure_stats_totals AS p + WHERE p.server_id = $1::integer + AND p.collection_time < $2::timestamp +) +GROUP BY s.server_id, s.collection_time, s.database_name ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET total_elapsed_time = EXCLUDED.total_elapsed_time, total_execution_count = EXCLUDED.total_execution_count, @@ -100,11 +152,49 @@ ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET /// /// The extra predicate the retention sweep adds to its one-day-slice DELETE (DarlingRetention.TimeSlicedDeleteSql; $1 - /// is the cutoff): a totals row is never purged before the procedure_stats rows of the same age. The cutoff is the raw - /// collector's own retention, so on a plain store the two purge together. On TimescaleDB raw chunks leave through a gated purge that - /// can hold them past the horizon, so the predicate also keeps every totals row at or after the oldest raw row. With no raw rows left - /// the oldest is NULL and the cutoff alone decides. + /// is the cutoff, $2 the raw floor): a totals row is never purged before the procedure_stats rows of the same age. The + /// cutoff is the raw collector's own retention, so on a plain store the two purge together. On TimescaleDB raw chunks leave through a + /// gated purge that can hold them past the horizon, so the predicate also keeps every totals row at or after the oldest raw row. With + /// no raw rows left the floor is NULL and the cutoff alone decides. + /// + /// The floor is a parameter, measured once (review of #5706, #1815). The first form was a + /// (SELECT min(collection_time) FROM collect.procedure_stats) inside the predicate, which the slice statement expands three + /// times: three unbounded scans of the whole raw table per DELETE, and on compressed chunks (no btree) the probe that timed out in + /// the field for the digest floor. reads it once before the DELETE. /// - public const string PrunePredicate = - "collection_time < COALESCE((SELECT min(collection_time) FROM collect.procedure_stats), $1)"; + public const string PrunePredicate = "collection_time < COALESCE($2::timestamp, $1)"; + + /// + /// The oldest instant collect.procedure_stats can still hold a row at, the $2 of ; NULL when + /// the table is empty. On a hypertable it is the earliest chunk's range_start from the chunk catalog (one metadata row, immune + /// to compression, as the digest floor of #1815 reads it); every surviving row sits at or after its chunk's start, so the floor is + /// never later than the true minimum and can only keep more totals, never delete too many. On a plain table, or a hypertable with no + /// chunks, it is one min(collection_time), which the table's time index answers at its edge. + /// + public static async Task MeasureRawFloorAsync( + NpgsqlConnection connection, + bool timescaleAvailable, + int commandTimeoutSeconds, + CancellationToken cancellationToken) + { + ArgumentNullException.ThrowIfNull(connection); + + if (timescaleAvailable) + { + /* AT TIME ZONE 'UTC' collapses the catalog's timestamptz to the naive-UTC discipline every stored timestamp follows. */ + await using var chunkProbe = new NpgsqlCommand( + "SELECT range_start AT TIME ZONE 'UTC' FROM timescaledb_information.chunks " + + "WHERE hypertable_schema = 'collect' AND hypertable_name = 'procedure_stats' " + + "ORDER BY range_start LIMIT 1", connection) + { CommandTimeout = commandTimeoutSeconds }; + if (await chunkProbe.ExecuteScalarAsync(cancellationToken) is DateTime chunkFloor) + { + return chunkFloor; + } + } + + await using var probe = new NpgsqlCommand("SELECT min(collection_time) FROM collect.procedure_stats", connection) + { CommandTimeout = commandTimeoutSeconds }; + return await probe.ExecuteScalarAsync(cancellationToken) as DateTime?; + } } diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs index 39b1074f41..1ac04118f2 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs @@ -7,6 +7,8 @@ */ using System; +using System.Collections.Generic; +using System.Linq; using System.Threading; using System.Threading.Tasks; using Npgsql; @@ -34,8 +36,11 @@ public static class ProcedureStatsTotalsWriter { /// /// Upserts the totals of the collection stamped for on the COPY's - /// transaction (). A of 0 or less writes nothing and costs - /// no round trip. Returns the totals rows the statement wrote (one per database in the collection). + /// transaction (), after totalling any collection a pre-V176 binary left above the + /// server's floor (). A of 0 or less writes nothing and + /// costs no round trip. are the databases the batch wrote (null entries are the NULL database); the + /// read-back is limited to them, and a null collection reads the whole collection. Returns the totals rows the upsert wrote (one per + /// database in the batch), not counting gap rows. /// public static async Task UpsertBatchAsync( NpgsqlConnection connection, @@ -44,6 +49,7 @@ public static async Task UpsertBatchAsync( DateTime collectionTime, int rowsWritten, int commandTimeoutSeconds, + IReadOnlyCollection? databaseNames, CancellationToken cancellationToken) { ArgumentNullException.ThrowIfNull(connection); @@ -54,11 +60,26 @@ public static async Task UpsertBatchAsync( return 0; } + /* Naive-UTC storage: Npgsql 6+ rejects Kind=Utc against `timestamp` - see PgCollectorRowWriter. */ + var stamp = DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified); + + /* The gap first: a collection an older binary wrote between the server's newest totals row and this batch. Normally an + empty index-range probe. Not limited to the batch's databases: those collections belong to nobody's batch. */ + await using (var gap = new NpgsqlCommand(ProcedureStatsTotals.GapFillSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }) + { + gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); + await gap.ExecuteNonQueryAsync(cancellationToken); + } + await using var command = new NpgsqlCommand(ProcedureStatsTotals.UpsertSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }; command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); - /* Naive-UTC storage: Npgsql 6+ rejects Kind=Utc against `timestamp` - see PgCollectorRowWriter. */ - command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified) }); + /* $3: the non-NULL names (NULL array = no limit); $4: whether the batch holds the NULL database. */ + var names = databaseNames?.Where(static name => name is not null).Distinct(StringComparer.Ordinal).ToArray(); + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Array | NpgsqlDbType.Text, Value = names is null ? DBNull.Value : names }); + command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Boolean, Value = databaseNames?.Any(static name => name is null) ?? false }); return await command.ExecuteNonQueryAsync(cancellationToken); } } From ff0bd67d35f3fc05698badd3d083c9044508ff27 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 17:55:27 -0400 Subject: [PATCH 5/7] Darling: the procedure totals gap fill runs behind a savepoint and a server-side statement_timeout and can never fail the batch; the read-back limit matches any row collection (seat review of #5706, part of #5638) --- .../ProcedureStatsTotalsTests.cs | 69 ++++++ .../ProcedureStatsTotalsWriterLiveTests.cs | 227 ++++++++++++++++++ .../DarlingCollectorRunner.cs | 21 +- .../ProcedureStatsTotalsWriter.cs | 139 +++++++++-- 4 files changed, 430 insertions(+), 26 deletions(-) diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs index f8c1da0c12..d1b8695736 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs @@ -7,7 +7,9 @@ */ using System; +using System.Collections.Generic; using System.Linq; +using PerformanceMonitor.Collectors; using PerformanceMonitor.Darling.Service; using PerformanceMonitor.Darling.Service.Mcp; using PerformanceMonitor.Darling.Storage; @@ -138,6 +140,73 @@ public void TheRunner_WritesTheTotalsOnTheCopysTransaction_AfterTheCopy_BeforeTh } } + /// + /// The read-back limit's type check (seat review of #5706). Every write goes through CopyBatchOnceAsync<TRow>(... List<TRow> rows ...) + /// and the catalog's only procedure_stats definition is a CollectorDefinitionBase<Row>, so the server, Azure + /// per-database and import paths all hand the writer a List<Row>; the helper accepts any IEnumerable<Row>. + /// + [Fact] + public void TheReadBackLimit_MatchesEveryRowCollectionShape_AndEveryProcedureStatsPathCarriesRows() + { + var rows = new List { Named("A"), Named("B"), Named("A"), Named(null!) }; + var expected = new string?[] { "A", "B", null }; + + Assert.Equal(expected, ProcedureStatsTotalsWriter.DatabaseNamesOf(rows)); + Assert.Equal(expected, ProcedureStatsTotalsWriter.DatabaseNamesOf(rows.ToArray())); + Assert.Equal(expected, ProcedureStatsTotalsWriter.DatabaseNamesOf(rows.AsEnumerable())); + Assert.Equal(expected, ProcedureStatsTotalsWriter.DatabaseNamesOf(new System.Collections.ObjectModel.ReadOnlyCollection(rows))); + Assert.Empty(ProcedureStatsTotalsWriter.DatabaseNamesOf(new List())!); + + /* Rows of another type (or none) read the whole collection. */ + Assert.Null(ProcedureStatsTotalsWriter.DatabaseNamesOf(new List { "A" })); + Assert.Null(ProcedureStatsTotalsWriter.DatabaseNamesOf(null)); + + /* The call-site trace: one writer call, fed by the helper, from the one generic COPY whose rows are a List... */ + var runner = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "DarlingCollectorRunner.cs")); + var start = runner.IndexOf("private async Task CopyBatchOnceAsync(", StringComparison.Ordinal); + Assert.True(start > 0); + var signature = runner[start..(start + 400)]; + Assert.Contains("List rows,", signature, StringComparison.Ordinal); + Assert.Contains("ProcedureStatsTotalsWriter.DatabaseNamesOf(rows)", runner[start..], StringComparison.Ordinal); + Assert.DoesNotContain("procedureRows", runner[start..], StringComparison.Ordinal); + Assert.Single(System.Text.RegularExpressions.Regex.Matches(runner, "ProcedureStatsTotalsWriter\\.UpsertBatchAsync\\(")); + + /* ...and every catalog definition that writes procedure_stats carries Row (so TRow = Row on every path that totals). */ + var writers = PerformanceMonitor.Collectors.CollectorCatalog.All + .Where(c => string.Equals(c.TargetTable, ProcedureStatsCollector.Instance.TargetTable, StringComparison.OrdinalIgnoreCase)) + .ToList(); + Assert.NotEmpty(writers); + Assert.All(writers, c => Assert.IsAssignableFrom>(c)); + } + + private static ProcedureStatsCollector.Row Named(string database) => new( + database, "dbo", "p", "P ", null, null, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, null, null, null, null); + + /// + /// The gap fill runs behind a savepoint and a server-side statement_timeout, restores the timeout on success, and rolls back to the + /// savepoint on a fault; the runner's call site stays free of any catch (the batch's own upsert is still fatal to it). + /// + [Fact] + public void TheGapFill_RunsBehindASavepointAndAServerSideTimeout_AndNeverFailsTheBatch() + { + var writer = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Storage", "ProcedureStatsTotalsWriter.cs")); + var gap = writer[writer.IndexOf("private static async Task TryGapFillAsync(", StringComparison.Ordinal)..]; + + var save = gap.IndexOf("transaction.SaveAsync(GapSavepointName", StringComparison.Ordinal); + var setTimeout = gap.IndexOf("SetStatementTimeoutAsync(", StringComparison.Ordinal); + var run = gap.IndexOf("ProcedureStatsTotals.GapFillSql", StringComparison.Ordinal); + var restore = gap.IndexOf("SetStatementTimeoutAsync(connection, transaction, previousTimeout", StringComparison.Ordinal); + var release = gap.IndexOf("transaction.ReleaseAsync(GapSavepointName", StringComparison.Ordinal); + var rollback = gap.IndexOf("transaction.RollbackAsync(GapSavepointName", StringComparison.Ordinal); + Assert.True(save > 0 && setTimeout > save && run > setTimeout && restore > run && release > restore && rollback > release, "save, bound, run, restore, release, then the rollback arm"); + Assert.Contains("catch (Exception ex) when (!cancellationToken.IsCancellationRequested)", gap, StringComparison.Ordinal); + Assert.Contains("set_config('statement_timeout', $1, true)", gap, StringComparison.Ordinal); + + /* The gap fill is the only statement behind the savepoint: the batch's own upsert stays outside it. */ + var upsert = writer.IndexOf("ProcedureStatsTotals.UpsertSql", StringComparison.Ordinal); + Assert.True(upsert > 0 && upsert < writer.IndexOf("private static async Task TryGapFillAsync(", StringComparison.Ordinal)); + } + [Fact] public void Retention_PurgesTheTotals_AtProcedureStatsDays_NeverBeforeTheRawRows() { diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs index 62e73d75c5..56011a99c1 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs @@ -555,4 +555,231 @@ public async Task OnTimescaleDb_WithACompressedOldestChunk_TheFloorComesFromTheC await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); } } + + /* ---- the gap fill never fails the batch (seat review of #5706) ---- */ + + private sealed class CapturingLogger : Microsoft.Extensions.Logging.ILogger + { + public List<(Microsoft.Extensions.Logging.LogLevel Level, string Message)> Entries { get; } = new(); + + public IDisposable? BeginScope(TState state) where TState : notnull => null; + + public bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) => true; + + public void Log(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, TState state, Exception? exception, Func formatter) => + Entries.Add((logLevel, formatter(state, exception))); + } + + /// + /// Plants the gap a rollback to a pre-V176 binary leaves: a collection at with raw rows (database + /// ) and no totals row, above an anchor collection at that has both. + /// + private static async Task PlantGapAsync(Rig rig, int serverId, DateTime anchorAt, DateTime gapAt, string gapDatabase, CancellationToken ct, DateTime? batchAt = null) + { + Assert.Equal(1, await rig.WriteAsync(anchorAt, new List { Row("Anchor", "p0", 10, 1, 60) }, ct)); + if (batchAt is not null) + { + /* The batch's own raw row, for a direct UpsertBatchAsync call to total; written before the gap row so the product's own gap fill finds nothing. */ + Assert.Equal(1, await rig.WriteAsync(batchAt.Value, new List { Row("DbA", "p2", 5, 1, 60) }, ct)); + } + + Assert.Equal(1, await rig.WriteAsync(gapAt, new List { Row(gapDatabase, "p1", 100, 2, 60) }, ct)); + var where = "server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time IN (" + Stamp(gapAt) + (batchAt is null ? "" : ", " + Stamp(batchAt.Value)) + ")"; + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE " + where, ct); + } + + private static async Task TotalsRowsAsync(Rig rig, int serverId, DateTime at, CancellationToken ct) => + Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time = " + Stamp(at), ct)); + + private static async Task RawRowsAsync(Rig rig, int serverId, DateTime at, CancellationToken ct) => + Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats WHERE server_id = " + serverId.ToString(CultureInfo.InvariantCulture) + " AND collection_time = " + Stamp(at), ct)); + + private static async Task ScalarTxAsync(NpgsqlConnection connection, NpgsqlTransaction transaction, string sql, CancellationToken ct) + { + await using var command = new NpgsqlCommand(sql, connection, transaction); + return await command.ExecuteScalarAsync(ct); + } + + /// + /// The normal gap: a collection with rows and no totals above the server's newest totals row is totalled by the next batch, a + /// healthy gap fill logs nothing, and its statement_timeout does not outlive it (the batch's own upsert and the rest of the + /// transaction run under the connection's original setting). The batch after it has an empty gap and takes the normal path. + /// + [Fact] + public async Task TheGapFill_TotalsARealGap_LogsNothing_AndRestoresTheStatementTimeout() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945310; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsGapOk", ct); + + var bodySucceeded = false; + try + { + var gapAt = T0.AddMinutes(1); + var batchAt = T0.AddMinutes(2); + await PlantGapAsync(rig, serverId, T0, gapAt, "GapDb", ct, batchAt); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + + var logger = new CapturingLogger(); + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + var before = (string)(await ScalarTxAsync(rig.Connection, tx, "SHOW statement_timeout", ct))!; + Assert.Equal(1, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, batchAt, 1, 30, null, ct, logger, "ProcTotalsGapOk")); + Assert.Equal(before, (string)(await ScalarTxAsync(rig.Connection, tx, "SHOW statement_timeout", ct))!); + await tx.CommitAsync(ct); + } + + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, gapAt, ct); + Assert.Equal(raw, totals); + Assert.Empty(logger.Entries); + + /* The next batch's gap (after the batch above, before this one) is empty: the normal path, through the product's write path. */ + Assert.Equal(1, await rig.WriteAsync(T0.AddMinutes(3), new List { Row("DbA", "p2", 5, 1, 60) }, ct)); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, T0.AddMinutes(3), ct)); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// A gap fill that FAILS (a trigger refusing the gap database's totals row stands in for the fault) does not fail the batch + /// (seat review of #5706): through the product's own write path the batch's rows and its own totals commit, the failure is skipped, + /// and because the batch's totals row is now the server's newest the NEXT batch does not retry the gap, even once the fault clears. + /// Before the fix the first batch threw, rolled back, and every later batch found the same anchor and threw again. + /// + [Fact] + public async Task AFailedGapFill_DoesNotFailTheBatch_AndTheNextBatchDoesNotRetryIt() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945311; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsGapFail", ct); + + var bodySucceeded = false; + try + { + var gapAt = T0.AddMinutes(1); + await PlantGapAsync(rig, serverId, T0, gapAt, "gapfail", ct); + + /* Only the gap database's totals row is refused; the batch's own database is not. */ + await ExecAsync(rig.Connection, "CREATE FUNCTION public.refuse_gap() RETURNS trigger LANGUAGE plpgsql AS $$ BEGIN IF NEW.database_name = 'gapfail' THEN RAISE EXCEPTION 'planted gap failure'; END IF; RETURN NEW; END $$", ct); + await ExecAsync(rig.Connection, "CREATE TRIGGER refuse_gap BEFORE INSERT OR UPDATE ON collect.procedure_stats_totals FOR EACH ROW EXECUTE FUNCTION public.refuse_gap()", ct); + + var batchAt = T0.AddMinutes(2); + Assert.Equal(1, await rig.WriteAsync(batchAt, new List { Row("DbA", "p2", 5, 1, 60) }, ct)); + + /* The batch committed: its rows and its own totals are stored; the gap was skipped. */ + Assert.Equal(1L, await RawRowsAsync(rig, serverId, batchAt, ct)); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, batchAt, ct)); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, batchAt, ct); + Assert.Equal(raw, totals); + + /* The fault clears; the next batch's anchor is the batch above, so the gap (an older collection) is not attempted again. */ + await ExecAsync(rig.Connection, "DROP TRIGGER refuse_gap ON collect.procedure_stats_totals", ct); + var nextAt = T0.AddMinutes(3); + Assert.Equal(1, await rig.WriteAsync(nextAt, new List { Row("DbA", "p2", 7, 1, 60) }, ct)); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, nextAt, ct)); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// A gap fill that exceeds its server-side bound (a trigger sleeping on the gap database's totals row, under a 300 ms + /// statement_timeout) is cancelled by the server, not by Npgsql's client timer, so the connection stays usable: the + /// transaction rolls back to the savepoint, the batch's own upsert runs under the connection's ORIGINAL timeout, a warning names + /// the server and the gap's range, and the commit lands. + /// + [Fact] + public async Task AGapFillThatTimesOut_IsCancelledByTheServer_LogsTheRange_AndTheBatchStillCommits() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945312; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsGapSlow", ct); + + var bodySucceeded = false; + try + { + var gapAt = T0.AddMinutes(1); + var batchAt = T0.AddMinutes(2); + await PlantGapAsync(rig, serverId, T0, gapAt, "gapslow", ct, batchAt); + await ExecAsync(rig.Connection, "CREATE FUNCTION public.slow_gap() RETURNS trigger LANGUAGE plpgsql AS $$ BEGIN IF NEW.database_name = 'gapslow' THEN PERFORM pg_sleep(30); END IF; RETURN NEW; END $$", ct); + await ExecAsync(rig.Connection, "CREATE TRIGGER slow_gap BEFORE INSERT OR UPDATE ON collect.procedure_stats_totals FOR EACH ROW EXECUTE FUNCTION public.slow_gap()", ct); + + var logger = new CapturingLogger(); + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + var before = (string)(await ScalarTxAsync(rig.Connection, tx, "SHOW statement_timeout", ct))!; + Assert.Equal(1, await ProcedureStatsTotalsWriter.UpsertBatchAsync( + rig.Connection, tx, serverId, batchAt, 1, 30, null, ct, logger, "ProcTotalsGapSlow", gapStatementTimeoutMilliseconds: 300)); + + /* Rolled back to the savepoint, so the SET LOCAL is gone and the connection answers inside the same transaction. */ + Assert.Equal(before, (string)(await ScalarTxAsync(rig.Connection, tx, "SHOW statement_timeout", ct))!); + await tx.CommitAsync(ct); + } + + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, batchAt, ct)); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + var warning = Assert.Single(logger.Entries); + Assert.Equal(Microsoft.Extensions.Logging.LogLevel.Warning, warning.Level); + Assert.Contains("ProcTotalsGapSlow", warning.Message, StringComparison.Ordinal); + Assert.Contains(T0.ToString("yyyy-MM-dd'T'HH:mm:ss", CultureInfo.InvariantCulture), warning.Message, StringComparison.Ordinal); + Assert.Contains(batchAt.ToString("yyyy-MM-dd'T'HH:mm:ss", CultureInfo.InvariantCulture), warning.Message, StringComparison.Ordinal); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// The read-back limit reaches the writer on the product's own path (seat review of #5706): the runner's List<TRow> + /// with TRow = Row arrives as the typed collection, so a second batch at the same collection_time that holds only DbA does not + /// recompute the first batch's DbB totals row (a null collection would read the whole collection and recreate it). + /// + [Fact] + public async Task TheReadBackLimit_ReachesTheWriter_OnTheRunnersOwnPath() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945313; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsLimit", ct); + + var bodySucceeded = false; + try + { + var at = T0.AddMinutes(5); + Assert.Equal(2, await rig.WriteAsync(at, new List { Row("DbA", "p1", 100, 1, 60), Row("DbB", "p1", 200, 2, 60) }, ct)); + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE database_name = 'DbB'", ct); + Assert.Equal(1, await rig.WriteAsync(at, new List { Row("DbA", "p2", 300, 3, 60) }, ct)); + + Assert.Equal(0L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE database_name = 'DbB'", ct))); + Assert.Equal(1L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals WHERE database_name = 'DbA'", ct))); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } } diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs index 763495d939..1566f5dbe6 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs @@ -4683,21 +4683,24 @@ await QueryStatsHourLedgerWriter.AddBatchAsync( /* #5638: the collection's per-database totals, read back from the rows the store now holds for this collection_time and upserted, on THIS transaction after the COPY and before the commit, so rows and totals - commit together or not at all. No savepoint and no catch, like the ledger above: a fault throws out of the - batch, the transaction rolls back and the rows are not stored, because rows the totals never saw would make a - read of the totals disagree with the rows. Recomputed, never added, so a second batch at this collection_time or - a re-attempt is exact. A batch of 0 rows writes nothing: the read keeps its collection_log axis for an idle run. */ + commit together or not at all. No savepoint and no catch HERE, like the ledger above: a fault in the upsert + throws out of the batch, the transaction rolls back and the rows are not stored, because rows the totals never + saw would make a read of the totals disagree with the rows. The one exception is inside the writer: the gap + fill of collections an older binary left behind runs behind its own savepoint and statement_timeout, and its + failure is logged and skipped, so it can never stop a server's collection. Recomputed, never added, so a + second batch at this collection_time or a re-attempt is exact. A batch of 0 rows writes nothing: the read + keeps its collection_log axis for an idle run. */ if (totalsBatch) { await ProcedureStatsTotalsWriter.UpsertBatchAsync( pgConnection, transaction, server.ServerId, storedCollectionTime, rowsWritten, ServiceCommandDeadlines.CollectionSweepSeconds, /* The databases THIS batch holds (one per batch on Azure SQL Database): the read-back is limited to them. Null - (rows of another type, an import) reads the whole collection. */ - (object)rows is List procedureRows - ? procedureRows.Select(static row => (string?)row.DatabaseName).Distinct().ToList() - : null, - cancellationToken); + (rows of another type, an import) reads the whole collection. DatabaseNamesOf matches any + IEnumerable. */ + ProcedureStatsTotalsWriter.DatabaseNamesOf(rows), + cancellationToken, + _logger, server.StorageName); } /* #3953: after the COPY and the dimension flush, in the unstamped region (#3095): a fault here is not diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs index 1ac04118f2..9d4d4a8ec3 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs @@ -8,11 +8,14 @@ using System; using System.Collections.Generic; +using System.Globalization; using System.Linq; using System.Threading; using System.Threading.Tasks; +using Microsoft.Extensions.Logging; using Npgsql; using NpgsqlTypes; +using PerformanceMonitor.Collectors; namespace PerformanceMonitor.Darling.Storage; @@ -21,11 +24,20 @@ namespace PerformanceMonitor.Darling.Storage; /// up to date after a collect.procedure_stats batch. The caller is /// DarlingCollectorRunner.CopyBatchOnceAsync, the only code that writes collect.procedure_stats. /// -/// Atomic with the COPY, and fatal to it. runs on the COPY's own transaction, after the COPY -/// and the dimension flush and before the commit, with no savepoint and no catch (the hour ledger's shape, #4605): a fault throws out of -/// the batch, the transaction rolls back and the batch's raw rows are not stored. Rows and totals therefore commit together or not at all, -/// and the read can trust a totals row to equal its collection's rows. The cost of a fault is the batch's sample, which -/// StoreWriteReattempt declines to re-run because the delta baselines have moved. +/// Atomic with the COPY, and fatal to it. runs the batch's own upsert on the COPY's own +/// transaction, after the COPY and the dimension flush and before the commit, with no savepoint and no catch (the hour ledger's shape, +/// #4605): a fault throws out of the batch, the transaction rolls back and the batch's raw rows are not stored. Rows and totals +/// therefore commit together or not at all, and the read can trust a totals row to equal its collection's rows. The cost of a fault is +/// the batch's sample, which StoreWriteReattempt declines to re-run because the delta baselines have moved. +/// +/// The gap fill is the exception: it can never fail the batch (seat review of #5706). It totals every collection a +/// pre-V176 binary wrote after the server's newest totals row, which after a rollback that ran for days can be millions of rows. If it +/// failed the batch, the next batch would see the same anchor and the same gap and fail again, and procedure_stats collection would +/// stop for that server for good. So it runs behind a savepoint (the #3953 shape), under a server-side statement_timeout (half +/// the command timeout, so the server cancels first and Npgsql's client-side cancel, which can break the connection, never fires). A +/// fault rolls back to the savepoint, logs a warning naming the server and the gap range, and lets the batch's own upsert run. The +/// batch commits, its own totals row becomes the new anchor and the gap is attempted exactly once; those collections stay out of the +/// trend, as before the fix. /// /// Exact when a collection spans batches. The statement recomputes from the rows the store holds for the collection /// (those of earlier committed batches and this batch's, visible on this transaction), so it never adds, and a second batch at the @@ -34,12 +46,30 @@ namespace PerformanceMonitor.Darling.Storage; /// public static class ProcedureStatsTotalsWriter { + /// The savepoint the gap fill runs behind. + internal const string GapSavepointName = "pst_gap"; + + /// + /// The databases a procedure_stats batch holds, for the read-back limit ('s + /// databaseNames): one entry per distinct database, null for the NULL database. Matches any + /// of , so the runner's List<TRow> with + /// TRow = Row qualifies on the server, Azure per-database and import paths alike. Anything else returns null, and a null + /// collection reads the whole collection (correct, but unbounded). + /// + public static IReadOnlyCollection? DatabaseNamesOf(object? rows) => + rows is IEnumerable typed + ? typed.Select(static row => (string?)row.DatabaseName).Distinct().ToList() + : null; + /// /// Upserts the totals of the collection stamped for on the COPY's - /// transaction (), after totalling any collection a pre-V176 binary left above the - /// server's floor (). A of 0 or less writes nothing and + /// transaction (), after trying to total any collection a pre-V176 binary left above the + /// server's floor (, behind a savepoint: its failure is logged to + /// and never fails the batch). A of 0 or less writes nothing and /// costs no round trip. are the databases the batch wrote (null entries are the NULL database); the - /// read-back is limited to them, and a null collection reads the whole collection. Returns the totals rows the upsert wrote (one per + /// read-back is limited to them, and a null collection reads the whole collection. + /// is the gap fill's server-side bound (default: half of + /// , at least a second); tests shrink it. Returns the totals rows the upsert wrote (one per /// database in the batch), not counting gap rows. /// public static async Task UpsertBatchAsync( @@ -50,7 +80,10 @@ public static async Task UpsertBatchAsync( int rowsWritten, int commandTimeoutSeconds, IReadOnlyCollection? databaseNames, - CancellationToken cancellationToken) + CancellationToken cancellationToken, + ILogger? logger = null, + string? serverName = null, + int? gapStatementTimeoutMilliseconds = null) { ArgumentNullException.ThrowIfNull(connection); ArgumentNullException.ThrowIfNull(transaction); @@ -63,14 +96,10 @@ public static async Task UpsertBatchAsync( /* Naive-UTC storage: Npgsql 6+ rejects Kind=Utc against `timestamp` - see PgCollectorRowWriter. */ var stamp = DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified); - /* The gap first: a collection an older binary wrote between the server's newest totals row and this batch. Normally an - empty index-range probe. Not limited to the batch's databases: those collections belong to nobody's batch. */ - await using (var gap = new NpgsqlCommand(ProcedureStatsTotals.GapFillSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }) - { - gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); - gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); - await gap.ExecuteNonQueryAsync(cancellationToken); - } + await TryGapFillAsync( + connection, transaction, serverId, stamp, commandTimeoutSeconds, + gapStatementTimeoutMilliseconds ?? Math.Max(1000, commandTimeoutSeconds * 500), + logger, serverName, cancellationToken); await using var command = new NpgsqlCommand(ProcedureStatsTotals.UpsertSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }; command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); @@ -82,4 +111,80 @@ public static async Task UpsertBatchAsync( command.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Boolean, Value = databaseNames?.Any(static name => name is null) ?? false }); return await command.ExecuteNonQueryAsync(cancellationToken); } + + /// + /// The gap first: a collection an older binary wrote between the server's newest totals row and this batch. Normally an empty + /// index-range probe. Not limited to the batch's databases: those collections belong to nobody's batch. Behind + /// and a server-side statement_timeout that is restored on success (a SET LOCAL + /// would otherwise outlive the savepoint and bound the batch's own upsert). A fault, a timeout included, rolls back to the + /// savepoint (which also undoes the SET LOCAL) and is logged; only the caller's cancellation escapes. + /// + private static async Task TryGapFillAsync( + NpgsqlConnection connection, + NpgsqlTransaction transaction, + int serverId, + DateTime stamp, + int commandTimeoutSeconds, + int statementTimeoutMilliseconds, + ILogger? logger, + string? serverName, + CancellationToken cancellationToken) + { + DateTime? anchor = null; + await transaction.SaveAsync(GapSavepointName, cancellationToken); + try + { + /* The previous timeout (to restore) and the gap's start (for the log line), in one round trip. */ + string previousTimeout; + await using (var read = new NpgsqlCommand( + "SELECT current_setting('statement_timeout'), (SELECT max(p.collection_time) FROM collect.procedure_stats_totals AS p WHERE p.server_id = $1 AND p.collection_time < $2)", + connection, transaction) { CommandTimeout = commandTimeoutSeconds }) + { + read.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + read.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); + await using var reader = await read.ExecuteReaderAsync(cancellationToken); + await reader.ReadAsync(cancellationToken); + previousTimeout = reader.GetString(0); + anchor = reader.IsDBNull(1) ? null : reader.GetDateTime(1); + } + + await SetStatementTimeoutAsync( + connection, transaction, statementTimeoutMilliseconds.ToString(CultureInfo.InvariantCulture) + "ms", commandTimeoutSeconds, cancellationToken); + + /* The client's own deadline stays at the full command timeout, above the server's bound, so the server cancels first. */ + await using (var gap = new NpgsqlCommand(ProcedureStatsTotals.GapFillSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }) + { + gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); + await gap.ExecuteNonQueryAsync(cancellationToken); + } + + await SetStatementTimeoutAsync(connection, transaction, previousTimeout, commandTimeoutSeconds, cancellationToken); + await transaction.ReleaseAsync(GapSavepointName, cancellationToken); + } + catch (Exception ex) when (!cancellationToken.IsCancellationRequested) + { + /* The transaction is aborted until this runs; it also undoes the SET LOCAL above. */ + await transaction.RollbackAsync(GapSavepointName, cancellationToken); + await transaction.ReleaseAsync(GapSavepointName, cancellationToken); + + logger?.LogWarning( + ex, + "Procedure totals gap fill (#5638) failed for server {ServerName} ({ServerId}): the collections after {GapAfter:o} and before {GapBefore:o} " + + "were not totalled, so they stay out of the duration trend (as before the fix). The batch continues and its own totals row becomes the new anchor; the gap is not retried.", + serverName, serverId, anchor, stamp); + } + } + + private static async Task SetStatementTimeoutAsync( + NpgsqlConnection connection, + NpgsqlTransaction transaction, + string value, + int commandTimeoutSeconds, + CancellationToken cancellationToken) + { + await using var set = new NpgsqlCommand("SELECT set_config('statement_timeout', $1, true)", connection, transaction) { CommandTimeout = commandTimeoutSeconds }; + set.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Text, Value = value }); + await set.ExecuteScalarAsync(cancellationToken); + } } From 131858d0dee67953e77f2142dbe66e3eb0010105 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 19:08:01 -0400 Subject: [PATCH 6/7] Darling: review round 2 of #5706 - the gap anchor takes the batch's own time, an empty gap costs one probe, the anchor is a bound parameter, the plain floor is an index probe per server and runs after the budget gate; V176 compose-stamp probe pin (part of #5638) --- .../ProcedureStatsTotalsTests.cs | 47 ++- .../ProcedureStatsTotalsWriterLiveTests.cs | 384 +++++++++++++++++- .../ProcedureTrendTotalsStitchLiveTests.cs | 1 + .../QueryStoreComposeStampTests.cs | 9 +- .../DarlingRetention.cs | 55 ++- .../ProcedureStatsTotals.cs | 114 +++++- .../ProcedureStatsTotalsWriter.cs | 58 ++- 7 files changed, 582 insertions(+), 86 deletions(-) diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs index d1b8695736..750e9a6263 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs @@ -32,7 +32,10 @@ public void TheGapFill_TotalsTheCollectionsBetweenTheNewestEarlierTotalsAndTheBa { var sql = Normalize(ProcedureStatsTotals.GapFillSql); - Assert.Contains("FROM collect.procedure_stats AS s\nWHERE s.server_id = $1::integer\nAND s.collection_time < $2::timestamp\nAND s.collection_time >\n(\n SELECT max(p.collection_time)\n FROM collect.procedure_stats_totals AS p\n WHERE p.server_id = $1::integer\n AND p.collection_time < $2::timestamp\n)", sql, StringComparison.Ordinal); + Assert.Contains("FROM collect.procedure_stats AS s\nWHERE s.server_id = $1::integer\nAND s.collection_time < $2::timestamp\nAND s.collection_time > $3::timestamp\nGROUP BY", sql, StringComparison.Ordinal); + + /* Round 2 (L2): the anchor is a bound parameter, so chunk exclusion sees both bounds; no subquery recomputes it. */ + Assert.DoesNotContain("SELECT max(", sql, StringComparison.Ordinal); Assert.Contains("ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET", sql, StringComparison.Ordinal); Assert.DoesNotContain("t.row_count +", sql, StringComparison.Ordinal); } @@ -49,10 +52,28 @@ public void ThePrunePredicate_TakesTheFloorAsAParameter_AndNeverScansProcedureSt Assert.DoesNotContain("FROM collect.procedure_stats ", delete, StringComparison.Ordinal); var retention = Normalize(RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "DarlingRetention.cs")); - var floor = retention.IndexOf("ProcedureStatsTotals.MeasureRawFloorAsync(", StringComparison.Ordinal); - var purge = retention.IndexOf("TimeSlicedDeleteSql(ProcedureStatsTotals.Table", StringComparison.Ordinal); - Assert.True(floor > 0 && purge > floor, "the floor is measured once, before the DELETE that binds it"); - Assert.Contains("secondParameter: new NpgsqlParameter", retention, StringComparison.Ordinal); + Assert.Contains("secondParameterFactory: async (floorConnection, ct) =>", retention, StringComparison.Ordinal); + Assert.Single(System.Text.RegularExpressions.Regex.Matches(retention, "ProcedureStatsTotals\\.MeasureRawFloorAsync\\(")); + + /* Round 2 (L4): the floor is measured inside PurgeOneAsync, after its wall-budget gate and on the purge's own connection. */ + var purgeOne = retention[retention.IndexOf("private static async Task PurgeOneAsync(", StringComparison.Ordinal)..]; + var gate = purgeOne.IndexOf("SkipTableOnBudget(tableName)", StringComparison.Ordinal); + var open = purgeOne.IndexOf("postgres.OpenConnectionAsync(", StringComparison.Ordinal); + var factory = purgeOne.IndexOf("await secondParameterFactory(connection, cancellationToken)", StringComparison.Ordinal); + Assert.True(gate > 0 && open > gate && factory > open, "the budget gate, then the connection, then the floor measured on it"); + } + + /// Round 2 (L3): the plain-store floor is one server-leading index probe per server with totals, never a global min(). + [Fact] + public void ThePlainFloor_IsAnIndexProbePerServerWithTotals_NotAGlobalMin() + { + var sql = Normalize(ProcedureStatsTotals.PlainRawFloorSql); + + Assert.Contains("CROSS JOIN LATERAL", sql, StringComparison.Ordinal); + Assert.Contains("WHERE p.server_id = servers.server_id\n ORDER BY p.collection_time\n LIMIT 1", sql, StringComparison.Ordinal); + Assert.Contains("FROM collect.procedure_stats_totals AS t", sql, StringComparison.Ordinal); + Assert.DoesNotContain("min(collection_time)", sql, StringComparison.Ordinal); + Assert.Contains("min(oldest.collection_time)", sql, StringComparison.Ordinal); } [Fact] @@ -200,7 +221,21 @@ public void TheGapFill_RunsBehindASavepointAndAServerSideTimeout_AndNeverFailsTh var rollback = gap.IndexOf("transaction.RollbackAsync(GapSavepointName", StringComparison.Ordinal); Assert.True(save > 0 && setTimeout > save && run > setTimeout && restore > run && release > restore && rollback > release, "save, bound, run, restore, release, then the rollback arm"); Assert.Contains("catch (Exception ex) when (!cancellationToken.IsCancellationRequested)", gap, StringComparison.Ordinal); - Assert.Contains("set_config('statement_timeout', $1, true)", gap, StringComparison.Ordinal); + Assert.Contains("set_config('statement_timeout', $1, true)", writer, StringComparison.Ordinal); + + /* Round 2 (L1): the anchor and the gap test are ONE statement that runs before the savepoint; with no anchor or no gap the + method returns before the savepoint, the timeout change and the gap statement, so the normal batch pays that one statement. */ + var probe = gap.IndexOf("ProcedureStatsTotals.GapProbeSql", StringComparison.Ordinal); + var early = gap.IndexOf("if (reader.IsDBNull(1) || !reader.GetBoolean(2))", StringComparison.Ordinal); + Assert.True(probe > 0 && early > probe && save > early, "probe, then the early return, then the savepoint"); + Assert.Single(System.Text.RegularExpressions.Regex.Matches(gap, "ExecuteReaderAsync")); + var probeSql = Normalize(ProcedureStatsTotals.GapProbeSql); + Assert.Contains("current_setting('statement_timeout')", probeSql, StringComparison.Ordinal); + Assert.Contains("p.collection_time <= $2::timestamp", probeSql, StringComparison.Ordinal); + Assert.DoesNotContain("p.collection_time < $2", probeSql, StringComparison.Ordinal); + Assert.Contains("s.collection_time > a.anchor", probeSql, StringComparison.Ordinal); + Assert.Contains("s.collection_time < $2::timestamp", probeSql, StringComparison.Ordinal); + Assert.Contains("EXISTS", probeSql, StringComparison.Ordinal); /* The gap fill is the only statement behind the savepoint: the batch's own upsert stays outside it. */ var upsert = writer.IndexOf("ProcedureStatsTotals.UpsertSql", StringComparison.Ordinal); diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs index 56011a99c1..bb844b319e 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsWriterLiveTests.cs @@ -9,6 +9,7 @@ using System; using System.Collections.Generic; using System.Globalization; +using System.Linq; using System.Reflection; using System.Threading; using System.Threading.Tasks; @@ -92,21 +93,33 @@ background jobs stopped so no policy compresses or drops a chunk under the test. }; } + /// Another monitored server on the same store, for the tests that need several servers' rows. + public ServerRuntime OtherServer(int serverId, string serverName) => new() + { + Config = new MonitoredServer { Name = serverName, Host = serverName }, + ConnectionString = "Server=" + serverName, + Target = Server.Target, + StorageName = serverName, + ServerId = serverId, + EngineEdition = 3, + }; + /// One batch through the product's WriteBatchAsync; a fault surfaces as the store's own exception. - public async Task WriteAsync(DateTime collectionTime, List rows, CancellationToken ct) + public async Task WriteAsync(DateTime collectionTime, List rows, CancellationToken ct, ServerRuntime? server = null) { + var target = server ?? Server; var context = new CollectorContext { - ServerId = Server.ServerId, - ServerName = Server.StorageName, + ServerId = target.ServerId, + ServerName = target.StorageName, CollectionTime = collectionTime, Deltas = Deltas, - Target = Server.Target, + Target = target.Target, }; var task = (Task)WriteBatchMethod.MakeGenericMethod(typeof(ProcedureStatsCollector.Row)).Invoke( Runner, - new object?[] { Connection, ProcedureStatsCollector.Instance, rows, Server, collectionTime, context, ct })!; + new object?[] { Connection, ProcedureStatsCollector.Instance, rows, target, collectionTime, context, ct })!; await task; return (int)task.GetType().GetProperty("Result")!.GetValue(task)!; } @@ -530,6 +543,31 @@ public async Task OnTimescaleDb_WithACompressedOldestChunk_TheFloorComesFromTheC Assert.True(floor <= T0, "the chunk floor is never later than the oldest raw row"); Assert.True(floor < T0, "the floor is the chunk's start, not the row's own time: it came from the catalog, not from min(collection_time)"); + /* Round 2 (L2): the gap statement binds its anchor, so both bounds are constants at plan time and only the chunks inside + (anchor, batch) are scanned: the compressed oldest chunk (and the newest one) are excluded, no DecompressChunk appears. */ + var gapAnchor = T0.AddDays(9); + var gapBatch = T0.AddDays(11); + var inRange = new List(); + var outOfRange = new List(); + await using (var chunks = new NpgsqlCommand( + "SELECT chunk_name, (range_start AT TIME ZONE 'UTC' < " + Stamp(gapBatch) + " AND range_end AT TIME ZONE 'UTC' > " + Stamp(gapAnchor) + ") " + + "FROM timescaledb_information.chunks WHERE hypertable_schema = 'collect' AND hypertable_name = 'procedure_stats'", rig.Connection)) + await using (var chunkReader = await chunks.ExecuteReaderAsync(ct)) + { + while (await chunkReader.ReadAsync(ct)) + { + (chunkReader.GetBoolean(1) ? inRange : outOfRange).Add(chunkReader.GetString(0)); + } + } + + Assert.Equal(2, outOfRange.Count); + Assert.Single(inRange); + var gapPlan = await ExplainAsync(rig.Connection, "EXPLAIN " + ProcedureStatsTotals.GapFillSql, ct, + (NpgsqlTypes.NpgsqlDbType.Integer, serverId), (NpgsqlTypes.NpgsqlDbType.Timestamp, gapBatch), (NpgsqlTypes.NpgsqlDbType.Timestamp, gapAnchor)); + Assert.Contains(inRange[0], gapPlan, StringComparison.Ordinal); + Assert.All(outOfRange, name => Assert.DoesNotContain(name, gapPlan, StringComparison.Ordinal)); + Assert.DoesNotContain("DecompressChunk", gapPlan, StringComparison.Ordinal); + /* A cutoff far past every collection while the raw chunk is still held: nothing at or after the floor may go. */ Assert.Equal(0, await RetentionDeleteAsync(rig.Connection, true, T0.AddDays(100), ct)); Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct))); @@ -782,4 +820,340 @@ public async Task TheReadBackLimit_ReachesTheWriter_OnTheRunnersOwnPath() await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); } } + + /* ---- round 2 of the review of #5706 ---- */ + + /// + /// M1: on Azure SQL Database every per-database batch of one cycle shares one collection_time. A gap fill that fails in + /// batch 1 must not be retried by batch 2 (same time, another database): the anchor takes the totals row batch 1 committed AT that + /// time. A trigger that bumps a sequence counts the gap statement's attempts (a sequence survives the savepoint rollback, a + /// counter table would not). A batch that rolled back leaves no anchor, so its re-attempt does try the gap again. + /// + [Fact] + public async Task TwoBatchesAtOneCollectionTime_TryAFailingGapOnce_AndTheSecondTakesTheNormalPath() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945314; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsGapCycle", ct); + + var bodySucceeded = false; + try + { + var gapAt = T0.AddMinutes(1); + var batchAt = T0.AddMinutes(2); + await PlantGapAsync(rig, serverId, T0, gapAt, "gapfail", ct, batchAt); + + await ExecAsync(rig.Connection, "CREATE SEQUENCE public.gap_attempts", ct); + await ExecAsync(rig.Connection, "CREATE FUNCTION public.refuse_gap() RETURNS trigger LANGUAGE plpgsql AS $$ BEGIN IF NEW.database_name = 'gapfail' THEN PERFORM nextval('public.gap_attempts'); RAISE EXCEPTION 'planted gap failure'; END IF; RETURN NEW; END $$", ct); + await ExecAsync(rig.Connection, "CREATE TRIGGER refuse_gap BEFORE INSERT OR UPDATE ON collect.procedure_stats_totals FOR EACH ROW EXECUTE FUNCTION public.refuse_gap()", ct); + + async Task AttemptsAsync() => + Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT CASE WHEN is_called THEN last_value ELSE 0 END FROM public.gap_attempts", ct)); + + var dbA = new List { "DbA" }; + + /* A batch that rolls back leaves no totals row at the batch's time, so it has no anchor there: the gap is tried (attempt 1). */ + var rolledBack = new CapturingLogger(); + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + Assert.Equal(1, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, batchAt, 1, 30, dbA, ct, rolledBack, "ProcTotalsGapCycle")); + await tx.RollbackAsync(ct); + } + + Assert.Equal(1L, await AttemptsAsync()); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, batchAt, ct)); + + /* Batch 1 of the cycle (DbA at T) commits: the gap is tried again (attempt 2), fails once, and DbA's totals row lands. */ + var logger = new CapturingLogger(); + await using (var tx = await rig.Connection.BeginTransactionAsync(ct)) + { + Assert.Equal(1, await ProcedureStatsTotalsWriter.UpsertBatchAsync(rig.Connection, tx, serverId, batchAt, 1, 30, dbA, ct, logger, "ProcTotalsGapCycle")); + await tx.CommitAsync(ct); + } + + Assert.Equal(2L, await AttemptsAsync()); + var warning = Assert.Single(logger.Entries); + Assert.Equal(Microsoft.Extensions.Logging.LogLevel.Warning, warning.Level); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, batchAt, ct)); + + /* Batch 2 of the same cycle (DbB, the same T), through the product's write path: the anchor is batch 1's row at T, the range + (T, T) is empty, and the gap statement does not run (no third attempt). Its own totals are exact. */ + Assert.Equal(1, await rig.WriteAsync(batchAt, new List { Row("DbB", "p3", 7, 1, 60) }, ct)); + Assert.Equal(2L, await AttemptsAsync()); + Assert.Equal(2L, await TotalsRowsAsync(rig, serverId, batchAt, ct)); + var (totals, raw) = await CompareAsync(rig.Connection, serverId, batchAt, ct); + Assert.Equal(raw, totals); + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, gapAt, ct)); + + /* The next cycle's batch finds T as its anchor too: still no further attempt. */ + Assert.Equal(1, await rig.WriteAsync(T0.AddMinutes(3), new List { Row("DbA", "p2", 9, 1, 60) }, ct)); + Assert.Equal(2L, await AttemptsAsync()); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// L1: a batch whose gap is empty pays the one probe statement and nothing else: no SAVEPOINT, no set_config and no gap + /// statement reach the server. Counted through pg_stat_statements (skipped on a rig that does not preload it), once for + /// a server whose first batch has no anchor and once for a later batch with an anchor and an empty range. + /// + [Fact] + public async Task AnEmptyGap_CostsOneProbeStatement_NoSavepointNoTimeoutNoGapStatement() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945315; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsProbe", ct); + + var bodySucceeded = false; + try + { + var preload = (string)(await ScalarAsync(rig.Connection, "SELECT current_setting('shared_preload_libraries')", ct))!; + Assert.SkipWhen(!preload.Split(',').Select(static part => part.Trim()).Contains("pg_stat_statements"), + "pg_stat_statements is not in shared_preload_libraries ('" + preload + "'): this rig must preload it to count the statements."); + await ExecAsync(rig.Connection, "CREATE EXTENSION IF NOT EXISTS pg_stat_statements", ct); + + async Task CallsAsync(string like) => + Convert.ToInt64(await ScalarAsync(rig.Connection, + "SELECT COALESCE(SUM(calls), 0)::bigint FROM pg_stat_statements WHERE dbid = (SELECT oid FROM pg_database WHERE datname = current_database()) AND query LIKE '" + like + "'", ct)); + + await ExecAsync(rig.Connection, "SELECT pg_stat_statements_reset(0, (SELECT oid FROM pg_database WHERE datname = current_database()), 0)", ct); + + /* The server's first batch (no totals row, so no anchor) and a second one (an anchor, an empty range between it and the batch). */ + Assert.Equal(1, await rig.WriteAsync(T0, new List { Row("DbA", "p1", 10, 1, 60) }, ct)); + Assert.Equal(1, await rig.WriteAsync(T0.AddMinutes(1), new List { Row("DbA", "p1", 11, 1, 60) }, ct)); + + Assert.Equal(2L, await CallsAsync("%a.anchor IS NOT NULL%")); + Assert.Equal(0L, await CallsAsync("%pst_gap%")); + Assert.Equal(0L, await CallsAsync("%set_config(%")); + Assert.Equal(0L, await CallsAsync("%s.collection_time > $3%")); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + private static async Task ExplainAsync(NpgsqlConnection connection, string sql, CancellationToken ct, params (NpgsqlTypes.NpgsqlDbType Type, object Value)[] parameters) + { + var plan = new System.Text.StringBuilder(); + await using var explain = new NpgsqlCommand(sql, connection); + foreach (var (type, value) in parameters) + { + explain.Parameters.AddWithValue(type, value); + } + + await using var reader = await explain.ExecuteReaderAsync(ct); + while (await reader.ReadAsync(ct)) + { + plan.AppendLine(reader.GetString(0)); + } + + return plan.ToString(); + } + + /// + /// L3: the plain-store floor is one server-leading index probe per server that has totals, never a scan of the table or the index, + /// and it leaves out a server without totals (which has nothing to protect). Three servers with totals plus one with older raw rows + /// and no totals; the plan reads idx_procedure_stats_time with server_id = servers.server_id three times. + /// + [Fact] + public async Task ThePlainFloor_IsAnIndexProbePerServerWithTotals_AndIgnoresAServerWithoutTotals() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945316; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsFloorA", ct); + + var bodySucceeded = false; + try + { + var a = rig.Server; + var b = rig.OtherServer(serverId - 1, "ProcTotalsFloorB"); + var c = rig.OtherServer(serverId - 2, "ProcTotalsFloorC"); + var d = rig.OtherServer(serverId - 3, "ProcTotalsFloorD"); + await rig.WriteAsync(T0.AddDays(3), new List { Row("DbA", "p1", 10, 1, 60) }, ct, a); + await rig.WriteAsync(T0.AddDays(2), new List { Row("DbA", "p1", 10, 1, 60) }, ct, b); + await rig.WriteAsync(T0.AddDays(4), new List { Row("DbA", "p1", 10, 1, 60) }, ct, c); + await rig.WriteAsync(T0, new List { Row("DbA", "p1", 10, 1, 60) }, ct, d); + await ExecAsync(rig.Connection, "DELETE FROM collect.procedure_stats_totals WHERE server_id = " + d.ServerId.ToString(CultureInfo.InvariantCulture), ct); + + /* Server D (older raw rows, no totals) does not move the floor; the oldest raw row of a server WITH totals is B's, day 2. */ + Assert.Equal(T0.AddDays(2), await ProcedureStatsTotals.MeasureRawFloorAsync(rig.Connection, false, 60, ct)); + + await ExecAsync(rig.Connection, "SET enable_seqscan = off", ct); + var plan = await ExplainAsync(rig.Connection, "EXPLAIN (ANALYZE, BUFFERS) " + ProcedureStatsTotals.PlainRawFloorSql, ct); + await ExecAsync(rig.Connection, "RESET enable_seqscan", ct); + + Assert.Matches("Index (Only )?Scan using idx_procedure_stats_time on procedure_stats p", plan); + Assert.Contains("Index Cond: (server_id = servers.server_id)", plan, StringComparison.Ordinal); + Assert.Contains("loops=3", plan, StringComparison.Ordinal); + Assert.DoesNotContain("Seq Scan on procedure_stats p", plan, StringComparison.Ordinal); + Assert.DoesNotContain("Seq Scan on procedure_stats ", plan, StringComparison.Ordinal); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// The live clock (#5608): whole seconds and naive, the discipline stored timestamps follow, so an equality lookup by Stamp finds it. Every offset below is whole days with days of margin, so the real clock the sweep reads cannot move a verdict. + private static DateTime NowToTheSecond() => LiveClock.Now(); + + private static async Task<(long Totals, DateTime? Oldest)> TotalsAsync(NpgsqlConnection connection, CancellationToken ct) + { + var count = Convert.ToInt64(await ScalarAsync(connection, "SELECT count(*) FROM collect.procedure_stats_totals", ct)); + var oldest = await ScalarAsync(connection, "SELECT min(collection_time) FROM collect.procedure_stats_totals", ct) as DateTime?; + return (count, oldest); + } + + /// + /// L5, plain store: the REAL retention sweep (DarlingRetention.PurgeAsync, not a copy of its DELETE) ages the totals out with + /// the raw rows: the two collections past the horizon go, the recent one stays. A floor that never reached the command (the + /// $2 unbound) would fail the table and leave all three. + /// + [Fact] + public async Task TheRealRetentionSweep_OnAPlainStore_PurgesExpiredTotals_AndKeepsTheRecentOnes() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945317; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsPurgePlain", ct); + + var bodySucceeded = false; + try + { + var now = NowToTheSecond(); + foreach (var age in new[] { 60, 45, 1 }) + { + Assert.Equal(1, await rig.WriteAsync(now.AddDays(-age), new List { Row("DbA", "p1", 10 + age, 1, 60) }, ct)); + } + + Assert.Equal(3L, (await TotalsAsync(rig.Connection, ct)).Totals); + + var logger = new CapturingLogger(); + await DarlingRetention.PurgeAsync(rig.DataSource, false, logger, ct, retentionDaysFor: static _ => 40); + + var (count, oldest) = await TotalsAsync(rig.Connection, ct); + Assert.Equal(1L, count); + Assert.True(oldest > now.AddDays(-2), "only the recent collection's totals row is left"); + Assert.DoesNotContain(logger.Entries, static entry => entry.Message.Contains("procedure_stats_totals", StringComparison.Ordinal)); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// L5, TimescaleDB store: the real sweep never drops the raw chunks of procedure_stats (the gated purge owns them), so it + /// holds every raw row and the floor is the oldest chunk's start: no totals row at or after it may go, though all three are older + /// than the horizon. Once the gated purge has dropped the oldest chunk, the next real sweep purges the totals older than the + /// new floor and keeps the rest. Without the floor bound as $2 the first sweep would delete the old totals. + /// + [Fact] + public async Task TheRealRetentionSweep_OnTimescaleDb_KeepsTotalsAtOrAfterTheHeldRawChunks() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945318; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsPurgeTsdb", ct, timescale: true); + + var bodySucceeded = false; + try + { + var now = NowToTheSecond(); + foreach (var age in new[] { 60, 45, 1 }) + { + Assert.Equal(1, await rig.WriteAsync(now.AddDays(-age), new List { Row("DbA", "p1", 10 + age, 1, 60) }, ct)); + } + + var logger = new CapturingLogger(); + await DarlingRetention.PurgeAsync(rig.DataSource, true, logger, ct, retentionDaysFor: static _ => 40); + + /* Raw is held, so nothing at or after the oldest chunk's start may go: all three totals rows are older than the 40-day horizon. */ + Assert.Equal(3L, (await TotalsAsync(rig.Connection, ct)).Totals); + Assert.Equal(3L, Convert.ToInt64(await ScalarAsync(rig.Connection, "SELECT count(*) FROM collect.procedure_stats", ct))); + + /* The gated raw purge drops the 60-day chunk; the floor moves to the 45-day chunk's start. */ + await ExecAsync(rig.Connection, "SELECT drop_chunks('collect.procedure_stats', older_than => " + Stamp(now.AddDays(-50)) + ")", ct); + await DarlingRetention.PurgeAsync(rig.DataSource, true, logger, ct, retentionDaysFor: static _ => 40); + + Assert.Equal(0L, await TotalsRowsAsync(rig, serverId, now.AddDays(-60), ct)); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, now.AddDays(-45), ct)); + Assert.Equal(1L, await TotalsRowsAsync(rig, serverId, now.AddDays(-1), ct)); + Assert.DoesNotContain(logger.Entries, static entry => entry.Message.Contains("procedure_stats_totals", StringComparison.Ordinal)); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } + + /// + /// L5, the branch that skips the purge when the floor cannot be measured: with procedure_stats unreadable (renamed away) the + /// floor probe throws, the real sweep leaves the totals untouched, counts the table failed (a warning names it) and carries on; the + /// next sweep, with the table back, catches up. + /// + [Fact] + public async Task WhenTheFloorCannotBeMeasured_TheSweepSkipsTheTotalsPurge_CountsItFailed_AndCatchesUpNextSweep() + { + Assert.SkipWhen(string.IsNullOrEmpty(BaseConnectionString), SkipReason); + var ct = TestContext.Current.CancellationToken; + const int serverId = -945319; + + await using var rig = await Rig.OpenAsync(serverId, "ProcTotalsPurgeFail", ct); + + var bodySucceeded = false; + try + { + var now = NowToTheSecond(); + foreach (var age in new[] { 60, 45, 1 }) + { + Assert.Equal(1, await rig.WriteAsync(now.AddDays(-age), new List { Row("DbA", "p1", 10 + age, 1, 60) }, ct)); + } + + await ExecAsync(rig.Connection, "ALTER TABLE collect.procedure_stats RENAME TO procedure_stats_hidden", ct); + + var logger = new CapturingLogger(); + await DarlingRetention.PurgeAsync(rig.DataSource, false, logger, ct, retentionDaysFor: static _ => 40); + + Assert.Equal(3L, (await TotalsAsync(rig.Connection, ct)).Totals); + Assert.Contains(logger.Entries, static entry => + entry.Level == Microsoft.Extensions.Logging.LogLevel.Warning + && entry.Message.Contains("Retention purge failed for collect.procedure_stats_totals", StringComparison.Ordinal)); + + await ExecAsync(rig.Connection, "ALTER TABLE collect.procedure_stats_hidden RENAME TO procedure_stats", ct); + await DarlingRetention.PurgeAsync(rig.DataSource, false, new CapturingLogger(), ct, retentionDaysFor: static _ => 40); + + var (count, oldest) = await TotalsAsync(rig.Connection, ct); + Assert.Equal(1L, count); + Assert.True(oldest > now.AddDays(-2)); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(rig.Scratch.ConnectionString, bodySucceeded, static (_, _) => Task.CompletedTask); + } + } } diff --git a/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs index 8d878daba9..9864463e8c 100644 --- a/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs +++ b/Darling/Darling.Tests/ProcedureTrendTotalsStitchLiveTests.cs @@ -607,6 +607,7 @@ procedure_stats heap beyond an index range. Functional only (no timing claimed). { explain.Parameters.AddWithValue(NpgsqlDbType.Integer, serverId); explain.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(2)); + explain.Parameters.AddWithValue(NpgsqlDbType.Timestamp, At(0)); await using var reader = await explain.ExecuteReaderAsync(ct); while (await reader.ReadAsync(ct)) { diff --git a/Darling/Darling.Tests/QueryStoreComposeStampTests.cs b/Darling/Darling.Tests/QueryStoreComposeStampTests.cs index 886971d4b5..1a7cd93596 100644 --- a/Darling/Darling.Tests/QueryStoreComposeStampTests.cs +++ b/Darling/Darling.Tests/QueryStoreComposeStampTests.cs @@ -430,16 +430,17 @@ public void TheProbe_HasThisRungsSentinelAndMapsItsArmToV173() var viewer = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Viewer", "ViewerDataService.cs"); Assert.Contains($"reader.GetBoolean({ProbeOrdinal})", viewer, StringComparison.Ordinal); - /* V174's (#5655) and V175's (#5631) sentinels sit above this one; the probe's last ordinal is the newest rung's. */ + /* V174's (#5655), V175's (#5631) and V176's (#5638) sentinels sit above this one; the probe's last ordinal is the newest rung's. */ Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 1})", viewer, StringComparison.Ordinal); Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 2})", viewer, StringComparison.Ordinal); - Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 3})", viewer, StringComparison.Ordinal); + Assert.Contains($"reader.GetBoolean({ProbeOrdinal + 3})", viewer, StringComparison.Ordinal); + Assert.DoesNotContain($"reader.GetBoolean({ProbeOrdinal + 4})", viewer, StringComparison.Ordinal); Assert.Equal(StorageVersion.SchemaVersion, ViewerDataService.RequiredStoreSchemaVersion); var method = typeof(ViewerDataService).GetMethod("MapProbedSchemaVersion", BindingFlags.NonPublic | BindingFlags.Static)!; var arity = method.GetParameters().Length; - Assert.Equal(ProbeOrdinal + 2, arity - 1); + Assert.Equal(ProbeOrdinal + 3, arity - 1); Assert.Equal("hasQueryStoreComposeStamp", method.GetParameters()[ProbeOrdinal].Name); var all = Enumerable.Repeat((object)true, arity).ToArray(); @@ -449,12 +450,14 @@ public void TheProbe_HasThisRungsSentinelAndMapsItsArmToV173() behind[ProbeOrdinal] = false; behind[ProbeOrdinal + 1] = false; behind[ProbeOrdinal + 2] = false; + behind[ProbeOrdinal + 3] = false; Assert.Equal(172, (int)method.Invoke(null, behind)!); /* Everything through V173's sentinel true and the newer one false maps to V173 itself. */ var atThisRung = (object[])all.Clone(); atThisRung[ProbeOrdinal + 1] = false; atThisRung[ProbeOrdinal + 2] = false; + atThisRung[ProbeOrdinal + 3] = false; Assert.Equal(QueryStoreComposeStamp.RungVersion, (int)method.Invoke(null, atThisRung)!); var arm = viewer.IndexOf("if (hasQueryStoreComposeStamp)", StringComparison.Ordinal); diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs index cf0486a07d..9bddd0ce1d 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs @@ -1015,33 +1015,24 @@ and a row is never purged before the procedure_stats rows of its age (ProcedureS "procedure_stats", retentionDaysFor?.Invoke("procedure_stats") ?? (CollectorScheduleDefaults.All.TryGetValue("procedure_stats", out var procedureSchedule) ? procedureSchedule.RetentionDays : DataRetentionBaseDays)); - /* The raw floor is measured ONCE here and bound as $2 (review of #5706, #1815): the predicate used to carry an unbounded - min() over procedure_stats that the slice statement expands three times, a whole-table scan each, and the chunk-catalog - form is how the digest floor above survives compressed chunks. A floor that cannot be measured skips this table's - purge for the cycle (counted failed): without the floor the guard against deleting totals the raw trend still reads - is unknown, and the totals only age out a sweep later. */ - DateTime? procedureRawFloor = null; - var procedureRawFloorMeasured = false; - try - { - await using var floorConnection = await postgres.OpenConnectionAsync(cancellationToken); - procedureRawFloor = await ProcedureStatsTotals.MeasureRawFloorAsync( - floorConnection, timescaleAvailable, DeleteTimeoutSeconds, cancellationToken); - procedureRawFloorMeasured = true; - } - catch (Exception ex) when (ex is not OperationCanceledException) - { - logger?.LogWarning("Retention purge: could not measure procedure_stats' floor for the totals purge: {Message}", ex.Message); - } - - var procedureTotalsDeleted = procedureRawFloorMeasured - ? await PurgeOneAsync( - postgres, ProcedureStatsTotals.Table, - TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate), - utcNow.AddDays(-procedureTotalsDays), logger, cancellationToken, - pacer: walPacer, - secondParameter: new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = procedureRawFloor is { } floorValue ? floorValue : DBNull.Value }) - : null; + /* The raw floor is measured ONCE, by PurgeOneAsync itself, and bound as $2 (review of #5706, #1815): the predicate used to + carry an unbounded min() over procedure_stats that the slice statement expands three times, a whole-table scan each, and + the chunk-catalog form is how the digest floor above survives compressed chunks. The measurement is a callback that runs + on the purge's own connection AFTER PurgeOneAsync's #5592 wall-budget gate (round 2, L4), so a pass whose budget is spent + opens no connection and runs no probe for this table. A floor that cannot be measured throws out of the callback, so the + table counts failed and its purge is skipped for the cycle: without the floor the guard against deleting totals the raw + trend still reads is unknown, and the totals only age out a sweep later. */ + var procedureTotalsDeleted = await PurgeOneAsync( + postgres, ProcedureStatsTotals.Table, + TimeSlicedDeleteSql(ProcedureStatsTotals.Table, "collection_time", ProcedureStatsTotals.PrunePredicate), + utcNow.AddDays(-procedureTotalsDays), logger, cancellationToken, + pacer: walPacer, + secondParameterFactory: async (floorConnection, ct) => + { + var procedureRawFloor = await ProcedureStatsTotals.MeasureRawFloorAsync( + floorConnection, timescaleAvailable, DeleteTimeoutSeconds, ct); + return new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = procedureRawFloor is { } floorValue ? floorValue : DBNull.Value }; + }); if (procedureTotalsDeleted is not null) { tablesPurged++; @@ -1852,6 +1843,10 @@ avoidable work on a path that already runs per table per day. */ /// COMMAND-TIMEOUT batch at half its cap instead of failing the table outright — the field failure this /// exists for was one 50k-row batch passing the 300 s command timeout under first-start load, on a /// store whose steady-state margin was ~2x rather than the cap's designed 5x. + /// + /// (the unsliced shape only) builds the statement's $2 from the purge's own + /// connection once the #5592 budget gate has passed, so a measurement the second parameter needs (the procedure totals' raw + /// floor) is never taken for a table the pass will not start. A throw out of it fails the table like any other fault. /// private static async Task PurgeOneAsync( NpgsqlDataSource postgres, @@ -1863,7 +1858,7 @@ avoidable work on a path that already runs per table per day. */ int batchSize = 1, string? adaptiveRowCapTimeColumn = null, RetentionWalPacer? pacer = null, - NpgsqlParameter? secondParameter = null) + Func>? secondParameterFactory = null) { /* #5592: a pass whose wall budget is already spent starts no further table: no connection, no statement. Every table's purge comes through here, so this is the one place that skips them. Nothing was deleted, @@ -1920,9 +1915,9 @@ reach the cap and the one execution is terminal. */ { using var command = new NpgsqlCommand(deleteSql, connection) { CommandTimeout = DeleteTimeoutSeconds }; command.Parameters.AddWithValue(cutoff); - if (secondParameter is not null) + if (secondParameterFactory is not null) { - command.Parameters.Add(secondParameter); + command.Parameters.Add(await secondParameterFactory(connection, cancellationToken)); } drained = await DrainBatchesAsync( diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs index e619b618ce..03577b4e25 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs @@ -112,14 +112,49 @@ ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET """; /// - /// Totals the collections a pre-V176 binary wrote after the floor (review of #5706): $1 is the server id and $2 the - /// batch's collection_time. PgMigrations lets an older binary write to a V176 store (a rollback), and the raw - /// trend reads procedure_stats only below the server's floor, so a collection that has rows, no totals and sits above the - /// floor would vanish from the trend. This totals every collection of the server that has rows strictly after the server's newest - /// totals row before the batch and strictly before the batch. A server with no totals row has nothing to total (its floor is - /// infinity and the raw arm reads it). Normally the range is empty and the statement is two index probes: a backward scan of the - /// totals key for the newest earlier row, then a range scan of procedure_stats (server_id, collection_time) from it that - /// finds no row. Same upsert target and recompute as , so it is idempotent and exact. + /// The gap probe, run on the COPY's transaction before anything else of the gap fill (round 2 review of #5706, L1): $1 is + /// the server id and $2 the batch's collection_time. One row: the connection's current statement_timeout + /// (to restore), the anchor (the server's newest totals row at or before the batch, NULL when it has none), and whether a gap + /// exists (a procedure_stats row of the server strictly after the anchor and strictly before the batch). An EXISTS + /// on the (server_id, collection_time) index stops at its first row, so it cannot be the "big gap" failure the savepoint + /// guards against, and the normal batch pays this one statement and nothing else: no savepoint, no timeout change, no gap + /// statement. The anchor is <= $2 (round 2, M1): on Azure SQL Database every per-database batch of a cycle + /// shares one collection_time, so a batch whose gap fill failed has still committed a totals row at that time, and the + /// next batch of the cycle must see it as its anchor (its range is then empty) instead of trying the same gap again. A + /// re-attempt of a batch that rolled back has no committed totals at that time, so it still tries the gap. + /// + public const string GapProbeSql = """ +SELECT + current_setting('statement_timeout'), + a.anchor, + a.anchor IS NOT NULL + AND EXISTS + ( + SELECT 1 + FROM collect.procedure_stats AS s + WHERE s.server_id = $1::integer + AND s.collection_time > a.anchor + AND s.collection_time < $2::timestamp + ) +FROM +( + SELECT max(p.collection_time) AS anchor + FROM collect.procedure_stats_totals AS p + WHERE p.server_id = $1::integer + AND p.collection_time <= $2::timestamp +) AS a; +"""; + + /// + /// Totals the collections a pre-V176 binary wrote after the floor (review of #5706): $1 is the server id, $2 the + /// batch's collection_time and $3 the anchor read. PgMigrations lets an older + /// binary write to a V176 store (a rollback), and the raw trend reads procedure_stats only below the server's floor, so a + /// collection that has rows, no totals and sits above the floor would vanish from the trend. This totals every collection of the + /// server that has rows strictly after the anchor and strictly before the batch. The writer runs it only when the probe found + /// such a row, so it is never the normal path. The anchor is a parameter, not a subquery (round 2, L2): both bounds are + /// then constants at plan time, which lets TimescaleDB exclude every chunk outside (anchor, batch), compressed ones + /// included, instead of keeping each chunk older than the batch. Same upsert target and recompute as , so + /// it is idempotent and exact. /// public const string GapFillSql = """ INSERT INTO collect.procedure_stats_totals AS t @@ -135,13 +170,7 @@ INSERT INTO collect.procedure_stats_totals AS t FROM collect.procedure_stats AS s WHERE s.server_id = $1::integer AND s.collection_time < $2::timestamp -AND s.collection_time > -( - SELECT max(p.collection_time) - FROM collect.procedure_stats_totals AS p - WHERE p.server_id = $1::integer - AND p.collection_time < $2::timestamp -) +AND s.collection_time > $3::timestamp GROUP BY s.server_id, s.collection_time, s.database_name ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET total_elapsed_time = EXCLUDED.total_elapsed_time, @@ -164,12 +193,57 @@ ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET /// public const string PrunePredicate = "collection_time < COALESCE($2::timestamp, $1)"; + /// + /// The plain-store floor (round 2 review of #5706, L3): the oldest procedure_stats row of any server that has totals rows, + /// as the minimum over those servers of each server's own ORDER BY collection_time LIMIT 1. The table's time index is + /// (server_id, collection_time), so a global min(collection_time) cannot read an index edge: nothing leads with + /// collection_time but two partial indexes, and the planner scans the whole table or index once per sweep. Each server's + /// own probe is one descent of the server-leading index. The servers come from a loose index scan of the totals key (the + /// recursive step is one index descent per server), so the statement is an index probe per server and never a scan. A server + /// without totals rows is left out on purpose: it has no totals to protect, and the trend stitch takes its floor per server. The + /// minimum across servers is never later than any one server's own floor, so the guard can only keep more totals. + /// + public const string PlainRawFloorSql = """ +WITH RECURSIVE servers AS +( + ( + SELECT t.server_id + FROM collect.procedure_stats_totals AS t + ORDER BY t.server_id + LIMIT 1 + ) + UNION ALL + SELECT + ( + SELECT t.server_id + FROM collect.procedure_stats_totals AS t + WHERE t.server_id > servers.server_id + ORDER BY t.server_id + LIMIT 1 + ) + FROM servers + WHERE servers.server_id IS NOT NULL +) +SELECT min(oldest.collection_time) +FROM servers +CROSS JOIN LATERAL +( + SELECT p.collection_time + FROM collect.procedure_stats AS p + WHERE p.server_id = servers.server_id + ORDER BY p.collection_time + LIMIT 1 +) AS oldest +WHERE servers.server_id IS NOT NULL; +"""; + /// /// The oldest instant collect.procedure_stats can still hold a row at, the $2 of ; NULL when - /// the table is empty. On a hypertable it is the earliest chunk's range_start from the chunk catalog (one metadata row, immune - /// to compression, as the digest floor of #1815 reads it); every surviving row sits at or after its chunk's start, so the floor is - /// never later than the true minimum and can only keep more totals, never delete too many. On a plain table, or a hypertable with no - /// chunks, it is one min(collection_time), which the table's time index answers at its edge. + /// the table holds no row of a server that has totals. On a hypertable it is the earliest chunk's range_start from the chunk + /// catalog (one metadata row, immune to compression, as the digest floor of #1815 reads it); every surviving row sits at or after + /// its chunk's start, so the floor is never later than the true minimum and can only keep more totals, never delete too many. On a + /// plain table, or a hypertable with no chunks, it is : one index probe per server with totals, not + /// a scan. /// public static async Task MeasureRawFloorAsync( NpgsqlConnection connection, @@ -193,7 +267,7 @@ ON CONFLICT (server_id, collection_time, database_name) DO UPDATE SET } } - await using var probe = new NpgsqlCommand("SELECT min(collection_time) FROM collect.procedure_stats", connection) + await using var probe = new NpgsqlCommand(PlainRawFloorSql, connection) { CommandTimeout = commandTimeoutSeconds }; return await probe.ExecuteScalarAsync(cancellationToken) as DateTime?; } diff --git a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs index 9d4d4a8ec3..fdc4b768e7 100644 --- a/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs +++ b/Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs @@ -36,8 +36,15 @@ namespace PerformanceMonitor.Darling.Storage; /// stop for that server for good. So it runs behind a savepoint (the #3953 shape), under a server-side statement_timeout (half /// the command timeout, so the server cancels first and Npgsql's client-side cancel, which can break the connection, never fires). A /// fault rolls back to the savepoint, logs a warning naming the server and the gap range, and lets the batch's own upsert run. The -/// batch commits, its own totals row becomes the new anchor and the gap is attempted exactly once; those collections stay out of the -/// trend, as before the fix. +/// batch commits and its own totals row becomes the new anchor, and the anchor takes rows AT the batch's time too +/// (), so no later batch of the same cycle (Azure writes one per database at one +/// collection_time) and no later cycle tries that gap again: a gap is attempted once per committed batch, never once per +/// batch of a cycle. A batch that rolls back leaves no anchor and so retries. Those collections stay out of the trend, as before +/// the fix. +/// +/// The normal batch pays one extra statement (round 2, L1). reads the +/// anchor and probes for a gap in one round trip; the savepoint, the timeout change and the gap statement run only when a gap +/// exists. The probe is bounded by the index, so it can fail the batch only as the batch's own upsert can. /// /// Exact when a collection spans batches. The statement recomputes from the rows the store holds for the collection /// (those of earlier committed batches and this batch's, visible on this transaction), so it never adds, and a second batch at the @@ -113,11 +120,12 @@ await TryGapFillAsync( } /// - /// The gap first: a collection an older binary wrote between the server's newest totals row and this batch. Normally an empty - /// index-range probe. Not limited to the batch's databases: those collections belong to nobody's batch. Behind - /// and a server-side statement_timeout that is restored on success (a SET LOCAL - /// would otherwise outlive the savepoint and bound the batch's own upsert). A fault, a timeout included, rolls back to the - /// savepoint (which also undoes the SET LOCAL) and is logged; only the caller's cancellation escapes. + /// The gap first: a collection an older binary wrote between the server's newest totals row (at or before this batch's time) + /// and this batch. One probe statement reads the anchor and whether a gap exists (); + /// normally there is none and nothing else runs. Not limited to the batch's databases: those collections belong to nobody's batch. + /// A gap runs behind and a server-side statement_timeout that is restored on success (a + /// SET LOCAL would otherwise outlive the savepoint and bound the batch's own upsert). A fault, a timeout included, rolls + /// back to the savepoint (which also undoes the SET LOCAL) and is logged; only the caller's cancellation escapes. /// private static async Task TryGapFillAsync( NpgsqlConnection connection, @@ -130,24 +138,28 @@ private static async Task TryGapFillAsync( string? serverName, CancellationToken cancellationToken) { - DateTime? anchor = null; - await transaction.SaveAsync(GapSavepointName, cancellationToken); - try + string previousTimeout; + DateTime anchor; + await using (var probe = new NpgsqlCommand(ProcedureStatsTotals.GapProbeSql, connection, transaction) { CommandTimeout = commandTimeoutSeconds }) { - /* The previous timeout (to restore) and the gap's start (for the log line), in one round trip. */ - string previousTimeout; - await using (var read = new NpgsqlCommand( - "SELECT current_setting('statement_timeout'), (SELECT max(p.collection_time) FROM collect.procedure_stats_totals AS p WHERE p.server_id = $1 AND p.collection_time < $2)", - connection, transaction) { CommandTimeout = commandTimeoutSeconds }) + probe.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); + probe.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); + await using var reader = await probe.ExecuteReaderAsync(cancellationToken); + await reader.ReadAsync(cancellationToken); + previousTimeout = reader.GetString(0); + + /* No totals row yet (a server's first batch) or no gap after the anchor: the normal path, nothing more to run. */ + if (reader.IsDBNull(1) || !reader.GetBoolean(2)) { - read.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); - read.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); - await using var reader = await read.ExecuteReaderAsync(cancellationToken); - await reader.ReadAsync(cancellationToken); - previousTimeout = reader.GetString(0); - anchor = reader.IsDBNull(1) ? null : reader.GetDateTime(1); + return; } + anchor = reader.GetDateTime(1); + } + + await transaction.SaveAsync(GapSavepointName, cancellationToken); + try + { await SetStatementTimeoutAsync( connection, transaction, statementTimeoutMilliseconds.ToString(CultureInfo.InvariantCulture) + "ms", commandTimeoutSeconds, cancellationToken); @@ -156,6 +168,7 @@ await SetStatementTimeoutAsync( { gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Integer, Value = serverId }); gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = stamp }); + gap.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Timestamp, Value = anchor }); await gap.ExecuteNonQueryAsync(cancellationToken); } @@ -171,7 +184,8 @@ await SetStatementTimeoutAsync( logger?.LogWarning( ex, "Procedure totals gap fill (#5638) failed for server {ServerName} ({ServerId}): the collections after {GapAfter:o} and before {GapBefore:o} " + - "were not totalled, so they stay out of the duration trend (as before the fix). The batch continues and its own totals row becomes the new anchor; the gap is not retried.", + "were not totalled, so they stay out of the duration trend (as before the fix). The batch continues and its own totals row becomes the new anchor; " + + "once this batch commits the gap is not retried, by a later batch of this cycle or of any other.", serverName, serverId, anchor, stamp); } } From 061989f800585234099bf9d1582aa3ad974f9e59 Mon Sep 17 00:00:00 2001 From: Erik Darling <2136037+erikdarlingdata@users.noreply.github.com> Date: Mon, 12 Oct 2026 19:53:25 -0400 Subject: [PATCH 7/7] Darling: the one-writer pin for collect.procedure_stats scans every Darling source file, not two named files (review of #5706, part of #5638) --- .../ProcedureStatsTotalsTests.cs | 21 +++++++++++++++---- 1 file changed, 17 insertions(+), 4 deletions(-) diff --git a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs index 750e9a6263..a54d3ef548 100644 --- a/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs +++ b/Darling/Darling.Tests/ProcedureStatsTotalsTests.cs @@ -8,6 +8,7 @@ using System; using System.Collections.Generic; +using System.IO; using System.Linq; using PerformanceMonitor.Collectors; using PerformanceMonitor.Darling.Service; @@ -153,12 +154,24 @@ public void TheRunner_WritesTheTotalsOnTheCopysTransaction_AfterTheCopy_BeforeTh Assert.DoesNotContain("catch", between, StringComparison.Ordinal); Assert.DoesNotContain("SAVEPOINT", between, StringComparison.OrdinalIgnoreCase); - /* collect.procedure_stats has exactly one writer: the runner's COPY. */ - foreach (var file in new[] { "DarlingWorker.cs", "DarlingRetention.cs" }) + /* collect.procedure_stats has exactly one writer, the runner's COPY (built from TargetTable, so it has no literal): no other Darling source file names an INSERT or COPY into it. */ + var scanned = 0; + foreach (var file in Directory.EnumerateFiles(RepoFile.PathTo("Darling"), "*.cs", SearchOption.AllDirectories)) { - var text = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", file); - Assert.DoesNotContain("INSERT INTO collect.procedure_stats ", text, StringComparison.Ordinal); + var relative = Path.GetRelativePath(RepoFile.Root, file).Replace('\\', '/'); + if (relative.Contains("/obj/", StringComparison.Ordinal) || relative.Contains("/bin/", StringComparison.Ordinal) + || relative.StartsWith("Darling/Darling.Tests/", StringComparison.Ordinal)) + { + continue; + } + + scanned++; + var text = File.ReadAllText(file); + Assert.False(text.Contains("INSERT INTO collect.procedure_stats ", StringComparison.Ordinal), relative + " writes collect.procedure_stats"); + Assert.False(text.Contains("COPY collect.procedure_stats ", StringComparison.Ordinal), relative + " COPYs into collect.procedure_stats"); } + + Assert.True(scanned > 300, "the scan saw " + scanned + " Darling source files"); } ///