Repository navigation
The at-the-cap aggregate test no longer races TimescaleDB's scheduler (#5603) - #5605
Merged
Merged
Conversation
…re the sweep (#5603) The live quiesce tests that need a running job worker now start it through one helper that returns only when the worker is blocked on the gate and the scheduler has finished the wake that launched it, so the scheduler's next wake is about 5 s away while the sweep and its assertions run. The product comments that said the scheduler ends a worker 'within a few seconds' now state the measured timing.
This was referenced Oct 9, 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.
Closes #5603.
SECTION: none (test-only)
No product behaviour changes. The live aggregate quiesce tests no longer need to see a TimescaleDB job worker alive inside a time window. The hold test and the at-the-cap test give their gate function a trap. The trap counts the scheduler's cancel and keeps waiting. The cancel test is built so that the scheduler cannot change its outcome. The product comments on the quiesce sweep give the measured scheduler timing.
Why
CI run 37856872462 ("Darling PG tests (1)") failed
AtTheCap_...atAggregateJobQuiesceTests.cs:445. After the zero-cap sweep the refresh worker was gone (expected 1, actual 0). The server log shows the worker (pid 1776) began its refresh at 23:15:11.889 and was cancelled about 30 ms later. The test had waited only for the worker to be listed.The first fix aligned each test with the scheduler's idle state. It narrowed the race but did not remove it. On a CI runner with one CPU burner per processor (8 live tests x 10 iterations x 4 shards):
origin/dev(run 37867434337) was 40 of 40 green. But 4 of the 40 reportedSkipped: 1. The onlyAssert.Skipin that file is the hold test's "TimescaleDB ended the job worker before the hold could be observed". So the same race happened 4 times, and the old test hid it as a skip.RunningJobWorker_HoldsTheDrop_UntilItExitsfailed atAggregateJobQuiesceTests.cs:392with "the hold was never observed". The alignment gives about 4.7 s before the next wake. The hold test's task start, its wait for the stop and its 2 s look loop all had to finish inside that gap. Under load they did not.The second round (hold and cancel tests read recorded facts, as described below) was run 37872675300: 78 of 80. The hold and cancel tests had 0 failures in 80 iterations. Both failures were
AtTheCap_..., the test that round left as it was.AggregateJobQuiesceTests.cs:503, "the job worker (pid 2288) the sweep must leave running is gone. The scheduler HAD woken since the worker was parked". The sweep's one look saw the worker, skipped and resumed. The worker was gone a moment later.AggregateJobQuiesceTests.cs:493, the zero-cap sweep returned 1 (it dropped the aggregate), expected 0. The one look saw no worker.job 1000 threw an errorfollowed byERROR: invalid transaction termination. Neither log has acanceling statement due to user requestline for that worker.This round measured what that error is, and gives the at-the-cap test the same trap the hold test has.
Measurements (local PostgreSQL 18.6, TimescaleDB 2.30.1, UTC, CI's worker settings)
Measured this round (policy worker parked on a plain gate or on the test's trapping gate):
A cancel of a worker on a plain gate shows up as
invalid transaction termination. Sentpg_cancel_backendto the parked policy worker at 02:40:31.363. The log hasjob 1000 threw an errorat .368 (5 ms later) andERROR: invalid transaction terminationat .392. The worker exited with code 1 at .430. There is nocanceling statement due to user requestline for it. So the error text in the two CI failures is what a cancel looks like on a plain gate.The trapping gate survives the cancel. Same test with the gate function the test plants. The cancel count went to 1. The worker was still listed (
active, waiting on the advisory lock) 1 s and 6 s after the cancel. The log has no error line for it.The scheduler's own cancel is trapped too. The worker was parked on the trapping gate and the jobs were stopped. In 2 runs the cancel count went to 1 and the foreign-cancel count stayed 0. The worker stayed listed for 3.229 s and 3.256 s after the scheduler's wake began. Then the scheduler's SIGTERM ended it.
Stopping the jobs does not wake the scheduler early. 20 runs with a worker parked on a plain gate and the scheduler idle again. The stop came 0 to 4.8 s into the idle gap. The next wake began 129 ms to 4.95 s after the stop. It always began 4.61 to 4.97 s after the scheduler was first seen idle (the timer is 5.0 s). The wake that did the cancel ended the worker 8 to 17 ms after it began.
Which test the passing error belongs to.
Shard 0 has the same error at 02:09:03.219 (refresh began 02:09:02.949), in iteration 2, which passed.
In the three iterations I read, three tests start a worker, in the same order each time. The second one's refresh runs about 5 s, which is the hold test. The third is the at-the-cap test (pid 2288 in iteration 3 matches). By elimination the first one, which holds the iteration-2 error, is
CancelledWhileWaiting_.... That test has no alignment and tolerates the worker's death. It is the same early cancel, 270 ms after launch, in a test that passes anyway.Inferred, not measured: why the cancel arrives 140 ms after launch. The scheduler has a wake that handles the new worker's start. Under load it can run after the worker is already blocked on the gate.
The test's idle check can already be true from the scheduler's earlier idle state, so the sweep stops the jobs before that wake runs. That wake then sees a stopped job and cancels the worker. This fits both CI failures and the passing iteration-2 case. The 20 runs above show that the stop itself does not wake the scheduler early, which leaves a wake that was already pending. It was not reproduced, because that needs the CPU load of the runner.
Measured in the earlier rounds:
WARNING: job 1000 did not exit after SIGINT, sending SIGTERMandFATAL: terminating background worker. A worker that does not swallow the cancel exits at once withjob 1000 threw an error. With a worker parked on the gate, the cancel reached the gate 4.96 to 4.99 s after the stop in 19 runs. The worker was gone 3.2 to 3.34 s after the cancel.stop_background_workers()? No (gone 1 ms after the call), so stopping the scratch database's scheduler cannot be used.pg_stat_activityrow at each swallowed cancel sawstate = activein 11 of 11 runs. Eight more runs traced the row for the whole time the worker lived after the cancel. It stayedactivewith an unchangedstate_changethroughout. A cancel at any other time did not come from the scheduler.ON ddl_command_start WHEN TAG IN ('DROP VIEW', 'DROP MATERIALIZED VIEW')fired once for the product's DROP inside itsDO $do$block. It saw the worker listed inpg_stat_activity, while that DROP was still waiting. So it fires before the DROP waits on the worker's locks.What changes
Darling/Darling.Tests/AggregateJobQuiesceTests.cs:AtTheCap_...(this round). Its scratch database getsPlantTrappingGateAsync. The idle alignment is gone: the worker is started withStartBlockedWorkerAsynclike the hold test's. The scheduler can now cancel the worker at any wake after the stop. The trap counts that cancel, and the worker survives 3 s or more after it. The zero-cap sweep and its assertions take milliseconds. Every existing assertion stays. One new assertion:w5551_foreign_cancels= 0. It is read once the worker is gone. A cancel the sweep itself sent is swallowed by the same trap, and the handler counts it a few milliseconds later. The failure message of the still-running check now names the gate's cancel counts. The test does not require a cancel to happen, and has no "or the worker is gone" branch.StartParkedWorkerAsync,ParkedWorker,SchedulerIdleSinceAsyncandSchedulerWokeSinceAsync, and the unusedusing NpgsqlTypes. Nothing else used them.RunningJobWorker_HoldsTheDrop_UntilItExitsandCancelledWhileWaiting_...(second round, code unchanged this round). The hold test's gate catchesquery_canceled, callsnextval('collect.w5551_cancels')and waits again. The test waits (60 s safety bound only) until the count is at least 1. That count proves the worker outlived the stop, however slowly the test ran. Every per-look assertion stays, plus the foreign-cancel count and an event-trigger count of DROPs that started beside a worker. The cancel test uses a ten-minute poll, so its cancel always lands in the wait.ZeroCapdoc now say only that the worker survives 3 s or more after a scheduler cancel. The text that said the sweep fits inside an idle gap is gone.Darling/PerformanceMonitor.Darling.Storage/TimescaleSupport.cshas two comments from the second round that give the measured timing. They say the next wake comes tens of milliseconds to about 5 s after the stop. They say a worker that ignores the cancel is gone after 8 s at most. Nothing in them became untrue, so this round leaves them as they are.Audit of every live test in
AggregateJobQuiesceLiveTestsSweep_StopsTheAggregatesJobsBeforeTheDrop...,EmptyFinalLookAtTheCap_...,FailedDrop_...,Reshape_...,PlainViewAndPlainPostgresStore_...: safe. No worker is ever running, because every policy starts a day out.RunningJobWorker_HoldsTheDrop_UntilItExits: recorded facts (trap and event trigger).CancelledWhileWaiting_...: ten-minute poll.AtTheCap_...: the CI failure. Now the trap, with the foreign-cancel check.Test plan
*AggregateJobQuiesce*(15 tests, including the 8 live ones) against a local PostgreSQL, 3 times in a row on the final head. Total 15, Failed 0 each time.*Census*495,*Ratchet*15,*Scrub*123,*Guard*338,*Hygiene*90,*DocComment*78,Stage=Guardtrait 1444. Failed 0 in each.AtTheCap_...this round. Each plant is one product line inTimescaleSupport.cs. Built, run, then reverted, andgit statuswas clean after each:Assert.Fail)w5551_foreign_cancels= 0, line 516#5551pg_cancel_backendin the wait loop) went RED onw5551_foreign_cancels. P9b (pg_terminate_backendin the wait loop) went RED on "gone and its gate never counted a cancel". P7 (no wait after the stop) went RED in the hold, cancel and at-the-cap tests. P5 (skip instead of drop on two empty looks) and P8 (no resume on cancel) went RED on their assertions.AggregateJobQuiesceTests.cs.darling-pgjob. Every shard reported 10 passed, 0 failed. Every iteration ran all 8 live tests: Total 8, Failed 0, Skipped 0. SoAtTheCap_...had 0 failures in 80, against 2 in the previous round, and no test was skipped. The cause of the early cancel stays inferred (see the Measurements section). The proof is this run plus the plants above.Fixes #5603