From: Noah Misch <noah@leadboat.com>
To: pgsql-hackers@postgresql.org
Subject: Re: heap_inplace_lock vs. autovacuum w/ LOCKTAG_TUPLE
Date: Sat, 26 Oct 2024 21:09:28 -0700
Message-ID: <20241027040928.9e.nmisch@google.com> (raw)
In-Reply-To: <20241026184936.ae.nmisch@google.com>
References: <20241026184936.ae.nmisch@google.com>
On Sat, Oct 26, 2024 at 11:49:36AM -0700, Noah Misch wrote:
> intra-grant-inplace-db.spec got a novel failure today:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=sarus&dt=2024-10-26%2014%3A08%3A58
>
> The isolationtester_waiting query is supposed to detect that step vac2 is
> blocked. vac2 didn't finish within the timeout, but isolationtester_waiting
> never considered it blocked.
> ... work on reproducing this.
I'm running loops of three workloads that might reproduce this, on s390x:
- A buildfarm config like buildfarm member sarus.
- A workload where autovacuum vac_update_datfrozenxid() takes >10s, but
non-auto "VACUUM (ONLY_DATABASE_STATS)" runs in a loop under
lock_timeout=5s. This notices if the non-auto VACUUM ever fails to cancel
autovacuum. I apply the attached inplace200-bench-vac-v0.1.patch, then run
contrib/amcheck/t/089_vac.pl.
- A workload to make vac2's deadlock detector run when an autovacuum worker is
starting. That's one of my candidate explanations of the events behind the
failure log. I apply the attached inplace190-repro-autovacuum-v0.1.patch,
then run intra-grant-inplace-db.spec with debug_parallel_query=regress and
autovacuum_naptime=1s. This regularly gets vac2 to cancel autovacuum.
So far, those have seen nothing like the failed run.
I'm inclined to make isolationtester log pg_stat_activity and pg_locks
whenever a step times out. That would have ruled out many explanations for
what happened on sarus. However, logging on timeout won't help much until
something can reproduce the timeout.
> It's odd that a new
> auto-analyze starts every minute, each of which exits due to blocking vac2.
Every autovacuum_naptime, a new worker cancels the old one due to wanting the
old worker's LOCKTAG_DATABASE_FROZEN_IDS. One can see this with "BEGIN; GRANT
TEMP ON DATABASE postgres TO pg_monitor;". That open transaction's xmax
prevents vac_update_datfrozenxid() from finishing. While that transaction
remains open, every autovacuum_naptime after the first will log a cancellation
of the previous autovacuum worker. (This assumes each autovacuum worker,
having negligible real work to do, reaches vac_update_datfrozenxid() before
the next autovacuum_naptime.) That's likely not ideal, but it doesn't explain
the sarus failure.
Attachments:download all (2 files, .tar.gz)inplace200-bench-vac-v0.1.patch (text/plain, 2.1K) download
Author: Noah Misch <noah@leadboat.com>
Commit: Noah Misch <noah@leadboat.com>
diff --git a/contrib/amcheck/t/089_vac.pl b/contrib/amcheck/t/089_vac.plnew file mode 100644index 0000000..a28ebd9--- /dev/null+++ b/contrib/amcheck/t/089_vac.pl@@ -0,0 +1,50 @@++# Copyright (c) 2021-2024, PostgreSQL Global Development Group++# Test VACUUM vs. slow autovac+use strict;+use warnings FATAL => 'all';++use PostgreSQL::Test::Cluster;+use PostgreSQL::Test::Utils;++use Test::More;++my ($node, $result);++#+# Test set-up+#+$node = PostgreSQL::Test::Cluster->new('main');+$node->init;+$node->append_conf('postgresql.conf', 'autovacuum_naptime = 1s');+$node->append_conf('postgresql.conf', 'log_lock_waits = on');+$node->append_conf('postgresql.conf', 'deadlock_timeout = 10ms');+$node->append_conf('postgresql.conf', q{backtrace_functions = 'ProcessInterrupts'});+$node->start;++my $grant_h = $node->background_psql('postgres');++# This running would block all vac_update_datfrozenxid => lock_timeout always+# $grant_h->query_safe(+# q(+# BEGIN;+# GRANT TEMP ON DATABASE postgres TO pg_monitor;+# ));++{+ local $ENV{PGOPTIONS} = '-clock_timeout=5s';+$node->pgbench(+ '--no-vacuum --client=1 --time=600',+ 0,+ [qr{actually processed}],+ [qr{^$}],+ 'vac',+ {+ 'vac' => 'VACUUM (ONLY_DATABASE_STATS);',+ });+}++$grant_h->quit;+$node->stop;+done_testing();diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.cindex ac8f5d9..20fe426 100644--- a/src/backend/commands/vacuum.c+++ b/src/backend/commands/vacuum.c@@ -1582,6 +1582,7 @@ vac_update_relstats(Relation relation,
* commits. As with vac_update_relstats, this avoids leaving dead tuples
* behind after a VACUUM.
*/
+#include "utils/fmgrprotos.h"
void
vac_update_datfrozenxid(void)
{
@@ -1607,6 +1608,9 @@ vac_update_datfrozenxid(void)
*/
LockDatabaseFrozenIds(ExclusiveLock);
+ if (AmAutoVacuumWorkerProcess())+ DirectFunctionCall1(pg_sleep, Float8GetDatum(10.0));+
/*
* Initialize the "min" calculation with
* GetOldestNonRemovableTransactionId(), which is a reasonable
inplace190-repro-autovacuum-v0.1.patch (text/plain, 2.2K) download
Author: Noah Misch <noah@leadboat.com>
Commit: Noah Misch <noah@leadboat.com>
diff --git a/src/test/isolation/Makefile b/src/test/isolation/Makefileindex ade2256..ca487de 100644--- a/src/test/isolation/Makefile+++ b/src/test/isolation/Makefile@@ -64,6 +64,9 @@ installcheck: all
check: all
$(pg_isolation_regress_check) --schedule=$(srcdir)/isolation_schedule
+nmcheck: all temp-install+ $(pg_isolation_regress_check) intra-grant-inplace-db+
# Non-default tests. It only makes sense to run these if set up to use
# prepared transactions, via TEMP_CONFIG for the check case, or via the
# postgresql.conf for the installcheck case.
diff --git a/src/test/isolation/expected/intra-grant-inplace-db.out b/src/test/isolation/expected/intra-grant-inplace-db.outindex a91402c..118cbaa 100644--- a/src/test/isolation/expected/intra-grant-inplace-db.out+++ b/src/test/isolation/expected/intra-grant-inplace-db.out@@ -8,6 +8,12 @@ step snap3:
step b1: BEGIN;
step grant1:
GRANT TEMP ON DATABASE isolation_regression TO regress_temp_grantee;
+ SELECT pg_sleep(random(0.000, 1.200));++pg_sleep+--------+ +(1 row)
step vac2: VACUUM (FREEZE); <waiting ...>
step snap3:
diff --git a/src/test/isolation/isolationtester.c b/src/test/isolation/isolationtester.cindex 0b342b5..8a5e585 100644--- a/src/test/isolation/isolationtester.c+++ b/src/test/isolation/isolationtester.c@@ -863,7 +863,7 @@ try_complete_step(TestSpec *testspec, PermutationStep *pstep, int flags)
while (PQisBusy(conn))
{
FD_SET(sock, &read_set);
- timeout.tv_sec = 0;+ timeout.tv_sec = 8;
timeout.tv_usec = 10000; /* Check for lock waits every 10ms. */
ret = select(sock + 1, &read_set, NULL, NULL, &timeout);
diff --git a/src/test/isolation/specs/intra-grant-inplace-db.spec b/src/test/isolation/specs/intra-grant-inplace-db.specindex 9de40ec..408e23f 100644--- a/src/test/isolation/specs/intra-grant-inplace-db.spec+++ b/src/test/isolation/specs/intra-grant-inplace-db.spec@@ -18,6 +18,7 @@ session s1
step b1 { BEGIN; }
step grant1 {
GRANT TEMP ON DATABASE isolation_regression TO regress_temp_grantee;
+ SELECT pg_sleep(random(0.000, 1.200));
}
step c1 { COMMIT; }
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-hackers@postgresql.org
Cc: noah@leadboat.com
Subject: Re: heap_inplace_lock vs. autovacuum w/ LOCKTAG_TUPLE
In-Reply-To: <20241027040928.9e.nmisch@google.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