Cc/fix flaky tests - #2032
Closed
tuhaihe wants to merge 6 commits into
Closed
Cc/fix flaky tests#2032tuhaihe wants to merge 6 commits into
tuhaihe wants to merge 6 commits into
Conversation
The regex that picks failed test files out of prove's "Test Summary
Report" required leading whitespace, but prove prints those lines flush
left:
Test Summary Report
-------------------
t/019_replslot_limit.pl (Wstat: 7424 (exited 29) Tests: 9 Failed: 2)
Nothing ever matched, so for the TAP suites (ic-recovery) the parser
reported STATUS=failed together with FAILED_TESTS=0 and PASSED_TESTS=0,
and the job summary claimed "Failed Tests | 0" while the job was red.
Match the line as prove actually prints it. On the ic-recovery log from
run 33169855823 the parser now reports 1 failed test (479 passed) and
names t/019_replslot_limit.pl; parsing of the pg_regress logs is
unchanged.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
The pax and singlenode copies of autovacuum-analyze still poke the stats
collector with
2: select pg_sleep(0.77); -- Force pgstat_report_stat() to send tabstat.
where the isolation2 copy has already moved to
gp_stat_force_next_flush(). Sleeping does not force anything: whether
the INSERT's 1000 tuple modifications have reached the collector by the
time the next query reads pg_stat_all_tables is a race, so
n_mod_since_analyze reads either 1000 or 0.
The pax expected output has that race baked in. Of its three sampling
points, two were captured before the flush and one after:
analyze_count | autoanalyze_count | n_mod_since_analyze
1 | 0 | 0 <- isolation2 says 1000
2 | 1 | 1000
2 | 2 | 0 <- isolation2 says 1000
so the suite fails whenever the collector happens to be quick. It did
so in 6 of the last 60 pushes to main, on both opt-on and opt-off.
Use gp_stat_force_next_flush() in all three copies and correct the two
stale pax values. The pax input file is now byte-identical to the
isolation2 one, and the only difference left between their expected
outputs is relpages, which genuinely differs because pax packs pages
differently.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
…ally gets
verify_cpu_usage() checks abs(measured - expected) <= err_rate, and the
first assertion asks for 90 +/- 10. But rg1_cpu_test runs with
cpu_max_percent=-1 as the only busy group, so it takes essentially every
core and gp_resgroup_status_per_host reports ~100, not 90 -- the true
value sits on the upper edge of the window and any upward sampling
jitter fails the test. The samples from the ic-resgroup-v2 job of run
33224642149 show exactly that:
99.62 99.54 96.61 106.98 99.60 -> mean 100.47, window [80,100]
A single sample of 106.98 is enough, and cpu_usage can exceed 100
because convertcpuusage() divides the cgroup cpu-time delta by a
separately measured wall-clock duration.
The same mistake is in the two-group case: with cpu_weight 100 and 200
and both groups uncapped they split the whole machine, so the shares are
~33 and ~67, not ~30 and ~60. Measured on the same run: 32.40 and
64.93, both still inside the window but off-centre.
Re-centre the three uncapped assertions on 100, 33 and 67, which turns
the margins from (-0.47, 7.60, 5.07) into (9.53, 9.40, 7.93). The three
capped assertions are already correct -- measured 9.93, 10.04 and 20.09
against expected 10, 10 and 20 -- and are left alone. Comments record
why the numbers are what they are.
Averaging all the samples instead of only the first (3fad475) did
not help: all six failures in the last 60 pushes to main are from after
that commit.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
Both tests park the walsender of seg1's primary so that the compact
phase blocks in syncrep, stop the mirror, and then expect the
post-cleanup phase to be taken over by a new vacuum worker:
2: SELECT gp_inject_fault_infinite('wal_sender_loop', 'suspend', dbid) ...
2: SELECT gp_inject_fault('vacuum_ao_after_compact', 'reset', dbid) ...
Injecting the fault only arms it. The walsender parks in it the next
time round WalSndLoop(), and on an otherwise idle cluster that takes a
while - measured on a demo cluster, six consecutive times:
3866 ms 7869 ms 7870 ms 8070 ms 7865 ms 7870 ms
The very next statement resumes the vacuum. If the compact phase
commits inside that window the walsender is still streaming, syncrep is
satisfied by the live mirror, the whole vacuum finishes on the same
gang, ao_vacuum_rel() never sees a NULL vacrelstats in a fresh backend,
and vacuum_worker_changed never fires. Both
gp_wait_until_triggered_fault() calls that follow then burn their full
ten minute ceiling, the test spends twenty minutes and fails, and the
progress views it queries afterwards return no rows because the vacuum
is long gone. That is what the ic-isolation2 failures look like: 11 of
the 57 failed test jobs in the last 60 pushes to main, up to 27 Aug.
Wait until the walsender has really been caught by the fault before
letting the vacuum go on. gp_wait_until_triggered_fault('wal_sender_loop')
is the same pattern pg_rewind_fail_missing_xlog already uses.
Verified on a three-primary demo cluster: three consecutive runs of both
tests pass, in their usual 63 s and 125 s rather than the twenty minutes
a timed-out run takes.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
task.sql creates four tasks just to check that second-based schedule
strings are accepted:
create task valid_task_1 schedule '1 second' as 'select 1';
...
Nothing ever asserts on their execution, but they are created active, so
the scheduler starts firing valid_task_1 once a second and keeps going
until the drops at the end of the file. Two failures follow from that,
and they always appear together.
Every run draws a run id from the cluster-wide Oid counter:
task->runId = NextRunId(); (pg_cron.c)
runId = GetNewOidWithIndex(pg_task_run_history, (job_metadata.c)
TaskRunHistoryRunIdIndexId, ...);
NextRunId() is called unconditionally, not under task_log_run. So a task
left running consumes one Oid per second for the rest of the regression
run, and oid_wraparound, which sets the counter and then asserts on exact
values, drifts by one:
SELECT gp_get_next_oid_master();
- 16387
+ 16388
DROP TASK also deletes the task's pg_task_run_history rows, and the
scheduler updates those same rows as a run moves from starting to
succeeded. When the delete scan meets a row the scheduler has just
updated, simple_heap_delete() returns TM_Updated:
drop task valid_task_1;
+ERROR: tuple concurrently updated (heapam.c:3112)
That aborts the drop, the task survives, and it goes on consuming Oids --
which is why the oid_wraparound failure only shows up in jobs where task
failed first.
The exposure is the window between the creates and the drops. On CI the
task test takes 3.7 to 5.8 seconds, so valid_task_1 fires three to five
times inside it; on an idle machine the test finishes in 0.5 s and the
scheduler never gets a turn, which is why this only fails under load.
Reproduced by holding that window open for five seconds, the length CI
shows:
original 5 scheduler runs per iteration, 25 over five iterations
deactivated 0
Deactivating each task right after it is created keeps the parser
coverage and takes the scheduler out of the picture. ALTER TASK ... NOT
ACTIVE is honoured before a task is ever launched -- ScheduleCronJobs()
skips inactive tasks ("if (!task->isActive) continue") rather than
cancelling them afterwards -- so no run is started at all.
Verified on a three-primary demo cluster: five consecutive rounds of task
followed by oid_wraparound all pass, leaving no rows in pg_task and no
rows in pg_task_run_history. With a task deliberately left running,
oid_wraparound fails the same way CI does, twice in twelve runs, against
zero failures in six runs with none running.
The race between DROP TASK and a running job is a real defect in its own
right and is not addressed here; this only stops the regression suite
from walking into it.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
ca0c180 took Greenplum's change that clamps a physical slot's restart_lsn to the last checkpoint's redo point: XLogRecPtr last_chkpt = GetRedoRecPtr(); if (slot->data.restart_lsn != lsn && slot->data.restart_lsn < last_chkpt) slot->data.restart_lsn = last_chkpt < lsn ? last_chkpt : lsn; but not the matching adaptation Greenplum had already made to 019_replslot_limit.pl. Upstream sets restart_lsn to the standby's flush position, so wait_for_catchup() settles where it lands; with the clamp it tracks checkpoints instead, and wait_for_catchup() says nothing about it. The test reads a primary-side wal_status, which GetWALAvailability() derives from restart_lsn. With a 1MB segment, max_wal_size 4MB and max_slot_wal_keep_size 6MB the two bounds land on 5 and 6 segments, so "extended" only holds when the slot is exactly six segments behind -- a window one segment wide, and the test advances exactly six. Measured, it sits on that edge with nothing to spare: extended|dist=6|safe=1048576 max_wal_size is 4MB and the advances write six, so automatic checkpoints fire throughout and their redo points land wherever they land. One segment further back reads "unreserved" instead, and the "unreserved" subtest that follows then reads "lost". That is the CI failure: # got: 'unreserved' # expected: 'extended' The WAL positions rule out any other cause: the last wait_for_catchup in the failing CI run targeted 0/1F00000, the same LSN a passing local run reaches, so both primaries generated identical WAL and restart_lsn is the only term that can differ. Greenplum's fix takes a CHECKPOINT before recording the position to wait for, at each of the four waits that precede a wal_status check. Waiting for a position captured after the checkpoint makes the reply that satisfies it arrive after that checkpoint, which pins restart_lsn to its redo point. The fifth wait is left alone, as Greenplum leaves it: that subtest is about the state before a checkpoint. Verified on a four-CPU container matching the CI runner. restart_lsn was 0/1800000 or 0/1800028 depending on checkpoint timing before the change and is 0/18000E8 on every run after it; six consecutive runs of the file pass with dist=6 each time, and the whole recovery suite passes. The failure itself never reproduced locally in roughly twenty runs, single file and whole suite, idle and loaded. Injecting one extra WAL segment reproduces it deterministically, which is what pinned the margin at one segment. Assisted-by: Claude Code Backpatch-through: REL_2_STABLE
Member
Author
|
Hi @Alena0704, would you like to take on this PR? This PR is mainly about fixing flaky tests. I noticed you have created some PRs related to this. Perhaps this PR could help you. FYI. |
Contributor
|
Yes, it looks like partly fixed in #2034 |
Collaborator
Yes, sure! I'll take a look. Thank you! |
Alena0704
reviewed
Sep 29, 2026
Alena0704
left a comment
Alena0704
left a comment
Collaborator
There was a problem hiding this comment.
I think we can rephrase commit message like that:
CI: fix parsing of failed TAP test files
prove prints failed file names without indentation, but the parser
expected leading whitespace and skipped them. Make it optional.
Test counts still need a separate fix.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
Member
Author
Good. These changes are made by claude code. I don't quite understand them 100%. So feel free to grab them when available. 😀 |
Alena0704
reviewed
Sep 29, 2026
Alena0704
left a comment
Alena0704
left a comment
Collaborator
There was a problem hiding this comment.
Correct but I suggest to rephrase the commit message:
Fix flaky autovacuum-analyze tests
Replace pg_sleep() with gp_stat_force_next_flush() to force a stats
flush instead of waiting. Update the expected output.
Assisted-by: Claude Code
Backpatch-through: REL_2_STABLE
Collaborator
I'll relook it to understand how to improve the test failure count. |
Alena0704
reviewed
Sep 29, 2026
Alena0704
left a comment
Alena0704
left a comment
Collaborator
There was a problem hiding this comment.
Correct. I would simplify the comment description because it Is easier to understand what is going on through the code than the commit message:
Wait for the wal_sender_loop fault to trigger before resuming VACUUM.
But the current description is fine too.
Collaborator
|
PR with refactored commit messages after review: #2060 |
5 of 13 tasks
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
3 participants
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.
Fixes #ISSUE_Number
What does this PR do?
Type of Change
Breaking Changes
Test Plan
make installcheckmake -C src/test installcheck-cbdb-parallelImpact
Performance:
User-facing changes:
Dependencies:
Checklist
Additional Context
CI Skip Instructions