Repository navigation
Run the Darling bootstrap's first CREATE DATABASE once, on its own deadline (#4352) - #4355
Merged
Merged
Conversation
The bootstrap's first-connection retry covered the pg_database probe and CREATE DATABASE together, both on the 10 s connect-probe deadline. A CREATE DATABASE that times out is cancelled and rolled back, so each retry copied template1 from the start under the same deadline, and a copy slower than 10 s failed all six attempts. The connect and the probe still retry as one unit on the 10 s deadline (OpenProbedMaintenanceConnectionAsync). CREATE DATABASE now runs once, on the probe's own connection, under ServiceCommandDeadlines.BootstrapSeconds. StartupCommandTimeoutTests' member census moves the create into the bootstrap group (34 sites, probe 1) and a source pin keeps it out of the retry. Checkpoint: not yet built; the boot-failure diagnostics for ComposeStoreRolesLiveTests follow.
…4352) BootMigratedAsync now wraps EnsureRunningAsync: any non-cancellation exception is rethrown with the cluster's own server log tail attached (pg_ctl's start log plus every file under the data directory's log/ folder, each under a header, last ~200 lines, read tolerantly). The CI failure artifact for this class does not collect the cluster's temp directory, so a bare 'connection open timed out' or 'CREATE DATABASE timed out' message currently gives no way to see what the server was doing during the stall.
The census (StoreSessionTimeZonePinCensusTests) only accepts a direct PinSessionTimeZoneUtc call on the same constructor line; the retry loop was calling it once into a local and reusing that local across attempts. Move the call inline on the NpgsqlConnection constructor, called once per attempt with the same connection string. No behaviour change: PinSessionTimeZoneUtc is a pure string transform.
erikdarlingdata
marked this pull request as ready for review
September 25, 2026 23:48
This was referenced Sep 25, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Refs #4352.
Leave #4352 open after merge: the stall's root cause is not established; the new diagnostics are meant to capture the next occurrence.
Why
ComposeStoreRolesLiveTestshas failed in CI 4 times since 2026-09-23 06:06Z, out of 659 "Darling PG tests (1)" job runs of the class (it hashes to shard 1), always the same way:No other class fails this way. The failure predates #4280 (2 of 653 runs failed without it, 2 of 6 with it; #4280's start-path additions are no-ops for a fresh cluster, so no mechanism ties it to that PR). All four times, the class runs alone at the end of shard 1, the failing test takes 1:59-2:27, and the next test in the class is slow (19-60s). The stall's root cause is not established: the cluster's own server log lives in the test's temp directory, which the CI failure artifact does not collect.
One mechanism was clear from the code: the old bootstrap retried the connection probe and CREATE DATABASE together on the same 10 s deadline. A CREATE DATABASE that times out is cancelled and rolled back, so every retry re-copies template1 from scratch under the same 10 s window, and a copy slower than 10 s fails all six attempts regardless of the underlying cause.
What changes
Product change (
DarlingManagedPostgres.EnsureDatabaseAsync): the store's first-run CREATE DATABASE now runs once, on the connection that already answered the existence probe, under the 60 sServiceCommandDeadlines.BootstrapSecondsdeadline, instead of being retried up to 6 times inside the 10 s connect-probe deadline. The connect-and-probe step (newOpenProbedMaintenanceConnectionAsync) still retries as a unit on the 10 s deadline, since that covers a different, known race (a backend that loses the post-start shared-memory reservation race dies on its first query). This changes field installs: a first-run database create whose template copy takes longer than 10 s but under 60 s can now finish, instead of restarting the copy from zero on every retry and failing outright.StartupCommandTimeoutTests' member census moves CREATE DATABASE into the bootstrap-deadline group (33 to 34 sites, connect-probe sites 2 to 1) and adds a source pin,TheCreateDatabase_RunsOnce_OutsideTheFirstConnectionRetry, that keeps it out of the retry. Doc comments inServiceCommandDeadlines.cs,DarlingWorker.cs,StartupFailureTriage.cs,DarlingStoreUpgrade.cs, andStartupFailureTriageTests.cswere updated to match.Test-only (
Darling/Darling.Tests/ComposeStoreRolesLiveTests.cs):BootMigratedAsyncnow wrapsEnsureRunningAsync. On any exception other thanOperationCanceledException, it rethrows anInvalidOperationExceptioncarrying the cluster's own server log tail: pg_ctl's start log (pg.log, next to the data directory) plus every file under the data directory'slog/folder (logging-collector output), each under a--- <path> ---header, last ~200 lines, read withFileShare.ReadWrite | FileShare.Deleteso a missing or locked file adds a one-line note instead of throwing from inside the catch block. This does not change what the tests exercise; it is meant to make the next occurrence of this stall attributable from the CI artifact alone.Test plan
dotnet build Darling/Darling.Tests/Darling.Tests.csproj -p:EnableWindowsTargeting=true- 0 errors, 0 warnings.dotnet build PerformanceMonitor.sln -m:1- 0 errors, 0 warnings.timescale/timescaledb:2.30.1-pg18container with template1 bloated to ~15M rows made a plainCREATE DATABASEtake 22s, in the target 15-40s range), but the reflection harness against aProjectReferenceto the service project kept losing sibling projects'ref/assemblies mid-solution build (CS0006) even after full solution and per-project rebuilds; not resolved in the time box.StartupCommandTimeoutTests(Windows-only, CI decides).StartupFailureTriageTests(Windows-only, CI decides).ComposeStoreRolesLiveTests(Windows-only, live-postgres bootstrap, CI decides; the next failure, if any, should now carry a server log tail).CHANGELOG entry
SECTION: Fixed
ENTRY:
CREATE DATABASEwas retried up to 6 times inside the same 10 second window used for the post-start connection probe. Because a timed-outCREATE DATABASEis cancelled and rolled back, every retry re-copied the template database from scratch under the same 10 second budget, so a copy that took longer than 10 seconds failed outright no matter how many retries ran. The create now runs once, on a 60 second budget, outside that retry.REF:
[ComposeStoreRolesLiveTests times out on CREATE DATABASE in CI, twice since #4280 #4352]: ComposeStoreRolesLiveTests times out on CREATE DATABASE in CI, twice since #4280 #4352
For the coordinator
ref/assemblies across the solution's project graph when building outside the solution context), not anything about the fix itself. If this proof still matters, a lane with more time, or one that runs the harness viadotnet runfrom inside a project added temporarily to the solution, would likely get past it faster.pm-pr lane report (census fix)
CI was red on this head (
build,Darling PG tests (1),Darling PostgreSQL tests) for one reason,confirmed the same test in every failing job's log:
Darling.Tests.StoreSessionTimeZonePinCensusTests.EveryStoreConnectionStringSourcePinsItsSessionTimeZoneToUtcThe census only accepts a DIRECT pin —
PinSessionTimeZoneUtc(...)called inline on the samenew NpgsqlConnection(...)line.OpenProbedMaintenanceConnectionAsync's new retry loop called the pin onceinto a local (
pinned) before the loop and reused that local on every attempt, which the census's owndocs call out as the rejected indirect shape (round-1 review on #4285).
Before:
After:
No behaviour change:
PinSessionTimeZoneUtcis a pure string transform of the samebuilder.ConnectionString, now computed once per attempt instead of once before the loop. The retry count,disposal on every failure path, and the deadlines are untouched.
New head:
8255dbb0(merge oforigin/devon top of the pin fix; the merge carried no conflicts).Ran locally (macOS, non-WPF classes only —
Darling.Teststargetsnet10.0-windowswithUseWPF, and thishost's runtime has no
Microsoft.WindowsDesktop.App, so no test class in this project can execute locally;this is a source-scan census, not a live-PG test, so it needs no PG rig either):
dotnet build Darling/Darling.Tests/Darling.Tests.csproj -p:EnableWindowsTargeting=true— build succeeded,0 Warning(s),0 Error(s), both before and after thedevmerge.CI must confirm the census,
StartupCommandTimeoutTests, andStorageCommandTimeoutTestsall pass at8255dbb0— none of that ran locally.