Skip to content

Give timescaledb.enable_job_execution_logging its own conf marker, so existing stores can heal (#3175) - #3177

Merged
erikdarlingdata merged 9 commits into
devfrom
fix/3175-job-execution-logging-marker
Sep 8, 2026
Merged

Give timescaledb.enable_job_execution_logging its own conf marker, so existing stores can heal (#3175)#3177
erikdarlingdata merged 9 commits into
devfrom
fix/3175-job-execution-logging-marker

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 8, 2026

Copy link
Copy Markdown
Owner

Closes #3175.

timescaledb.enable_job_execution_logging was written into the v1 postgresql.conf block by #1681. That is the one block EnsureConfAppended cannot heal: it skips a block whose marker it finds, and v1's marker is present on every cluster that already exists — so the append carrying the GUC only ever reached a fresh initdb. Every store older than that release has had timescaledb_information.job_history empty the whole time, and a maximum over an empty job_history returns zero rows, which reads as "no run exceeded the line" rather than "this instrument is off".

The change

The setting gets its own v11 marker, the way every setting added after v1 is handled, and it is moved rather than duplicated — leaving a copy in BuildConfAppend would cost nothing at runtime and would leave the repository asserting this setting in the block that provably cannot deliver it, which is the reading that produced the defect. TheJobExecutionLoggingGuc_IsInV11AndNotInTheUnhealableV1Block pins both halves so it cannot drift back.

get_store_metrics now reports the GUC's effective value, source and sourcefile on every response, in a job_history block present whatever the state — the #2813 precedent one step further, because here the absence being guarded is the absence of rows in the instrument this tool's own description redirects a maximum question to. Four states, never a bool: "the probe did not run", "this server has no such setting" and "it is switched off" call for three different readings of an empty job_history, and Off splits again on whether anything set it off, because those need different actions.

The GUC name is a single constant on the platform-neutral side (StoreSelfMetrics), so the name the conf block writes and the name the probe binds cannot drift. A retyped copy would not error: pg_settings would return no row for a name nobody registered, which this read reports as "the server has no such setting" — indistinguishable from a plain-PostgreSQL store.

Why not widen the v1 marker, measured rather than asserted

Making v1's check ask "is the GUC line present?" would re-append the whole shared v1 block to every pre-existing cluster. Measured on TimescaleDB 2.30.0 / PG 17 in a throwaway container: a conf carrying an operator's shared_preload_libraries = 'timescaledb,pg_stat_statements' came back up serving 'timescaledb' alone once the v1 block was appended behind it — the GUC is list-valued and the last assignment replaces the list rather than extending it. listen_addresses would likewise re-assert loopback over a conf-configured exposure, and port would override a hand-edited one. HealingAConfWithoutV11_AppendsOnlyThatBlock_AndReAppliesNoV1Setting asserts every v1 setting still has exactly one assignment after a heal, with the v1 names derived from the v1 builder rather than listed.

ConfV1Block_ContentIsFrozen_ANewSettingNeedsItsOwnMarker is the pin whose absence let this happen: adding anything to the v1 builder now goes red on the commit that types it. EveryConfMarker_IsDistinct_AndNoneIsASubstringOfAnother closes the other route — EnsureConfAppended asks each question as Contains, so a marker that became a substring of another would let a cluster carrying only the longer block answer "present" for the shorter one and never gain it. The v1 marker is nearly a prefix of every later one and is saved only by the parenthesised version segment; that is not obvious by eye.

Reload: the append is enough where it matters, and nothing reloads where it is not

EnsureConfAppended runs before pg_ctl start, so on a service-owned start the setting is live on the very start that writes it — no reload needed. Measured for the record rather than assumed: the GUC's pg_settings.context is sighup, and a conf append plus one pg_reload_conf() moved it from off / source = default to on / source = configuration file. The gated E2E pins context = 'sighup' against the bundled TimescaleDB, so if it ever became restart-only that reasoning goes red instead of the comment quietly becoming fiction.

The exception is the adopted-listener path: when a postmaster is already running, this service neither stops nor signals it, so the heal waits for the next service-owned start. No reload is issued, and that is a decision. v9 and v10 carry the same exposure and the same choice; signalling a server this service did not start is the same class of act as stopping one; and a reload would apply this block while leaving the restart-only settings the same heal may have just appended (v2/v3/v4/v5/v7) inert. A half-applied conf is worse than a consistently deferred one — it removes the operator's ability to reason about the server's state from "did the service own this start".

Existing clusters: logging starts now, and there is nothing to recover

A store that has been running without the GUC wrote no per-run rows, and TimescaleDB does not retain what it was told not to record. The append's log line states that rather than implying it, and so does the On note in the MCP response: coverage begins at the moment logging was switched on, so an empty job_history window that predates the heal is expected and is not evidence about those runs. job_stats remains the unconditional surface — which is why every shipped read already uses it, and why no shipped read had to change here.

One thing the append cannot beat, and the reason the check reads the effective value rather than the marker: postgresql.auto.conf is read after postgresql.conf, so an ALTER SYSTEM SET ... = off wins. Measured — with the appended block last in postgresql.conf, the effective value stayed off with sourcefile naming postgresql.auto.conf. A marker check would have called that store healed.

Legibility: the check, not the doc

Recommended and built: a check, in get_store_metrics. Not documentation, for two reasons. The redirect is issued by the product, in that tool's own description, so a product that sends a caller to an instrument should say whether it is switched on. And the documentation half already existed — TheDescription_...NotAMaximum has required the description to name job_history since #3119, and passed the entire time job_history was empty on every older store. Naming a route is not the route working. TheDescription_SaysJobHistoryNeedsItsGucOn_AndTheResponseReportsIt asserts the sentence and the shipped read together, so either half disappearing lands there rather than leaving advice to go look somewhere this tool declines to look.

No shipped read queries job_history — checked; every one uses job_stats, deliberately, and TimescaleSupport cites job_history only as the provenance of a constant. So there was no read to gate; the surface that needed the check is the one that redirects.

Verification, and what it does not cover

CI caught two, both mine, and the second one taught the more interesting thing. Round 1: Darling Linux build pass 1m56s, review pass 5m13s, verify pass 5m43s, check-branches pass 4s, description-drift pass 8s, and Darling PostgreSQL tests FAIL at 4m41s — 8,161 tests, 8,154 passed, 6 not executed, 1 failed: ExistingStore_GainsJobExecutionLogging_OnNextStart_Gated, Expected: 1 Actual: 2. Not the product: the assertion counted shared_preload_libraries = as a substring, and initdb's generated postgresql.conf already documents the setting as a commented line, so a healthy cluster reads 2. The ungated twin could not have caught it, because its fixture held only the product's own blocks and none of initdb's decoys — an isolated fixture hiding the class of bug. Both now count live assignments through one comment-skipping helper, and the ungated fixture carries a stock commented preamble so the same instrument error goes red locally.

Round 2 got past that and failed differently: pg_settings has no row for timescaledb.enable_job_execution_logging — on a cluster whose conf demonstrably carried the preload line, with the count assertions above it all green. The test's own failure message named the wrong cause ("the library is not preloaded"). Measured: timescaledb in shared_preload_libraries loads the loader, and the loader pulls in the versioned library — the one that defines this GUC — only for a database that has the extension installed. From a database created TEMPLATE template0 on 2.30.0/PG17, the GUC has zero pg_settings rows while the loader-defined timescaledb.max_background_workers still has one. EnsureRunningAsync creates the store database; TimescaleSupport creates the extension later in the worker's bootstrap, so the E2E now stands in for that step before reading the setting, and the message names both causes.

Enabling it goes through LiveTimescaleProbe.TryEnableAsync rather than a bare CREATE EXTENSION, and the flag is asserted: that statement terminates the backend when the library is on disk but unpreloaded (#1922), and with no SCHEMA clause it lands the extension on whatever schema resolves first. Worth noting the meta-test that bans the masking shape matches TimescaleSupport.TryEnableAsync call sites, so the hand-rolled statement passed it by not being one — passing a guard by falling outside it is worse than tripping it.

That finding also corrected shipped prose: the NotRegistered note said "this store has no TimescaleDB library loaded", which is one of the two causes and not the one a mid-bootstrap store hits. It now states both and the consequence they share — job_history does not exist on this connection either way. A second probe to split the two causes was considered and left out, because no case is known where they lead to different advice.

The Windows-only suites cannot run on macOS, so the real DarlingManagedPostgresTests.cs, DarlingMcpStoreMetricsToolsTests.cs and StoreLogSeverityLocaleTests.cs were compiled into a throwaway net10.0 console against the shipped build via an xunit shim: 11 executed, 0 failed, 0 missing (the harness treats a wanted-but-absent test as a failure, so a rename cannot read as a clean run). Then 11 mutations killed, each confirmed applied by both a byte check and a non-empty git diff --numstat before the build: the GUC put back in v1, the v11 block writing off, the v1 marker widened to a prefix, a new setting added to v1, Recording leaking to every non-Off state, the two Off notes collapsed, the description's defaults OFF clause dropped, the GUC name retyped into the probe SQL instead of bound, the v11 factory call deleted from EnsureConfAppended, and the ungated pin reverted to the substring instrument (which reproduces CI's Expected: 1 Actual: 2 locally — the category, closed).

The first correction there is mine: deleting the v11 arm looked like it survived until StoreLogSeverityLocaleTests was pulled into the harness. The pre-existing EveryDeclaredConfMarkerIsWrittenByAFactoryEnsureConfAppendedCalls parses EnsureConfAppended's body and requires the factory writing each declared marker to be called from it, so it kills that mutation, ungated. The wiring was already guarded and the harness was under-claiming its own scope.

Two measured survivors, reported because they scope the claim rather than weaken it. Inverting the v11 gate to if (conf.Contains(...)) survives every ungated pin — the body still names the factory — and that is the exact shape of the original defect, a gate that skips when it should append. It is covered only by ExistingStore_GainsJobExecutionLogging_OnNextStart_Gated, which needs a real cluster and therefore only runs in the Windows build job (DARLING_TEST_PGRUNTIME is set there, and the run above proves the gate is live rather than skipping). And removing the stock commented decoys from the ungated fixture also survives — correctly: with an assignment-counting instrument the decoys change no answer. They are a trap for a future wrong instrument, which is what the pair of mutations measures.

The CI path itself was rehearsed locally against a real cluster, so the fix was not shipped on reasoning: a store-like database created TEMPLATE template0 on a TimescaleDB cluster starts at zero pg_settings rows for the GUC, LiveTimescaleProbe.TryEnableAsync returns true, the count goes to one, and the read then returns exactly what the gated E2E asserts — setting = on, source = configuration file, boot_val = off, context = sighup. The only assertion that cannot be rehearsed off Windows is the sourcefile path comparison.

All four states of the new read were measured against real servers, not one measured and three reasoned about — the shipped GetJobExecutionLoggingAsync and the shipped JobHistoryNote driven from a net10.0 harness against three throwaway containers: TimescaleDB with the GUC on (On, recording=true, source = configuration file), TimescaleDB with it unset (Off, source = default, overridden=false), plain PostgreSQL 17 (NotRegistered, every field null), and TimescaleDB with an ALTER SYSTEM ... = off (Off, source = configuration file, overridden=true, and the separate note) — plus the second route into NotRegistered, a TimescaleDB cluster queried from a database with no extension. CI can only show one of those on one cluster.

The gated test rewinds a provisioned conf to the exact field shape — v1 marker present, no v11 block, and no assignment of the GUC anywhere, an absence rather than an off — then takes the reading together with boot_val, source and sourcefile in one row, because on on its own would be worthless: boot_val = 'off' is what proves the observed on is not the value this server would have served regardless.

Review findings, both applied: a dangling <c> reference to a test name that does not exist, and the broad catch now letting OperationCanceledException through rather than reporting a cancellation as an unreadable measurement. One more came out of measuring rather than review: pg_settings.sourcefile is superuser-only, so the MCP's least-privilege role gets a null there — verified with a plain LOGIN role, where setting, source, boot_val and context all came back and sourcefile did not. OffByExplicitOverride keys on source for that reason, and the note and the description no longer promise the filename unconditionally.

One review finding deliberately not taken, and it is a file-ownership call rather than a disagreement. TimescaleSupport.cs:1822-1824 still attributes the GUC to BuildConfAppend, which this PR makes stale. Two open PRs are rewriting that file (#3178 at +528/-229, #3168 at +152/-70) and the sentence sits inside HeaviestHourlyRefreshObservedCeilingSeconds' doc comment — the constant #3168 exists to re-derive — so a one-line fix from here conflicts with both and gets rewritten anyway. Handed over with the replacement text, whose second clause matters more than the builder name: #3168's census premise is scoped to a store where this GUC is on. On any store initdb'd before the boundary the same query returns nothing, and nothing distinguishes that from a clean result — so a ceiling re-derived from job_history is a statement about one store until this PR has been deployed and logging has accumulated.

The heal is confirmed against a real cluster carrying the v1 marker. Darling PostgreSQL tests on the final commit: 4m28s, Total: 8161, Errors: 0, Failed: 0, Skipped: 6, Not Run: 0, Time: 94.412s (and the same shape at 4m36s on 5bcda8a0), with Darling Linux build 1m51s, review, verify, check-branches and description-drift all green. The step list is a real run rather than a fast-path no-op — Initialize and start throwaway PostgreSQL and Run Darling PG tests both success, the pg-runtime build skipped on a cache hit, the failure-artifact upload skipped. And the six SKIPs are enumerated in the log and none of them is new here: two DarlingStoreUpgradeTests upgrade E2Es, three DarlingCollectorRunnerTests live-SQL-Server E2Es (DARLING_TEST_SQL is intentionally unset) and one NpgsqlRootCertificateValidationTests platform case. So ExistingStore_GainsJobExecutionLogging_OnNextStart_Gated and the live probe test both executed — the total is unchanged from the rounds where the gated test failed, which is what rules out "it stopped running".

All eight checks are green on the final commit (6abdff6): build 8m45sLite.Tests Total: 3510, Failed: 0, Skipped: 0, Not Run: 0 and Darling.Tests Total: 8161, Failed: 0, Skipped: 331, Not Run: 0 (331 skips there rather than 6, because that job leaves DARLING_TEST_PG and DARLING_TEST_PGRUNTIME unset — a strict subset of the suite the PG job ran) — plus Darling PostgreSQL tests 4m28s, Darling Linux build 1m49s, Darling whole-tree guards 20s, verify 2m41s, review 2m9s, check-branches 3s, description-drift 14s. Worth recording that build was cancelled in two earlier rounds by the next push landing mid-run: a cancelled conclusion with a plausible five-to-six-minute duration reads like a result and is not one.

One review finding deliberately not taken, and it is a file-ownership call rather than a disagreement. TimescaleSupport.cs:1822-1824 still attributes the GUC to BuildConfAppend, which this PR makes stale. Two open PRs are rewriting that file (#3178 at +528/-229, #3168 at +152/-70) and the sentence sits inside HeaviestHourlyRefreshObservedCeilingSeconds' doc comment — the constant #3168 exists to re-derive — so a one-line fix from here conflicts with both and gets rewritten anyway. Handed over with the replacement text, whose second clause matters more than the builder name: #3168's census premise is scoped to a store where this GUC is on. On any store initdb'd before the boundary the same query returns nothing, and nothing distinguishes that from a clean result — so a ceiling re-derived from job_history is a statement about one store until this PR has been deployed and logging has accumulated.

The heal is confirmed against a real cluster carrying the v1 marker. Darling PostgreSQL tests on the final commit: 4m28s, Total: 8161, Errors: 0, Failed: 0, Skipped: 6, Not Run: 0, Time: 94.412s (and the same shape at 4m36s on 5bcda8a0), with Darling Linux build 1m51s, review, verify, check-branches and description-drift all green. The step list is a real run rather than a fast-path no-op — Initialize and start throwaway PostgreSQL and Run Darling PG tests both success, the pg-runtime build skipped on a cache hit, the failure-artifact upload skipped. And the six SKIPs are enumerated in the log and none of them is new here: two DarlingStoreUpgradeTests upgrade E2Es, three DarlingCollectorRunnerTests live-SQL-Server E2Es (DARLING_TEST_SQL is intentionally unset) and one NpgsqlRootCertificateValidationTests platform case. So ExistingStore_GainsJobExecutionLogging_OnNextStart_Gated and the live probe test both executed — the total is unchanged from the rounds where the gated test failed, which is what rules out "it stopped running".

The Windows build job was cancelled twice by the next push landing while it ran, and cancelled is not passed — a plausible five-to-six-minute duration that reads like a result and is not one. Its partial log is worth more than its conclusion, though: on 5bcda8a0 it got as far as Lite.Tests Total: 3508, Errors: 0, Failed: 0, Skipped: 0, Not Run: 0, Time: 287.100s before the cancellation landed on a later step. Its remaining step, Run Darling tests, carries no env: block (verified in build.yml), so it runs the same Darling.Tests suite with DARLING_TEST_PG and DARLING_TEST_PGRUNTIME unset — a strict subset of what Darling PostgreSQL tests just ran green. It is running again on the final commit.

Not verified: the heal has not been run against a real pre-existing FIELD store — only against a real cluster rewound to exactly that shape (v1 marker present, no v11 block, no assignment of the GUC anywhere). What a field store adds over that is age and accumulated content, neither of which EnsureConfAppended reads. The container measurements are TimescaleDB 2.30.0 / PG 17, not the bundled 2.28.1 / PG 18 — the context = 'sighup' claim is re-pinned against the bundled runtime by the gated test, but the shared_preload_libraries clobber and the ALTER SYSTEM precedence are PostgreSQL semantics measured on 17 and not re-measured on 18. No live store was touched; this changes provisioning code, not a running cluster.

CHANGELOG entry text (not committed — coordinator appends)

Goes under ### Fixed in [Unreleased], and needs one line added to the link-reference block at the bottom of the file: [#3175]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/3175. The #1681 mention is deliberately a bare number, not a reference, so it needs no definition.

  • Darling: the TimescaleDB job-execution-logging GUC now heals on existing stores instead of only fresh ones ([job_history is silently empty on clusters predating ~2026-08-17, because its GUC lives in the one postgresql.conf block EnsureConfAppended cannot heal #3175]) - timescaledb.enable_job_execution_logging is what makes timescaledb_information.job_history record one row per background-job run, and Self-alert FIRINGS are never logged — only resolutions are, so the log shows 'Recovered' with no preceding event #1681 put it in the v1 postgresql.conf block - the one block EnsureConfAppended cannot heal, because it skips a block whose marker it finds and v1's marker is present on every cluster that already exists. So the setting only ever reached a fresh initdb, and every older store has had job_history empty the whole time. That is worse than a plainly missing setting: a maximum over an empty job_history returns zero rows, which reads as "no run exceeded the line" rather than "this instrument is off" - an absence that reads as health. Measured on two field stores running the same binary: one carried all ten markers, no GUC line, an effective off with source = default and ONE history row for 110 jobs; the other carried the line and 39,020 rows. The setting now has its own v11 marker and is moved out of v1 rather than duplicated, so the repository no longer asserts it in the block that cannot deliver it. Existing clusters gain it on their next service-owned start - the append runs before pg_ctl start, so it is live on that very start - and there is no history to recover: logging starts then, which the log line states rather than implies. Not widened, and the harm is measured: re-appending the shared v1 block would clobber shared_preload_libraries, which is list-valued and takes the last assignment as a REPLACEMENT - a conf carrying an operator's 'timescaledb,pg_stat_statements' came back up serving 'timescaledb' alone. get_store_metrics also now reports that GUC's effective value, source and sourcefile on every response, in four states rather than a bool, because that tool's own description redirects a maximum question to job_history and had no way to say whether the route was live - and it reads the effective value rather than the marker because an ALTER SYSTEM in postgresql.auto.conf beats the append, measured. Three new pins close the category rather than the instance: the v1 block's content is frozen (adding a setting there now fails on the commit that types it - the pin whose absence let this through), no marker may be a substring of another (EnsureConfAppended asks with Contains), and a heal must re-apply no v1 setting

)

The GUC that makes timescaledb_information.job_history record anything was
written into the v1 postgresql.conf block, which is the one block
EnsureConfAppended cannot heal: its marker is already present on every
pre-existing cluster, so the append carrying the setting was skipped and it
only ever reached a fresh initdb. A maximum over the resulting empty
job_history returns zero rows, which reads as "no run exceeded the line"
rather than "this instrument is off".

The setting moves to its own v11 marker, the way every setting added after v1
is handled. get_store_metrics now reports the GUC's effective value, source and
sourcefile on every response, because that tool's own description redirects a
maximum question to job_history and had no way to say whether the route was
live.
Comment thread Darling/PerformanceMonitor.Darling.Service/DarlingManagedPostgres.cs Outdated
@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Review

Scope: Darling-only (DarlingManagedPostgres, DarlingStoreMetricsReader, DarlingMcpStoreMetricsTools, StoreSelfMetrics). Confirmed there's no Lite counterpart to keep in parity here — Lite has no self-managed PostgreSQL/TimescaleDB store or get_store_metrics tool (it writes DuckDB), so this isn't a parity gap.

Correctness:

  • The v11 EnsureConfAppended block follows the exact same pattern as v1–v10 (checked against the conf snapshot read once at the top of the method, appended-not-rewritten, own marker), and is correctly placed after v8's fingerprint check so it doesn't disturb that check's "no fingerprint line above" invariant. Good.
  • JobExecutionLoggingSql is parameterized ($1) — no injection risk. The GUC name is bound from a single shared constant (StoreSelfMetrics.JobExecutionLoggingSetting) rather than retyped in both the conf-writer and the prober, which is exactly right for the failure mode this PR is fixing (a silent drift would degrade to "server has no such setting" rather than erroring).
  • Read-probe (GetJobExecutionLoggingAsync) is try/catch (Exception) with no OperationCanceledException exclusion — every other broad catch in TimescaleSupport.cs in this codebase uses catch (Exception ex) when (ex is not OperationCanceledException). Here it looks intentional per the doc comment ("a precondition check must never be able to fail the read it qualifies"), and the call site doesn't thread a real cancellation token today, so low risk — flagging only because it's a deviation from the prevailing local convention.
  • Left one inline comment: a dangling <c> cross-reference to a nonexistent test name in DarlingManagedPostgres.cs.

Security: No new file/process/network surface; SQL is parameterized; nothing user-controlled reaches the query.

Performance: Adds one small, indexed pg_settings lookup per get_store_metrics call (via the pooled data source, not a dedicated connection like the retention-hold read a few lines up) — negligible.

No missing-index suggestions per your instructions, and none were relevant here anyway (no new T-SQL).

…t reference

The gated E2E asserted "exactly one shared_preload_libraries" with a substring
count, which reads 2 on a healthy cluster: initdb's generated postgresql.conf
already documents the setting as a commented line. CI caught it; the ungated
twin could not, because its fixture held only the product's own blocks. Both
now count live assignments through one comment-skipping helper, and the ungated
fixture carries initdb's commented decoys so the same instrument error goes red
locally.

Also from review: the v11 marker's doc comment referenced a test name that does
not exist, and the pg_settings probe now lets OperationCanceledException through
rather than reporting a cancellation as an unreadable measurement. The
sourcefile column is superuser-only, so the note and the tool description no
longer promise it unconditionally.
@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Reviewed the full diff (both commits) against CONTRIBUTING.md's conventions.

Summary: No correctness, parity, or security issues found. This is a Darling-only change (TimescaleDB conf healing + get_store_metrics job_history precondition reporting) — Lite has no PostgreSQL/TimescaleDB store or get_store_metrics MCP tool, so there is no parity gap to flag.

What I specifically checked and found solid:

  • Marker-drift protection: ConfMarkerV11 is one of 11 ConfMarker* constants; EveryConfMarker_IsDistinct_AndNoneIsASubstringOfAnother correctly enumerates all 11 via reflection and the substring-safety claim holds (v1's marker text at the position where later markers insert their (vN ...) segment differs, so it's not a prefix of any of them).
  • Single source of truth for the GUC name: StoreSelfMetrics.JobExecutionLoggingSetting is referenced by constant at all three sites (conf writer, MCP reader, log line) — verified no retyped copy exists anywhere in Darling/.
  • EnsureConfAppended placement: the new v11 check reads the same conf snapshot captured once at the top of the method, consistent with how v9/v10 do it, and it's placed after the v8 fingerprint check per the method's own documented invariant (no block before v8 may write a fingerprint line).
  • SQL parameterization: JobExecutionLoggingSql binds $1 via AddWithValue, no string interpolation of the setting name into SQL — same positional-parameter idiom used throughout Darling.Service.
  • Second commit's fix is real: switching from a substring count (Contains(name + " = ")) to a comment-skipping live-assignment count is correct — initdb's generated postgresql.conf really does emit every setting as a commented default line, so the old assertion was counting decoys.
  • OffByExplicitOverride correctly keys off source rather than sourcefile, since sourcefile/sourceline are superuser-only in pg_settings and the MCP role is least-privilege — the code and the description text were both updated consistently in commit 2 to stop promising sourcefile unconditionally.
  • Cancellation handling: the second commit's catch (Exception ex) when (ex is not OperationCanceledException) is a correct, deliberate exception — a cancelled caller shouldn't get back Unreadable as if it were a measurement.

Nothing rises to a blocking or even a nit-level comment; the PR's own description already documents the two review findings that were applied (dangling <c> test-name reference, the OperationCanceledException catch) and a couple of honestly-scoped known gaps (no real pre-existing field cluster tested, PG18/2.28.1 not re-measured for the shared_preload_libraries/ALTER SYSTEM precedence claims) — those are reasonable to leave as follow-up given the mechanism (conf append + effective-value read) doesn't change between PG17 and PG18.

@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Reviewed the diff (Darling-only: DarlingManagedPostgres.cs, StoreSelfMetrics.cs, DarlingStoreMetricsReader.cs, DarlingMcpStoreMetricsTools.cs, plus their tests). No Lite counterpart is needed here — this is Darling's managed-PostgreSQL conf healing and an MCP read, neither of which has a Lite/DuckDB analogue, so no parity gap.

Correctness: the v11 marker/block, the removal from BuildConfAppend, and the EnsureConfAppended gating all check out — placed after v8 (so it doesn't carry a fingerprint line and doesn't perturb the v8 staleness check), before pg_ctl start (so it's live without a reload on a service-owned start), and gated on the same conf snapshot read at the top of the method like v9/v10. The GUC name is a single constant (StoreSelfMetrics.JobExecutionLoggingSetting) consumed by both the conf writer and the pg_settings probe, so a rename can't drift between them. AddWithValue(value) for the positional $1 parameter matches the established pattern used throughout the other Mcp/*.cs readers. The four-state JobExecutionLoggingStatus (including the Off/OffByExplicitOverride split) and the Unreadable failure-isolation in GetJobExecutionLoggingAsync look right, and the new tests (marker substring-independence, the v1-freeze pin, the healing invariant using a decoy-laden fixture) are the kind of tests that would have actually caught #3175 and would catch a regression of it.

One doc-drift nit (not in the diff, so flagging here instead of inline): Darling/PerformanceMonitor.Darling.Storage/TimescaleSupport.cs lines 1822-1824 still say timescaledb_information.job_history's succeeded column exists "because DarlingManagedPostgres.BuildConfAppend turns timescaledb.enable_job_execution_logging on (#1681)". That's now stale — the setting moved to BuildJobExecutionLoggingConfAppend/v11 per this PR. Given this codebase's stated comment-accuracy bar (and that a stale comment about this exact mechanism is what let #3175 happen in the first place), worth a one-line fix while it's fresh.

No security, injection, or performance concerns — the new SQL is a single parameterized pg_settings lookup with no schema-qualification issue (it's a catalog view, not user DDL), and the added JSON block is O(1) extra work per get_store_metrics call.

CI's second round said pg_settings had no row for the GUC on a cluster whose
conf carried the preload line, and the test's failure message named the wrong
cause. Measured: timescaledb in shared_preload_libraries loads the LOADER, and
the loader pulls in the versioned library that defines this GUC only for a
database that has the extension. From a database created TEMPLATE template0 the
GUC has zero pg_settings rows while the loader-defined
timescaledb.max_background_workers still has one.

EnsureRunningAsync creates the store database; TimescaleSupport creates the
extension later in the worker's bootstrap. The gated E2E now stands in for that
step before reading the setting, and its failure message names both causes.

The NotRegistered note said "this store has no TimescaleDB library loaded",
which is one of the two causes and not the one a mid-bootstrap store would hit.
It now states both and the consequence they share: job_history does not exist on
this connection either way.
…E EXTENSION

A bare CREATE EXTENSION IF NOT EXISTS timescaledb TERMINATES THE BACKEND when
the library is on disk but absent from shared_preload_libraries (#1922), and
with no SCHEMA clause it lands the extension on whatever schema resolves first.
LiveTimescaleProbe handles both and returns a flag, so the precondition is
asserted instead of assumed: a store that could not be enabled now says so
rather than presenting as a setting that is absent.

The meta-test that bans the masking shape matches TimescaleSupport.TryEnableAsync
call sites, so a hand-rolled statement passed it by not being one — which is
worse than tripping it.
@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Reviewed this PR end-to-end (all 5 commits) against CONTRIBUTING.md's conventions, correctness/edge-cases, Lite/Darling parity, security, and performance. No issues found — this is a clean, well-verified fix. Notes from the review:

Correctness

  • Confirmed BuildConfAppend (v1) now only writes 4 settings (shared_preload_libraries, port, listen_addresses, default_toast_compression), matching the frozen list ConfV1Block_ContentIsFrozen_ANewSettingNeedsItsOwnMarker asserts — the GUC really was moved out, not duplicated.
  • Verified all 11 ConfMarker* constants are distinct and none is a substring of another (the v1 marker's -- vs. v2-v11's (vN ...) -- really does save it).
  • EnsureConfAppended places the new v11 check after v9/v10 and before the method returns, consistent with the "no fingerprint line" invariant the v8 staleness check depends on, and it's called unconditionally before the "already running / adopted listener" branch in EnsureRunningAsync — so the documented "heal always writes the file; the adopted path just defers the reload" behavior is accurate, not just asserted in comments.
  • JobExecutionLoggingSql is parameterized (WHERE name = $1, unnamed AddWithValue), matching the established positional-parameter idiom used elsewhere in DarlingCollectorCostReader/DarlingObjectStatsReader/etc. No injection concern.
  • The four-state enum (Unreadable/NotRegistered/Off/On) and OffByExplicitOverride (keyed on source, not the superuser-only sourcefile) correctly avoid inventing an answer the probe didn't measure, and the failure-isolation in GetJobExecutionLoggingAsync can't fail the get_store_metrics response it qualifies.

Lite/Darling parity

  • No parity gap. timescaledb_information.job_history / get_store_metrics are Darling-only (PostgreSQL/TimescaleDB-specific); Lite's own job_history table is an unrelated SQL Agent history collector. Nothing in Lite/ needed a matching change.

Security / performance

  • No new file/network/process surface; the new read is one extra pg_settings lookup per get_store_metrics call, isolated with the same command-timeout convention (McpCommandDeadlines.ReadSeconds) as the reader's other queries.

Nice catch-and-fix cycle on the CI failures baked into this branch's history (substring-vs-assignment counting, the loader-vs-versioned-library preload distinction) — both fixes are correctly reflected in the final diff.

@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Reviewed against CONTRIBUTING.md conventions and the correctness/parity/security/perf checklist. No T-SQL touched here (pure C#/Npgsql, Darling-only — TimescaleDB provisioning and MCP read path), so the T-SQL style rules don't apply.

Parity: No Lite counterpart exists for TimescaleDB conf management or job_history/job_execution_logging — this is Darling/PostgreSQL-specific functionality with no DuckDB equivalent, so there's no parity drift to flag.

Correctness:

  • The v11 marker follows the exact established pattern for v2–v10 (EnsureConfAppended checks conf.Contains(ConfMarkerV11) before appending, same as every prior versioned block) — verified against DarlingManagedPostgres.cs:1388-1554.
  • Verified BuildConfAppend now emits exactly the 4 settings the new ConfV1Block_ContentIsFrozen_ANewSettingNeedsItsOwnMarker test pins (default_toast_compression, listen_addresses, port, shared_preload_libraries) — the removed timescaledb.enable_job_execution_logging line is fully gone from the builder, only left as a source comment (which doesn't leak into the returned string, so the DoesNotContain assertions in the new tests are sound).
  • JobExecutionLoggingSql is parameterized (WHERE name = $1 + positional AddWithValue), matching the existing pattern in the same file (e.g. line 322) — no SQL injection surface.
  • The GUC name constant is defined once (StoreSelfMetrics.JobExecutionLoggingSetting) and consumed by both the conf-writer and the reader, closing off the drift risk called out in the PR description.
  • GetJobExecutionLoggingAsync's failure isolation (catch-and-report-Unreadable, explicitly re-throwing/propagating OperationCanceledException) is consistent with the review finding mentioned in the PR description and matches the "never fail the response it qualifies" contract.
  • LiveTimescaleProbe referenced in the new gated E2E test already exists in Darling.Tests — not a dangling reference.

Security: No new input handling, no secrets, no file/process/network surface beyond the existing Npgsql/postgresql.conf append pattern already used for v2–v10.

Performance: The new job_history precondition read is one extra pooled-connection round trip on get_store_metrics, isolated with its own try/catch so it can't fail or block the rest of the response — reasonable given it's a single indexed catalog lookup (pg_settings by name).

No findings to raise — this is a solid, narrowly-scoped fix with strong test coverage (unit + gated E2E) for the actual defect (v1 marker being unhealable) and the MCP-side blind spot it created.

@claude

claude Bot commented Sep 8, 2026

Copy link
Copy Markdown

Reviewed. This is a Darling-only change (TimescaleDB job_history has no Lite/DuckDB analog, so no parity gap to flag) and it's unusually well-substantiated — two-store field measurements, mutation testing, and a real gated E2E against the bundled runtime.

Checked specifically:

  • The move is complete and non-duplicated. timescaledb.enable_job_execution_logging is cleanly removed from BuildConfAppend (v1) and lives only in the new BuildJobExecutionLoggingConfAppend (v11), appended last in EnsureConfAppended after v10 — consistent with the pattern every other post-v1 setting uses, and consistent with the v8 fingerprint check's invariant that no block between v9 and the end writes a fingerprint line.
  • v1 freeze list matches reality. ConfV1Block_ContentIsFrozen_ANewSettingNeedsItsOwnMarker pins v1 to exactly default_toast_compression, listen_addresses, port, shared_preload_libraries — verified against BuildConfAppend's actual output.
  • The marker-name constant is shared, not retyped, between the conf-writer (DarlingManagedPostgres) and the probe (DarlingStoreMetricsReader.JobExecutionLoggingSql) via StoreSelfMetrics.JobExecutionLoggingSetting — placed on the platform-neutral side specifically to avoid the Windows-only [SupportedOSPlatform] tag leaking onto the read path. Reasonable.
  • The four-state read (Unreadable/NotRegistered/Off/On) and OffByExplicitOverride are internally consistent: Off is only "override" when source is present and non-default, which correctly distinguishes an unhealed store (source = default) from an ALTER SYSTEM override the v11 append can never beat (since postgresql.auto.conf reads last).
  • The broad catch that swallows everything except OperationCanceledException in GetJobExecutionLoggingAsync matches the established codebase-wide convention (same shape used throughout DarlingCommandExecutor, DarlingRetention, DarlingCollectorRunner, etc.), so it's not a one-off pattern deviation.
  • SQL is parameterized (WHERE name = $1 via positional AddWithValue), no injection surface; no secrets or new file/process/network surface beyond the existing managed-conf-append mechanism this block reuses verbatim.
  • Style: comments correctly carry WHY/measurements per the T-SQL-adjacent PostgreSQL conventions in CONTRIBUTING.md; this PR touches no T-SQL.

No correctness bugs, parity gaps, or security issues found. The one thing knowingly left stale — TimescaleSupport.cs:1822-1824's doc comment still attributing the GUC to BuildConfAppend — is disclosed in the PR description as a deliberate handoff to #3178/#3168, which are already rewriting that file, so I'm not re-flagging it here.

@erikdarlingdata
erikdarlingdata merged commit 0034254 into dev Sep 8, 2026
8 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/3175-job-execution-logging-marker branch September 8, 2026 15:43
erikdarlingdata added a commit that referenced this pull request Sep 8, 2026
#3175/#3177 gave timescaledb.enable_job_execution_logging its own conf marker,
so existing stores heal. That does not widen either census: both reads predate
the heal, and a later one would have to state its own scope rather than
inherit this one's.
erikdarlingdata added a commit that referenced this pull request Sep 8, 2026
…on, and re-derive the compression grid with it (#3178)

* Re-derive HeaviestHourlyRefreshObservedCeilingSeconds from a job_history census

The constant was 594 s, the maximum of a 16-run record that mixed a census
of the boundary day's tail with a sample of the days after it. The census
read the comment named as the fix has been done: every run of job
policy_refresh_continuous_aggregate query_store_stats_interval_hourly since
the 13:44:23 boundary, one row per run from
timescaledb_information.job_history, read at 2026-09-08 01:37Z.

57 succeeded runs after the boundary, 194 s to 896 s, median 418 s, none
failed and none without a finish time; 304 runs at or before it, median
1081.7 s, maximum 13300.7 s. The estimator is unchanged, so the constant is
896.

Two pre-registered triggers fired together. The 95th percentile is no longer
the maximum at 57 readings (830 s, 66 s below it), so the sample-size half of
the maximum-versus-percentile argument is retired and the decision is re-taken
on the half that never referenced n. And the sizing figure now sits 146 s
ABOVE RefreshSlotWarningSeconds, so every assertion holding the grid clear of
it is false. Those are left with their conditions exactly as written.

* Drop the "well inside one phase slot" margin from the two places that state it

At 896 s of a 900 s slot the refresh still fits, so "inside one phase slot"
is true and load-bearing; the margin that made it "well inside" is 4 s and
naming it as comfort is the claim that has stopped being true.

* Give every deliberately-red assertion its own note, not three of six

Three of the six failing methods carried a comment explaining why they are
left failing and which decision owns the remedy; three did not, so the same
inversion read as an oversight in half the places it appears. Conditions are
unchanged in all six.

NoCompressionMinuteStartsWhileTheHeaviestRefreshIsStillRunning also needed the
distinction its two halves now have: the grid clearance genuinely passes (the
nearest compression minute is 1,320 s past the heaviest start), and only the
watch-line ordering and the 26%-gap literal derived from it are false.

* Retire the second reason the excluded run was out, where it was still asserted

The open-question paragraph closed on "the excluded run is disqualified by
its duration alone", which was the belt to the boundary's braces. At a 896 s
population maximum 864 s is an ordinary member of the post-boundary range, so
that belt is gone and the sentence was contradicting the paragraph above it.
The positional rule needs no second reason, which is why it was chosen over
one.

* Re-derive the refresh grid so contention cannot depend on list position

The hourly phase map is injective now: the heaviest refresh is answered by
identity and every other policy takes its own consecutive minute, so thirteen
policies hold thirteen distinct minutes at any list order. The hour is three
derived bands - the light band and its guard, the heaviest refresh's window,
the compression band - and the window is the remainder, so nothing sizes
itself from the ceiling it has to hold.

The compression grid is re-derived from the same rule rather than renumbered,
the guard band comes from the light refreshes' own ceiling, and the band's
width comes from the catalog and a stated per-minute spread.

* Re-derive OtherHourlyRefreshObservedCeilingSeconds from a job_history census

226.8 s over 874 runs of the twelve non-heaviest hourly refresh policies,
post-boundary, with nothing removed by the succeeded/finish filter. The
midnight regime stays in, because the guard band is now derived from this
figure and a readout of a margin has to include the runs that consumed it.

The census's shape, the midnight mechanism behind the two largest runs, and
the guard band the ceiling sizes are all pinned against the constants rather
than restated.

* Point four figures at the re-derived window instead of the 15-minute slot

PercentOfSlot's doc quoted 99.6%, which was 896 against a 900 s slot; against
the window the hour can spare it is 71.1%, which is what the test asserts.
The narrowing pin's margin, the population clause's warning-band note and one
watch-line figure were reading the same way.

* Scope both job_history censuses to the one store whose GUC is on

timescaledb_information.job_history only records executions where
timescaledb.enable_job_execution_logging is on, it is off by default, and the
conf block that sets it cannot be healed onto a cluster that predates it - so
a maximum over that view on an older store returns zero rows and reads as
nothing exceeded the line. Both censuses are one store's, said as a
precondition of the read rather than as a caveat about the workload.

The refresh-slot warning line names that route, so it now names the condition
too: a pin on a pointer's presence cannot tell an operator that following it
may return nothing.

* Test injectivity through the shipped phase map, not a copy of its rule

The rotation control re-implemented the counting rule inline, because the
public map can only be called at the one order HourlyRefreshPhaseOrder has.
That proved the rule injective under permutation and left the shipped method
exercised at exactly one order.

The map now takes the order as a parameter and the product passes its own
list. Only the order is a parameter: the geometry still comes from the
registry, so the seam cannot fabricate a different grid.

* Make the rotation control assert the map responded, per view

Comparing the two minute sequences passes for an overload that ignores its
order parameter, because that still returns a permutation of the unrotated
minutes. What has to change is the minute a named view gets.

* Say the census scope is a property of the read, now that the GUC heals

#3175/#3177 gave timescaledb.enable_job_execution_logging its own conf marker,
so existing stores heal. That does not widen either census: both reads predate
the heal, and a later one would have to state its own scope rather than
inherit this one's.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant