pg.ddx.io pgsql-bugs@postgresql.org mailing list archive
help / color / mirror / Atom feedFrom: Manu <manuelreyesbravo@gmail.com>
To: Zsolt Parragi <zsolt.parragi@percona.com>
Cc: Daniel Gustafsson <daniel@yesql.se>
Cc: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Cc: Masahiko Sawada <sawada.mshk@gmail.com>
Cc: Nikolay Samokhvalov <nik@postgres.ai>
Cc: pgsql-bugs@lists.postgresql.org
Subject: Re: autovacuum: automatically propagate updated parameters
Date: Thu, 24 Sep 2026 18:35:36 -0300
Message-ID: <179028573649.493682.4321152895319402838@gmail.com> (raw)
In-Reply-To: <CAN4CZFP-zBeCPWRHshj+10ofF0-NvPmG47qgP9fGhnS4AAf5LA@mail.gmail.com>
References: <CAN4CZFP-zBeCPWRHshj+10ofF0-NvPmG47qgP9fGhnS4AAf5LA@mail.gmail.com>
Hi,
I ran v3 on REL_19_STABLE (e60ee52841d) with --enable-cassert and
--enable-injection-points, next to Nikolay's v2 and two cut-down copies
of v3, to check the new tests and the polling question from upthread.
1. Each part of the fix has a test that fails without it
v3 tests and injection points, no fix: tests 1-3 pass, 4 fails
v3 without the SetLatch() in
autovac_recalculate_workers_for_balance(): tests 1-4 pass, 5 fails
v3: all pass
2. Stability
test_autovacuum passed 30 of 30 runs on an idle machine, and 20 of 20
with every CPU busy (one busy loop per core), at about 10 s and 16 s a
run.
3. A case the tests don't cover: a worker leaving the balance
Test 5 checks a worker joining while the leader waits. A worker
leaving goes through another path: FreeWorkerInfo() sets
AutoVacRebalance, and the launcher recalculates the count and so does
the SetLatch(). I added it as test 6 (attached, on top of v3): the
second worker joins and is held as in test 5, the leader goes to 400,
then the second worker is released and exits. With v3 the leader,
still in ParallelFinish, logs cost_limit=800 by the first check after
the worker is gone, and the parallel worker ends at 800.
Without the SetLatch() the test stops earlier, at the join, like test
5, so it does not tell the two paths apart. It does show that the
launcher path works, which the current tests don't exercise.
4. Polling vs. waking, measured
With the parallel worker held before its index and the leader waiting
for it for 20 s, the leader's voluntary context switches were:
v3: 0
Nikolay's v2: 199 (9.9 per second)
The time from pg_reload_conf() to the leader logging the new limit was
7 ms with v3 and 8 ms with v2. So the timed wait costs about ten
wakeups a second for as long as the largest index takes, and makes no
difference to how fast a reload is picked up.
5. Things I checked in the code, in case they come up
- The extra SetLatch() does not cut short a busy worker's cost delay:
vacuum_delay_point() sleeps with pg_usleep(), not on the latch, so
"a worker that is busy vacuuming ignores the extra wakeup" holds.
- No wakeup is lost in the wait. The refresh runs at the top of each
pass, before WaitLatch(). A SetLatch() after it makes WaitLatch()
return at once, and one between WaitLatch() and ResetLatch() is
followed by another pass that reads the current count anyway, since
the count is written before the SetLatch().
- The leader also wakes for its workers' messages, but
parallel_vacuum_propagate_shared_delay_params() bumps the generation
only when a value changed, so those wakeups make no worker re-read
its parameters.
The scripts and all outputs are in the second attachment.
Regards,
Manu
diff --git a/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl b/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
--- a/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
+++ b/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
@@ -8,6 +8,7 @@
use PostgreSQL::Test::Cluster;
use PostgreSQL::Test::Utils;
use Test::More;
+use Time::HiRes qw(usleep);
if ($ENV{enable_injection_points} ne 'yes')
{
@@ -395,5 +396,78 @@
$node->safe_psql('postgres',
"SELECT injection_points_detach('autovacuum-worker-cost-balanced')");
+
+# Test 6 (added for review):
+# The reverse of test 5: a worker LEAVES the balance while the leader waits.
+# That rebalance takes another path: the leaving worker sets AutoVacRebalance
+# in FreeWorkerInfo(), and the launcher recalculates the count.
+
+$node->poll_query_until(
+ 'postgres', q{
+ SELECT count(*) = 0 FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND datname = 'regress_db2'
+}) or die "second autovacuum worker from test 5 did not finish";
+
+prepare_for_next_test($node, 6);
+$node->safe_psql('regress_db2',
+ 'ALTER TABLE filler SET (autovacuum_enabled = false)');
+$node->safe_psql('regress_db2', 'UPDATE filler SET id = id + 1 WHERE true');
+$log_offset = -s $node->logfile;
+
+start_leader_waiting_for_worker($node);
+
+# A second worker joins and is held, as in test 5: the leader goes to 400.
+$node->safe_psql('postgres',
+ "SELECT injection_points_attach('autovacuum-worker-cost-balanced', 'wait')"
+);
+$node->safe_psql('regress_db2',
+ 'ALTER TABLE filler SET (autovacuum_enabled = true)');
+$node->wait_for_log(
+ qr/Autovacuum VacuumUpdateCosts\(db=$postgresoid, rel=$testautovacoid, dobalance=yes, cost_limit=400,/,
+ $log_offset);
+
+# Now let the second worker finish and leave, with the leader still waiting.
+my $leave_offset = -s $node->logfile;
+$node->safe_psql('postgres',
+ "SELECT injection_points_wakeup('autovacuum-worker-cost-balanced')");
+$node->safe_psql('postgres',
+ "SELECT injection_points_detach('autovacuum-worker-cost-balanced')");
+$node->poll_query_until(
+ 'postgres', q{
+ SELECT count(*) = 0 FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND datname = 'regress_db2'
+}) or die "second autovacuum worker did not finish";
+my $left_at = time;
+
+# The waiting leader should go back to the whole limit. Poll the log for up
+# to 30 s instead of the default timeout.
+my $seen = 0;
+for (my $i = 0; $i < 300; $i++)
+{
+ if (slurp_file($node->logfile, $leave_offset) =~
+ /Autovacuum VacuumUpdateCosts\(db=$postgresoid, rel=$testautovacoid, dobalance=yes, cost_limit=800,/)
+ {
+ $seen = 1;
+ last;
+ }
+ usleep(100_000);
+}
+my $still_waiting = $node->safe_psql(
+ 'postgres', q{
+ SELECT count(*) FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND wait_event = 'ParallelFinish'});
+note("leader still in ParallelFinish when checked: $still_waiting; waited "
+ . (time - $left_at) . " s");
+ok($seen, 'waiting leader returns to the whole limit when a worker leaves');
+
+release_worker($node);
+$node->wait_for_log(
+ qr/automatic vacuum of table "postgres\.public\.test_autovac"/,
+ $leave_offset);
+my @limits6 =
+ slurp_file($node->logfile, $leave_offset) =~
+ /parallel autovacuum worker updated cost params: cost_limit=(\d+),/g;
+note("parallel worker cost_limit sequence after the worker left: @limits6");
+is($limits6[-1] // 'none', '800', 'parallel worker ends at the whole limit');
$node->stop;
done_testing();
# Review of Zsolt v3 (Bharath approach + tests) for the parallel autovacuum
# cost-parameter wait. All builds from REL_19_STABLE e60ee52841d,
# --enable-cassert --enable-injection-points --enable-tap-tests.
# zsolt + v3
# nikv2 + Nikolay v2 (timed wait)
# nofix v3 tests and injection points, without the parallel.c and autovacuum.c changes
# nowake v3 without the autovacuum.c change (the SetLatch)
======== stability.sh ========
#!/bin/bash
# Run the whole test_autovacuum TAP suite N times on one build and count
# failures; keep the log of every failing run.
# stability.sh <build> <runs> [label]
# LOAD=1 runs it while every CPU is busy (one busy loop per core), the
# kind of machine where timing-dependent tests break.
set -u
B=$1; N=$2; L=${3:-idle}
A=$(cd "$(dirname "$0")" && pwd)
OUT=$A/stability.$B.$L.txt
: > $OUT
if [ "${LOAD:-0}" = 1 ]; then
for _ in $(seq "$(nproc)"); do ( while :; do :; done ) & done
trap 'kill $(jobs -p) 2>/dev/null' EXIT
fi
fail=0
for i in $(seq 1 $N); do
t0=$(date +%s.%N)
if make -C $HOME/pgav/b-$B/src/test/modules/test_autovacuum check > /tmp/claude-1000/stab.$B.log 2>&1; then r=ok; else r=FAIL; fail=$((fail+1));
mkdir -p $A/stability-fail; cp -r $HOME/pgav/b-$B/src/test/modules/test_autovacuum/tmp_check/log $A/stability-fail/$B.$L.run$i 2>/dev/null
cp /tmp/claude-1000/stab.$B.log $A/stability-fail/$B.$L.run$i.make.log; fi
printf '%s run %2d %s %.1fs\n' "$B/$L" $i $r "$(echo "$(date +%s.%N) - $t0" | bc)" | tee -a $OUT
done
echo "$B/$L: $fail failures in $N runs" | tee -a $OUT
======== wakeups.sh ========
#!/bin/bash
# How often the autovacuum leader wakes up while it only waits for a parallel
# worker, and how fast it picks up a config reload, with each proposed fix.
# zsolt v3 (wait in WaitForParallelWorkersToFinish(), woken by the reload
# signal or by SetLatch() on a rebalance)
# nikv2 v2 (timed wait in vacuumparallel.c, 100 ms)
# The parallel worker is held at the build's own injection point before its
# index; the leader goes through its own indexes and then waits. Wakeups are
# the leader's voluntary context switches over HOLD seconds (/proc).
# wakeups.sh [HOLD]
set -u
HOLD=${1:-20}
A=$(cd "$(dirname "$0")" && pwd)
for B in zsolt nikv2; do
I=$HOME/pgav/i-$B/bin
case $B in
zsolt) WPT=parallel-autovacuum-worker-before-index; LPT=parallel-autovacuum-leader-before-index ;;
nikv2) WPT=parallel-vacuum-worker-before-index; LPT=parallel-vacuum-leader-before-index ;;
esac
D=$(mktemp -d /tmp/claude-1000/wk.XXXX); P=55440
"$I/initdb" -D $D -A trust --no-sync -U postgres >/dev/null
cat >> $D/postgresql.conf <<EOF
port = $P
unix_socket_directories = '/tmp'
autovacuum_max_workers = 1
autovacuum_worker_slots = 2
autovacuum_max_parallel_workers = 2
max_worker_processes = 10
max_parallel_workers = 10
log_min_messages = debug2
log_line_prefix = '%m [%p] '
autovacuum_naptime = '1s'
min_parallel_index_scan_size = 0
autovacuum_vacuum_threshold = 100000
autovacuum_analyze_threshold = 100000
autovacuum_vacuum_insert_threshold = -1
EOF
"$I/pg_ctl" -D $D -l $D/log -w start >/dev/null
q() { "$I/psql" -X -qAt -h /tmp -p $P -U postgres -c "$1"; }
q "CREATE EXTENSION injection_points"
q "CREATE TABLE test_autovac (id serial primary key, c1 int, c2 int, c3 int)
WITH (autovacuum_parallel_workers = 1, autovacuum_vacuum_threshold = 50, autovacuum_enabled = false)"
q "INSERT INTO test_autovac (c1, c2, c3) SELECT g, g, g FROM generate_series(1, 10000) g"
q "CREATE INDEX i1 ON test_autovac (c1)"; q "CREATE INDEX i2 ON test_autovac (c2)"; q "CREATE INDEX i3 ON test_autovac (c3)"
q "UPDATE test_autovac SET c1 = c1 + 1"
q "SELECT injection_points_attach('$WPT', 'wait')"
q "SELECT injection_points_attach('$LPT', 'wait')"
q "ALTER TABLE test_autovac SET (autovacuum_enabled = true)"
for _ in $(seq 60); do [ "$(q "SELECT count(*) FROM pg_stat_activity WHERE wait_event = '$LPT'")" = 1 ] && break; sleep 0.5; done
for _ in $(seq 60); do [ "$(q "SELECT count(*) FROM pg_stat_activity WHERE wait_event = '$WPT'")" = 1 ] && break; sleep 0.5; done
q "SELECT injection_points_wakeup('$LPT')"; q "SELECT injection_points_detach('$LPT')"
sleep 2
LEADER=$(q "SELECT pid FROM pg_stat_activity WHERE backend_type = 'autovacuum worker'")
WEV=$(q "SELECT wait_event_type || '/' || wait_event FROM pg_stat_activity WHERE pid = $LEADER")
v0=$(awk '/^voluntary_ctxt_switches/{print $2}' /proc/$LEADER/status)
sleep $HOLD
v1=$(awk '/^voluntary_ctxt_switches/{print $2}' /proc/$LEADER/status)
# reload latency: from pg_reload_conf() to the leader's VacuumUpdateCosts with the new limit
off=$(stat -c %s $D/log)
q "ALTER SYSTEM SET autovacuum_vacuum_cost_limit = 777"
t0=$(date +%s.%N); q "SELECT pg_reload_conf()"
for _ in $(seq 300); do tail -c +$((off+1)) $D/log | grep -q "pid\|cost_limit=777" && tail -c +$((off+1)) $D/log | grep -q "VacuumUpdateCosts.*cost_limit=777" && break; sleep 0.01; done
t1=$(date +%s.%N)
lat=$(echo "($t1 - $t0) * 1000" | bc)
printf '%-6s leader %s waiting as %-28s voluntary wakeups in %ss: %6d (%.1f/s) reload seen after %5.0f ms\n' \
$B $LEADER "$WEV" $HOLD $((v1 - v0)) "$(echo "($v1 - $v0) / $HOLD" | bc -l)" "$lat"
q "SELECT injection_points_wakeup('$WPT')"; q "SELECT injection_points_detach('$WPT')"
"$I/pg_ctl" -D $D -m fast -w stop >/dev/null
cp $D/log $A/wakeups.$B.server.log
rm -rf $D
done
======== build_partial.sh ========
#!/bin/bash
# Zsolt's v3 with parts of the fix taken out, to check that each test fails
# without the part it is meant to test (the tests and injection points stay):
# nofix without the refresh in WaitForParallelWorkersToFinish() and
# without the SetLatch() in autovac_recalculate_workers_for_balance()
# nowake only without the SetLatch()
set -eu
BASE=${BASE:-e60ee52841d}
SRC=$HOME/Proyectos/postgresql
W=$HOME/pgav
A=$(cd "$(dirname "$0")" && pwd)
P=$(ls $A/zsolt-latest/nocfbot-v3-0001-*.patch)
mk() { # name files-to-exclude...
local name=$1; shift
local tree=$W/src-$name
if [ ! -d $tree ]; then
git -C $SRC worktree add -q --detach $tree $BASE
local ex=(); for f in "$@"; do ex+=(--exclude="$f"); done
git -C $tree apply --whitespace=nowarn "${ex[@]}" "$P"
# parallel_vacuum_refresh_cost_params() stays defined but unused when
# parallel.c is excluded; that is fine for a test-only build.
fi
mkdir -p $W/b-$name && cd $W/b-$name
$tree/configure --prefix=$W/i-$name --enable-cassert --enable-injection-points \
--enable-tap-tests --quiet > configure.log 2>&1
make -j"$(nproc)" -s > build.log 2>&1
make -s install > install.log 2>&1
make -C src/test/modules/injection_points -s install >> install.log 2>&1
echo "$name: warnings=$(grep -c 'warning:' build.log) | $(git -C $tree diff --stat | tr '\n' ' ' | sed 's/ */ /g')"
}
mk nofix src/backend/access/transam/parallel.c src/backend/postmaster/autovacuum.c
mk nowake src/backend/postmaster/autovacuum.c
echo PARTIAL-DONE
======== run_test6.sh ========
#!/bin/bash
# Run 003_rebalance_worker_leaves.pl (Zsolt's tests + test 6) on one build.
# The file is copied into the build's source tree for this run only and is
# removed afterwards, whatever the outcome, so it never leaks into other runs.
# run_test6.sh <build>
set -u
B=$1
A=$(cd "$(dirname "$0")" && pwd)
T=$HOME/pgav/src-$B/src/test/modules/test_autovacuum/t
cp $A/003_rebalance_worker_leaves.pl $T/
trap 'rm -f $T/003_rebalance_worker_leaves.pl' EXIT
export PG_TEST_TIMEOUT_DEFAULT=60
make -C $HOME/pgav/b-$B/src/test/modules/test_autovacuum check \
PROVE_TESTS=t/003_rebalance_worker_leaves.pl > $A/test6.$B.log 2>&1
echo "== $B exit=$?"
L=$HOME/pgav/b-$B/src/test/modules/test_autovacuum/tmp_check/log
grep -hE '(ok|not ok) [0-9]+ - |# leader still|# parallel worker cost_limit sequence|die:|Looks like' \
$L/regress_log_003_rebalance_worker_leaves | sed 's/^\[[^]]*\]//' | cut -c1-170
mkdir -p $A/test6-logs/$B && cp $L/* $A/test6-logs/$B/
======== results: stability, idle ========
zsolt/idle run 1 ok 9.9s
zsolt/idle run 2 ok 9.4s
zsolt/idle run 3 ok 9.5s
zsolt/idle run 4 ok 9.9s
zsolt/idle run 5 ok 9.5s
zsolt/idle run 6 ok 9.5s
zsolt/idle run 7 FAIL 9.6s
zsolt/idle run 8 ok 9.7s
zsolt/idle run 9 ok 9.4s
zsolt/idle run 10 ok 9.7s
zsolt/idle run 11 ok 9.7s
zsolt/idle run 12 ok 10.7s
zsolt/idle run 13 ok 9.8s
zsolt/idle run 14 ok 9.8s
zsolt/idle run 15 ok 9.4s
zsolt/idle run 16 ok 9.6s
zsolt/idle run 17 ok 9.6s
zsolt/idle run 18 ok 9.6s
zsolt/idle run 19 ok 9.5s
zsolt/idle run 20 ok 9.3s
zsolt/idle run 21 ok 9.7s
zsolt/idle run 22 ok 10.0s
zsolt/idle run 23 ok 9.8s
zsolt/idle run 24 ok 9.7s
zsolt/idle run 25 ok 9.2s
zsolt/idle run 26 ok 9.5s
zsolt/idle run 27 ok 9.6s
zsolt/idle run 28 ok 9.6s
zsolt/idle run 29 ok 9.4s
zsolt/idle run 30 ok 9.4s
zsolt/idle: 1 failures in 30 runs
NOTE: run 7 above is not a test failure: prove globbed t/003_rebalance_worker_leaves.pl, a file I placed in the source tree by mistake and removed during the run ('Cannot detect source'). t/001_parallel_autovacuum.pl itself passed in run 7 (see stability-fail/zsolt.idle.run7.make.log). Valid result: 001 passed 30 of 30.
======== results: stability, every CPU busy ========
zsolt/load run 1 ok 16.6s
zsolt/load run 2 ok 16.7s
zsolt/load run 3 ok 16.1s
zsolt/load run 4 ok 16.4s
zsolt/load run 5 ok 15.7s
zsolt/load run 6 ok 16.9s
zsolt/load run 7 ok 16.8s
zsolt/load run 8 ok 16.5s
zsolt/load run 9 ok 16.3s
zsolt/load run 10 ok 18.5s
zsolt/load run 11 ok 16.9s
zsolt/load run 12 ok 18.3s
zsolt/load run 13 ok 19.0s
zsolt/load run 14 ok 16.5s
zsolt/load run 15 ok 16.8s
zsolt/load run 16 ok 16.9s
zsolt/load run 17 ok 16.8s
zsolt/load run 18 ok 16.3s
zsolt/load run 19 ok 17.5s
zsolt/load run 20 ok 17.2s
zsolt/load: 0 failures in 20 runs
======== results: v3 tests on the cut-down builds ========
-- nofix
(1.395s) ok 1 - parallel autovacuum on test_autovac table
(1.159s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(30.943s) # die: timed out waiting for file pgav/b-nofix/src/test/modules/test_autovacuum/tmp_check/log/001_parallel_autovacuum_main.log co
(0.104s) # Looks like your test exited with 255 just after 3.
-- nowake
(1.321s) ok 1 - parallel autovacuum on test_autovac table
(1.144s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(0.872s) ok 4 - config reload reaches parallel workers while the leader waits
(31.539s) # die: timed out waiting for file pgav/b-nowake/src/test/modules/test_autovacuum/tmp_check/log/001_parallel_autovacuum_main.log c
(0.103s) # Looks like your test exited with 255 just after 4.
======== results: v3 tests + test 6 ========
== zsolt exit=0
(1.444s) ok 1 - parallel autovacuum on test_autovac table
(1.147s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(1.759s) # parallel worker cost_limit sequence: 250
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(1.194s) ok 4 - config reload reaches parallel workers while the leader waits
(1.684s) ok 5 - cost limit rebalance reaches parallel workers while the leader waits
(0.983s) # leader still in ParallelFinish when checked: 1; waited 0 s
(0.000s) ok 6 - waiting leader returns to the whole limit when a worker leaves
(0.105s) # parallel worker cost_limit sequence after the worker left: 800
(0.000s) ok 7 - parallel worker ends at the whole limit
== nowake exit=2
(1.332s) ok 1 - parallel autovacuum on test_autovac table
(1.256s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(1.657s) # parallel worker cost_limit sequence: 250
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(1.091s) ok 4 - config reload reaches parallel workers while the leader waits
(61.605s) # die: timed out waiting for file pgav/b-nowake/src/test/modules/test_autovacuum/tmp_check/log/003_rebalance_worker_leaves_main.log contents to match
(0.104s) # Looks like your test exited with 255 just after 4.
======== results: leader wakeups while waiting 20 s ========
zsolt leader 272238 waiting as IPC/ParallelFinish voluntary wakeups in 20s: 0 (0.0/s) reload seen after 7 ms
nikv2 leader 278985 waiting as IPC/ParallelFinish voluntary wakeups in 20s: 199 (9.9/s) reload seen after 8 ms
Attachments:
[text/plain] nocfbot-v3-add-test-worker-leaves.diff.txt (3.4K, ../179028573649.493682.4321152895319402838@gmail.com/2-nocfbot-v3-add-test-worker-leaves.diff.txt)
download | inline diff:
diff --git a/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl b/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
--- a/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
+++ b/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
@@ -8,6 +8,7 @@
use PostgreSQL::Test::Cluster;
use PostgreSQL::Test::Utils;
use Test::More;
+use Time::HiRes qw(usleep);
if ($ENV{enable_injection_points} ne 'yes')
{
@@ -395,5 +396,78 @@
$node->safe_psql('postgres',
"SELECT injection_points_detach('autovacuum-worker-cost-balanced')");
+
+# Test 6 (added for review):
+# The reverse of test 5: a worker LEAVES the balance while the leader waits.
+# That rebalance takes another path: the leaving worker sets AutoVacRebalance
+# in FreeWorkerInfo(), and the launcher recalculates the count.
+
+$node->poll_query_until(
+ 'postgres', q{
+ SELECT count(*) = 0 FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND datname = 'regress_db2'
+}) or die "second autovacuum worker from test 5 did not finish";
+
+prepare_for_next_test($node, 6);
+$node->safe_psql('regress_db2',
+ 'ALTER TABLE filler SET (autovacuum_enabled = false)');
+$node->safe_psql('regress_db2', 'UPDATE filler SET id = id + 1 WHERE true');
+$log_offset = -s $node->logfile;
+
+start_leader_waiting_for_worker($node);
+
+# A second worker joins and is held, as in test 5: the leader goes to 400.
+$node->safe_psql('postgres',
+ "SELECT injection_points_attach('autovacuum-worker-cost-balanced', 'wait')"
+);
+$node->safe_psql('regress_db2',
+ 'ALTER TABLE filler SET (autovacuum_enabled = true)');
+$node->wait_for_log(
+ qr/Autovacuum VacuumUpdateCosts\(db=$postgresoid, rel=$testautovacoid, dobalance=yes, cost_limit=400,/,
+ $log_offset);
+
+# Now let the second worker finish and leave, with the leader still waiting.
+my $leave_offset = -s $node->logfile;
+$node->safe_psql('postgres',
+ "SELECT injection_points_wakeup('autovacuum-worker-cost-balanced')");
+$node->safe_psql('postgres',
+ "SELECT injection_points_detach('autovacuum-worker-cost-balanced')");
+$node->poll_query_until(
+ 'postgres', q{
+ SELECT count(*) = 0 FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND datname = 'regress_db2'
+}) or die "second autovacuum worker did not finish";
+my $left_at = time;
+
+# The waiting leader should go back to the whole limit. Poll the log for up
+# to 30 s instead of the default timeout.
+my $seen = 0;
+for (my $i = 0; $i < 300; $i++)
+{
+ if (slurp_file($node->logfile, $leave_offset) =~
+ /Autovacuum VacuumUpdateCosts\(db=$postgresoid, rel=$testautovacoid, dobalance=yes, cost_limit=800,/)
+ {
+ $seen = 1;
+ last;
+ }
+ usleep(100_000);
+}
+my $still_waiting = $node->safe_psql(
+ 'postgres', q{
+ SELECT count(*) FROM pg_stat_activity
+ WHERE backend_type = 'autovacuum worker' AND wait_event = 'ParallelFinish'});
+note("leader still in ParallelFinish when checked: $still_waiting; waited "
+ . (time - $left_at) . " s");
+ok($seen, 'waiting leader returns to the whole limit when a worker leaves');
+
+release_worker($node);
+$node->wait_for_log(
+ qr/automatic vacuum of table "postgres\.public\.test_autovac"/,
+ $leave_offset);
+my @limits6 =
+ slurp_file($node->logfile, $leave_offset) =~
+ /parallel autovacuum worker updated cost params: cost_limit=(\d+),/g;
+note("parallel worker cost_limit sequence after the worker left: @limits6");
+is($limits6[-1] // 'none', '800', 'parallel worker ends at the whole limit');
$node->stop;
done_testing();
[text/plain] nocfbot-av-cost-wait-review.txt (12.2K, ../179028573649.493682.4321152895319402838@gmail.com/3-nocfbot-av-cost-wait-review.txt)
download | inline:
# Review of Zsolt v3 (Bharath approach + tests) for the parallel autovacuum
# cost-parameter wait. All builds from REL_19_STABLE e60ee52841d,
# --enable-cassert --enable-injection-points --enable-tap-tests.
# zsolt + v3
# nikv2 + Nikolay v2 (timed wait)
# nofix v3 tests and injection points, without the parallel.c and autovacuum.c changes
# nowake v3 without the autovacuum.c change (the SetLatch)
======== stability.sh ========
#!/bin/bash
# Run the whole test_autovacuum TAP suite N times on one build and count
# failures; keep the log of every failing run.
# stability.sh <build> <runs> [label]
# LOAD=1 runs it while every CPU is busy (one busy loop per core), the
# kind of machine where timing-dependent tests break.
set -u
B=$1; N=$2; L=${3:-idle}
A=$(cd "$(dirname "$0")" && pwd)
OUT=$A/stability.$B.$L.txt
: > $OUT
if [ "${LOAD:-0}" = 1 ]; then
for _ in $(seq "$(nproc)"); do ( while :; do :; done ) & done
trap 'kill $(jobs -p) 2>/dev/null' EXIT
fi
fail=0
for i in $(seq 1 $N); do
t0=$(date +%s.%N)
if make -C $HOME/pgav/b-$B/src/test/modules/test_autovacuum check > /tmp/claude-1000/stab.$B.log 2>&1; then r=ok; else r=FAIL; fail=$((fail+1));
mkdir -p $A/stability-fail; cp -r $HOME/pgav/b-$B/src/test/modules/test_autovacuum/tmp_check/log $A/stability-fail/$B.$L.run$i 2>/dev/null
cp /tmp/claude-1000/stab.$B.log $A/stability-fail/$B.$L.run$i.make.log; fi
printf '%s run %2d %s %.1fs\n' "$B/$L" $i $r "$(echo "$(date +%s.%N) - $t0" | bc)" | tee -a $OUT
done
echo "$B/$L: $fail failures in $N runs" | tee -a $OUT
======== wakeups.sh ========
#!/bin/bash
# How often the autovacuum leader wakes up while it only waits for a parallel
# worker, and how fast it picks up a config reload, with each proposed fix.
# zsolt v3 (wait in WaitForParallelWorkersToFinish(), woken by the reload
# signal or by SetLatch() on a rebalance)
# nikv2 v2 (timed wait in vacuumparallel.c, 100 ms)
# The parallel worker is held at the build's own injection point before its
# index; the leader goes through its own indexes and then waits. Wakeups are
# the leader's voluntary context switches over HOLD seconds (/proc).
# wakeups.sh [HOLD]
set -u
HOLD=${1:-20}
A=$(cd "$(dirname "$0")" && pwd)
for B in zsolt nikv2; do
I=$HOME/pgav/i-$B/bin
case $B in
zsolt) WPT=parallel-autovacuum-worker-before-index; LPT=parallel-autovacuum-leader-before-index ;;
nikv2) WPT=parallel-vacuum-worker-before-index; LPT=parallel-vacuum-leader-before-index ;;
esac
D=$(mktemp -d /tmp/claude-1000/wk.XXXX); P=55440
"$I/initdb" -D $D -A trust --no-sync -U postgres >/dev/null
cat >> $D/postgresql.conf <<EOF
port = $P
unix_socket_directories = '/tmp'
autovacuum_max_workers = 1
autovacuum_worker_slots = 2
autovacuum_max_parallel_workers = 2
max_worker_processes = 10
max_parallel_workers = 10
log_min_messages = debug2
log_line_prefix = '%m [%p] '
autovacuum_naptime = '1s'
min_parallel_index_scan_size = 0
autovacuum_vacuum_threshold = 100000
autovacuum_analyze_threshold = 100000
autovacuum_vacuum_insert_threshold = -1
EOF
"$I/pg_ctl" -D $D -l $D/log -w start >/dev/null
q() { "$I/psql" -X -qAt -h /tmp -p $P -U postgres -c "$1"; }
q "CREATE EXTENSION injection_points"
q "CREATE TABLE test_autovac (id serial primary key, c1 int, c2 int, c3 int)
WITH (autovacuum_parallel_workers = 1, autovacuum_vacuum_threshold = 50, autovacuum_enabled = false)"
q "INSERT INTO test_autovac (c1, c2, c3) SELECT g, g, g FROM generate_series(1, 10000) g"
q "CREATE INDEX i1 ON test_autovac (c1)"; q "CREATE INDEX i2 ON test_autovac (c2)"; q "CREATE INDEX i3 ON test_autovac (c3)"
q "UPDATE test_autovac SET c1 = c1 + 1"
q "SELECT injection_points_attach('$WPT', 'wait')"
q "SELECT injection_points_attach('$LPT', 'wait')"
q "ALTER TABLE test_autovac SET (autovacuum_enabled = true)"
for _ in $(seq 60); do [ "$(q "SELECT count(*) FROM pg_stat_activity WHERE wait_event = '$LPT'")" = 1 ] && break; sleep 0.5; done
for _ in $(seq 60); do [ "$(q "SELECT count(*) FROM pg_stat_activity WHERE wait_event = '$WPT'")" = 1 ] && break; sleep 0.5; done
q "SELECT injection_points_wakeup('$LPT')"; q "SELECT injection_points_detach('$LPT')"
sleep 2
LEADER=$(q "SELECT pid FROM pg_stat_activity WHERE backend_type = 'autovacuum worker'")
WEV=$(q "SELECT wait_event_type || '/' || wait_event FROM pg_stat_activity WHERE pid = $LEADER")
v0=$(awk '/^voluntary_ctxt_switches/{print $2}' /proc/$LEADER/status)
sleep $HOLD
v1=$(awk '/^voluntary_ctxt_switches/{print $2}' /proc/$LEADER/status)
# reload latency: from pg_reload_conf() to the leader's VacuumUpdateCosts with the new limit
off=$(stat -c %s $D/log)
q "ALTER SYSTEM SET autovacuum_vacuum_cost_limit = 777"
t0=$(date +%s.%N); q "SELECT pg_reload_conf()"
for _ in $(seq 300); do tail -c +$((off+1)) $D/log | grep -q "pid\|cost_limit=777" && tail -c +$((off+1)) $D/log | grep -q "VacuumUpdateCosts.*cost_limit=777" && break; sleep 0.01; done
t1=$(date +%s.%N)
lat=$(echo "($t1 - $t0) * 1000" | bc)
printf '%-6s leader %s waiting as %-28s voluntary wakeups in %ss: %6d (%.1f/s) reload seen after %5.0f ms\n' \
$B $LEADER "$WEV" $HOLD $((v1 - v0)) "$(echo "($v1 - $v0) / $HOLD" | bc -l)" "$lat"
q "SELECT injection_points_wakeup('$WPT')"; q "SELECT injection_points_detach('$WPT')"
"$I/pg_ctl" -D $D -m fast -w stop >/dev/null
cp $D/log $A/wakeups.$B.server.log
rm -rf $D
done
======== build_partial.sh ========
#!/bin/bash
# Zsolt's v3 with parts of the fix taken out, to check that each test fails
# without the part it is meant to test (the tests and injection points stay):
# nofix without the refresh in WaitForParallelWorkersToFinish() and
# without the SetLatch() in autovac_recalculate_workers_for_balance()
# nowake only without the SetLatch()
set -eu
BASE=${BASE:-e60ee52841d}
SRC=$HOME/Proyectos/postgresql
W=$HOME/pgav
A=$(cd "$(dirname "$0")" && pwd)
P=$(ls $A/zsolt-latest/nocfbot-v3-0001-*.patch)
mk() { # name files-to-exclude...
local name=$1; shift
local tree=$W/src-$name
if [ ! -d $tree ]; then
git -C $SRC worktree add -q --detach $tree $BASE
local ex=(); for f in "$@"; do ex+=(--exclude="$f"); done
git -C $tree apply --whitespace=nowarn "${ex[@]}" "$P"
# parallel_vacuum_refresh_cost_params() stays defined but unused when
# parallel.c is excluded; that is fine for a test-only build.
fi
mkdir -p $W/b-$name && cd $W/b-$name
$tree/configure --prefix=$W/i-$name --enable-cassert --enable-injection-points \
--enable-tap-tests --quiet > configure.log 2>&1
make -j"$(nproc)" -s > build.log 2>&1
make -s install > install.log 2>&1
make -C src/test/modules/injection_points -s install >> install.log 2>&1
echo "$name: warnings=$(grep -c 'warning:' build.log) | $(git -C $tree diff --stat | tr '\n' ' ' | sed 's/ */ /g')"
}
mk nofix src/backend/access/transam/parallel.c src/backend/postmaster/autovacuum.c
mk nowake src/backend/postmaster/autovacuum.c
echo PARTIAL-DONE
======== run_test6.sh ========
#!/bin/bash
# Run 003_rebalance_worker_leaves.pl (Zsolt's tests + test 6) on one build.
# The file is copied into the build's source tree for this run only and is
# removed afterwards, whatever the outcome, so it never leaks into other runs.
# run_test6.sh <build>
set -u
B=$1
A=$(cd "$(dirname "$0")" && pwd)
T=$HOME/pgav/src-$B/src/test/modules/test_autovacuum/t
cp $A/003_rebalance_worker_leaves.pl $T/
trap 'rm -f $T/003_rebalance_worker_leaves.pl' EXIT
export PG_TEST_TIMEOUT_DEFAULT=60
make -C $HOME/pgav/b-$B/src/test/modules/test_autovacuum check \
PROVE_TESTS=t/003_rebalance_worker_leaves.pl > $A/test6.$B.log 2>&1
echo "== $B exit=$?"
L=$HOME/pgav/b-$B/src/test/modules/test_autovacuum/tmp_check/log
grep -hE '(ok|not ok) [0-9]+ - |# leader still|# parallel worker cost_limit sequence|die:|Looks like' \
$L/regress_log_003_rebalance_worker_leaves | sed 's/^\[[^]]*\]//' | cut -c1-170
mkdir -p $A/test6-logs/$B && cp $L/* $A/test6-logs/$B/
======== results: stability, idle ========
zsolt/idle run 1 ok 9.9s
zsolt/idle run 2 ok 9.4s
zsolt/idle run 3 ok 9.5s
zsolt/idle run 4 ok 9.9s
zsolt/idle run 5 ok 9.5s
zsolt/idle run 6 ok 9.5s
zsolt/idle run 7 FAIL 9.6s
zsolt/idle run 8 ok 9.7s
zsolt/idle run 9 ok 9.4s
zsolt/idle run 10 ok 9.7s
zsolt/idle run 11 ok 9.7s
zsolt/idle run 12 ok 10.7s
zsolt/idle run 13 ok 9.8s
zsolt/idle run 14 ok 9.8s
zsolt/idle run 15 ok 9.4s
zsolt/idle run 16 ok 9.6s
zsolt/idle run 17 ok 9.6s
zsolt/idle run 18 ok 9.6s
zsolt/idle run 19 ok 9.5s
zsolt/idle run 20 ok 9.3s
zsolt/idle run 21 ok 9.7s
zsolt/idle run 22 ok 10.0s
zsolt/idle run 23 ok 9.8s
zsolt/idle run 24 ok 9.7s
zsolt/idle run 25 ok 9.2s
zsolt/idle run 26 ok 9.5s
zsolt/idle run 27 ok 9.6s
zsolt/idle run 28 ok 9.6s
zsolt/idle run 29 ok 9.4s
zsolt/idle run 30 ok 9.4s
zsolt/idle: 1 failures in 30 runs
NOTE: run 7 above is not a test failure: prove globbed t/003_rebalance_worker_leaves.pl, a file I placed in the source tree by mistake and removed during the run ('Cannot detect source'). t/001_parallel_autovacuum.pl itself passed in run 7 (see stability-fail/zsolt.idle.run7.make.log). Valid result: 001 passed 30 of 30.
======== results: stability, every CPU busy ========
zsolt/load run 1 ok 16.6s
zsolt/load run 2 ok 16.7s
zsolt/load run 3 ok 16.1s
zsolt/load run 4 ok 16.4s
zsolt/load run 5 ok 15.7s
zsolt/load run 6 ok 16.9s
zsolt/load run 7 ok 16.8s
zsolt/load run 8 ok 16.5s
zsolt/load run 9 ok 16.3s
zsolt/load run 10 ok 18.5s
zsolt/load run 11 ok 16.9s
zsolt/load run 12 ok 18.3s
zsolt/load run 13 ok 19.0s
zsolt/load run 14 ok 16.5s
zsolt/load run 15 ok 16.8s
zsolt/load run 16 ok 16.9s
zsolt/load run 17 ok 16.8s
zsolt/load run 18 ok 16.3s
zsolt/load run 19 ok 17.5s
zsolt/load run 20 ok 17.2s
zsolt/load: 0 failures in 20 runs
======== results: v3 tests on the cut-down builds ========
-- nofix
(1.395s) ok 1 - parallel autovacuum on test_autovac table
(1.159s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(30.943s) # die: timed out waiting for file pgav/b-nofix/src/test/modules/test_autovacuum/tmp_check/log/001_parallel_autovacuum_main.log co
(0.104s) # Looks like your test exited with 255 just after 3.
-- nowake
(1.321s) ok 1 - parallel autovacuum on test_autovac table
(1.144s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(0.872s) ok 4 - config reload reaches parallel workers while the leader waits
(31.539s) # die: timed out waiting for file pgav/b-nowake/src/test/modules/test_autovacuum/tmp_check/log/001_parallel_autovacuum_main.log c
(0.103s) # Looks like your test exited with 255 just after 4.
======== results: v3 tests + test 6 ========
== zsolt exit=0
(1.444s) ok 1 - parallel autovacuum on test_autovac table
(1.147s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(1.759s) # parallel worker cost_limit sequence: 250
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(1.194s) ok 4 - config reload reaches parallel workers while the leader waits
(1.684s) ok 5 - cost limit rebalance reaches parallel workers while the leader waits
(0.983s) # leader still in ParallelFinish when checked: 1; waited 0 s
(0.000s) ok 6 - waiting leader returns to the whole limit when a worker leaves
(0.105s) # parallel worker cost_limit sequence after the worker left: 800
(0.000s) ok 7 - parallel worker ends at the whole limit
== nowake exit=2
(1.332s) ok 1 - parallel autovacuum on test_autovac table
(1.256s) ok 2 - vacuum delay parameter changes are propagated to parallel vacuum workers
(1.657s) # parallel worker cost_limit sequence: 250
(0.000s) ok 3 - parallel workers see the rebalanced cost limit
(1.091s) ok 4 - config reload reaches parallel workers while the leader waits
(61.605s) # die: timed out waiting for file pgav/b-nowake/src/test/modules/test_autovacuum/tmp_check/log/003_rebalance_worker_leaves_main.log contents to match
(0.104s) # Looks like your test exited with 255 just after 4.
======== results: leader wakeups while waiting 20 s ========
zsolt leader 272238 waiting as IPC/ParallelFinish voluntary wakeups in 20s: 0 (0.0/s) reload seen after 7 ms
nikv2 leader 278985 waiting as IPC/ParallelFinish voluntary wakeups in 20s: 199 (9.9/s) reload seen after 8 ms
view thread (43+ messages) latest in thread
Message-ID: <179028573649.493682.4321152895319402838@gmail.com>
Permalink: ../179028573649.493682.4321152895319402838@gmail.com/
Also on: postgresql.org/message-id/179028573649.493682.4321152895319402838@gmail.com
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-bugs@postgresql.org
Cc: manuelreyesbravo@gmail.com, zsolt.parragi@percona.com, daniel@yesql.se, bharath.rupireddyforpostgres@gmail.com, sawada.mshk@gmail.com, nik@postgres.ai, pgsql-bugs@lists.postgresql.org
Subject: Re: autovacuum: automatically propagate updated parameters
In-Reply-To: <179028573649.493682.4321152895319402838@gmail.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox