Check log_line_prefix for %Q, and stop claiming auto_explain is unavailable (#2538, #2564) by erikdarlingdata · Pull Request #2584 · erikdarlingdata/PerformanceMonitor

erikdarlingdata · 2026-08-24T23:18:08Z

Two findings from measuring the plan-capture mechanism on a live PostgreSQL 17 rather than reasoning about it. One is a new precondition; the other is a defect in what shipped a few hours ago in #2582.

1. A captured plan is an orphan without `%Q`

auto_explain with log_format=json emits no query identifier at all, even with compute_query_id=on. The JSON body carries Query Text and Plan and nothing that identifies the statement.

The id appears in exactly one place — the log line prefix — and there it matches pg_stat_statements.queryid exactly:

log_line_prefix = 'QID=%Q '
  auto_explain line   -> QID=-4828029293864693941
  pg_stat_statements  -> queryid = -4828029293864693941

So without %Q, every plan we capture is unjoinable to the statement it came from — and nothing about the configuration looks wrong. That is the failure worth a facet rather than a footnote: it looks like the feature working.

New plan_attribution facet reports it. No migration: the row-per-facet shape from #2564 means a new precondition is a query change, not a schema change, which is the first time that design has paid off.

Two ways to get this check wrong, both reproduced before writing the right one

LIKE '%%Q%' parses as wildcard-wildcard-Q-wildcard, so it matches any value containing the letter Q. strpos(..., '%Q') > 0 takes the two characters literally and needs no escape clause.
Case matters and is load-bearing. %q and %Q are different prefix escapes — %q truncates the prefix in non-session processes — and %q is common in real configurations.

Verified against a live server with log_line_prefix = '%m [%p] %q%u@%d QUEUE ', which contains %q and two literal Qs: correctly unsatisfied. The LIKE version says satisfied.

2. `extension_available` said no on every PostgreSQL server in existence

This shipped in #2582 and was wrong from the first row.

The facet asked pg_available_extensions, and auto_explain is a preload-only module — no CREATE EXTENSION, no control file on disk (ls .../extension/ | grep explain is empty), so it never appears there. Including on servers that are running it.

Caught by running the shipped query against a container with the module loaded and serving a 250ms threshold:

library_loaded      | t | pg_stat_statements,auto_explain
capture_threshold   | t | 250ms
extension_available | f | (not present)   <-- and the detail said "a platform limitation"

Two rows apart, contradicting each other, telling every reader that plan capture was impossible on their platform. That is exactly the send-half-the-readers-to-the-wrong-fix failure #2564 was written to prevent — except aimed at all of them.

It now reports availability it can prove: catalogued, or already loaded, since a loaded library is proof of its own availability. A negative says plainly that it is inconclusive, names the reason, and points at the cluster parameter group's allowed values for shared_preload_libraries — where the real answer lives on Aurora/RDS, and which SQL cannot see. The catalog check is kept rather than dropped, because a managed provider shipping a control file would still be a true positive.

Verified

The SQL was extracted from the compiled source file, not retyped, and run against live PostgreSQL 17 containers in four states:

state	result
stock server, nothing loaded	5 facets, all unsatisfied, `extension_available` now says inconclusive rather than unavailable
`%q` present plus literal `Q`s	`plan_attribution` correctly unsatisfied (the `LIKE` bug's exact case)
`%Q` present	`plan_attribution` satisfied
auto_explain loaded, threshold 250ms, `%Q` present	all 5 satisfied, contradiction gone

capture_threshold reports 250ms — the GUC rendering with its unit, which is why observed is stored as the server's own text and never cast.

Context

The fleet measurement behind this is on #2538: auto_explain is in Aurora's allowed shared_preload_libraries on both 16.11 and 17.7, loaded on zero of 51 cluster parameter groups, and all 14 auto_explain.* parameters are already present and dynamic — so the cost is one static change plus one writer reboot per cluster, after which every knob (including sample_rate) moves live.

…ilable (#2538, #2564) Two findings from measuring the plan-capture mechanism on PostgreSQL 17. auto_explain emits NO query identifier in its plan output, even with compute_query_id on. The id appears only in the log line prefix, and with %Q present it equals pg_stat_statements.queryid exactly. Without it every captured plan is an orphan that cannot be joined to the statement it came from, and nothing about the configuration looks wrong. New plan_attribution facet reports it - no migration needed, because row-per-facet makes a new precondition a query change. Matched with strpos, not LIKE: '%%Q%' parses as wildcard-wildcard-Q- wildcard and reports success on any value containing the letter Q. And case-sensitively, because %q and %Q are different prefix escapes and %q is common. Both wrong answers were reproduced on a live server first. Second: extension_available was false on every server in existence. auto_explain is a preload-only module - no CREATE EXTENSION, no control file - so it never appears in pg_available_extensions. A container with the module loaded and serving a 250ms threshold reported library_loaded true and extension_available false two rows apart, telling the reader plan capture was a platform limitation. It now reports availability it can prove, and a negative says it is inconclusive and names why. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

claude · 2026-08-24T23:20:35Z

        var sql = PgPlanCaptureReadinessCollector.Instance.BuildQuery(MakeContext()).Text;

-        foreach (var facet in new[] { "library_loaded", "capture_threshold", "extension_available", "plan_text_setting" })
+        foreach (var facet in new[] { "library_loaded", "capture_threshold", "extension_available", "plan_text_setting", "plan_attribution" })


This adds plan_attribution to the facet list here, but the UNION ALL count assertion a few lines below (Assert.Equal(3, Regex.Matches(sql, @"\bUNION ALL\b").Count);) wasn't updated to match. Five SELECTs joined by UNION ALL means 4 occurrences now, not 3:

$ grep -c "UNION ALL" PerformanceMonitor.Collectors/PgPlanCaptureReadinessCollector.cs 4

This test will fail as written. The method name (TheFourFacets_AreSeparateRows) and its doc-comment above are also now stale.

claude · 2026-08-24T23:20:37Z

+
         plan_text_setting   - auto_explain.log_format. Recorded rather than judged: any format proves
                               capture is happening, and #2565 has not chosen what we would read.
+         plan_attribution    - log_line_prefix carrying %Q. Measured on PostgreSQL 17 while investigating


Minor: the comment block introducing this list (line 74) still says "Four facets, each a separate row" — now stale since plan_attribution makes five. Same staleness in Darling/PerformanceMonitor.Darling.Storage/DarlingPgPlanCaptureReadinessReader.cs:27 ("The four facets have a causal order..."). Given this codebase's convention that comments carry load-bearing reasoning, worth a one-word fix so the count doesn't mislead the next reader.

claude · 2026-08-24T23:20:44Z

Reviewed. The two new-facet correctness points from the description (strpos over LIKE, case-sensitive %Q/%q, and treating unloaded-but-cataloged/loaded auto_explain as proof of availability) all check out against the query text.

One real issue found: Lite.Tests/PgPlanCaptureReadinessCollectorDefinitionTests.cs's TheFourFacets_AreSeparateRows test asserts UNION ALL appears 3 times, but the query now has 5 SELECTs (4 UNION ALLs) after this PR adds the plan_attribution facet — the test will fail as written. Left an inline comment with a suggested fix.

Also flagged (minor): two doc comments ("Four facets...") in the collector and in DarlingPgPlanCaptureReadinessReader.cs weren't updated to five when plan_attribution was added.

No Lite/Darling parity concern — this collector's readiness UI only exists on the Darling (PostgreSQL) side; Lite doesn't support PostgreSQL targets, and Lite.Tests only exercises the shared collector definition, which is correctly shared.

CI caught the fifth facet leaving Assert.Equal(3, ...) stale: the roster was updated, the UNION ALL count was not, so the guard whose job is to catch a collapsed facet failed for arithmetic instead. N facets are joined by N-1 UNION ALLs by construction, so the assertion now says that. Renamed off TheFourFacets_, and swept the four-facet prose out of the collector, the reader and the viewer service. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

claude · 2026-08-24T23:31:58Z

 ## [Unreleased]

 ### Added
+- **A captured PostgreSQL plan is an orphan without `%Q`, so plan-capture readiness now checks for it** ([#2538]) - measured on PostgreSQL 17 while working out which capture mechanism is viable, and it is the kind of thing that makes a feature look like it is working while producing nothing usable. `auto_explain` with `log_format=json` emits **no query identifier at all**, even with `compute_query_id=on` - the JSON body carries `Query Text` and `Plan` and nothing that identifies the statement. The id appears in exactly one place, the **log line prefix**, and with `%Q` present it equals `pg_stat_statements.queryid` exactly (verified both sides: `-4828029293864693941`). So without `%Q` every captured plan is an orphan that cannot be joined to the statement it came from, and nothing about the configuration looks wrong. The new `plan_attribution` facet reports it, and needs **no migration** - the row-per-facet shape means a new precondition is a query change, not a schema change. Matched with `strpos` rather than `LIKE`, because `LIKE '%%Q%'` parses as wildcard-wildcard-Q-wildcard and reports success on any value containing the letter Q; and case-sensitively, because `%q` and `%Q` are **different** prefix escapes - `%q` truncates the prefix in non-session processes and is common in real configurations. Both wrong answers were reproduced against a live server before the right one was: a prefix of `%m [%p] %q%u@%d QUEUE ` correctly reports unsatisfied.


([#2538]) is a reference-style link, but there's no [#2538]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2538 definition anywhere in this file (only #2564, #2550, #2562, etc. have their definitions at the bottom). On GitHub's markdown renderer this will show up as literal [#2538] text rather than a link. Worth adding the missing reference-link definition alongside the others near the end of the file.

claude · 2026-08-24T23:32:12Z

+           and adding a fifth facet left it stale — the roster was updated, the count was not, and a guard
+           whose whole job is to catch a collapsed facet failed for arithmetic instead. N facets are joined by
+           N-1 UNION ALLs by construction, so saying that is both the real invariant and un-staleable. */
+        Assert.Equal(facets.Length - 1, Regex.Matches(sql, @"\bUNION ALL\b").Count);


Nice fix turning the stale Assert.Equal(3, ...) into a derived facets.Length - 1 check — but neither of this PR's two behavioral fixes has a regression guard of its own:

extension_available's new "loaded-is-proof-of-availability" OR logic (the fix for the Detect whether PostgreSQL plans can be captured at all, and say so — the shippable first slice of #2538 #2564 contradiction) isn't asserted anywhere — a test like TheLibraryCheck_IsBoundaryAware_NotASubstringMatch below, but checking that the shared_preload_libraries regex actually appears inside the extension_available branch (e.g. Assert.Contains("EXISTS (SELECT 1 FROM pg_catalog.pg_available_extensions...) OR coalesce(current_setting('shared_preload_libraries'", sql)), would lock in the exact bug this PR fixes.

plan_attribution's strpos-not-LIKE and case-sensitive %Q-not-%q reasoning (the two wrong answers the PR description says were "reproduced before writing the right one") also has no assertion — e.g. Assert.DoesNotContain("LIKE '%%Q%'", sql) plus Assert.Contains("strpos(coalesce(current_setting('log_line_prefix', true), ''), '%Q')", sql).

Given both are exactly the kind of subtle-regex mistake that shipped broken once already in #2582 and was only caught by manual testing against a live server, a string-match test (matching this file's existing style) seems cheap insurance against a future refactor silently reintroducing either bug.

claude · 2026-08-24T23:32:38Z

Reviewed. The core logic checks out:

plan_attribution (new facet): strpos vs LIKE '%%Q%' and the case-sensitive %Q/%q distinction are both correct and match the PR description's reasoning. Column types/order match the other four UNION ALL branches exactly.
extension_available fix: the new OR coalesce(current_setting('shared_preload_libraries', true), '') ~ '(^|,)\sauto_explain\s(,|$)' reuses the already-boundary-safe library_loaded regex, correctly reports 'inconclusive' rather than 'unavailable' on a negative, and is schema-free (no CHECK constraint on facet in the v87 migration, confirmed in PgMigrations.cs), so 'no migration' in the PR description checks out.
Lite/Darling parity: no drift. Confirmed Lite/Database/DuckDbSchemaGenerator.cs filters CollectorCatalog.All to TargetEngine == CollectorTargetEngine.SqlServer only — Lite never generates a table for any PostgreSQL collector, including this one, so Lite.Tests needing an update while no Lite/ production file changes is expected, not a gap.
Darling reader/UI: DarlingPgPlanCaptureReadinessReader's causal-order CASE and ViewerServerTab.Postgres.cs's note text both correctly include plan_attribution in the right causal position.

Two things worth a look (left as inline comments too):

CHANGELOG.md:11 — ([PostgreSQL has no execution plan capture, which is where a DBM comparison is lost #2538]) has no matching [PostgreSQL has no execution plan capture, which is where a DBM comparison is lost #2538]: https://... reference-link definition anywhere in the file (unlike Detect whether PostgreSQL plans can be captured at all, and say so — the shippable first slice of #2538 #2564 right below it), so it will render as literal bracket text on GitHub.
Test coverage gap — neither the extension_available OR-fix nor the plan_attribution strpos/case-sensitivity logic has a dedicated regression test (unlike the analogous library_loaded boundary-match test). Given this facet has now shipped with two separate live-server-only-caught bugs across two PRs, a cheap string-match assertion for each would guard against a future refactor quietly reintroducing either one.

Nothing else stood out on correctness, security, or performance — this is read-only catalog/GUC access on an hourly collector, no user input involved.

pg_extension_availability covers the five true extensions and deliberately not pg_wait_sampling: preload-only modules never appear in pg_available_extensions even where they are loaded, so listing it would manufacture a permanent false absent - the defect #2564 shipped and #2584 fixed. SHOW shared_preload_libraries is the check for that one. GRANT SELECT on a schema is not valid PostgreSQL; SELECT is a table, column and sequence privilege. The PostgreSQL 13 fallback is the three statements the first-target runbook already carries, including the ALTER DEFAULT PRIVILEGES that covers tables created later.

…llector returns anything (#3184) * Document the two PostgreSQL target grants that decide whether three collectors return anything The permissions section said one role covers every collector. It does not. pg_stats filters every row through has_column_privilege and pg_monitor confers no SELECT on user tables, so a pg_monitor-only role reads pg_stats as EMPTY rather than as denied — nothing logs a PERMISSIONS skip, and pg_column_stats stores zero rows forever, pg_table_bloat_stats suppresses the estimate it exists for, and the statistics-based index-bloat estimator is unavailable. Measured on a 50-target fleet: 59,757 of 59,757 pg_table_bloat_stats rows across 49 targets carry estimate_unavailable, and pg_column_stats holds zero rows all time, against 553 SUCCESS runs. pg_read_all_data was documented only in the V91/V94 migration-rung table, where nobody provisioning a target reads. pgstattuple's per-database CREATE EXTENSION requirement for pg_index_bloat was not stated in this section at all. * Correct the index-bloat grant claims: there is no statistics-based estimator Two paragraphs described a statistics-based index-bloat estimator that pg_read_all_data unlocks. No such estimator exists at any grant level. PgIndexBloatCollector references pg_read_all_data zero times and pgstatindex twenty-two, and its type header records the decision: #2561 proposed porting the ioguix btree estimator and rejected it, because under exactly these permissions the exact function works and the estimator is blind. So pg_read_all_data changes two collectors, not three - pg_column_stats and pg_table_bloat_stats. Index bloat is measured-only regardless of grants and needs the pgstattuple extension instead. The extension is pgstattuple; the function the collector calls is pgstatindex. The same paragraph tells the reader the skip names the missing function, so the function name is the string they grep for. The pg_stats/has_column_privilege mechanism is unchanged and verified: PgTableBloatStatsCollector carries estimate_unavailable ten times and reads pg_stats twelve, and PgColumnStatsCollector filters through has_column_privilege. * Name the four collectors that need an extension, instead of counting the ones that do not The section now documents pgstattuple as a per-database install for pg_index_bloat, two paragraphs above a sentence asserting that every collector but one needs nothing installed. Four need one: pg_statement_stats (pg_stat_statements), pg_index_bloat (pgstattuple), pg_buffer_usage (pg_buffercache), and pg_wait_sampling (the pg_wait_sampling module). The count was already stale on its own terms - the README reports 27 PostgreSQL collectors and the table below lists 12, so "the other six" matched neither. Naming the collectors instead of counting the remainder means adding a fifth requires editing the list, rather than silently invalidating a number nothing checks. * Name all six extension-dependent collectors, and the two that are per-database pg_kernel_stats needs pg_stat_kcache and pg_predicate_stats needs pg_qualstats; both were missing. Confirmed two ways: the collectors say so (PgKernelStatsCollector.cs:80, PgPredicateStatsCollector.cs:47) and tonight's PG store carries 191 PERMISSIONS rows across 48 servers naming the missing object for four of the six, the other two being installed on those targets. A code read and a runtime read find different subsets and neither alone is the answer. Also records what an operator has to do differently per dependency: pgstattuple and pg_qualstats are per-database, and pg_wait_sampling is preload-only like pg_stat_statements, so it needs shared_preload_libraries and a restart rather than a CREATE EXTENSION. * Scope the extension-availability claim, and fix an invalid PG13 grant pg_extension_availability covers the five true extensions and deliberately not pg_wait_sampling: preload-only modules never appear in pg_available_extensions even where they are loaded, so listing it would manufacture a permanent false absent - the defect #2564 shipped and #2584 fixed. SHOW shared_preload_libraries is the check for that one. GRANT SELECT on a schema is not valid PostgreSQL; SELECT is a table, column and sequence privilege. The PostgreSQL 13 fallback is the three statements the first-target runbook already carries, including the ALTER DEFAULT PRIVILEGES that covers tables created later. * Stop calling pgstattuple a grant The lead said "two further grants" while the paragraph below it says pgstattuple is a per-database extension rather than a grant. One grant (pg_read_all_data) and one extension (pgstattuple), deciding three collectors between them. --------- Co-authored-by: Erik Darling <erik@erikdarling.com>

claude Bot reviewed Aug 24, 2026

View reviewed changes

erikdarlingdata mentioned this pull request Aug 24, 2026

Choose the PostgreSQL plan capture mechanism (auto_explain vs on-demand EXPLAIN vs extension) #2565

Closed

erikdarlingdata merged commit aa2c636 into dev Aug 24, 2026
6 checks passed

claude Bot mentioned this pull request Sep 9, 2026

Document the PostgreSQL grant and extensions that decide whether a collector returns anything #3184

Merged

erikdarlingdata deleted the feature/2538-plan-attribution-facet branch September 12, 2026 20:32

Navigation Menu

Repository navigation

Check log_line_prefix for %Q, and stop claiming auto_explain is unavailable (#2538, #2564) - #2584

Check log_line_prefix for %Q, and stop claiming auto_explain is unavailable (#2538, #2564)#2584
erikdarlingdata merged 2 commits into
devfrom
feature/2538-plan-attribution-facet

erikdarlingdata commented Aug 24, 2026

Uh oh!

claude Bot Aug 24, 2026

Uh oh!

claude Bot Aug 24, 2026

Uh oh!

claude Bot commented Aug 24, 2026

Uh oh!

claude Bot Aug 24, 2026

Uh oh!

claude Bot Aug 24, 2026

Uh oh!

claude Bot commented Aug 24, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Conversation

erikdarlingdata commented Aug 24, 2026

1. A captured plan is an orphan without %Q

Two ways to get this check wrong, both reproduced before writing the right one

2. extension_available said no on every PostgreSQL server in existence

Verified

Context

Uh oh!

claude Bot Aug 24, 2026

Choose a reason for hiding this comment

Uh oh!

claude Bot Aug 24, 2026

Choose a reason for hiding this comment

Uh oh!

claude Bot commented Aug 24, 2026

Uh oh!

claude Bot Aug 24, 2026

Choose a reason for hiding this comment

Uh oh!

claude Bot Aug 24, 2026

Choose a reason for hiding this comment

Uh oh!

claude Bot commented Aug 24, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

1. A captured plan is an orphan without `%Q`

2. `extension_available` said no on every PostgreSQL server in existence