From: Noah Misch <noah@leadboat.com>
To: Alexander Lakhin <exclusion@gmail.com>
Cc: Melanie Plageman <melanieplageman@gmail.com>
Cc: Heikki Linnakangas <hlinnaka@iki.fi>
Cc: Andres Freund <andres@anarazel.de>
Cc: pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
Date: Sat, 11 Jan 2025 13:44:54 -0800
Message-ID: <20250111214454.9a.nmisch@google.com> (raw)
In-Reply-To: <20241113002657.ce@rfd.leadboat.com>
References: <17821-dd8c334263399284@postgresql.org>
<13d30799-0107-6502-c81c-39ff5f1e7eb0@gmail.com>
<BEB9A06A-3B05-41DC-AEE4-AD3DC4AD67E5@anarazel.de>
<25c3399b-58a3-d727-7f97-93394fd1afa9@gmail.com>
<2a203fd8-e9c8-5f5d-40f8-707848905a1a@gmail.com>
<CAAKRu_bWz0KhTKW3SzetvhZL3gpsnyekB2WFCn-MO4aCx=37=g@mail.gmail.com>
<53a0f263-bece-bc96-e016-1690628a9980@gmail.com>
<20241113002657.ce@rfd.leadboat.com>
On Tue, Nov 12, 2024 at 04:26:57PM -0800, Noah Misch wrote:
> This looked a lot like the former LP_UNUSED race conditions that inplace.spec
> demonstrated. I forked inplace.spec to use regular MVCC updates (attached).
> That reproduces the symptoms you describe. This happens because syscache is a
> way to get a tuple without a pin on the tuple's page and without satisfying
> any snapshot. Either a pin or a snapshot would stop the pruning. That's how
> regular UPDATE statements avoid this.
>
> Some options for fixing it:
>
> 1. Make the ItemIdIsNormal() check a runtime check that causes heap_update()
> to return TM_Deleted. It could Assert(RelationSupportsSysCache(rel)), too.
>
> 2. Like the previous, but introduce a TM_Pruned. If pruning hadn't happened,
> heap_update() would have returned TM_Updated or TM_Deleted. We don't know
> which one heap_update() would have returned, because pruning erased the
> t_ctid that would have driven that decision.
>
> 3. Before using a syscache tuple for a heap_update(), pin its buffer and
> compare the syscache xmin to the buffer tuple xmin. Normally, they'll
> match. If they don't match, ERROR or re-fetch the latest tuple as though
> the syscache lookup had experienced a cache miss.
>
> 4. Take a self-exclusive heavyweight lock before we use the syscache to fetch
> the old tuple for a heap_update(). That's how we avoid this if the only
> catalog-modifying commands are ALTER TABLE.
>
> I think this defect can't corrupt catalogs or other data. It's merely a
> source of transient failure.
I got that wrong ...
> While one of the test permutations does update a
> pg_class tuple of a different rel, the update then fails with a primary key
> violation. All misdirected updates will fail that way, because we don't
> update the primary key columns of syscache relations. With assertions
> disabled, I think heap_update() looks for an old tuple at lp_off=0, hence
> treating the page header as a tuple header.
It does.
> Bytes of pd_lsn become the
> putative xmin. The attached test gets "ERROR: attempted to update invisible
> tuple" error from that, but other PageHeader bit patterns might reach "could
> not access status of transaction", unique constraint violations, etc.
A UNIQUE constraint violation is too late to avoid page header corruption. I
modified the test case to reach page header corruption. Attached. Key parts:
lsn |checksum|flags|lower|upper|special|pagesize|version|prune_xid
------+--------+-----+-----+-----+-------+--------+-------+---------
1/6AF8| 0| 0| 0| 11| 38| 8192| 4| 0
(1 row)
ERROR: invalid page in block 11 of relation base/16384/16462
A UNIQUE violation implies heap_update() succeeded, and heap_update() success
implies changes to the old tuple header. Since the test catches us wrongly
treating the page header as a tuple header, overwrites ensue as follows:
Page header field | Overwritten as though it were this heap tuple header field
------------------------------------------------------------------------------
pd_lsn.xrecoff | xmax
pd_lower | ctid.ip_blkid.bi_hi
pd_upper | ctid.ip_blkid.bi_lo
pd_special | ctid.ip_posid
t_ctid=(11,38) caused those values of "lower", "upper", and "special". When
the page is next read from disk, it gets "ERROR: invalid page".
> I recommend (2) or (1), since they're self-contained. (3) or (4) potentially
> give a better user experience for this rare failure, but that's code churn at
> every DDL heap_update() site. How do you see it?
I plan to write (1).
Attachments:repro-ItemIdIsNormal-v2.patch (text/plain, 15.7K) download
Author: Noah Misch <noah@leadboat.com>
Commit: Noah Misch <noah@leadboat.com>
diff --git a/src/backend/access/heap/heapam.c b/src/backend/access/heap/heapam.cindex 485525f..fed1279 100644--- a/src/backend/access/heap/heapam.c+++ b/src/backend/access/heap/heapam.c@@ -49,6 +49,7 @@
#include "storage/predicate.h"
#include "storage/procarray.h"
#include "utils/datum.h"
+#include "utils/injection_point.h"
#include "utils/inval.h"
#include "utils/spccache.h"
@@ -3236,6 +3237,7 @@ heap_update(Relation relation, ItemPointer otid, HeapTuple newtup,
interesting_attrs = bms_add_members(interesting_attrs, id_attrs);
block = ItemPointerGetBlockNumber(otid);
+ INJECTION_POINT("heap_update-before-pin");
buffer = ReadBuffer(relation, block);
page = BufferGetPage(buffer);
@@ -6375,6 +6377,9 @@ heap_inplace_update_and_unlock(Relation relation,
*/
PreInplace_Inval();
+ INJECTION_POINT_LOAD("SIInsertDataEntries2");+ INJECTION_POINT_LOAD("SIInsertDataEntries3");+
/*----------
* NO EREPORT(ERROR) from here till changes are complete
*
diff --git a/src/backend/storage/ipc/sinvaladt.c b/src/backend/storage/ipc/sinvaladt.cindex 2da9173..ed0f173 100644--- a/src/backend/storage/ipc/sinvaladt.c+++ b/src/backend/storage/ipc/sinvaladt.c@@ -25,6 +25,7 @@
#include "storage/shmem.h"
#include "storage/sinvaladt.h"
#include "storage/spin.h"
+#include "utils/injection_point.h"
/*
* Conceptually, the shared cache invalidation messages are stored in an
@@ -386,6 +387,17 @@ SIInsertDataEntries(const SharedInvalidationMessage *data, int n)
int max;
int i;
+ /*+ * CacheInvalidateSmgr skips the injection point, since this+ * facilitates a test that needs this only for delaying pg_class+ * syscache invals and relcache invals.+ */+ if (n != 1 || data->sm.id != SHAREDINVALSMGR_ID)+ {+ INJECTION_POINT("SIInsertDataEntries2");+ INJECTION_POINT("SIInsertDataEntries3");+ }+
n -= nthistime;
LWLockAcquire(SInvalWriteLock, LW_EXCLUSIVE);
diff --git a/src/test/modules/injection_points/Makefile b/src/test/modules/injection_points/Makefileindex 0753a9d..802ea8c 100644--- a/src/test/modules/injection_points/Makefile+++ b/src/test/modules/injection_points/Makefile@@ -13,7 +13,8 @@ PGFILEDESC = "injection_points - facility for injection points"
REGRESS = injection_points reindex_conc
REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress
-ISOLATION = basic inplace+EXTRA_INSTALL = contrib/pageinspect contrib/pg_buffercache+ISOLATION = basic syscache-update-pruned inplace
TAP_TESTS = 1
diff --git a/src/test/modules/injection_points/expected/syscache-update-pruned.out b/src/test/modules/injection_points/expected/syscache-update-pruned.outnew file mode 100644index 0000000..2125dd2--- /dev/null+++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out@@ -0,0 +1,73 @@+Parsed test spec with 4 sessions++starting permutation: xids4 cachefill1 at2 vac3 grant1 wakegrant4 wakeinval4 validate4+debug_assertions+----------------+on +(1 row)++mkrels+------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++step xids4: + DO $$+ DECLARE+ goal pg_lsn := '1/1';+ diff bigint := pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn());+ BEGIN+ IF diff < 0 THEN+ RAISE EXCEPTION 'WAL is too far ahead by %; use a lower pg_resetwal argument', pg_size_pretty(-diff);+ END IF;+ RAISE LOG 'closing WAL gap of %', pg_size_pretty(diff);+ WHILE pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn()) > 0 LOOP+ PERFORM pg_logical_emit_message(true, '', '');+ ROLLBACK; -- one aborted XID per iteration+ END LOOP;+ RAISE LOG 'closing WAL stopped at %', pg_current_wal_insert_lsn();+ END+ $$;++step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0;+?column?+--------+t +(1 row)++step at2: ALTER TABLE vactest.orig50 SET (fillfactor = 50); <waiting ...>+step vac3: VACUUM pg_class; <waiting ...>+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>+step wakegrant4: + SELECT injection_points_detach('heap_update-before-pin');+ SELECT injection_points_wakeup('heap_update-before-pin');++injection_points_detach+-----------------------+ +(1 row)++injection_points_wakeup+-----------------------+ +(1 row)++PQconsumeInput failed: server closed the connection unexpectedly+ This probably means the server terminated abnormally+ before or while processing the request.+diff --git a/src/test/modules/injection_points/expected/syscache-update-pruned_1.out b/src/test/modules/injection_points/expected/syscache-update-pruned_1.outnew file mode 100644index 0000000..1f89721--- /dev/null+++ b/src/test/modules/injection_points/expected/syscache-update-pruned_1.out@@ -0,0 +1,125 @@+Parsed test spec with 4 sessions++starting permutation: xids4 cachefill1 at2 vac3 grant1 wakegrant4 wakeinval4 validate4+debug_assertions+----------------+off +(1 row)++mkrels+------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++injection_points_attach+-----------------------+ +(1 row)++step xids4: + DO $$+ DECLARE+ goal pg_lsn := '1/1';+ diff bigint := pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn());+ BEGIN+ IF diff < 0 THEN+ RAISE EXCEPTION 'WAL is too far ahead by %; use a lower pg_resetwal argument', pg_size_pretty(-diff);+ END IF;+ RAISE LOG 'closing WAL gap of %', pg_size_pretty(diff);+ WHILE pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn()) > 0 LOOP+ PERFORM pg_logical_emit_message(true, '', '');+ ROLLBACK; -- one aborted XID per iteration+ END LOOP;+ RAISE LOG 'closing WAL stopped at %', pg_current_wal_insert_lsn();+ END+ $$;++step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0;+?column?+--------+t +(1 row)++step at2: ALTER TABLE vactest.orig50 SET (fillfactor = 50); <waiting ...>+step vac3: VACUUM pg_class; <waiting ...>+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>+step wakegrant4: + SELECT injection_points_detach('heap_update-before-pin');+ SELECT injection_points_wakeup('heap_update-before-pin');++injection_points_detach+-----------------------+ +(1 row)++injection_points_wakeup+-----------------------+ +(1 row)++step grant1: <... completed>+step wakeinval4: + SELECT injection_points_detach('SIInsertDataEntries2');+ SELECT injection_points_detach('SIInsertDataEntries3');+ SELECT injection_points_wakeup('SIInsertDataEntries2');+ SELECT injection_points_wakeup('SIInsertDataEntries3');++injection_points_detach+-----------------------+ +(1 row)++injection_points_detach+-----------------------+ +(1 row)++injection_points_wakeup+-----------------------+ +(1 row)++injection_points_wakeup+-----------------------+ +(1 row)++step at2: <... completed>+step vac3: <... completed>+step validate4: + SELECT * FROM page_header(get_raw_page('pg_class', 11));+ CREATE EXTENSION pg_buffercache;+ SELECT count(pg_buffercache_evict(bufferid)) > 0 FROM pg_buffercache;+ DROP EXTENSION pg_buffercache;+ REINDEX INDEX pg_class_oid_index;++lsn |checksum|flags|lower|upper|special|pagesize|version|prune_xid+------+--------+-----+-----+-----+-------+--------+-------+---------+1/6AF8| 0| 0| 0| 11| 38| 8192| 4| 0+(1 row)++?column?+--------+t +(1 row)++ERROR: invalid page in block 11 of relation base/16384/16462+teardown failed: ERROR: invalid page in block 11 of relation base/16384/16462++starting permutation: cachefill1 at2 vac3 grant1 mkrels4 wakegrant4 wakeinval4+debug_assertions+----------------+off +(1 row)++setup failed: ERROR: extension "pageinspect" already existsdiff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.buildindex 989b4db..a5e881f 100644--- a/src/test/modules/injection_points/meson.build+++ b/src/test/modules/injection_points/meson.build@@ -43,6 +43,7 @@ tests += {
'isolation': {
'specs': [
'basic',
+ 'syscache-update-pruned',
'inplace',
],
},
diff --git a/src/test/modules/injection_points/specs/syscache-update-pruned.spec b/src/test/modules/injection_points/specs/syscache-update-pruned.specnew file mode 100644index 0000000..bde61c5--- /dev/null+++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec@@ -0,0 +1,162 @@+# Test race conditions involving:+# - s1: heap_update($FROM_SYSCACHE), without a snapshot or pin+# - s2: ALTER TABLE making $FROM_SYSCACHE a dead tuple+# - s3: "VACUUM pg_class" making $FROM_SYSCACHE become LP_UNUSED++# This is a derivative work of inplace.spec. When introduced, that spec+# reached basically the same race condition, for inplace updates. Commit+# a07e03f fixed the inplace update case.++# All sessions disable debug_parallel_query. The most prominent+# incompatibility between this test and parallel query involves the two+# SIInsertDataEntries injection point waits. We hold RelCacheInitLock during+# those waits, so parallel workers could hang in startup.++setup { SHOW debug_assertions; -- distinguish the two expected outputs }+# Need s2 to make a non-HOT update. Otherwise, "VACUUM pg_class" would leave+# an LP_REDIRECT that persists. To get non-HOT, make rels so the pg_class row+# for vactest.orig50 is on a filled page (assuming BLCKSZ=8192). Just to save+# on filesystem syscalls, use relkind=c for every other rel.+setup+{+ SET debug_parallel_query = off;+ CREATE EXTENSION pageinspect;+ CREATE EXTENSION injection_points;+ CREATE SCHEMA vactest;+ CREATE FUNCTION vactest.mkrels(text, int, int) RETURNS void+ LANGUAGE plpgsql SET search_path = vactest AS $$+ DECLARE+ tname text;+ BEGIN+ FOR i in $2 .. $3 LOOP+ tname := $1 || i;+ EXECUTE FORMAT('CREATE TYPE ' || tname || ' AS ()');+ RAISE DEBUG '% at %', tname, ctid+ FROM pg_class WHERE oid = tname::regclass;+ END LOOP;+ END+ $$;+}+setup { VACUUM FULL pg_class; -- reduce free space }+setup+{+ SELECT vactest.mkrels('orig', 1, 49);+ CREATE TABLE vactest.orig50 ();+ SELECT vactest.mkrels('orig', 51, 100);+}+teardown+{+ DROP SCHEMA vactest CASCADE;+ DROP EXTENSION injection_points;+ DROP EXTENSION pageinspect;+}++# Wait during GRANT.+session s1+setup {+ SET debug_parallel_query = off;+ SELECT injection_points_set_local();+ SELECT injection_points_attach('heap_update-before-pin', 'wait');+}+step cachefill1 { SELECT pg_relation_filenode('vactest.orig50') > 0; }+step grant1 { GRANT SELECT ON vactest.orig50 TO PUBLIC; }++# Update of the tuple grant1 will update. Wait before sending invals, so s1+# will not get a cache miss. Choose the command for making that update from+# among those whose heavyweight locking does not conflict with GRANT's+# heavyweight locking. (GRANT will see our XID as committed, so observing+# that XID in the tuple xmax also won't block GRANT.)+session s2+setup {+ SET debug_parallel_query = off;+ SELECT injection_points_set_local();+ SELECT injection_points_attach('SIInsertDataEntries2', 'wait');+}+step at2 { ALTER TABLE vactest.orig50 SET (fillfactor = 50); }++# VACUUM to achieve LP_UNUSED. Again delay any s1 cache miss.+session s3+setup {+ SET debug_parallel_query = off;+ SELECT injection_points_set_local();+ SELECT injection_points_attach('SIInsertDataEntries3', 'wait');+}+step vac3 { VACUUM pg_class; }++# Non-blocking actions.+session s4+setup { SET debug_parallel_query = off; }+# Part of the mission is tricking heap_update() into treating lp_off=0 as an+# "old tuple". For that to work, the page header needs to look enough like a+# tuple header. Specifically, (pd_lsn.xlogid, pd_lsn.xrecoff) needs to+# suffice as a plausible (xmin, xmax). xmin should be known-committed, and+# xmax should be known-aborted.+#+# Our caller used pg_resetwal to leave the WAL position somewhat lower than+# 1/1. Advance it to 1/1, achieving xlogid = 1 = BootstrapTransactionId. In+# passing, burn XIDs so xrecoff will be a known-aborted XID in CLOG.+step xids4 {+ DO $$+ DECLARE+ goal pg_lsn := '1/1';+ diff bigint := pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn());+ BEGIN+ IF diff < 0 THEN+ RAISE EXCEPTION 'WAL is too far ahead by %; use a lower pg_resetwal argument', pg_size_pretty(-diff);+ END IF;+ RAISE LOG 'closing WAL gap of %', pg_size_pretty(diff);+ WHILE pg_wal_lsn_diff(goal, pg_current_wal_insert_lsn()) > 0 LOOP+ PERFORM pg_logical_emit_message(true, '', '');+ ROLLBACK; -- one aborted XID per iteration+ END LOOP;+ RAISE LOG 'closing WAL stopped at %', pg_current_wal_insert_lsn();+ END+ $$;+}+# Reuse the lp that s1 is waiting to change. I've observed reuse at the 1st+# or 18th CREATE, so create excess.+step mkrels4 {+ SELECT vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED+}+step wakegrant4 {+ SELECT injection_points_detach('heap_update-before-pin');+ SELECT injection_points_wakeup('heap_update-before-pin');+}+step wakeinval4 {+ SELECT injection_points_detach('SIInsertDataEntries2');+ SELECT injection_points_detach('SIInsertDataEntries3');+ SELECT injection_points_wakeup('SIInsertDataEntries2');+ SELECT injection_points_wakeup('SIInsertDataEntries3');+}+# The bug corrupts pd_lower, pd_upper, and pd_special. That causes the page+# to fail validation when re-reading from disk.+step validate4 {+ SELECT * FROM page_header(get_raw_page('pg_class', 11));+ CREATE EXTENSION pg_buffercache;+ SELECT count(pg_buffercache_evict(bufferid)) > 0 FROM pg_buffercache;+ DROP EXTENSION pg_buffercache;+ REINDEX INDEX pg_class_oid_index;+}++# tuple $FROM_SYSCACHE becomes LP_UNUSED. This permutation must come first,+# because it relies on a particular WAL position that pg_resetwal set before+# this spec began.+permutation+ xids4+ cachefill1 # reads pg_class tuple T0 for vactest.orig50, xmax invalid+ at2(wakeinval4) # T0 becomes eligible for pruning, T1 is successor+ vac3(at2) # T0 becomes LP_UNUSED+ grant1(wakegrant4) # pauses at heap_update(T0)+ wakegrant4 # s1 wakes, assertion failure or page header corruption+ wakeinval4+ validate4++# add mkrels4: tuple $FROM_SYSCACHE changes from LP_UNUSED to a successor+permutation+ cachefill1 # reads pg_class tuple T0 for vactest.orig50, xmax invalid+ at2(wakeinval4) # T0 becomes eligible for pruning, T1 is successor+ vac3(at2) # T0 becomes LP_UNUSED+ grant1(wakegrant4) # pauses at heap_update(T0)+ mkrels4 # T0 becomes a new rel+ wakegrant4 # s1 wakes, "duplicate key value violates unique"+ wakeinval4diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.cindex cbef6d4..e1a6b06 100644--- a/src/test/regress/pg_regress.c+++ b/src/test/regress/pg_regress.c@@ -2475,6 +2475,24 @@ regression_main(int argc, char *argv[],
}
/*
+ * FIXME want this for syscache-update-pruned.spec only. That test+ * needs to reach wal position 1/1, and this beats writing 12GB of WAL+ * to get there.+ */+ snprintf(buf, sizeof(buf),+ "\"%s%spg_resetwal\" -D \"%s/data\" "+ "--wal-segsize=16 --next-wal-file=0000000100000000000000FF",+ bindir ? bindir : "",+ bindir ? "/" : "",+ temp_instance);+ fflush(NULL);+ if (system(buf))+ {+ bail("pg_resetwal failed\n"+ "# Command was: %s", buf);+ }++ /*
* Start the temp postmaster
*/
snprintf(buf, sizeof(buf),
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: noah@leadboat.com, exclusion@gmail.com, melanieplageman@gmail.com, hlinnaka@iki.fi, andres@anarazel.de, pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
In-Reply-To: <20250111214454.9a.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