Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

### Added

- **The payload-dimension GC now stands down when the purge it depends on failed** ([#1789], closes [#1782]) - the dimension GC prunes `query_text_dim` / `query_plan_dim` rows whose `last_seen` has aged past the fact tables' own retention plus a margin, on the reasoning that any fact which could still reference that content is gone. The fact purge immediately above it in the same sweep is **failure-isolated**: a table whose `drop_chunks` fails, and whose DELETE fallback then also fails, is warned and skipped while the sweep continues straight into the GC. Those rows are still there, still carrying digests, and their dimension rows get pruned out from under them - the resolving view then hands back NULL payload for real collected data, with **no error raised anywhere**, which reads as a collection outage rather than a retention bug. A dim-feeding table that failed its purge now defers the GC for that cycle with one fixed log line (`dimension GC deferred: raw purges held, facts may outlive their policy window`), self-ending on the next sweep that purges cleanly and needing no operator.

**The issue's original premise was disproved before this was built, and the fix is keyed to a different trigger than the one reported.** #1782 proposed that a HELD tiered retention policy could let facts outlive the cutoff. It cannot: there are TWO purges on these tables, and only the tiered 4-day policy is coverage-gated. Darling's own catalog sweep drops the same tables at their per-collector horizon - 30 days for `query_stats` and `procedure_stats` - with no coverage check and no held check at all. So a held policy changes whether facts live 4 days or 30, both inside the 32-day dimension cutoff, and the ordering survives any retention override because both sides resolve through the same `retentionDaysFor`. Guarding on the held state would have deferred the GC indefinitely on a store whose policies are held for unrelated reasons - unbounded dimension growth, which is the exact failure #1768 exists to prevent - to prevent something that cannot happen by that route. The guard is keyed to the reachable trigger instead.

Verified at the seam rather than at the sides, because the defect is wiring: the live test injects a **genuine** total purge failure (the fact table is renamed for the duration, so both statements fail against a relation that does not exist) and asserts the referenced dimension row survives, then restores it and asserts the same row is pruned once the purge is healthy - so the test cannot pass merely because the GC never ran. Watched red against the unguarded form.

Establishing all of the above surfaced a larger, opposite-signed defect in the same file, filed separately as [#1784]: that ungated catalog sweep **bypasses the #1680 coverage gate entirely**, dropping rollup-uncovered raw history at 30 days on a store where the gate is deliberately holding the tiered policy to protect it.

- **The query text and plan XML now live once each, not once per collected row** ([#1768], closes [#1767]) - on a production field instance `query_stats` (176 GB) and `procedure_stats` (58 GB) were **94% of a 250 GB store**, and the cause was schema-level rather than anything retention or compression could reach. Chunk-level measurement: a representative `query_stats` chunk was 88.97 GB raw (12.41 GB table + 74.15 GB TOAST) compressing to 17.98 GB - of which **17.5 MB was the table and 16.73 GB was TOAST**. Columnar compression crushes the monitoring numerics 665x; TOAST compression manages 4.1x because it is byte-level and has no cross-row awareness, so re-collecting the same cached plan every minute stores that plan again every minute. **99.9% of the compressed chunk was payload, and the monitoring numbers were nearly free.** Both payloads move into hash-keyed dimension tables (`collect.query_text_dim`, `collect.query_plan_dim`) and the fact rows carry only a digest. A dedup PoC over a real 1-hour window - 514,896 rows, 3,166 MB of inline payload - collapsed to ~23 MB of distinct content, and the ratio *improves* as the window widens because distinct plans grow far slower than rows. `procedure_stats` has no `query_text` column at all, so its entire share is plan XML; both fact tables share ONE plan dimension, which also means the same vendor application's plan collected from fifty servers is stored once fleet-wide.

**The key is a SHA-256 CONTENT digest, not one of SQL Server's own hash columns**, and that is a deliberate departure from the issue's sketch because each alternative is wrong in a way that fails silently. `query_plan_hash` is a plan-SHAPE hash: the same shape recompiled with different sniffed parameter values carries the same hash and DIFFERENT XML, so a shape-keyed dimension with `ON CONFLICT DO NOTHING` would pin the first XML forever and serve stale `ParameterCompiledValue`s - the single most diagnostic element of a plan for this product's audience. `query_hash` is a query-SHAPE hash and would pin one arbitrary literal variant where every reader today shows the LATEST text. `plan_handle` does not determine the XML at all: `query_stats` captures the STATEMENT plan via `dm_exec_text_query_plan(plan_handle, statement_start_offset, statement_end_offset)` and the offsets are not stored - **this codebase already recorded that exact failure**, in `QueryStatsCollector`'s delta key ("keying on plan_handle alone cross-contaminated multi-statement plans (one plan_handle, many statements at different offsets)"). A content digest rests on no cache-internals assumption. It costs two `bytea` columns per row, roughly 1% of the payload it removes, and it does **not** cost dedup ratio, because the repetition being collapsed is the same cached plan re-read each cycle: measured on a live SQL Server, **69 of 89 cached plans hashed byte-identical across a 20-second gap**, which is the property the whole design turns on.
Expand Down Expand Up @@ -1820,6 +1828,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
[#1777]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/1777
[#1780]: https://github.com/erikdarlingdata/PerformanceMonitor/pull/1780
[#1781]: https://github.com/erikdarlingdata/PerformanceMonitor/pull/1781
[#1782]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/1782
[#1783]: https://github.com/erikdarlingdata/PerformanceMonitor/pull/1783
[#1784]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/1784
[#1786]: https://github.com/erikdarlingdata/PerformanceMonitor/pull/1786
[#1789]: https://github.com/erikdarlingdata/PerformanceMonitor/pull/1789
[#1792]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/1792
106 changes: 106 additions & 0 deletions Darling/Darling.Tests/PayloadDimensionLiveTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,15 @@ namespace Darling.Tests;
[Collection("live-postgres")]
public sealed class PayloadDimensionLiveTests
{
/// <summary>
/// The exact line the dimension GC emits when it stands down, pinned in FULL rather than by prefix: it is
/// a field signature an operator greps for, and a partial pin would let the wording drift to name a cause
/// the guard does not actually detect -- which is how it came to say "raw purges held" while the shipped
/// trigger was a purge that did not complete.
/// </summary>
private const string DeferralSignature =
"dimension GC deferred: a dim-feeding table kept rows past its horizon this cycle; dimension content is retained until its purge completes";

private const string SkipReason =
"Set DARLING_TEST_PG to a Postgres connection string to run the payload-dimension store tests.";

Expand Down Expand Up @@ -731,4 +740,101 @@ AND NOT EXISTS (SELECT 1 FROM {dimTable} AS d WHERE d.digest = f.{digestColumn
await DeleteDimRowAsync(writer, PayloadDimensions.QueryPlanDimTable, planDigest, ct);
}
}

/// <summary>
/// The dimension GC must NOT prune while a table that feeds it failed to purge this cycle (#1782).
///
/// <para>The cutoff assumes facts past their retention are gone. The fact loop is failure-isolated, so a
/// table whose drop_chunks fails AND whose DELETE fallback then also fails is warned, skipped, and the
/// sweep continues straight into the GC — pruning dimension rows those surviving facts still reference.
/// The digests dangle and the resolving view serves NULL payload with no error raised anywhere, which is
/// the whole reason this is a guard and not a comment.</para>
///
/// <para>The failure is injected by RENAMING query_stats for the duration, which is a genuine total
/// failure of both purge paths (the relation the statements name does not exist) rather than a simulated
/// one — and it exercises the real seam: the sweep sets the flag, and the GC reads it. It is restored in
/// a finally, and the whole live collection is serialized, so no sibling class can observe the rename.</para>
/// </summary>
[Fact]
public async Task DimensionGc_DefersWhenADimFeedingTableFailedItsPurge_ThenPrunesOnceItSucceeds()
{
var connectionString = Environment.GetEnvironmentVariable("DARLING_TEST_PG");
Assert.SkipWhen(string.IsNullOrEmpty(connectionString), SkipReason);

var ct = TestContext.Current.CancellationToken;
await using var connection = await OpenMigratedStoreAsync(connectionString!, ct);

/* Far past the ~32-day cutoff, so an unguarded GC would certainly take it. */
var digest = PayloadDimensions.Digest("pm1782-" + Guid.NewGuid().ToString("N"));
var ancient = DateTime.SpecifyKind(DateTime.UtcNow.AddDays(-400), DateTimeKind.Unspecified);

await using var postgres = NpgsqlDataSource.Create(connectionString!);
var renamed = false;

try
{
using (var seed = new NpgsqlCommand(
$"INSERT INTO {PayloadDimensions.QueryPlanDimTable} (digest, query_plan_xml, last_seen) " +
"VALUES ($1, $2, $3) ON CONFLICT (digest) DO NOTHING", connection))
{
seed.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Bytea, Value = digest });
seed.Parameters.AddWithValue("<ShowPlanXML pm1782=\"1\"/>");
seed.Parameters.AddWithValue(ancient);
await seed.ExecuteNonQueryAsync(ct);
}

Assert.Equal(1L, await DimRowCountAsync(connection, digest, ct));

using (var rename = new NpgsqlCommand(
"ALTER TABLE collect.query_stats RENAME TO query_stats_pm1782", connection))
{
await rename.ExecuteNonQueryAsync(ct);
renamed = true;
}

var deferredLog = new CapturingTestLogger();
await DarlingRetention.PurgeAsync(postgres, timescaleAvailable: true, deferredLog, ct);

/* The SUBSTANTIVE property first, deliberately: this is the assertion that distinguishes
"the guard held" from "the guard logged and pruned anyway", so it is the one a mutation
must land on. Asserting the log line first would let a broken guard go red on missing
TEXT while the actual data loss went unexamined. */
Assert.Equal(1L, await DimRowCountAsync(connection, digest, ct));
Assert.Contains(DeferralSignature, deferredLog.Joined, StringComparison.Ordinal);

using (var restore = new NpgsqlCommand(
"ALTER TABLE collect.query_stats_pm1782 RENAME TO query_stats", connection))
{
await restore.ExecuteNonQueryAsync(ct);
renamed = false;
}

/* Control: with the purge healthy again the guard opens and the same row is pruned, so the test
cannot pass merely because the GC never runs. */
var prunedLog = new CapturingTestLogger();
await DarlingRetention.PurgeAsync(postgres, timescaleAvailable: true, prunedLog, ct);

Assert.DoesNotContain(DeferralSignature, prunedLog.Joined, StringComparison.Ordinal);
Assert.Equal(0L, await DimRowCountAsync(connection, digest, ct));
}
finally
{
if (renamed)
{
using var restore = new NpgsqlCommand(
"ALTER TABLE IF EXISTS collect.query_stats_pm1782 RENAME TO query_stats", connection);
await restore.ExecuteNonQueryAsync(ct);
}

await DeleteDimRowAsync(connection, PayloadDimensions.QueryPlanDimTable, digest, ct);
}
}

private static async Task<long> DimRowCountAsync(NpgsqlConnection connection, byte[] digest, CancellationToken ct)
{
using var read = new NpgsqlCommand(
$"SELECT COUNT(*) FROM {PayloadDimensions.QueryPlanDimTable} WHERE digest = $1", connection);
read.Parameters.Add(new NpgsqlParameter { NpgsqlDbType = NpgsqlDbType.Bytea, Value = digest });
return (long)(await read.ExecuteScalarAsync(ct))!;
}
}
72 changes: 60 additions & 12 deletions Darling/PerformanceMonitor.Darling.Service/DarlingRetention.cs
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,10 @@
*/

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Globalization;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Logging;
Expand Down Expand Up @@ -138,6 +140,12 @@ public static async Task<PurgeSummary> PurgeAsync(
/* Naive-UTC storage: Npgsql 6+ rejects Kind=Utc against `timestamp` — see PgCollectorRowWriter. */
var utcNow = DateTime.SpecifyKind(DateTime.UtcNow, DateTimeKind.Unspecified);

/* Set when a table that feeds a payload dimension could not be purged this cycle, which invalidates
the dimension GC's cutoff (#1782). Tracked here rather than inferred later because the sweep is the
only thing that knows: a failed purge is warned and skipped, leaving no state a later query could
read back. */
var dimFeedingPurgeFailed = false;

try
{
foreach (var definition in CollectorCatalog.All)
Expand All @@ -149,6 +157,7 @@ drift degrades to a loud warning (and a WARNING run-record) instead of killing t
logger?.LogWarning("Retention purge: no schedule entry for '{Collector}' — {Table} was not purged",
definition.Name, definition.TargetTable);
tablesFailed++;
dimFeedingPurgeFailed |= PayloadDimensions.ForTable(definition.TargetTable).Count > 0;
continue;
}

Expand Down Expand Up @@ -185,6 +194,11 @@ table still honors its horizon instead of growing unbounded. */
else
{
tablesFailed++;

/* Both paths failed for this table, so its rows are still there past their horizon. If it
feeds a payload dimension, that invalidates the dimension GC's cutoff for this cycle
(#1782) — see the guard below. */
dimFeedingPurgeFailed |= PayloadDimensions.ForTable(definition.TargetTable).Count > 0;
}
}

Expand Down Expand Up @@ -222,20 +236,54 @@ the dims and orphan a reader — plus a margin covering the two ways a fact can
widestFactRetentionDays = Math.Max(widestFactRetentionDays, factRetentionDays);
}

var dimensionCutoff = utcNow.AddDays(-(widestFactRetentionDays + TimescaleSupport.ChunkIntervalDays + 1));
foreach (var dimTable in PayloadDimensions.DimTables)
/* That whole cutoff embeds one assumption: facts older than their retention are GONE. It holds
while the fact purge SUCCEEDS — and the loop above is failure-isolated, so a table whose
drop_chunks fails AND whose DELETE fallback then also fails is warned, skipped, and the sweep
continues straight into this GC. Those facts persist past the cutoff while their dimension rows
are pruned on schedule: the digests dangle, and the resolving view serves NULL payload with no
error raised anywhere (#1782).

So a dim-feeding table failing its purge defers the GC for that cycle. It is keyed to the
failure rather than to the retention POLICY's held state, because a held policy cannot cause
this: the catalog sweep above drops these tables at their own 30-day horizon regardless of the
policy, two days inside this 32-day cutoff, and the ordering survives any override since both
sides resolve through the same retentionDaysFor. Deferring on a held policy would stall the GC
indefinitely on a store whose policies are held for entirely unrelated reasons.

Self-ending by construction: the next sweep that purges cleanly runs the GC, and nothing needs
an operator. And it fails toward the recoverable side — deferring costs bounded dimension
growth, visible and reclaimed by the next cycle, where pruning early corrupts the read path
silently. */
if (dimFeedingPurgeFailed)
{
var dimDeleted = await PurgeOneAsync(
postgres, dimTable, TimeSlicedDeleteSql(dimTable, PayloadDimensions.LastSeenColumn),
dimensionCutoff, logger, cancellationToken);
if (dimDeleted is not null)
{
tablesPurged++;
totalRowsDeleted += dimDeleted.Value;
}
else
/* One line, deliberately a fixed string never interpolated: it is the field signature an
operator greps for when the dimensions stop shrinking, so it must not vary by store. It
names the observable STATE -- a table still holding rows past its horizon -- and not any
cause of it. Two different things produce that state: a purge statement that failed, and a
purge deliberately skipped because its rollup does not cover the table (#1784). Naming
either one here would be a lie in the other case and would send the reader after the wrong
remedy, which is the one thing a diagnostic line must not do. The preceding per-table
warning already says which table and which of the two it was, so the cause is one line
above, owned by the code that actually knows it. */
logger?.LogWarning("dimension GC deferred: a dim-feeding table kept rows past its horizon this cycle; dimension content is retained until its purge completes");
}
else
{
var dimensionCutoff = utcNow.AddDays(-(widestFactRetentionDays + TimescaleSupport.ChunkIntervalDays + 1));
foreach (var dimTable in PayloadDimensions.DimTables)
{
tablesFailed++;
var dimDeleted = await PurgeOneAsync(
postgres, dimTable, TimeSlicedDeleteSql(dimTable, PayloadDimensions.LastSeenColumn),
dimensionCutoff, logger, cancellationToken);
if (dimDeleted is not null)
{
tablesPurged++;
totalRowsDeleted += dimDeleted.Value;
}
else
{
tablesFailed++;
}
}
}

Expand Down
Loading