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
8 changes: 4 additions & 4 deletions .github/workflows/build.yml
Original file line number Diff line number Diff line change
Expand Up @@ -725,8 +725,8 @@ jobs:
#
# The values are the product's own derivation from the live hypertable count
# (TimescaleSupport.HypertableCount = the 62-collector catalog + collection_log = 63):
# timescaledb.max_background_workers = HypertableCount + 2 = 68
# max_worker_processes = 3 + (HypertableCount + 2) + 8 = 79
# timescaledb.max_background_workers = HypertableCount + 2 = 69
# max_worker_processes = 3 + (HypertableCount + 2) + 8 = 80
# Hard-coded here because a workflow cannot call into the product — so
# CiClusterWorkerSizingTests parses THIS FILE and fails the build if either number stops
# matching the formula as collectors are added, and CiClusterWorkerSizingLiveTests asserts
Expand All @@ -744,8 +744,8 @@ jobs:
Add-Content -Path "$dataDir\postgresql.conf" -Value "shared_preload_libraries = 'timescaledb'"
Add-Content -Path "$dataDir\postgresql.conf" -Value "port = 5541"
Add-Content -Path "$dataDir\postgresql.conf" -Value "listen_addresses = '127.0.0.1'"
Add-Content -Path "$dataDir\postgresql.conf" -Value "timescaledb.max_background_workers = 68"
Add-Content -Path "$dataDir\postgresql.conf" -Value "max_worker_processes = 79"
Add-Content -Path "$dataDir\postgresql.conf" -Value "timescaledb.max_background_workers = 69"
Add-Content -Path "$dataDir\postgresql.conf" -Value "max_worker_processes = 80"
& "$bin\pg_ctl.exe" -D $dataDir -l $logFile -w start
if ($LASTEXITCODE -ne 0) { if (Test-Path $logFile) { Get-Content $logFile -Tail 50 }; throw "pg_ctl start failed ($LASTEXITCODE)" }
& "$bin\createdb.exe" -h 127.0.0.1 -p 5541 -U darling darling
Expand Down
8 changes: 4 additions & 4 deletions .github/workflows/nightly.yml
Original file line number Diff line number Diff line change
Expand Up @@ -369,8 +369,8 @@ jobs:
# customer runs and made scheduler-racing failures luck-of-the-slot instead of reproducible.
# Values are the product's own derivation from the live hypertable count
# (TimescaleSupport.HypertableCount = the 62-collector catalog + collection_log = 63):
# timescaledb.max_background_workers = HypertableCount + 2 = 68
# max_worker_processes = 3 + (HypertableCount + 2) + 8 = 79
# timescaledb.max_background_workers = HypertableCount + 2 = 69
# max_worker_processes = 3 + (HypertableCount + 2) + 8 = 80
# Kept honest by CiClusterWorkerSizingTests (parses this file against the formula) and
# CiClusterWorkerSizingLiveTests (asserts the running cluster serves them). Must configure
# the cluster identically to build.yml's darling-pg job: that guard parses the appended
Expand All @@ -391,8 +391,8 @@ jobs:
Add-Content -Path "$dataDir\postgresql.conf" -Value "shared_preload_libraries = 'timescaledb'"
Add-Content -Path "$dataDir\postgresql.conf" -Value "port = 5541"
Add-Content -Path "$dataDir\postgresql.conf" -Value "listen_addresses = '127.0.0.1'"
Add-Content -Path "$dataDir\postgresql.conf" -Value "timescaledb.max_background_workers = 68"
Add-Content -Path "$dataDir\postgresql.conf" -Value "max_worker_processes = 79"
Add-Content -Path "$dataDir\postgresql.conf" -Value "timescaledb.max_background_workers = 69"
Add-Content -Path "$dataDir\postgresql.conf" -Value "max_worker_processes = 80"
& "$bin\pg_ctl.exe" -D $dataDir -l $logFile -w start
if ($LASTEXITCODE -ne 0) { if (Test-Path $logFile) { Get-Content $logFile -Tail 50 }; throw "pg_ctl start failed ($LASTEXITCODE)" }
& "$bin\createdb.exe" -h 127.0.0.1 -p 5541 -U darling darling
Expand Down
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
## [Unreleased]

### Added
- **PostgreSQL execution plans, captured and redacted** ([#2566], part of [#2538]) - schema **v99** adds `collect.pg_plan_capture`, reading `auto_explain`'s JSON output out of the server log. **Its own table, NOT `query_plan_dim`**: that one holds SQL Server plan XML and `plan_xml_compression = none` is a documented contract with direct-SQL consumers who read the column AS XML - dropping JSON rows into it would break their dashboards with no schema change to notice, no error, and no version to key off. **No query text and no literals reach the store, and that is the load-bearing part.** `auto_explain` emits `Query Text` verbatim and `auto_explain.log_parameter_max_length = 0` does NOT suppress it (that setting covers bind parameters only - measured on #2565); literals also sit inside the plan tree in `Filter` and its relatives. So the text is dropped outright - statement identity is `query_id`, whose normalised text already lives in `pg_statement_stats` - and every remaining string is redacted before storage. **Redaction is deliberately asymmetric**: quoted literals go from every string, but bare numbers only from condition fields, because a blanket numeric strip would rewrite a relation genuinely named `transactionitems1` into `transactionitems?` - destroying identity to hide a value that was never there. Verified against 25 real captured plans: **zero literals survived**, and the digit-bearing name survived intact. `plan_hash` is taken of the REDACTED plan so the same shape recurs to the same hash whatever values it ran with. The log read is **bounded to a 4 MB tail** because #2565 measured 772 MB of log in twenty seconds at capture-everything, and truncated blocks at the window edge are skipped rather than stored half-parsed. **Self-hosted in practice**: reading the log needs `pg_read_server_files` AND an explicit `GRANT EXECUTE ON FUNCTION pg_read_file` - measured, the role alone does NOT carry it, because the function's ACL is `postgres=X/postgres` - and on Aurora or RDS there is no filesystem at all, so the panel stays empty by design and says so.
- **Which PostgreSQL columns are filtered on, and where the planner is wrong about them** ([#2603]) - `pg_index_usage_stats` records indexes that were USED; schema **v98** adds `collect.pg_predicate_stats` from `pg_qualstats`, which records predicates that were EVALUATED **including the ones with no index behind them**. That is the index-candidate signal, and it is invisible to every other collector because nothing records a scan that had no index to record. **The counts are a SAMPLE and the rate is stored on every row**: `pg_qualstats.sample_rate` defaults to `1/max_connections` - 0.01 on the verification rig, where `pg_qualstats()` returned ZERO rows on a server that had just run the queries it was meant to record. A small count means the sampler fired rarely, not that the predicate is rare, and the counts are deliberately NOT scaled up by the rate because three observations at 1% is not three hundred. **`worst_estimate_error_ratio` is a different problem from selectivity** - measured at **57.9x** on one predicate beside 1.04x on another: the first means the plan was built on a wrong row count, which an index will not fix. **Runs per database, and that is load-bearing**: the function returns cluster-wide rows keyed by `dbid`, but `lrelid`/`lattnum` are OIDs meaningful only inside their own database while `pg_class` and `pg_attribute` are per-database catalogs - unscoped, the join either silently DROPS other databases' rows or resolves them against whatever local object shares the OID and reports a confident wrong column name. Measured: two cross-database rows present, neither colliding locally that day, so the failure would have been silent loss and different OID luck would have produced the wrong name. The extension is itself per-database, so databases without it degrade to a named non-fatal skip.
- **OS CPU and disk per query on PostgreSQL** ([#2603]) - `pg_stat_statements` reports elapsed time, which cannot separate a query that was WAITING from one burning processor. Schema **v97** adds `collect.pg_kernel_stats` from `pg_stat_kcache`: the kernel's own user CPU, system CPU and bytes that reached the disk, keyed by the same `queryid` so the two halves compose. **`exec_read_bytes = 0` does NOT mean the query read nothing** - the counters come from `getrusage` and measure I/O that reached the DEVICE, so a read served by the OS page cache is genuinely zero, which was the case on every row of the verification rig while writes were not. Zero reads with high CPU is a cached workload working properly; it is not comparable to a logical-read figure, and the columns are named `_bytes` so nothing in a SQL Server codebase reads them as one. **Only top-level statements are collected**: with `pg_stat_statements.track = 'all'` a nested statement appears both on its own row and inside its caller's, and summing them double-counts every function body on the server - the rig ran `track = 'top'` where that filter is inert, which is exactly why it is pinned rather than remembered. Times convert seconds to milliseconds once, in the collector, because a column named `_ms` holding seconds is wrong by a thousand and looks entirely plausible. Ranked by **CPU**, not bytes. Cumulative like the wait profile, but this table can do better than inferring a reset from a counter moving backwards: `stats_since` is collected, so the read detects a reset from the stamp changing AND from the backwards check. **Carries `database_name`, and that is not a contradiction of v95** - the function exposes `dbid` and `pg_database` is a SHARED catalog, so the name resolves correctly from any connection; `pg_wait_sampling` omits it because its catalog genuinely cannot support the claim.
- **PostgreSQL wait analysis stops being Aurora-only** ([#2603]) - `PgWaitStatsCollector` reads `aurora_stat_system_waits()`, so every self-hosted, on-prem and plain-RDS target had **no wait data at all**, which is backwards: self-hosted is where the extension story is richest. Schema **v96** adds `collect.pg_wait_sampling` from the `pg_wait_sampling` module, attributing each wait to the `queryid` that waited so it joins `pg_statement_stats` - the "which query waited on what" question this product answers on SQL Server. **Every design choice came from running it.** `event_type = 'Activity'` is excluded at the source: measured on an idle PostgreSQL 17 the entire top of the raw profile was background processes waiting for work (`AutovacuumMain`, `LogicalLauncherMain`, `WalWriterMain`, `CheckpointerMain`), accumulating samples forever precisely BECAUSE nothing was happening, while attributed waits returned nothing at all - rank that and every healthy server reports autovacuum's idle loop as its top wait. The filter is `IS DISTINCT FROM`, never `<>`, because a NULL event means the backend was **not waiting** and `NULL <> 'Activity'` is NULL rather than true, which would silently discard every on-CPU sample; those are kept and labelled **`CPU`/`Running`** instead of stored as a blank row that sorts near the top of a count-ranked grid (23 samples across 11 backends arrived exactly that way). **`sample_count` is a tally, not a duration** - `profile_period_ms` travels beside it because a count is uninterpretable alone, and the samples-to-milliseconds multiplication happens once in the read where the header says *Est. Wait*. The profile is **cumulative**, so a counter going BACKWARDS is a reset (`pg_wait_sampling_reset_profile`, or a restart nobody chose) rather than a negative wait: the read uses the newest value whole in that case and flags `counter_reset`, where `GREATEST(new - old, 0)` would have quietly reported zero waits across a restart. **No `database_name`, deliberately** - the profile is cluster-wide and version 1.1 exposes no database column, so claiming that attribution would be the same scope error v95 removed from three other tables. Absent module degrades to a named non-fatal skip, and the Extensions panel says whether installing it would help.
Expand Down
5 changes: 3 additions & 2 deletions Darling/Darling.Tests/PgSchemaGeneratorTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -45,13 +45,13 @@ Availability Group collectors (#991) = 38, plus plan_correction (#1952 automatic
the planner statistics that explain WHY a plan was chosen) = 59, plus
pg_replication_stats (#2544, connected standbys as distinct from slots) = 60, plus
pg_buffer_usage (#2544, what is resident in shared buffers) = 61, plus
pg_index_bloat (#2561) and pg_wait_sampling, pg_kernel_stats and pg_predicate_stats (#2603) = 65. The catalog is
pg_index_bloat (#2561) and pg_wait_sampling, pg_kernel_stats, pg_predicate_stats (#2603) and pg_plan_capture (#2566) = 66. The catalog is
deliberately
engine-mixed: the schema generator walks it to
create tables and one store can hold both engines' data, so splitting it per engine would
fragment DDL generation. Dispatch is gated separately, by engine, in
CollectorCatalog.AppliesTo(definition, target). */
Assert.Equal(65, CollectorCatalog.All.Count);
Assert.Equal(66, CollectorCatalog.All.Count);

/* Uniqueness is asserted AGAINST THE COUNT rather than against a second literal. The literals here
had drifted to 45 while the real figure tracked the count, so the test that exists to catch a
Expand Down Expand Up @@ -635,6 +635,7 @@ public void EveryPostgresRung_IsIdenticalToTheGeneratedSchema()
(96, PgWaitSamplingCollector.Instance),
(97, PgKernelStatsCollector.Instance),
(98, PgPredicateStatsCollector.Instance),
(99, PgPlanCaptureCollector.Instance),
};

/* Every PostgreSQL collector must appear above. One added without a rung listed here would
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4677,6 +4677,7 @@ await DarlingObservability.LogCollectionAsync(
["pg_wait_sampling"] = (r, s, ct) => r.RunAsync(PgWaitSamplingCollector.Instance, s, ct),
["pg_kernel_stats"] = (r, s, ct) => r.RunAsync(PgKernelStatsCollector.Instance, s, ct),
["pg_predicate_stats"] = (r, s, ct) => r.RunAsync(PgPredicateStatsCollector.Instance, s, ct),
["pg_plan_capture"] = (r, s, ct) => r.RunAsync(PgPlanCaptureCollector.Instance, s, ct),
["pg_column_stats"] = (r, s, ct) => r.RunAsync(PgColumnStatsCollector.Instance, s, ct),
["pg_replication_stats"] = (r, s, ct) => r.RunAsync(PgReplicationStatsCollector.Instance, s, ct),
["pg_buffer_usage"] = (r, s, ct) => r.RunAsync(PgBufferUsageCollector.Instance, s, ct),
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,109 @@
/*
* Copyright (c) 2026 Erik Darling, Darling Data LLC
*
* This file is part of the SQL Server Performance Monitor Lite.
*
* Licensed under the MIT License. See LICENSE file in the project root for full license information.
*/

using System;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;
using Npgsql;

namespace PerformanceMonitor.Darling.Storage;

/// <summary>
/// Reads <c>collect.pg_plan_capture</c> — plans captured by <c>auto_explain</c> (#2566).
///
/// <para><b>Grouped by plan, not by capture.</b> The collector reads a bounded tail of the log every cycle,
/// so the same plan is legitimately captured many times — and the overlapping window means the SAME
/// execution can be seen twice. Returning raw captures would rank by how often the reader happened to look.
/// Rows are grouped on <c>(query_id, plan_hash)</c>, which is what makes "this shape ran a lot and is slow"
/// answerable at all.</para>
///
/// <para><b>The plan JSON returned here is already redacted</b> — the collector strips it before storage, so
/// there is no un-redacted copy anywhere for a read to leak. Nothing here needs to re-check that, and
/// nothing here should re-derive it.</para>
///
/// <para>Ranked by TOTAL duration rather than max: a plan that takes 40 ms and runs constantly costs more
/// than one that took 900 ms once, and the second is usually a cold cache.</para>
/// </summary>
public static class DarlingPgPlanCaptureReader
{
/// <param name="Captures">How many times this shape was seen. A count of the CAPTURES, which the
/// overlapping tail read can inflate — treat it as a frequency signal rather than an execution count;
/// <c>pg_statement_stats.calls</c> is the authority on that.</param>
/// <param name="PlanJson">Redacted at collection. Literals and query text never reach the store.</param>
public sealed record PgPlanCaptureRow(
long QueryId,
string? PlanHash,
string? TopNodeType,
int NodeCount,
long Captures,
double TotalDurationMs,
double MaxDurationMs,
double AvgDurationMs,
string? PlanJson,
DateTime LastSeen);

/* DISTINCT ON inside the aggregate is not what is wanted here: the JSON is identical for a given
plan_hash by construction (the hash is OF the redacted JSON), so any row's copy will do and min()
avoids a second scan to pick one. */
public const string PgPlanCaptureSql = """
SELECT
query_id,
plan_hash,
min(top_node_type) AS top_node_type,
max(node_count) AS node_count,
count(*) AS captures,
sum(duration_ms) AS total_duration_ms,
max(duration_ms) AS max_duration_ms,
avg(duration_ms) AS avg_duration_ms,
min(plan_json) AS plan_json,
max(collection_time) AS last_seen
FROM pg_plan_capture
WHERE server_id = $1
AND collection_time >= $2
AND collection_time <= $3
GROUP BY query_id, plan_hash
ORDER BY sum(duration_ms) DESC
LIMIT $4
""";

public static async Task<List<PgPlanCaptureRow>> GetPgPlanCaptureAsync(
NpgsqlDataSource postgres, int serverId, DateTime startUtc, DateTime endUtc, int limit,
CancellationToken cancellationToken = default)
{
ArgumentNullException.ThrowIfNull(postgres);

var rows = new List<PgPlanCaptureRow>();
await using var command = postgres.CreateCommand(PgPlanCaptureSql);
command.Parameters.AddWithValue(serverId);
/* SpecifyKind(Unspecified) at the BIND, the convention every PostgreSQL read here follows. */
command.Parameters.AddWithValue(DateTime.SpecifyKind(startUtc, DateTimeKind.Unspecified));
command.Parameters.AddWithValue(DateTime.SpecifyKind(endUtc, DateTimeKind.Unspecified));
command.Parameters.AddWithValue(limit);

await using var reader = await command.ExecuteReaderAsync(cancellationToken);
while (await reader.ReadAsync(cancellationToken))
{
rows.Add(new PgPlanCaptureRow(
QueryId: reader.IsDBNull(0) ? 0 : reader.GetInt64(0),
PlanHash: reader.IsDBNull(1) ? null : reader.GetString(1),
TopNodeType: reader.IsDBNull(2) ? null : reader.GetString(2),
NodeCount: reader.IsDBNull(3) ? 0 : reader.GetInt32(3),
Captures: reader.IsDBNull(4) ? 0 : reader.GetInt64(4),
TotalDurationMs: reader.IsDBNull(5) ? 0 : reader.GetDouble(5),
MaxDurationMs: reader.IsDBNull(6) ? 0 : reader.GetDouble(6),
AvgDurationMs: reader.IsDBNull(7) ? 0 : Convert.ToDouble(reader.GetValue(7)),
PlanJson: reader.IsDBNull(8) ? null : reader.GetString(8),
LastSeen: reader.IsDBNull(9)
? default
: DateTime.SpecifyKind(reader.GetDateTime(9), DateTimeKind.Utc)));
}

return rows;
}
}
Loading
Loading