pg.ddx.io  pgsql-bugs@postgresql.org mailing list archive  
help / color / mirror / Atom feed
BUG #17821: Assertion failed in heap_update() due to heap pruning
13+ messages / 5 participants
[nested] [flat]

* BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2023-03-02 13:00  PG Bug reporting form <noreply@postgresql.org>
  0 siblings, 1 reply; 13+ messages in thread

From: PG Bug reporting form @ 2023-03-02 13:00 UTC (permalink / raw)
  To: pgsql-bugs@lists.postgresql.org; +Cc: exclusion@gmail.com

The following bug has been logged on the website:

Bug reference:      17821
Logged by:          Alexander Lakhin
Email address:      exclusion@gmail.com
PostgreSQL version: 15.2
Operating system:   Ubuntu 22.04
Description:        

When performing multi-threaded tests, I've stumbled upon a failed
assertion with the following stack trace:

Core was generated by `postgres: postgres regress003 127.0.0.1(35610) GRANT 
                        '.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill_implementation (no_tid=0, signo=6,
threadid=140650166969280) at ./nptl/pthread_kill.c:44
44      ./nptl/pthread_kill.c: No such file or directory.
(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6,
threadid=140650166969280) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=140650166969280) at
./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140650166969280, signo=signo@entry=6) at
./nptl/pthread_kill.c:89
#3  0x00007febad28e476 in __GI_raise (sig=sig@entry=6) at
../sysdeps/posix/raise.c:26
#4  0x00007febad2747f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x0000556725c44981 in ExceptionalCondition
(conditionName=conditionName@entry=0x556725dc6b00 "ItemIdIsNormal(lp)",
fileName=fileName@entry=0x556725dc48e0 "heapam.c",
lineNumber=lineNumber@entry=3024) at assert.c:66
#6  0x00005567249f3aa7 in heap_update
(relation=relation@entry=0x7feb61671cd8, otid=otid@entry=0x61900002c3fc,
newtup=newtup@entry=0x61900002c3f8, cid=<optimized out>,
crosscheck=crosscheck@entry=0x0, wait=wait@entry=true, 
    tmfd=<optimized out>, lockmode=<optimized out>) at heapam.c:3024
#7  0x00005567249f8d46 in simple_heap_update
(relation=relation@entry=0x7feb61671cd8, otid=otid@entry=0x61900002c3fc,
tup=tup@entry=0x61900002c3f8) at heapam.c:3969
#8  0x0000556724c367ba in CatalogTupleUpdate
(heapRel=heapRel@entry=0x7feb61671cd8, otid=0x61900002c3fc,
tup=0x61900002c3f8) at indexing.c:309
#9  0x0000556724bfc30c in ExecGrant_Relation
(istmt=istmt@entry=0x7ffdeb8ca1e0) at aclchk.c:2041
#10 0x0000556724bffee3 in ExecGrantStmt_oids
(istmt=istmt@entry=0x7ffdeb8ca1e0) at aclchk.c:598
#11 0x0000556724c00ab0 in ExecuteGrantStmt (stmt=stmt@entry=0x625000005df0)
at aclchk.c:583
#12 0x00005567257ccac7 in ProcessUtilitySlow
(pstate=pstate@entry=0x61900002c298, pstmt=pstmt@entry=0x625000005ec0,
queryString=queryString@entry=0x625000005218 "GRANT SELECT ON pg_proc TO
CURRENT_USER;", 
    context=context@entry=PROCESS_UTILITY_TOPLEVEL, params=params@entry=0x0,
queryEnv=queryEnv@entry=0x0, dest=<optimized out>, qc=<optimized out>) at
utility.c:1802
#13 0x00005567257c92a5 in standard_ProcessUtility
(pstmt=pstmt@entry=0x625000005ec0,
queryString=queryString@entry=0x625000005218 "GRANT SELECT ON pg_proc TO
CURRENT_USER;", readOnlyTree=readOnlyTree@entry=false, 
    context=context@entry=PROCESS_UTILITY_TOPLEVEL, params=params@entry=0x0,
queryEnv=queryEnv@entry=0x0, dest=<optimized out>, qc=<optimized out>) at
utility.c:973
#14 0x00007feba7e91d97 in pgss_ProcessUtility (pstmt=<optimized out>,
queryString=<optimized out>, readOnlyTree=<optimized out>,
context=<optimized out>, params=<optimized out>, queryEnv=<optimized out>,
dest=<optimized out>, 
    qc=<optimized out>) at pg_stat_statements.c:1143
#15 0x00005567257c9906 in ProcessUtility (pstmt=pstmt@entry=0x625000005ec0,
queryString=<optimized out>, readOnlyTree=<optimized out>,
context=context@entry=PROCESS_UTILITY_TOPLEVEL, params=<optimized out>,
queryEnv=<optimized out>, 
    dest=0x6250000066f0, qc=0x7ffdeb8cae50) at utility.c:526
#16 0x00005567257c2488 in PortalRunUtility
(portal=portal@entry=0x62500002fa18, pstmt=pstmt@entry=0x625000005ec0,
isTopLevel=isTopLevel@entry=true,
setHoldSnapshot=setHoldSnapshot@entry=false, dest=dest@entry=0x6250000066f0,

    qc=qc@entry=0x7ffdeb8cae50) at pquery.c:1158
#17 0x00005567257c3010 in PortalRunMulti
(portal=portal@entry=0x62500002fa18, isTopLevel=isTopLevel@entry=true,
setHoldSnapshot=setHoldSnapshot@entry=false, dest=dest@entry=0x6250000066f0,
altdest=altdest@entry=0x6250000066f0, 
    qc=qc@entry=0x7ffdeb8cae50) at pquery.c:1315
#18 0x00005567257c3d82 in PortalRun (portal=portal@entry=0x62500002fa18,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true,
run_once=run_once@entry=true, dest=dest@entry=0x6250000066f0, 
    altdest=altdest@entry=0x6250000066f0, qc=<optimized out>) at
pquery.c:791
#19 0x00005567257b7f59 in exec_simple_query
(query_string=query_string@entry=0x625000005218 "GRANT SELECT ON pg_proc TO
CURRENT_USER;") at postgres.c:1240
#20 0x00005567257bcead in PostgresMain (dbname=dbname@entry=0x62900001b268
"regress003", username=username@entry=0x62900001b248 "postgres") at
postgres.c:4572
#21 0x000055672555f72b in BackendRun (port=port@entry=0x614000230640) at
postmaster.c:4461
#22 0x0000556725567fc7 in BackendStartup (port=port@entry=0x614000230640) at
postmaster.c:4189
#23 0x00005567255685c4 in ServerLoop () at postmaster.c:1779
#24 0x000055672556acbb in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x603000000370) at postmaster.c:1463
#25 0x00005567251c4499 in main (argc=3, argv=0x603000000370) at main.c:200

After series of experiments I came to the following simple reproduction:
numclients=2
for ((i=1;i<=300;i++)); do
  echo "iteration $i"
  for ((j=1;j<=numclients;j++)); do
    for ((k=1;k<=300;k++)); do echo "GRANT ALL ON pg_class TO public;"; done
| psql >psql-$j.log 2>&1 &
  done
  wait
  grep 'TRAP:' server.log && { res=0; break; }
  psql -c "VACUUM FULL pg_class" >psql-vacuum.log
done
pg_ctl -w -t 10 -D "$PGDB" stop

...
iteration 3
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3024,
PID: 1817582
waiting for server to shut down............. failed

To ease the reproduction I did:
sed 's/minfree = Max(minfree, BLCKSZ \/ 10)/minfree = Max(minfree, BLCKSZ \/
1)/' -i src/backend/access/heap/pruneheap.c
(I believe that that doesn't change modus vivendi of the page pruning
too much.)
With some debugging messages added, I see:

2023-03-02 15:22:13.027 MSK|[unknown]|[unknown]|640094f5.1ba5ab|LOG: 
connection received: host=[local]
2023-03-02 15:22:13.027 MSK|law|test1|640094f5.1ba5ab|LOG:  connection
authorized: user=law database=test1 application_name=psql
2023-03-02 15:22:13.027 MSK|[unknown]|[unknown]|640094f5.1ba5ac|LOG: 
connection received: host=[local]
2023-03-02 15:22:13.028 MSK|law|test1|640094f5.1ba5ac|LOG:  connection
authorized: user=law database=test1 application_name=psql
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG:  statement: GRANT
ALL ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG: 
ExecuteGrantStmt(): before objectNamesToOids()
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG: 
ExecuteGrantStmt(): after objectNamesToOids()
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG: 
ExecGrant_Relation() after SearchSysCache1();
ItemPointerGetOffsetNumber(&tuple->t_self): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG: 
ExecGrant_Relationi(): before CatalogTupleUpdate();
ItemPointerGetOffsetNumber(&newtuple->t_self): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG:  heap_update():
after ReadBuffer(); buffer: 2012, ItemPointerGetOffsetNumber(otid): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|LOG:  heap_update():
after PageGetItemId(); ItemPointerGetOffsetNumber(otid): 24, lp->lp_flags:
1
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ab|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG:  statement: GRANT
ALL ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG: 
ExecuteGrantStmt(): before objectNamesToOids()
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG: 
heap_page_prune_execute() before ItemIdSetUnused(); buffer: 2012, off: 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG: 
ExecuteGrantStmt(): after objectNamesToOids()
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG: 
ExecGrant_Relation() after SearchSysCache1();
ItemPointerGetOffsetNumber(&tuple->t_self): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG: 
ExecGrant_Relationi(): before CatalogTupleUpdate();
ItemPointerGetOffsetNumber(&newtuple->t_self): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG:  heap_update():
after ReadBuffer(); buffer: 2012, ItemPointerGetOffsetNumber(otid): 24
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG:  heap_update():
after PageGetItemId(); ItemPointerGetOffsetNumber(otid): 24, lp->lp_flags:
0
2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
ON pg_class TO public;
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3025,
PID: 1811884

So it looks like the session 1ba5ac made linepointer 24 unused while
pruning in the guts of objectNamesToOids(), then got the same
offset (24) from the SearchSysCache1() and finally was surprised
inside heap_update() to see an unused line pointer.
This raises two questions for me.
1) Was it legal to prune that linepointer (what if ExecGrant do not
perform
heap_modify_tuple() in this case, will an unused line pointer be left
behind?)?
2) Should page pruning be reflected in SysCache somehow?



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2023-03-04 06:00  Alexander Lakhin <exclusion@gmail.com>
  parent: PG Bug reporting form <noreply@postgresql.org>
  0 siblings, 1 reply; 13+ messages in thread

From: Alexander Lakhin @ 2023-03-04 06:00 UTC (permalink / raw)
  To: pgsql-bugs@lists.postgresql.org

02.03.2023 16:00, PG Bug reporting form wrote:
> #5  0x0000556725c44981 in ExceptionalCondition
> (conditionName=conditionName@entry=0x556725dc6b00 "ItemIdIsNormal(lp)",
> fileName=fileName@entry=0x556725dc48e0 "heapam.c",
> lineNumber=lineNumber@entry=3024) at assert.c:66
> ...
> 2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG:
> ExecuteGrantStmt(): before objectNamesToOids()
> 2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
> ON pg_class TO public;
> 2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|LOG:
> heap_page_prune_execute() before ItemIdSetUnused(); buffer: 2012, off: 24
> 2023-03-02 15:22:13.031 MSK|law|test1|640094f5.1ba5ac|STATEMENT:  GRANT ALL
> ON pg_class TO public;
> ...
>
> So it looks like the session 1ba5ac made linepointer 24 unused while
> pruning in the guts of objectNamesToOids(), then got the same
> offset (24) from the SearchSysCache1() and finally was surprised
> inside heap_update() to see an unused line pointer.
> This raises two questions for me.
> 1) Was it legal to prune that linepointer (what if ExecGrant do not
> perform
> heap_modify_tuple() in this case, will an unused line pointer be left
> behind?)?
> 2) Should page pruning be reflected in SysCache somehow?

Further investigation gave me a positive answer to the first question.
With more debug logging added I see that when that pruning executed
there was a redirection happened. There was dead items found in a tuple
chain starting from position 22, and redirection 22 -> 25 was performed,
so item 24 became unused.
The fragment of the detailed log is attached, and also you can look at
a dump of the modified page at the moment of the Assert.

SELECT * from heap_page_item_attrs(pg_read_binary_file('page.bin'), 
1259::oid, true);
shows:
...
  21 |   3600 |        1 |    225 |    680 |      0 |        0 | (10,21) 
|          33 |      11011 |     32 | 
1111111111111111111111111111111000000000 |       | ...
  22 |     25 |        2 |      0 |        |        | |         
|             |            | |                                          
|       |
  23 |      0 |        3 |      0 |        |        | |         
|             |            | |                                          
|       |
  24 |      0 |        0 |      0 |        |        | |         
|             |            | |                                          
|       |
  25 |   3368 |        1 |    225 | 222501 |      0 |        0 | (10,25) 
|       32801 |      10499 |     32 | 
1111111111111111111111111111111000000000 |       | ...
(25 rows)

So we have only the second question left.

Best regards,
Alexander

Attachments:

server.log (text/x-log, 4.7K) download 2023-03-04 06:57:14.834 MSK|law|test1|6402c19a.1e2bbc|LOG: connection authorized: user=law database=test1 application_name=psql 2023-03-04 06:57:14.834 MSK|law|test1|6402c19a.1e2bbd|LOG: connection authorized: user=law database=test1 application_name=psql 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: statement: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: ExecuteGrantStmt(): before objectNamesToOids() 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: ExecuteGrantStmt(): after objectNamesToOids() 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: ExecGrant_Relation() after SearchSysCache1(); ItemPointerGetOffsetNumber(&tuple->t_self): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: ExecGrant_Relationi(): before CatalogTupleUpdate(); ItemPointerGetOffsetNumber(&newtuple->t_self): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: heap_update(): after ReadBuffer(); buffer: 2014, ItemPointerGetOffsetNumber(otid): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|LOG: heap_update(): after PageGetItemId(); ItemPointerGetOffsetNumber(otid): 24, lp->lp_flags: 1 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbd|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: statement: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: ExecuteGrantStmt(): before objectNamesToOids() 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_prune_chain() before heap_prune_record_unused() 2; nchain: 3, chainitems[0]: 22, latestdead: 24, chainitems[1]: 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_prune_chain() before heap_prune_record_redirect(); i: 2, nchain: 3, rootoffnum: 22, chainitems[2]: 25 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_page_prune() before heap_page_prune_execute(); buffer: 2014, BufferGetBlockNumber(buffer): 10, prstate.nredirected: 1, prstate.ndead: 0, prstate.nunused: 1, prstate.nowunused[0]: 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_page_prune_execute() before ItemIdSetRedirect(); buffer: 2014, fromoff: 22, tooff: 25, fromlp: 0x7fac9205ac6c 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_page_prune_execute() before ItemIdSetUnused(); buffer: 2014, off: 24, lp: 0x7fac9205ac74 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: ExecuteGrantStmt(): after objectNamesToOids() 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: ExecGrant_Relation() after SearchSysCache1(); ItemPointerGetOffsetNumber(&tuple->t_self): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: ExecGrant_Relationi(): before CatalogTupleUpdate(); ItemPointerGetOffsetNumber(&newtuple->t_self): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_update(): after ReadBuffer(); buffer: 2014, ItemPointerGetOffsetNumber(otid): 24 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|LOG: heap_update(): after PageGetItemId(); ItemPointerGetOffsetNumber(otid): 24, lp->lp_flags: 0 2023-03-04 06:57:14.838 MSK|law|test1|6402c19a.1e2bbc|STATEMENT: GRANT ALL ON pg_class TO public; TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3025, PID: 1977276
page.bin (application/octet-stream, 8.0K) download ^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2023-03-04 16:48  Andres Freund <andres@anarazel.de>
  parent: Alexander Lakhin <exclusion@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Andres Freund @ 2023-03-04 16:48 UTC (permalink / raw)
  To: pgsql-bugs@lists.postgresql.org, Alexander Lakhin <exclusion@gmail.com>

Hi

On March 3, 2023 10:00:00 PM PST, Alexander Lakhin <exclusion@gmail.com> wrote:
>02.03.2023 16:00, PG Bug reporting form wrote:
>So we have only the second question left.

My first suspicion would be that we aren't holding a lock in the right moment, to enforce cache invalidation processing.

Greetings,

Andres
-- 
Sent from my Android device with K-9 Mail. Please excuse my brevity.





^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2023-10-07 08:00  Alexander Lakhin <exclusion@gmail.com>
  parent: Andres Freund <andres@anarazel.de>
  0 siblings, 1 reply; 13+ messages in thread

From: Alexander Lakhin @ 2023-10-07 08:00 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

Hi,

04.03.2023 19:48, Andres Freund wrote:
> My first suspicion would be that we aren't holding a lock in the right moment, to enforce cache invalidation processing.
>

I've encountered another case of that assertion failure (this time with pg_statistic):
numclients=10
for ((c=1;c<=numclients;c++)); do
   createdb db$c
done

for ((i=1;i<=50;i++)); do
   echo "iteration $i"

   for ((c=1;c<=numclients;c++)); do
     echo "
CREATE TABLE t(i int4, t1 text[], t2 text[]);
INSERT INTO t SELECT g,  ARRAY[repeat('x', g)], ARRAY[repeat('x', g)] FROM generate_series(1, 200) g;
ANALYZE t;
     " | psql -d db$c >/dev/null
   done

   for ((c=1;c<=numclients;c++)); do
     echo "
ANALYZE t;
     " | psql -d db$c >/dev/null &

     echo "
SELECT * FROM t WHERE i = 1;
ANALYZE t;
     " | psql -d db$c >/dev/null &
   done
   wait
   grep 'TRAP:' server.log && { break; }

   for ((c=1;c<=numclients;c++)); do
     echo "
DROP TABLE t; VACUUM pg_statistic;
     " | psql -d db$c >/dev/null
   done
done

...
iteration 13
server closed the connection unexpectedly
         This probably means the server terminated abnormally
         before or while processing the request.
connection to server was lost
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3074, PID: 89697

Reproduced on REL_12_STABLE (starting from 5e0928005) .. master.
(Modifying pruneheap.c as in [1] not needed for this case.)

Here we have the following sequence of events:
Session 1
ANALYZE t; // needed just to produce material for pruning
     do_analyze_rel() -> update_attstats() -> CatalogTupleUpdateWithInfo() -> heap_update(ctid(18,16)); 
PrepareToInvalidateCacheTuple(hashvalue: {hash1})
                 Session 2:
                 SELECT * FROM t WHERE i = 1;
                     SearchCatCacheInternal(hashValue: {hash1})
                         SearchCatCacheMiss(hashValue: {hash1})
     ProcessInvalidationMessages()
     CatCacheInvalidate(hashValue: {hash1})
     CatCacheInvalidate(hashValue: {hash2})
                             CatCacheInvalidate(hashValue: {hash1})
                         SearchCatCacheMiss returns tid(18,16)

                 ANALYZE t;
                     do_analyze_rel() -> update_attstats()
                         attno=0 SearchSysCache3() -> SearchCatCacheInternal(hashValue: {hash2}) -> SearchCatCacheMiss() 
-> heap_page_prune(block: 18)
                         attno=1 SearchSysCache3() -> SearchCatCacheInternal(hashValue: {hash1}) -> oldtup = tid(18,16)
                         CatalogTupleUpdateWithInfo() -> heap_update(tid(18, 16))

(A server.log with additional tracing messages for one of the failed runs
is attached.)

In other words, a backend can get some tuple id from catcache and then prune
the underlying page while searching for another (missing) entry in the cache
(any other reading of the page that may trigger pruning will do as well).
After that, an attempt to update that tuple might trigger the Assert().

[1] https://www.postgresql.org/message-id/17821-dd8c334263399284%40postgresql.org

Best regards,
Alexander

Attachments:

server-db6.log (text/x-log, 23.9K) download 2023-10-07 10:02:26.542 MSK|law|postgres|65210282.3b728|LOG: statement: CREATE DATABASE db6; 2023-10-07 10:02:26.551 MSK|law|postgres|65210282.3b728|STATEMENT: CREATE DATABASE db6; 2023-10-07 10:02:26.680 MSK|law|db6|65210282.3b742|LOG: connection authenticated: user="law" method=trust (.../pg_hba.conf:117) 2023-10-07 10:02:26.680 MSK|law|db6|65210282.3b742|LOG: connection authorized: user=law database=db6 application_name=psql 2023-10-07 10:02:26.682 MSK|law|db6|65210282.3b742|LOG: statement: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 18759199 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: 18759199 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1141534850 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1141534850 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1081954613 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1081954613 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|STATEMENT: CREATE TABLE t(i int4, t1 text[], t2 text[]); 2023-10-07 10:02:26.683 MSK|law|db6|65210282.3b742|LOG: statement: INSERT INTO t SELECT g, ARRAY[repeat('x', g)], ARRAY[repeat('x', g)] FROM generate_series(1, 200) g; 2023-10-07 10:02:26.684 MSK|law|db6|65210282.3b742|LOG: statement: ANALYZE t; 2023-10-07 10:02:26.684 MSK|law|db6|65210282.3b742|LOG: !!!do_analyze_rel 2023-10-07 10:02:26.684 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.684 MSK|law|db6|65210282.3b742|LOG: !!!do_analyze_rel| numrows: 200 2023-10-07 10:02:26.684 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!do_analyze_rel| before update_attstats 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!update_attstats| before SearchSysCache3(), attno: 0 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: 869244076 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!update_attstats| before SearchSysCache3(), attno: 1 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: -1994117683 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!update_attstats| before SearchSysCache3(), attno: 2 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!SearchCatCacheMiss| returning NULL 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: -1923937160 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!do_analyze_rel| after update_attstats 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.685 MSK|law|db6|65210282.3b742|LOG: disconnection: session time: 0:00:00.005 user=law database=db6 host=[local] 2023-10-07 10:02:26.723 MSK|law|db6|65210282.3b775|LOG: connection authenticated: user="law" method=trust (.../pg_hba.conf:117) 2023-10-07 10:02:26.723 MSK|law|db6|65210282.3b775|LOG: connection authorized: user=law database=db6 application_name=psql 2023-10-07 10:02:26.723 MSK|law|db6|65210282.3b775|LOG: statement: ANALYZE t; 2023-10-07 10:02:26.723 MSK|law|db6|65210282.3b775|LOG: !!!do_analyze_rel 2023-10-07 10:02:26.723 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!do_analyze_rel| numrows: 200 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b779|LOG: connection authenticated: user="law" method=trust (.../pg_hba.conf:117) 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b779|LOG: connection authorized: user=law database=db6 application_name=psql 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!do_analyze_rel| before update_attstats 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| before SearchSysCache3(), attno: 0 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (17, 26) 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after heap_modify_tuple(), ItemPointerGetBlockNumber(&stup->t_self) 17, ItemPointerGetOffsetNumber(&stup->t_self): 26 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!heap_update| relation: 2619, buffer: 6550, ItemPointerGetBlockNumber(otid): 17, ItemPointerGetOffsetNumber(otid): 26 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: 869244076 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after CatalogTupleUpdateWithInfo() 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| before SearchSysCache3(), attno: 1 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (18, 16) 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after heap_modify_tuple(), ItemPointerGetBlockNumber(&stup->t_self) 18, ItemPointerGetOffsetNumber(&stup->t_self): 16 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|LOG: !!!heap_update| relation: 2619, buffer: 6551, ItemPointerGetBlockNumber(otid): 18, ItemPointerGetOffsetNumber(otid): 16 2023-10-07 10:02:26.724 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: statement: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: -1994117683 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after CatalogTupleUpdateWithInfo() 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| before SearchSysCache3(), attno: 2 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (19, 1) 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after heap_modify_tuple(), ItemPointerGetBlockNumber(&stup->t_self) 19, ItemPointerGetOffsetNumber(&stup->t_self): 1 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!heap_update| relation: 2619, buffer: 11207, ItemPointerGetBlockNumber(otid): 19, ItemPointerGetOffsetNumber(otid): 1 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!update_attstats| after CatalogTupleUpdateWithInfo() 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!do_analyze_rel| after update_attstats 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (17, 26) 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!ProcessInvalidationMessages 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!CatCacheInvalidate| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (18, 16) 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: -1923937160 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (19, 2) 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: SELECT * FROM t WHERE i = 1; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b775|LOG: disconnection: session time: 0:00:00.003 user=law database=db6 host=[local] 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: statement: ANALYZE t; 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|LOG: !!!do_analyze_rel 2023-10-07 10:02:26.725 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!do_analyze_rel| numrows: 200 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!do_analyze_rel| before update_attstats 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!update_attstats| before SearchSysCache3(), attno: 0 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| cache->cc_relname: pg_statistic, hashValue: 869244076 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!heap_page_prune() before heap_page_prune_execute(); relation: 2619, buffer: 6550, BufferGetBlockNumber(buffer): 17, prstate.nredirected: 0, prstate.ndead: 1, prstate.nunused: 0, prstate.nowunused[0]: -1, query: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!heap_page_prune| end 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!heap_page_prune() before heap_page_prune_execute(); relation: 2619, buffer: 6551, BufferGetBlockNumber(buffer): 18, prstate.nredirected: 0, prstate.ndead: 1, prstate.nunused: 0, prstate.nowunused[0]: -1, query: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!heap_page_prune| end 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheMiss| returning ct->tuple: (18, 17) 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!update_attstats| after heap_modify_tuple(), ItemPointerGetBlockNumber(&stup->t_self) 18, ItemPointerGetOffsetNumber(&stup->t_self): 17 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!heap_update| relation: 2619, buffer: 6551, ItemPointerGetBlockNumber(otid): 18, ItemPointerGetOffsetNumber(otid): 17 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!PrepareToInvalidateCacheTuple| relation: 2619, hashvalue: 869244076 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!update_attstats| after CatalogTupleUpdateWithInfo() 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!update_attstats| before SearchSysCache3(), attno: 1 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!SearchCatCacheInternal| cache->cc_relname: pg_statistic, hashValue: -1994117683 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|LOG: !!!update_attstats| after heap_modify_tuple(), ItemPointerGetBlockNumber(&stup->t_self) 18, ItemPointerGetOffsetNumber(&stup->t_self): 16 2023-10-07 10:02:26.726 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; 2023-10-07 10:02:26.727 MSK|law|db6|65210282.3b779|LOG: !!!heap_update| relation: 2619, buffer: 6551, ItemPointerGetBlockNumber(otid): 18, ItemPointerGetOffsetNumber(otid): 16 2023-10-07 10:02:26.727 MSK|law|db6|65210282.3b779|STATEMENT: ANALYZE t; TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3090, PID: 243577 postgres: law db6 [local] ANALYZE(ExceptionalCondition+0x69)[0x55e5ebc98e4c] postgres: law db6 [local] ANALYZE(heap_update+0x579)[0x55e5eb7953c5] postgres: law db6 [local] ANALYZE(simple_heap_update+0x62)[0x55e5eb7969f4] postgres: law db6 [local] ANALYZE(CatalogTupleUpdateWithInfo+0x4d)[0x55e5eb83eaa2] postgres: law db6 [local] ANALYZE(+0x25a936)[0x55e5eb8ba936] postgres: law db6 [local] ANALYZE(+0x25d856)[0x55e5eb8bd856] postgres: law db6 [local] ANALYZE(analyze_rel+0x2b0)[0x55e5eb8be0b7] postgres: law db6 [local] ANALYZE(vacuum+0x4d2)[0x55e5eb950865] postgres: law db6 [local] ANALYZE(ExecVacuum+0x96d)[0x55e5eb951224] postgres: law db6 [local] ANALYZE(standard_ProcessUtility+0x6d2)[0x55e5ebb518a4] postgres: law db6 [local] ANALYZE(ProcessUtility+0xb7)[0x55e5ebb51d89] postgres: law db6 [local] ANALYZE(+0x4ef146)[0x55e5ebb4f146] postgres: law db6 [local] ANALYZE(+0x4ef440)[0x55e5ebb4f440] postgres: law db6 [local] ANALYZE(PortalRun+0x193)[0x55e5ebb4f842] postgres: law db6 [local] ANALYZE(+0x4ebaac)[0x55e5ebb4baac] postgres: law db6 [local] ANALYZE(PostgresMain+0x713)[0x55e5ebb4d92d] postgres: law db6 [local] ANALYZE(+0x444c4d)[0x55e5ebaa4c4d] postgres: law db6 [local] ANALYZE(+0x447c88)[0x55e5ebaa7c88] postgres: law db6 [local] ANALYZE(+0x447e26)[0x55e5ebaa7e26] postgres: law db6 [local] ANALYZE(BackgroundWorkerInitializeConnection+0x0)[0x55e5ebaa936b] postgres: law db6 [local] ANALYZE(main+0x21a)[0x55e5eb9c5d9c] postgres: law db6 [local] ANALYZE(_start+0x25)[0x55e5eb7335c5]
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2024-04-09 12:00  Alexander Lakhin <exclusion@gmail.com>
  parent: Alexander Lakhin <exclusion@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Alexander Lakhin @ 2024-04-09 12:00 UTC (permalink / raw)
  To: Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; +Cc: Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

Hello,

07.10.2023 11:00, Alexander Lakhin wrote:
>
> I've encountered another case of that assertion failure (this time with pg_statistic):

That second case is not reproduced anymore, after ad98fb142, but the first
is still actual.

I also discovered another one, with pg_subscription:
echo "
CREATE ROLE su SUPERUSER;
CREATE SUBSCRIPTION sub CONNECTION 'dbname=nonexisting'
   PUBLICATION pub WITH (connect = false);
" | psql

for ((i=1;i<=20;i++)); do
   echo "iteration $i"

   for ((k=1;k<=100;k++)); do
     for ((j=1;j<=200;j++)); do echo "
ALTER SUBSCRIPTION sub SET (synchronous_commit = false);
     "; done | psql >/dev/null 2>&1 &

     for ((j=1;j<=200;j++)); do echo "
ALTER SUBSCRIPTION sub OWNER TO su;
ALTER SUBSCRIPTION sub SET (slot_name = NONE);
     "; done | psql >/dev/null 2>&1 &
     wait
   done

   grep 'TRAP:' server.log && break;
done

This script fails for me as below:
...
iteration 5
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3296, PID: 388093

(sed 's/minfree = Max(minfree, BLCKSZ \/ 10)/minfree = Max(minfree, BLCKSZ \/1)/'
-i src/backend/access/heap/pruneheap.c
is highly recommended for reproducing)

Melanie and Heikki, as you have been working on pruning over the recent
months, perhaps this defect could be of interest to you...

Best regards,
Alexander





^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2024-04-09 17:41  Melanie Plageman <melanieplageman@gmail.com>
  parent: Alexander Lakhin <exclusion@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Melanie Plageman @ 2024-04-09 17:41 UTC (permalink / raw)
  To: Alexander Lakhin <exclusion@gmail.com>; +Cc: Heikki Linnakangas <hlinnaka@iki.fi>; Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

On Tue, Apr 9, 2024 at 8:00 AM Alexander Lakhin <exclusion@gmail.com> wrote:
>
> Hello,
>
> 07.10.2023 11:00, Alexander Lakhin wrote:
> >
> > I've encountered another case of that assertion failure (this time with pg_statistic):
>
> That second case is not reproduced anymore, after ad98fb142, but the first
> is still actual.
>
> I also discovered another one, with pg_subscription:
> echo "
> CREATE ROLE su SUPERUSER;
> CREATE SUBSCRIPTION sub CONNECTION 'dbname=nonexisting'
>    PUBLICATION pub WITH (connect = false);
> " | psql
>
> for ((i=1;i<=20;i++)); do
>    echo "iteration $i"
>
>    for ((k=1;k<=100;k++)); do
>      for ((j=1;j<=200;j++)); do echo "
> ALTER SUBSCRIPTION sub SET (synchronous_commit = false);
>      "; done | psql >/dev/null 2>&1 &
>
>      for ((j=1;j<=200;j++)); do echo "
> ALTER SUBSCRIPTION sub OWNER TO su;
> ALTER SUBSCRIPTION sub SET (slot_name = NONE);
>      "; done | psql >/dev/null 2>&1 &
>      wait
>    done
>
>    grep 'TRAP:' server.log && break;
> done
>
> This script fails for me as below:
> ...
> iteration 5
> TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3296, PID: 388093
>
> (sed 's/minfree = Max(minfree, BLCKSZ \/ 10)/minfree = Max(minfree, BLCKSZ \/1)/'
> -i src/backend/access/heap/pruneheap.c
> is highly recommended for reproducing)
>
> Melanie and Heikki, as you have been working on pruning over the recent
> months, perhaps this defect could be of interest to you...

Hi Alexander,

Just to confirm, the original bug was filed against 15, but I see
ad98fb142 was committed on master as well as backpatched. You are able
to reproduce  your pg_subscription example on master? I tried your
repro (including the modification to minfree) and wasn't able to
reproduce on master on my machine. This could totally be my fault, but
I just wanted to confirm you were able to repro on master.

- Melanie





^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2024-04-09 19:00  Alexander Lakhin <exclusion@gmail.com>
  parent: Melanie Plageman <melanieplageman@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Alexander Lakhin @ 2024-04-09 19:00 UTC (permalink / raw)
  To: Melanie Plageman <melanieplageman@gmail.com>; +Cc: Heikki Linnakangas <hlinnaka@iki.fi>; Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

Hi Melanie,

09.04.2024 20:41, Melanie Plageman wrote:
> Just to confirm, the original bug was filed against 15, but I see
> ad98fb142 was committed on master as well as backpatched. You are able
> to reproduce  your pg_subscription example on master? I tried your
> repro (including the modification to minfree) and wasn't able to
> reproduce on master on my machine. This could totally be my fault, but
> I just wanted to confirm you were able to repro on master.
>

Yes, I reproduced both cases on master (27074bce0).
Please look at the self-contained script that works for me:
.../repro-17821-SUBSCRIPTION.sh
...
CREATE ROLE
WARNING:  subscription was created, but is not connected
HINT:  To initiate replication, you must manually create the replication slot, enable the subscription, and refresh the 
subscription.
CREATE SUBSCRIPTION
iteration 1
iteration 2
iteration 3
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3296, PID: 1069025
TRAP: failed Assert("ItemIdIsNormal(lp)"), File: "heapam.c", Line: 3296, PID: 1069621

Best regards,
Alexander
sed 's/minfree = Max(minfree, BLCKSZ \/ 10)/minfree = Max(minfree, BLCKSZ \/1)/' -i src/backend/access/heap/pruneheap.c
./configure --enable-debug --enable-cassert -q && make -j8 -s && TESTS=test_setup make -s check-tests

PGROOT=`pwd`/tmp_install/usr/local/pgsql
export PGDATA=`pwd`/tmpdb

export PATH="$PGROOT/bin:$PATH"
export LD_LIBRARY_PATH="$PGROOT/lib"

[ -f "$PGDATA/postmaster.pid" ] && pg_ctl stop -m immediate

rm *.log
rm -rf "$PGDATA"; initdb >initdb.log 2>&1

export PGPORT=15431
echo "
fsync=off
port=$PGPORT
" >> $PGDATA/postgresql.auto.conf

ulimit -c unlimited
pg_ctl -l server.log start
createdb regression
export PGDATABASE=regression
export PGHOST=127.0.0.1

res=0

echo "
CREATE ROLE su SUPERUSER;
CREATE SUBSCRIPTION sub CONNECTION 'dbname=nonexisting'
  PUBLICATION pub WITH (connect = false);
" | psql

for ((i=1;i<=20;i++)); do
  echo "iteration $i"

  for ((k=1;k<=100;k++)); do
    for ((j=1;j<=200;j++)); do echo "
ALTER SUBSCRIPTION sub SET (synchronous_commit = false);
    "; done | psql >/dev/null 2>&1 &
 
    for ((j=1;j<=200;j++)); do echo "
ALTER SUBSCRIPTION sub OWNER TO su;
ALTER SUBSCRIPTION sub SET (slot_name = NONE);
    "; done | psql >/dev/null 2>&1 &
    wait
  done

grep 'TRAP:' server.log && break;
done

pg_ctl -w -t 5 stop || pg_ctl stop -m immediate


Attachments:

repro-17821-SUBSCRIPTION.sh.txt (text/plain, 1.3K) download sed 's/minfree = Max(minfree, BLCKSZ \/ 10)/minfree = Max(minfree, BLCKSZ \/1)/' -i src/backend/access/heap/pruneheap.c ./configure --enable-debug --enable-cassert -q && make -j8 -s && TESTS=test_setup make -s check-tests PGROOT=`pwd`/tmp_install/usr/local/pgsql export PGDATA=`pwd`/tmpdb export PATH="$PGROOT/bin:$PATH" export LD_LIBRARY_PATH="$PGROOT/lib" [ -f "$PGDATA/postmaster.pid" ] && pg_ctl stop -m immediate rm *.log rm -rf "$PGDATA"; initdb >initdb.log 2>&1 export PGPORT=15431 echo " fsync=off port=$PGPORT " >> $PGDATA/postgresql.auto.conf ulimit -c unlimited pg_ctl -l server.log start createdb regression export PGDATABASE=regression export PGHOST=127.0.0.1 res=0 echo " CREATE ROLE su SUPERUSER; CREATE SUBSCRIPTION sub CONNECTION 'dbname=nonexisting' PUBLICATION pub WITH (connect = false); " | psql for ((i=1;i<=20;i++)); do echo "iteration $i" for ((k=1;k<=100;k++)); do for ((j=1;j<=200;j++)); do echo " ALTER SUBSCRIPTION sub SET (synchronous_commit = false); "; done | psql >/dev/null 2>&1 & for ((j=1;j<=200;j++)); do echo " ALTER SUBSCRIPTION sub OWNER TO su; ALTER SUBSCRIPTION sub SET (slot_name = NONE); "; done | psql >/dev/null 2>&1 & wait done grep 'TRAP:' server.log && break; done pg_ctl -w -t 5 stop || pg_ctl stop -m immediate
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2024-11-13 00:26  Noah Misch <noah@leadboat.com>
  parent: Alexander Lakhin <exclusion@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Noah Misch @ 2024-11-13 00:26 UTC (permalink / raw)
  To: Alexander Lakhin <exclusion@gmail.com>; +Cc: Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

On Tue, Apr 09, 2024 at 10:00:00PM +0300, Alexander Lakhin wrote:
> 09.04.2024 20:41, Melanie Plageman wrote:
> > Just to confirm, the original bug was filed against 15, but I see
> > ad98fb142 was committed on master as well as backpatched. You are able
> > to reproduce  your pg_subscription example on master? I tried your
> > repro (including the modification to minfree) and wasn't able to
> > reproduce on master on my machine. This could totally be my fault, but
> > I just wanted to confirm you were able to repro on master.
> 
> Yes, I reproduced both cases on master (27074bce0).

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.  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.  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.

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?

Thanks,
nm
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.c
index d00300c..787a995 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"
 
@@ -3233,6 +3234,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);
 
@@ -6372,6 +6374,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.c
index ff81744..d837f41 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/Makefile
index 0753a9d..013c68e 100644
--- a/src/test/modules/injection_points/Makefile
+++ b/src/test/modules/injection_points/Makefile
@@ -13,7 +13,7 @@ PGFILEDESC = "injection_points - facility for injection points"
 REGRESS = injection_points reindex_conc
 REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress
 
-ISOLATION = basic inplace
+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.out
new file mode 100644
index 0000000..9caba9a
--- /dev/null
+++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out
@@ -0,0 +1,133 @@
+Parsed test spec with 4 sessions
+
+starting permutation: cachefill1 at2 vac3 grant1 mkrels4 wakegrant4 wakeinval4
+mkrels
+------
+      
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0;
+?column?
+--------
+t       
+(1 row)
+
+step at2: ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; <waiting ...>
+step vac3: VACUUM pg_class; <waiting ...>
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step mkrels4: 
+	SELECT vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+
+mkrels
+------
+      
+(1 row)
+
+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>
+ERROR:  duplicate key value violates unique constraint "pg_class_oid_index"
+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>
+
+starting permutation: cachefill1 at2 vac3 grant1 wakegrant4 wakeinval4
+mkrels
+------
+      
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+injection_points_attach
+-----------------------
+                       
+(1 row)
+
+step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0;
+?column?
+--------
+t       
+(1 row)
+
+step at2: ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; <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/meson.build b/src/test/modules/injection_points/meson.build
index 58f1900..626039e 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.spec
new file mode 100644
index 0000000..50dde9a
--- /dev/null
+++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec
@@ -0,0 +1,107 @@
+# 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.
+
+# 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
+{
+	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;
+}
+
+# Wait during GRANT.
+session s1
+setup	{
+	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.  It has to be an update that uses a
+# relation lock instead of LockTuple(), else GRANT would block it.  Wait
+# before sending invals, so s1 will not get a cache miss.
+session s2
+setup	{
+	SELECT injection_points_set_local();
+	SELECT injection_points_attach('SIInsertDataEntries2', 'wait');
+}
+step at2		{ ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; }
+
+# VACUUM to achieve LP_UNUSED.  Again delay any s1 cache miss.
+session s3
+setup	{
+	SELECT injection_points_set_local();
+	SELECT injection_points_attach('SIInsertDataEntries3', 'wait');
+}
+step vac3		{ VACUUM pg_class; }
+
+# Non-blocking actions.
+session s4
+# 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');
+}
+
+# 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"
+	wakeinval4
+
+# subtract mkrels4: tuple $FROM_SYSCACHE becomes LP_UNUSED
+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)
+	wakegrant4		# s1 wakes, assertion failure
+	wakeinval4

Attachments:

repro-ItemIdIsNormal-v1.patch (text/plain, 10.1K) 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.c index d00300c..787a995 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" @@ -3233,6 +3234,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); @@ -6372,6 +6374,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.c index ff81744..d837f41 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/Makefile index 0753a9d..013c68e 100644 --- a/src/test/modules/injection_points/Makefile +++ b/src/test/modules/injection_points/Makefile @@ -13,7 +13,7 @@ PGFILEDESC = "injection_points - facility for injection points" REGRESS = injection_points reindex_conc REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress -ISOLATION = basic inplace +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.out new file mode 100644 index 0000000..9caba9a --- /dev/null +++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out @@ -0,0 +1,133 @@ +Parsed test spec with 4 sessions + +starting permutation: cachefill1 at2 vac3 grant1 mkrels4 wakegrant4 wakeinval4 +mkrels +------ + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0; +?column? +-------- +t +(1 row) + +step at2: ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; <waiting ...> +step vac3: VACUUM pg_class; <waiting ...> +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step mkrels4: + SELECT vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED + +mkrels +------ + +(1 row) + +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> +ERROR: duplicate key value violates unique constraint "pg_class_oid_index" +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> + +starting permutation: cachefill1 at2 vac3 grant1 wakegrant4 wakeinval4 +mkrels +------ + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +injection_points_attach +----------------------- + +(1 row) + +step cachefill1: SELECT pg_relation_filenode('vactest.orig50') > 0; +?column? +-------- +t +(1 row) + +step at2: ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; <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/meson.build b/src/test/modules/injection_points/meson.build index 58f1900..626039e 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.spec new file mode 100644 index 0000000..50dde9a --- /dev/null +++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec @@ -0,0 +1,107 @@ +# 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. + +# 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 +{ + 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; +} + +# Wait during GRANT. +session s1 +setup { + 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. It has to be an update that uses a +# relation lock instead of LockTuple(), else GRANT would block it. Wait +# before sending invals, so s1 will not get a cache miss. +session s2 +setup { + SELECT injection_points_set_local(); + SELECT injection_points_attach('SIInsertDataEntries2', 'wait'); +} +step at2 { ALTER TABLE vactest.orig50 FORCE ROW LEVEL SECURITY; } + +# VACUUM to achieve LP_UNUSED. Again delay any s1 cache miss. +session s3 +setup { + SELECT injection_points_set_local(); + SELECT injection_points_attach('SIInsertDataEntries3', 'wait'); +} +step vac3 { VACUUM pg_class; } + +# Non-blocking actions. +session s4 +# 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'); +} + +# 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" + wakeinval4 + +# subtract mkrels4: tuple $FROM_SYSCACHE becomes LP_UNUSED +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) + wakegrant4 # s1 wakes, assertion failure + wakeinval4
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2025-01-11 21:44  Noah Misch <noah@leadboat.com>
  parent: Noah Misch <noah@leadboat.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Noah Misch @ 2025-01-11 21:44 UTC (permalink / raw)
  To: Alexander Lakhin <exclusion@gmail.com>; +Cc: Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

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).
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.c
index 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.c
index 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/Makefile
index 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.out
new file mode 100644
index 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.out
new file mode 100644
index 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 exists
diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build
index 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.spec
new file mode 100644
index 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"
+	wakeinval4
diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
index 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),

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.c index 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.c index 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/Makefile index 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.out new file mode 100644 index 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.out new file mode 100644 index 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 exists diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build index 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.spec new file mode 100644 index 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" + wakeinval4 diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 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),
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2025-01-23 02:13  Noah Misch <noah@leadboat.com>
  parent: Noah Misch <noah@leadboat.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Noah Misch @ 2025-01-23 02:13 UTC (permalink / raw)
  To: Alexander Lakhin <exclusion@gmail.com>; +Cc: Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; Andres Freund <andres@anarazel.de>; pgsql-bugs@lists.postgresql.org

On Sat, Jan 11, 2025 at 01:44:54PM -0800, Noah Misch wrote:
> On Tue, Nov 12, 2024 at 04:26:57PM -0800, Noah Misch wrote:
> > 1. Make the ItemIdIsNormal() check a runtime check that causes heap_update()
> >    to return TM_Deleted.  It could Assert(RelationSupportsSysCache(rel)), too.

> A UNIQUE constraint violation is too late to avoid page header corruption.

> the page is next read from disk, it gets "ERROR:  invalid page".

> I plan to write (1).

Attached.  Outside of comments and tests, it's a simple 20-line patch.  Since
only two weeks will remain before release freeze, in the absence of review, I
would push this after 2025-01-25T16:00+0000.  Unfortunately, while this
prevents the page header corruption, there's a preexisting loss of DDL changes
that it doesn't fix.  I'll start a new thread about that, but I've included a
preview in Appendix 1 below.  Would anyone else like to work on the problem in
Appendix 1?  If so, let me know and feel free to start that thread yourself.
I may not get to it in 2025.

The new code sets TM_FailureData.xmax to invalid, which TM_Deleted may have
never done before.  I see no problem at sites using that xmax:

src/backend/executor/nodeModifyTable.c:3137:				if (TransactionIdIsCurrentTransactionId(context->tmfd.xmax))
src/backend/executor/nodeModifyTable.c:3307:							if (TransactionIdIsCurrentTransactionId(context->tmfd.xmax))
src/backend/access/heap/heapam_handler.c:395:			priorXmax = tmfd->xmax;
src/backend/access/heap/heapam_handler.c:488:						tmfd->xmax = priorXmax;

The first two will rightly compute
TransactionIdIsCurrentTransactionId()==false.  The second two are dealing with
tmfd from heap_lock_tuple(), not from heap_update().  Those grep matches are
from v18, but v13 and PGXN don't have additional challenges.

The test was sensitive at first to debug_parallel_query, debug_discard_caches,
autovacuum, and -DCATCACHE_FORCE_RELEASE.  It would have avoided an
alternative output to have a GUC controlling -DCATCACHE_FORCE_RELEASE, like we
have debug_discard_caches to control CLOBBER_CACHE_ALWAYS.  I'll not be
shocked if the buildfarm finds another way to make the test unstable.  We may
end up disabling autovacuum for src/test/modules/injection_points, since
autovacuum doesn't mix with non-local injection points that autovacuum can
reach.  For now, I've aimed to preserve compatibility with autovacuum=on.


==== Appendix 1: the unfixed loss of DDL changes

Unfortunately, I found a related case the patch doesn't fix.  The known-to-me
fixes for this other case are more invasive than the fix for $SUBJECT, so I
plan to move forward with the $SUBJECT fix and bring the following to a new
thread.  The third & last permutation of the $SUBJECT patch test case covers
the unfixed case.  In brief, suppose the oldtup for a catalog update is a
syscache entry with xmin=1234 ctid=(11,38).  We call CatalogTupleUpdate(rel,
'(11,38)', newtup).  Meanwhile, the tuple has been updated twice with a VACUUM
between the two updates, so (11,38) now contains an xmin=5678 tuple for the
same primary key.  CatalogTupleUpdate() has no way to know that its caller
used a stale oldtup, so the effect is to discard the two intervening updates.

To fix that, I lean toward the following:

- Make heap_modify_tuple() copy xmin from the oldtup.
- Make simple_heap_update() assert that newtup contains a valid xmin.
- In heap_update(), if newtup contains a valid xmin and otid now points to
  tuple with a different xmin, fail with TM_Deleted.  (Invalid xmin is also
  okay for heap_update() callers that don't route through
  simple_heap_update(), e.g. ExecUpdate().  ExecUpdate() has a snapshot
  preventing the loss.)

Catalog updates not based on heap_copytuple() or heap_modify_tuple() would
need changes.  They'll keep working in non-assert builds if they pass invalid
xmin.  They'll break if they pass garbage bytes in xmin.

Better ideas?  Other ways our lack of snapshot protecting oldtup might break?

Two of my upthread alternatives would also fix this, but they both entail the
churn of changing every CatalogTupleUpdate() caller (6 PGXN modules and ~200
postgresql.git calls):

> > 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.


==== Appendix 2: UNIQUE violation helps less than theorized

The repro-ItemIdIsNormal-v2.patch test case (see previous message of thread)
didn't get the UNIQUE violation I expected.  I opted to find out why not,
because I thought at the time we'll be relying long-term on the UNIQUE
violation when a different live tuple has replaced the ctid we're updating.
The problem update makes index entries for its new tuple, but this code stops
us from reporting the violation:

					 * Otherwise we have a definite conflict.  But before
					 * complaining, look to see if the tuple we want to insert
					 * is itself now committed dead --- if so, don't complain.
					 * This is a waste of time in normal scenarios but we must
					 * do it to support CREATE INDEX CONCURRENTLY.
...
					if (table_index_fetch_tuple_check(heapRel, &htid,
													  SnapshotSelf, NULL))

Since the page header corruption sets pd_lower=0, PageGetMaxOffsetNumber()
concludes the page has no tuples, and that table_index_fetch_tuple_check()
finds nothing.
Author:     Noah Misch <noah@leadboat.com>
Commit:     Noah Misch <noah@leadboat.com>

    Disable runningcheck for src/test/modules/injection_points/specs.
    
    Directory "injection_points" has specified NO_INSTALLCHECK since before
    commit c35f419d6efbdf1a050250d84b687e6705917711 added the specs, but
    that commit neglected to disable the corresponding meson runningcheck.
    The alternative would be to enable "make installcheck" for ISOLATION,
    but the GNU make build system lacks a concept of setting NO_INSTALLCHECK
    for REGRESS without also setting it for ISOLATION.  Back-patch to v17,
    where that commit first appeared, to avoid surprises when back-patching
    additional specs.
    
    Reviewed by FIXME.
    
    Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org

diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build
index 989b4db..ebe79fe 100644
--- a/src/test/modules/injection_points/meson.build
+++ b/src/test/modules/injection_points/meson.build
@@ -45,6 +45,7 @@ tests += {
       'basic',
       'inplace',
     ],
+    'runningcheck': false, # align with GNU make build system
   },
   'tap': {
     'env': {
Author:     Noah Misch <noah@leadboat.com>
Commit:     Noah Misch <noah@leadboat.com>

    Merge copies of converting an XID to a FullTransactionId.
    
    Assume twophase.c is the performance-sensitive caller, and preserve its
    choice of unlikely() branch hint.  Add some retrospective rationale for
    that choice.  Back-patch to v17, for the next commit to use it.
    
    Reviewed (in earlier versions) by Michael Paquier.
    
    Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org
    Discussion: https://postgr.es/m/20250116010051.f3.nmisch@google.com

diff --git a/contrib/amcheck/verify_heapam.c b/contrib/amcheck/verify_heapam.c
index 8a8e36d..8273123 100644
--- a/contrib/amcheck/verify_heapam.c
+++ b/contrib/amcheck/verify_heapam.c
@@ -1877,7 +1877,9 @@ check_tuple(HeapCheckContext *ctx, bool *xmin_commit_status_ok,
 /*
  * Convert a TransactionId into a FullTransactionId using our cached values of
  * the valid transaction ID range.  It is the caller's responsibility to have
- * already updated the cached values, if necessary.
+ * already updated the cached values, if necessary.  This is akin to
+ * FullTransactionIdFromAllowableAt(), but it tolerates corruption in the form
+ * of an xid before epoch 0.
  */
 static FullTransactionId
 FullTransactionIdFromXidAndCtx(TransactionId xid, const HeapCheckContext *ctx)
diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c
index ab2f4a8..73a8055 100644
--- a/src/backend/access/transam/twophase.c
+++ b/src/backend/access/transam/twophase.c
@@ -929,32 +929,16 @@ TwoPhaseGetDummyProc(TransactionId xid, bool lock_held)
 /*
  * Compute the FullTransactionId for the given TransactionId.
  *
- * The wrap logic is safe here because the span of active xids cannot exceed one
- * epoch at any given time.
+ * This is safe if the xid has not yet reached COMMIT PREPARED or ROLLBACK
+ * PREPARED.  After those commands, concurrent vac_truncate_clog() may make
+ * the xid cease to qualify as allowable.  XXX Not all callers limit their
+ * calls accordingly.
  */
 static inline FullTransactionId
 AdjustToFullTransactionId(TransactionId xid)
 {
-	FullTransactionId nextFullXid;
-	TransactionId nextXid;
-	uint32		epoch;
-
 	Assert(TransactionIdIsValid(xid));
-
-	LWLockAcquire(XidGenLock, LW_SHARED);
-	nextFullXid = TransamVariables->nextXid;
-	LWLockRelease(XidGenLock);
-
-	nextXid = XidFromFullTransactionId(nextFullXid);
-	epoch = EpochFromFullTransactionId(nextFullXid);
-	if (unlikely(xid > nextXid))
-	{
-		/* Wraparound occurred, must be from a prev epoch. */
-		Assert(epoch > 0);
-		epoch--;
-	}
-
-	return FullTransactionIdFromEpochAndXid(epoch, xid);
+	return FullTransactionIdFromAllowableAt(ReadNextFullTransactionId(), xid);
 }
 
 static inline int
diff --git a/src/backend/access/transam/xlogreader.c b/src/backend/access/transam/xlogreader.c
index 3596af0..91b6a91 100644
--- a/src/backend/access/transam/xlogreader.c
+++ b/src/backend/access/transam/xlogreader.c
@@ -2166,28 +2166,14 @@ RestoreBlockImage(XLogReaderState *record, uint8 block_id, char *page)
 FullTransactionId
 XLogRecGetFullXid(XLogReaderState *record)
 {
-	TransactionId xid,
-				next_xid;
-	uint32		epoch;
-
 	/*
 	 * This function is only safe during replay, because it depends on the
 	 * replay state.  See AdvanceNextFullTransactionIdPastXid() for more.
 	 */
 	Assert(AmStartupProcess() || !IsUnderPostmaster);
 
-	xid = XLogRecGetXid(record);
-	next_xid = XidFromFullTransactionId(TransamVariables->nextXid);
-	epoch = EpochFromFullTransactionId(TransamVariables->nextXid);
-
-	/*
-	 * If xid is numerically greater than next_xid, it has to be from the last
-	 * epoch.
-	 */
-	if (unlikely(xid > next_xid))
-		--epoch;
-
-	return FullTransactionIdFromEpochAndXid(epoch, xid);
+	return FullTransactionIdFromAllowableAt(TransamVariables->nextXid,
+											XLogRecGetXid(record));
 }
 
 #endif
diff --git a/src/backend/utils/adt/xid8funcs.c b/src/backend/utils/adt/xid8funcs.c
index 4736755..20b28b2 100644
--- a/src/backend/utils/adt/xid8funcs.c
+++ b/src/backend/utils/adt/xid8funcs.c
@@ -97,15 +97,11 @@ static bool
 TransactionIdInRecentPast(FullTransactionId fxid, TransactionId *extracted_xid)
 {
 	TransactionId xid = XidFromFullTransactionId(fxid);
-	uint32		now_epoch;
-	TransactionId now_epoch_next_xid;
 	FullTransactionId now_fullxid;
-	TransactionId oldest_xid;
-	FullTransactionId oldest_fxid;
+	TransactionId oldest_clog_xid;
+	FullTransactionId oldest_clog_fxid;
 
 	now_fullxid = ReadNextFullTransactionId();
-	now_epoch_next_xid = XidFromFullTransactionId(now_fullxid);
-	now_epoch = EpochFromFullTransactionId(now_fullxid);
 
 	if (extracted_xid != NULL)
 		*extracted_xid = xid;
@@ -135,52 +131,19 @@ TransactionIdInRecentPast(FullTransactionId fxid, TransactionId *extracted_xid)
 
 	/*
 	 * If fxid is not older than TransamVariables->oldestClogXid, the relevant
-	 * CLOG entry is guaranteed to still exist.  Convert
-	 * TransamVariables->oldestClogXid into a FullTransactionId to compare it
-	 * with fxid.  Determine the right epoch knowing that oldest_fxid
-	 * shouldn't be more than 2^31 older than now_fullxid.
+	 * CLOG entry is guaranteed to still exist.
+	 *
+	 * TransamVariables->oldestXid governs allowable XIDs.  Usually,
+	 * oldestClogXid==oldestXid.  It's also possible for oldestClogXid to
+	 * follow oldestXid, in which case oldestXid might advance after our
+	 * ReadNextFullTransactionId() call.  If oldestXid has advanced, that
+	 * advancement reinstated the usual oldestClogXid==oldestXid.  Whether or
+	 * not that happened, oldestClogXid is allowable relative to now_fullxid.
 	 */
-	oldest_xid = TransamVariables->oldestClogXid;
-	Assert(TransactionIdPrecedesOrEquals(oldest_xid, now_epoch_next_xid));
-	if (oldest_xid <= now_epoch_next_xid)
-	{
-		oldest_fxid = FullTransactionIdFromEpochAndXid(now_epoch, oldest_xid);
-	}
-	else
-	{
-		Assert(now_epoch > 0);
-		oldest_fxid = FullTransactionIdFromEpochAndXid(now_epoch - 1, oldest_xid);
-	}
-	return !FullTransactionIdPrecedes(fxid, oldest_fxid);
-}
-
-/*
- * Convert a TransactionId obtained from a snapshot held by the caller to a
- * FullTransactionId.  Use next_fxid as a reference FullTransactionId, so that
- * we can compute the high order bits.  It must have been obtained by the
- * caller with ReadNextFullTransactionId() after the snapshot was created.
- */
-static FullTransactionId
-widen_snapshot_xid(TransactionId xid, FullTransactionId next_fxid)
-{
-	TransactionId next_xid = XidFromFullTransactionId(next_fxid);
-	uint32		epoch = EpochFromFullTransactionId(next_fxid);
-
-	/* Special transaction ID. */
-	if (!TransactionIdIsNormal(xid))
-		return FullTransactionIdFromEpochAndXid(0, xid);
-
-	/*
-	 * The 64 bit result must be <= next_fxid, since next_fxid hadn't been
-	 * issued yet when the snapshot was created.  Every TransactionId in the
-	 * snapshot must therefore be from the same epoch as next_fxid, or the
-	 * epoch before.  We know this because next_fxid is never allow to get
-	 * more than one epoch ahead of the TransactionIds in any snapshot.
-	 */
-	if (xid > next_xid)
-		epoch--;
-
-	return FullTransactionIdFromEpochAndXid(epoch, xid);
+	oldest_clog_xid = TransamVariables->oldestClogXid;
+	oldest_clog_fxid =
+		FullTransactionIdFromAllowableAt(now_fullxid, oldest_clog_xid);
+	return !FullTransactionIdPrecedes(fxid, oldest_clog_fxid);
 }
 
 /*
@@ -420,12 +383,18 @@ pg_current_snapshot(PG_FUNCTION_ARGS)
 	nxip = cur->xcnt;
 	snap = palloc(PG_SNAPSHOT_SIZE(nxip));
 
-	/* fill */
-	snap->xmin = widen_snapshot_xid(cur->xmin, next_fxid);
-	snap->xmax = widen_snapshot_xid(cur->xmax, next_fxid);
+	/*
+	 * Fill.  This is the current backend's active snapshot, so MyProc->xmin
+	 * is <= all these XIDs.  As long as that remains so, oldestXid can't
+	 * advance past any of these XIDs.  Hence, these XIDs remain allowable
+	 * relative to next_fxid.
+	 */
+	snap->xmin = FullTransactionIdFromAllowableAt(next_fxid, cur->xmin);
+	snap->xmax = FullTransactionIdFromAllowableAt(next_fxid, cur->xmax);
 	snap->nxip = nxip;
 	for (i = 0; i < nxip; i++)
-		snap->xip[i] = widen_snapshot_xid(cur->xip[i], next_fxid);
+		snap->xip[i] =
+			FullTransactionIdFromAllowableAt(next_fxid, cur->xip[i]);
 
 	/*
 	 * We want them guaranteed to be in ascending order.  This also removes
diff --git a/src/include/access/transam.h b/src/include/access/transam.h
index 0cab865..7d82cd2 100644
--- a/src/include/access/transam.h
+++ b/src/include/access/transam.h
@@ -370,6 +370,49 @@ FullTransactionIdNewer(FullTransactionId a, FullTransactionId b)
 	return b;
 }
 
+/*
+ * Compute FullTransactionId for the given TransactionId, assuming xid was
+ * between [oldestXid, nextXid] at the time when TransamVariables->nextXid was
+ * nextFullXid.  When adding calls, evaluate what prevents xid from preceding
+ * oldestXid if SetTransactionIdLimit() runs between the collection of xid and
+ * the collection of nextFullXid.
+ */
+static inline FullTransactionId
+FullTransactionIdFromAllowableAt(FullTransactionId nextFullXid,
+								 TransactionId xid)
+{
+	uint32		epoch;
+
+	/* Special transaction ID. */
+	if (!TransactionIdIsNormal(xid))
+		return FullTransactionIdFromEpochAndXid(0, xid);
+
+	Assert(TransactionIdPrecedesOrEquals(xid,
+										 XidFromFullTransactionId(nextFullXid)));
+
+	/*
+	 * The 64 bit result must be <= nextFullXid, since nextFullXid hadn't been
+	 * issued yet when xid was in the past.  The xid must therefore be from
+	 * the epoch of nextFullXid or the epoch before.  We know this because we
+	 * must remove (by freezing) an XID before assigning the XID half an epoch
+	 * ahead of it.
+	 *
+	 * The unlikely() branch hint is dubious.  It's perfect for the first 2^32
+	 * XIDs of a cluster's life.  Right at 2^32 XIDs, misprediction shoots to
+	 * 100%, then improves until perfection returns 2^31 XIDs later.  Since
+	 * current callers pass relatively-recent XIDs, expect >90% prediction
+	 * accuracy overall.  This favors average latency over tail latency.
+	 */
+	epoch = EpochFromFullTransactionId(nextFullXid);
+	if (unlikely(xid > XidFromFullTransactionId(nextFullXid)))
+	{
+		Assert(epoch != 0);
+		epoch--;
+	}
+
+	return FullTransactionIdFromEpochAndXid(epoch, xid);
+}
+
 #endif							/* FRONTEND */
 
 #endif							/* TRANSAM_H */
Author:     Noah Misch <noah@leadboat.com>
Commit:     Noah Misch <noah@leadboat.com>

    At update of non-LP_NORMAL TID, fail instead of corrupting page header.
    
    The right mix of DDL and VACUUM could corrupt a page header such that
    PageIsVerified() durably fails, requiring a restore from backup.  One of
    the test permutations shows a variant not yet fixed.
    
    This makes !TransactionIdIsValid(TM_FailureData.xmax) possible with
    TM_Deleted.  Core and PGXN appear indifferent to that.
    
    Per bug #17821 from Alexander Lakhin.  Back-patch to v13 (all supported
    versions).  The test case is v17+, since it uses INJECTION_POINT.
    
    Reviewed by FIXME.
    
    Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org

diff --git a/src/backend/access/heap/heapam.c b/src/backend/access/heap/heapam.c
index b634995..9d00808 100644
--- a/src/backend/access/heap/heapam.c
+++ b/src/backend/access/heap/heapam.c
@@ -49,8 +49,10 @@
 #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"
+#include "utils/syscache.h"
 
 
 static HeapTuple heap_prepare_insert(Relation relation, HeapTuple tup,
@@ -3254,6 +3256,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);
 
@@ -3269,7 +3272,51 @@ heap_update(Relation relation, ItemPointer otid, HeapTuple newtup,
 	LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE);
 
 	lp = PageGetItemId(page, ItemPointerGetOffsetNumber(otid));
-	Assert(ItemIdIsNormal(lp));
+
+	/*
+	 * Usually, a buffer pin and/or snapshot blocks pruning of otid, ensuring
+	 * we see LP_NORMAL here.  When the otid origin is a syscache, we may have
+	 * neither a pin nor a snapshot.  Hence, we may see other LP_ states, each
+	 * of which indicates concurrent pruning.
+	 *
+	 * Failing with TM_Updated would be most accurate.  However, unlike other
+	 * TM_Updated scenarios, we don't know the successor ctid in LP_UNUSED and
+	 * LP_DEAD cases.  While the distinction between TM_Updated and TM_Deleted
+	 * does matter to SQL statements UPDATE and MERGE, those SQL statements
+	 * hold a snapshot that ensures LP_NORMAL.  Hence, the choice between
+	 * TM_Updated and TM_Deleted affects only the wording of error messages.
+	 * Settle on TM_Deleted, for two reasons.  First, it avoids complicating
+	 * the specification of when tmfd->ctid is valid.  Second, it creates
+	 * error log evidence that we took this branch.
+	 *
+	 * Since it's possible to see LP_UNUSED at otid, it's also possible to see
+	 * LP_NORMAL for a tuple that replaced LP_UNUSED.  If it's a tuple for an
+	 * unrelated row, we'll fail with "duplicate key value violates unique".
+	 * XXX if otid is the live, newer version of the newtup row, we'll discard
+	 * changes originating in versions of this catalog row after the version
+	 * the caller got from syscache.  See syscache-update-pruned.spec.
+	 */
+	if (!ItemIdIsNormal(lp))
+	{
+		Assert(RelationSupportsSysCache(RelationGetRelid(relation)));
+
+		UnlockReleaseBuffer(buffer);
+		Assert(!have_tuple_lock);
+		if (vmbuffer != InvalidBuffer)
+			ReleaseBuffer(vmbuffer);
+		tmfd->ctid = *otid;
+		tmfd->xmax = InvalidTransactionId;
+		tmfd->cmax = InvalidCommandId;
+		*update_indexes = TU_None;
+
+		bms_free(hot_attrs);
+		bms_free(sum_attrs);
+		bms_free(key_attrs);
+		bms_free(id_attrs);
+		/* modified_attrs not yet initialized */
+		bms_free(interesting_attrs);
+		return TM_Deleted;
+	}
 
 	/*
 	 * Fill in enough data in oldtup for HeapDetermineColumnsInfo to work
diff --git a/src/backend/utils/cache/inval.c b/src/backend/utils/cache/inval.c
index f41d314..32cf28b 100644
--- a/src/backend/utils/cache/inval.c
+++ b/src/backend/utils/cache/inval.c
@@ -123,6 +123,7 @@
 #include "storage/sinval.h"
 #include "storage/smgr.h"
 #include "utils/catcache.h"
+#include "utils/injection_point.h"
 #include "utils/inval.h"
 #include "utils/memdebug.h"
 #include "utils/memutils.h"
@@ -1134,6 +1135,8 @@ AtEOXact_Inval(bool isCommit)
 	/* Must be at top of stack */
 	Assert(transInvalInfo->my_level == 1 && transInvalInfo->parent == NULL);
 
+	INJECTION_POINT("AtEOXact_Inval-with-transInvalInfo");
+
 	if (isCommit)
 	{
 		/*
diff --git a/src/include/access/tableam.h b/src/include/access/tableam.h
index 09b9b39..131c050 100644
--- a/src/include/access/tableam.h
+++ b/src/include/access/tableam.h
@@ -136,7 +136,8 @@ typedef enum TU_UpdateIndexes
  *
  * xmax is the outdating transaction's XID.  If the caller wants to visit the
  * replacement tuple, it must check that this matches before believing the
- * replacement is really a match.
+ * replacement is really a match.  This is InvalidTransactionId if the target
+ * was !LP_NORMAL (expected only for a TID retrieved from syscache).
  *
  * cmax is the outdating command's CID, but only when the failure code is
  * TM_SelfModified (i.e., something in the current transaction outdated the
diff --git a/src/test/modules/injection_points/Makefile b/src/test/modules/injection_points/Makefile
index 0753a9d..4f0161f 100644
--- a/src/test/modules/injection_points/Makefile
+++ b/src/test/modules/injection_points/Makefile
@@ -5,7 +5,8 @@ OBJS = \
 	$(WIN32RES) \
 	injection_points.o \
 	injection_stats.o \
-	injection_stats_fixed.o
+	injection_stats_fixed.o \
+	regress_injection.o
 EXTENSION = injection_points
 DATA = injection_points--1.0.sql
 PGFILEDESC = "injection_points - facility for injection points"
@@ -13,7 +14,7 @@ PGFILEDESC = "injection_points - facility for injection points"
 REGRESS = injection_points reindex_conc
 REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress
 
-ISOLATION = basic inplace
+ISOLATION = basic inplace syscache-update-pruned
 
 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.out
new file mode 100644
index 0000000..5dc5a1d
--- /dev/null
+++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out
@@ -0,0 +1,87 @@
+Parsed test spec with 4 sessions
+
+starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 wakegrant4
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+ERROR:  tuple concurrently deleted
+step wakegrant4: <... completed>
+
+starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 mkrels4 wakegrant4
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step mkrels4: 
+	SELECT FROM vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+ERROR:  duplicate key value violates unique constraint "pg_class_oid_index"
+step wakegrant4: <... completed>
+
+starting permutation: snap3 cachefill1 at2 mkrels4 r3 waitprunable4 vac4 grant1 wakeinval4 at4 wakegrant4 inspect4
+step snap3: BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT;
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step mkrels4: 
+	SELECT FROM vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+
+step r3: ROLLBACK;
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step at4: ALTER TABLE vactest.child50 INHERIT vactest.orig50;
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+step wakegrant4: <... completed>
+step inspect4: 
+	SELECT relhastriggers, relhassubclass FROM pg_class
+		WHERE oid = 'vactest.orig50'::regclass;
+
+relhastriggers|relhassubclass
+--------------+--------------
+f             |f             
+(1 row)
+
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.out
new file mode 100644
index 0000000..b18857c
--- /dev/null
+++ b/src/test/modules/injection_points/expected/syscache-update-pruned_1.out
@@ -0,0 +1,86 @@
+Parsed test spec with 4 sessions
+
+starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 wakegrant4
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+step wakegrant4: <... completed>
+
+starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 mkrels4 wakegrant4
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step mkrels4: 
+	SELECT FROM vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+step wakegrant4: <... completed>
+
+starting permutation: snap3 cachefill1 at2 mkrels4 r3 waitprunable4 vac4 grant1 wakeinval4 at4 wakegrant4 inspect4
+step snap3: BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT;
+step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50');
+step at2: 
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+ <waiting ...>
+step mkrels4: 
+	SELECT FROM vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+
+step r3: ROLLBACK;
+step waitprunable4: CALL vactest.wait_prunable();
+step vac4: VACUUM pg_class;
+step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
+step wakeinval4: 
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+ <waiting ...>
+step at2: <... completed>
+step wakeinval4: <... completed>
+step at4: ALTER TABLE vactest.child50 INHERIT vactest.orig50;
+step wakegrant4: 
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+ <waiting ...>
+step grant1: <... completed>
+ERROR:  tuple concurrently updated
+step wakegrant4: <... completed>
+step inspect4: 
+	SELECT relhastriggers, relhassubclass FROM pg_class
+		WHERE oid = 'vactest.orig50'::regclass;
+
+relhastriggers|relhassubclass
+--------------+--------------
+t             |t             
+(1 row)
+
diff --git a/src/test/modules/injection_points/injection_points--1.0.sql b/src/test/modules/injection_points/injection_points--1.0.sql
index 6c81d55..c445bf6 100644
--- a/src/test/modules/injection_points/injection_points--1.0.sql
+++ b/src/test/modules/injection_points/injection_points--1.0.sql
@@ -97,3 +97,11 @@ CREATE FUNCTION injection_points_stats_fixed(OUT numattach int8,
 RETURNS record
 AS 'MODULE_PATHNAME', 'injection_points_stats_fixed'
 LANGUAGE C STRICT;
+
+--
+-- regress_injection.c functions
+--
+CREATE FUNCTION removable_cutoff(rel regclass)
+RETURNS xid8
+AS 'MODULE_PATHNAME'
+LANGUAGE C CALLED ON NULL INPUT;
diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build
index ebe79fe..259045e 100644
--- a/src/test/modules/injection_points/meson.build
+++ b/src/test/modules/injection_points/meson.build
@@ -8,6 +8,7 @@ injection_points_sources = files(
   'injection_points.c',
   'injection_stats.c',
   'injection_stats_fixed.c',
+  'regress_injection.c',
 )
 
 if host_system == 'windows'
@@ -44,8 +45,9 @@ tests += {
     'specs': [
       'basic',
       'inplace',
+      'syscache-update-pruned',
     ],
-    'runningcheck': false, # align with GNU make build system
+    'runningcheck': false, # see syscache-update-pruned
   },
   'tap': {
     'env': {
diff --git a/src/test/modules/injection_points/regress_injection.c b/src/test/modules/injection_points/regress_injection.c
new file mode 100644
index 0000000..422f416
--- /dev/null
+++ b/src/test/modules/injection_points/regress_injection.c
@@ -0,0 +1,71 @@
+/*--------------------------------------------------------------------------
+ *
+ * regress_injection.c
+ *		Functions supporting test-specific subject matter.
+ *
+ * Portions Copyright (c) 1996-2025, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994, Regents of the University of California
+ *
+ * IDENTIFICATION
+ *		src/test/modules/injection_points/regress_injection.c
+ *
+ * -------------------------------------------------------------------------
+ */
+
+#include "postgres.h"
+
+#include "access/table.h"
+#include "fmgr.h"
+#include "miscadmin.h"
+#include "storage/procarray.h"
+#include "utils/xid8.h"
+
+/*
+ * removable_cutoff - for syscache-update-pruned.spec
+ *
+ * Wrapper around GetOldestNonRemovableTransactionId().  In general, this can
+ * move backward.  runningcheck=false isolation tests can reasonably prevent
+ * that.  For the causes of backward movement, see
+ * postgr.es/m/CAEze2Wj%2BV0kTx86xB_YbyaqTr5hnE_igdWAwuhSyjXBYscf5-Q%40mail.gmail.com
+ * and the header comment for ComputeXidHorizons().  One can assume this
+ * doesn't move backward if one arranges for concurrent activity not to reach
+ * AbortTransaction() and not to allocate an XID while connected to another
+ * database.  Non-runningcheck tests can control most concurrent activity,
+ * except autovacuum and the isolationtester control connection.  Neither
+ * allocates XIDs, and AbortTransaction() in those would justify test failure.
+ */
+PG_FUNCTION_INFO_V1(removable_cutoff);
+Datum
+removable_cutoff(PG_FUNCTION_ARGS)
+{
+	Relation	rel = NULL;
+	TransactionId xid;
+	FullTransactionId next_fxid_before,
+				next_fxid;
+
+	/* could take other relkinds callee takes, but we've not yet needed it */
+	if (!PG_ARGISNULL(0))
+		rel = table_open(PG_GETARG_OID(0), AccessShareLock);
+
+	/*
+	 * No lock or snapshot necessarily prevents oldestXid from advancing past
+	 * "xid" while this function runs.  That concerns us only in that we must
+	 * not ascribe "xid" to the wrong epoch.  (That may never arise in
+	 * isolation testing, but let's set a good example.)  As a crude solution,
+	 * retry until nextXid doesn't change.
+	 */
+	next_fxid = ReadNextFullTransactionId();
+	do
+	{
+		CHECK_FOR_INTERRUPTS();
+		next_fxid_before = next_fxid;
+		xid = GetOldestNonRemovableTransactionId(rel);
+		next_fxid = ReadNextFullTransactionId();
+	} while (!FullTransactionIdEquals(next_fxid, next_fxid_before));
+
+	if (rel)
+		table_close(rel, AccessShareLock);
+
+	PG_RETURN_FULLTRANSACTIONID(FullTransactionIdFromAllowableAt(next_fxid,
+																 xid));
+}
diff --git a/src/test/modules/injection_points/specs/syscache-update-pruned.spec b/src/test/modules/injection_points/specs/syscache-update-pruned.spec
new file mode 100644
index 0000000..b48e897
--- /dev/null
+++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec
@@ -0,0 +1,179 @@
+# 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, which exercises the corresponding
+# race condition for inplace updates.
+
+# Despite local injection points, this is incompatible with runningcheck.
+# First, removable_cutoff() could move backward, per its header comment.
+# Second, other activity could trigger sinval queue overflow, negating our
+# efforts to delay inval.  Third, this deadlock emerges:
+#
+# - step at2 waits at an injection point, with interrupts held
+# - an unrelated backend waits for at2 to do PROCSIGNAL_BARRIER_SMGRRELEASE
+# - step waitprunable4 waits for the unrelated backend to release its xmin
+
+# The alternative expected output is for -DCATCACHE_FORCE_RELEASE, a setting
+# that thwarts testing the race conditions this spec seeks.
+
+
+# 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
+{
+	CREATE EXTENSION injection_points;
+	CREATE SCHEMA vactest;
+	-- Ensure a leader RELOID catcache entry.  PARALLEL RESTRICTED since a
+	-- parallel worker running pg_relation_filenode() would lack that effect.
+	CREATE FUNCTION vactest.reloid_catcache_set(regclass) RETURNS int
+		LANGUAGE sql PARALLEL RESTRICTED
+		AS 'SELECT 0 FROM pg_relation_filenode($1)';
+	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
+	$$;
+	CREATE PROCEDURE vactest.wait_prunable() LANGUAGE plpgsql AS $$
+	DECLARE
+		barrier xid8;
+		cutoff xid8;
+	BEGIN
+		barrier := pg_current_xact_id();
+		-- autovacuum worker RelationCacheInitializePhase3() or the
+		-- isolationtester control connection might hold a snapshot that
+		-- limits pruning.  Sleep until that clears.
+		LOOP
+			ROLLBACK;  -- release MyProc->xmin, which could be the oldest
+			cutoff := removable_cutoff('pg_class');
+			EXIT WHEN cutoff >= barrier;
+			RAISE LOG 'removable cutoff %; waiting for %', cutoff, barrier;
+			PERFORM pg_sleep(.1);
+		END LOOP;
+	END
+	$$;
+}
+setup	{ CALL vactest.wait_prunable();  -- maximize next two VACUUMs }
+setup	{ VACUUM FULL pg_class;  -- reduce free space }
+setup	{ VACUUM FREEZE pg_class;  -- populate fsm etc. }
+setup
+{
+	SELECT FROM vactest.mkrels('orig', 1, 49);
+	CREATE TABLE vactest.orig50 (c int) WITH (autovacuum_enabled = off);
+	CREATE TABLE vactest.child50 (c int) WITH (autovacuum_enabled = off);
+	SELECT FROM vactest.mkrels('orig', 51, 100);
+}
+teardown
+{
+	DROP SCHEMA vactest CASCADE;
+	DROP EXTENSION injection_points;
+}
+
+# Wait during GRANT.  Disable debug_discard_caches, since we're here to
+# exercise an outcome that happens under permissible cache staleness.
+session s1
+setup	{
+	SET debug_discard_caches = 0;
+	SELECT FROM injection_points_set_local();
+	SELECT FROM injection_points_attach('heap_update-before-pin', 'wait');
+}
+step cachefill1	{ SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); }
+step grant1	{ GRANT SELECT ON vactest.orig50 TO PUBLIC; }
+
+# Update of the tuple that grant1 will update.  Wait before sending invals, so
+# s1 will not get a cache miss.  Choose the commands for making such updates
+# 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	{
+	SELECT FROM injection_points_set_local();
+	SELECT FROM
+		injection_points_attach('AtEOXact_Inval-with-transInvalInfo', 'wait');
+}
+step at2	{
+	CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50
+		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
+}
+
+# Hold snapshot to block pruning.
+session s3
+step snap3	{ BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT; }
+step r3		{ ROLLBACK; }
+
+# Non-blocking actions.
+session s4
+step waitprunable4	{ CALL vactest.wait_prunable(); }
+step vac4		{ VACUUM pg_class; }
+# 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 FROM vactest.mkrels('intruder', 1, 100);  -- repopulate LP_UNUSED
+}
+step wakegrant4	{
+	SELECT FROM injection_points_detach('heap_update-before-pin');
+	SELECT FROM injection_points_wakeup('heap_update-before-pin');
+}
+step at4	{ ALTER TABLE vactest.child50 INHERIT vactest.orig50; }
+step wakeinval4	{
+	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
+	SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo');
+}
+# Witness effects of steps at2 and/or at4.
+step inspect4	{
+	SELECT relhastriggers, relhassubclass FROM pg_class
+		WHERE oid = 'vactest.orig50'::regclass;
+}
+
+# TID from syscache becomes LP_UNUSED.  Before the bug fix, this permutation
+# made s1 fail with "attempted to update invisible tuple" or an assert.
+# However, suppose a pd_lsn value such that (pd_lsn.xlogid, pd_lsn.xrecoff)
+# passed for (xmin, xmax) with xmin known-committed and xmax known-aborted.
+# Persistent page header corruption ensued.  For example, s1 overwrote
+# pd_lower, pd_upper, and pd_special as though they were t_ctid.
+permutation
+	cachefill1			# reads pg_class tuple T0, xmax invalid
+	at2					# T0 dead, T1 live
+	waitprunable4		# T0 prunable
+	vac4				# T0 becomes LP_UNUSED
+	grant1				# pauses at heap_update(T0)
+	wakeinval4(at2)		# at2 sends inval message
+	wakegrant4(grant1)	# s1 wakes: "tuple concurrently deleted"
+
+# add mkrels4: LP_UNUSED becomes a different rel's row
+permutation
+	cachefill1			# reads pg_class tuple T0, xmax invalid
+	at2					# T0 dead, T1 live
+	waitprunable4		# T0 prunable
+	vac4				# T0 becomes LP_UNUSED
+	grant1				# pauses at heap_update(T0)
+	wakeinval4(at2)		# at2 sends inval message
+	mkrels4				# T0 becomes a new rel
+	wakegrant4(grant1)	# s1 wakes: "duplicate key value violates unique"
+
+# TID from syscache becomes LP_UNUSED, then becomes a newer version of the
+# original rel's row.
+permutation
+	snap3				# sets MyProc->xmin
+	cachefill1			# reads pg_class tuple T0, xmax invalid
+	at2					# T0 dead, T1 live
+	mkrels4				# T1's page becomes full
+	r3					# clears MyProc->xmin
+	waitprunable4		# T0 prunable
+	vac4				# T0 becomes LP_UNUSED
+	grant1				# pauses at heap_update(T0)
+	wakeinval4(at2)		# at2 sends inval message
+	at4					# T1 dead, T0 live
+	wakegrant4(grant1)	# s1 wakes: T0 dead, T2 live
+	inspect4			# observe loss of at2+at4 changes XXX is an extant bug

Attachments:

update-unused-lp-10-no-installcheck-v1.patch (text/plain, 1.2K) download Author: Noah Misch <noah@leadboat.com> Commit: Noah Misch <noah@leadboat.com> Disable runningcheck for src/test/modules/injection_points/specs. Directory "injection_points" has specified NO_INSTALLCHECK since before commit c35f419d6efbdf1a050250d84b687e6705917711 added the specs, but that commit neglected to disable the corresponding meson runningcheck. The alternative would be to enable "make installcheck" for ISOLATION, but the GNU make build system lacks a concept of setting NO_INSTALLCHECK for REGRESS without also setting it for ISOLATION. Back-patch to v17, where that commit first appeared, to avoid surprises when back-patching additional specs. Reviewed by FIXME. Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build index 989b4db..ebe79fe 100644 --- a/src/test/modules/injection_points/meson.build +++ b/src/test/modules/injection_points/meson.build @@ -45,6 +45,7 @@ tests += { 'basic', 'inplace', ], + 'runningcheck': false, # align with GNU make build system }, 'tap': { 'env': {
update-unused-lp-40-xid2fxid-v1.patch (text/plain, 10.1K) download Author: Noah Misch <noah@leadboat.com> Commit: Noah Misch <noah@leadboat.com> Merge copies of converting an XID to a FullTransactionId. Assume twophase.c is the performance-sensitive caller, and preserve its choice of unlikely() branch hint. Add some retrospective rationale for that choice. Back-patch to v17, for the next commit to use it. Reviewed (in earlier versions) by Michael Paquier. Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org Discussion: https://postgr.es/m/20250116010051.f3.nmisch@google.com diff --git a/contrib/amcheck/verify_heapam.c b/contrib/amcheck/verify_heapam.c index 8a8e36d..8273123 100644 --- a/contrib/amcheck/verify_heapam.c +++ b/contrib/amcheck/verify_heapam.c @@ -1877,7 +1877,9 @@ check_tuple(HeapCheckContext *ctx, bool *xmin_commit_status_ok, /* * Convert a TransactionId into a FullTransactionId using our cached values of * the valid transaction ID range. It is the caller's responsibility to have - * already updated the cached values, if necessary. + * already updated the cached values, if necessary. This is akin to + * FullTransactionIdFromAllowableAt(), but it tolerates corruption in the form + * of an xid before epoch 0. */ static FullTransactionId FullTransactionIdFromXidAndCtx(TransactionId xid, const HeapCheckContext *ctx) diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c index ab2f4a8..73a8055 100644 --- a/src/backend/access/transam/twophase.c +++ b/src/backend/access/transam/twophase.c @@ -929,32 +929,16 @@ TwoPhaseGetDummyProc(TransactionId xid, bool lock_held) /* * Compute the FullTransactionId for the given TransactionId. * - * The wrap logic is safe here because the span of active xids cannot exceed one - * epoch at any given time. + * This is safe if the xid has not yet reached COMMIT PREPARED or ROLLBACK + * PREPARED. After those commands, concurrent vac_truncate_clog() may make + * the xid cease to qualify as allowable. XXX Not all callers limit their + * calls accordingly. */ static inline FullTransactionId AdjustToFullTransactionId(TransactionId xid) { - FullTransactionId nextFullXid; - TransactionId nextXid; - uint32 epoch; - Assert(TransactionIdIsValid(xid)); - - LWLockAcquire(XidGenLock, LW_SHARED); - nextFullXid = TransamVariables->nextXid; - LWLockRelease(XidGenLock); - - nextXid = XidFromFullTransactionId(nextFullXid); - epoch = EpochFromFullTransactionId(nextFullXid); - if (unlikely(xid > nextXid)) - { - /* Wraparound occurred, must be from a prev epoch. */ - Assert(epoch > 0); - epoch--; - } - - return FullTransactionIdFromEpochAndXid(epoch, xid); + return FullTransactionIdFromAllowableAt(ReadNextFullTransactionId(), xid); } static inline int diff --git a/src/backend/access/transam/xlogreader.c b/src/backend/access/transam/xlogreader.c index 3596af0..91b6a91 100644 --- a/src/backend/access/transam/xlogreader.c +++ b/src/backend/access/transam/xlogreader.c @@ -2166,28 +2166,14 @@ RestoreBlockImage(XLogReaderState *record, uint8 block_id, char *page) FullTransactionId XLogRecGetFullXid(XLogReaderState *record) { - TransactionId xid, - next_xid; - uint32 epoch; - /* * This function is only safe during replay, because it depends on the * replay state. See AdvanceNextFullTransactionIdPastXid() for more. */ Assert(AmStartupProcess() || !IsUnderPostmaster); - xid = XLogRecGetXid(record); - next_xid = XidFromFullTransactionId(TransamVariables->nextXid); - epoch = EpochFromFullTransactionId(TransamVariables->nextXid); - - /* - * If xid is numerically greater than next_xid, it has to be from the last - * epoch. - */ - if (unlikely(xid > next_xid)) - --epoch; - - return FullTransactionIdFromEpochAndXid(epoch, xid); + return FullTransactionIdFromAllowableAt(TransamVariables->nextXid, + XLogRecGetXid(record)); } #endif diff --git a/src/backend/utils/adt/xid8funcs.c b/src/backend/utils/adt/xid8funcs.c index 4736755..20b28b2 100644 --- a/src/backend/utils/adt/xid8funcs.c +++ b/src/backend/utils/adt/xid8funcs.c @@ -97,15 +97,11 @@ static bool TransactionIdInRecentPast(FullTransactionId fxid, TransactionId *extracted_xid) { TransactionId xid = XidFromFullTransactionId(fxid); - uint32 now_epoch; - TransactionId now_epoch_next_xid; FullTransactionId now_fullxid; - TransactionId oldest_xid; - FullTransactionId oldest_fxid; + TransactionId oldest_clog_xid; + FullTransactionId oldest_clog_fxid; now_fullxid = ReadNextFullTransactionId(); - now_epoch_next_xid = XidFromFullTransactionId(now_fullxid); - now_epoch = EpochFromFullTransactionId(now_fullxid); if (extracted_xid != NULL) *extracted_xid = xid; @@ -135,52 +131,19 @@ TransactionIdInRecentPast(FullTransactionId fxid, TransactionId *extracted_xid) /* * If fxid is not older than TransamVariables->oldestClogXid, the relevant - * CLOG entry is guaranteed to still exist. Convert - * TransamVariables->oldestClogXid into a FullTransactionId to compare it - * with fxid. Determine the right epoch knowing that oldest_fxid - * shouldn't be more than 2^31 older than now_fullxid. + * CLOG entry is guaranteed to still exist. + * + * TransamVariables->oldestXid governs allowable XIDs. Usually, + * oldestClogXid==oldestXid. It's also possible for oldestClogXid to + * follow oldestXid, in which case oldestXid might advance after our + * ReadNextFullTransactionId() call. If oldestXid has advanced, that + * advancement reinstated the usual oldestClogXid==oldestXid. Whether or + * not that happened, oldestClogXid is allowable relative to now_fullxid. */ - oldest_xid = TransamVariables->oldestClogXid; - Assert(TransactionIdPrecedesOrEquals(oldest_xid, now_epoch_next_xid)); - if (oldest_xid <= now_epoch_next_xid) - { - oldest_fxid = FullTransactionIdFromEpochAndXid(now_epoch, oldest_xid); - } - else - { - Assert(now_epoch > 0); - oldest_fxid = FullTransactionIdFromEpochAndXid(now_epoch - 1, oldest_xid); - } - return !FullTransactionIdPrecedes(fxid, oldest_fxid); -} - -/* - * Convert a TransactionId obtained from a snapshot held by the caller to a - * FullTransactionId. Use next_fxid as a reference FullTransactionId, so that - * we can compute the high order bits. It must have been obtained by the - * caller with ReadNextFullTransactionId() after the snapshot was created. - */ -static FullTransactionId -widen_snapshot_xid(TransactionId xid, FullTransactionId next_fxid) -{ - TransactionId next_xid = XidFromFullTransactionId(next_fxid); - uint32 epoch = EpochFromFullTransactionId(next_fxid); - - /* Special transaction ID. */ - if (!TransactionIdIsNormal(xid)) - return FullTransactionIdFromEpochAndXid(0, xid); - - /* - * The 64 bit result must be <= next_fxid, since next_fxid hadn't been - * issued yet when the snapshot was created. Every TransactionId in the - * snapshot must therefore be from the same epoch as next_fxid, or the - * epoch before. We know this because next_fxid is never allow to get - * more than one epoch ahead of the TransactionIds in any snapshot. - */ - if (xid > next_xid) - epoch--; - - return FullTransactionIdFromEpochAndXid(epoch, xid); + oldest_clog_xid = TransamVariables->oldestClogXid; + oldest_clog_fxid = + FullTransactionIdFromAllowableAt(now_fullxid, oldest_clog_xid); + return !FullTransactionIdPrecedes(fxid, oldest_clog_fxid); } /* @@ -420,12 +383,18 @@ pg_current_snapshot(PG_FUNCTION_ARGS) nxip = cur->xcnt; snap = palloc(PG_SNAPSHOT_SIZE(nxip)); - /* fill */ - snap->xmin = widen_snapshot_xid(cur->xmin, next_fxid); - snap->xmax = widen_snapshot_xid(cur->xmax, next_fxid); + /* + * Fill. This is the current backend's active snapshot, so MyProc->xmin + * is <= all these XIDs. As long as that remains so, oldestXid can't + * advance past any of these XIDs. Hence, these XIDs remain allowable + * relative to next_fxid. + */ + snap->xmin = FullTransactionIdFromAllowableAt(next_fxid, cur->xmin); + snap->xmax = FullTransactionIdFromAllowableAt(next_fxid, cur->xmax); snap->nxip = nxip; for (i = 0; i < nxip; i++) - snap->xip[i] = widen_snapshot_xid(cur->xip[i], next_fxid); + snap->xip[i] = + FullTransactionIdFromAllowableAt(next_fxid, cur->xip[i]); /* * We want them guaranteed to be in ascending order. This also removes diff --git a/src/include/access/transam.h b/src/include/access/transam.h index 0cab865..7d82cd2 100644 --- a/src/include/access/transam.h +++ b/src/include/access/transam.h @@ -370,6 +370,49 @@ FullTransactionIdNewer(FullTransactionId a, FullTransactionId b) return b; } +/* + * Compute FullTransactionId for the given TransactionId, assuming xid was + * between [oldestXid, nextXid] at the time when TransamVariables->nextXid was + * nextFullXid. When adding calls, evaluate what prevents xid from preceding + * oldestXid if SetTransactionIdLimit() runs between the collection of xid and + * the collection of nextFullXid. + */ +static inline FullTransactionId +FullTransactionIdFromAllowableAt(FullTransactionId nextFullXid, + TransactionId xid) +{ + uint32 epoch; + + /* Special transaction ID. */ + if (!TransactionIdIsNormal(xid)) + return FullTransactionIdFromEpochAndXid(0, xid); + + Assert(TransactionIdPrecedesOrEquals(xid, + XidFromFullTransactionId(nextFullXid))); + + /* + * The 64 bit result must be <= nextFullXid, since nextFullXid hadn't been + * issued yet when xid was in the past. The xid must therefore be from + * the epoch of nextFullXid or the epoch before. We know this because we + * must remove (by freezing) an XID before assigning the XID half an epoch + * ahead of it. + * + * The unlikely() branch hint is dubious. It's perfect for the first 2^32 + * XIDs of a cluster's life. Right at 2^32 XIDs, misprediction shoots to + * 100%, then improves until perfection returns 2^31 XIDs later. Since + * current callers pass relatively-recent XIDs, expect >90% prediction + * accuracy overall. This favors average latency over tail latency. + */ + epoch = EpochFromFullTransactionId(nextFullXid); + if (unlikely(xid > XidFromFullTransactionId(nextFullXid))) + { + Assert(epoch != 0); + epoch--; + } + + return FullTransactionIdFromEpochAndXid(epoch, xid); +} + #endif /* FRONTEND */ #endif /* TRANSAM_H */
update-unused-lp-50-fix-v1.patch (text/plain, 24.8K) download Author: Noah Misch <noah@leadboat.com> Commit: Noah Misch <noah@leadboat.com> At update of non-LP_NORMAL TID, fail instead of corrupting page header. The right mix of DDL and VACUUM could corrupt a page header such that PageIsVerified() durably fails, requiring a restore from backup. One of the test permutations shows a variant not yet fixed. This makes !TransactionIdIsValid(TM_FailureData.xmax) possible with TM_Deleted. Core and PGXN appear indifferent to that. Per bug #17821 from Alexander Lakhin. Back-patch to v13 (all supported versions). The test case is v17+, since it uses INJECTION_POINT. Reviewed by FIXME. Discussion: https://postgr.es/m/17821-dd8c334263399284@postgresql.org diff --git a/src/backend/access/heap/heapam.c b/src/backend/access/heap/heapam.c index b634995..9d00808 100644 --- a/src/backend/access/heap/heapam.c +++ b/src/backend/access/heap/heapam.c @@ -49,8 +49,10 @@ #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" +#include "utils/syscache.h" static HeapTuple heap_prepare_insert(Relation relation, HeapTuple tup, @@ -3254,6 +3256,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); @@ -3269,7 +3272,51 @@ heap_update(Relation relation, ItemPointer otid, HeapTuple newtup, LockBuffer(buffer, BUFFER_LOCK_EXCLUSIVE); lp = PageGetItemId(page, ItemPointerGetOffsetNumber(otid)); - Assert(ItemIdIsNormal(lp)); + + /* + * Usually, a buffer pin and/or snapshot blocks pruning of otid, ensuring + * we see LP_NORMAL here. When the otid origin is a syscache, we may have + * neither a pin nor a snapshot. Hence, we may see other LP_ states, each + * of which indicates concurrent pruning. + * + * Failing with TM_Updated would be most accurate. However, unlike other + * TM_Updated scenarios, we don't know the successor ctid in LP_UNUSED and + * LP_DEAD cases. While the distinction between TM_Updated and TM_Deleted + * does matter to SQL statements UPDATE and MERGE, those SQL statements + * hold a snapshot that ensures LP_NORMAL. Hence, the choice between + * TM_Updated and TM_Deleted affects only the wording of error messages. + * Settle on TM_Deleted, for two reasons. First, it avoids complicating + * the specification of when tmfd->ctid is valid. Second, it creates + * error log evidence that we took this branch. + * + * Since it's possible to see LP_UNUSED at otid, it's also possible to see + * LP_NORMAL for a tuple that replaced LP_UNUSED. If it's a tuple for an + * unrelated row, we'll fail with "duplicate key value violates unique". + * XXX if otid is the live, newer version of the newtup row, we'll discard + * changes originating in versions of this catalog row after the version + * the caller got from syscache. See syscache-update-pruned.spec. + */ + if (!ItemIdIsNormal(lp)) + { + Assert(RelationSupportsSysCache(RelationGetRelid(relation))); + + UnlockReleaseBuffer(buffer); + Assert(!have_tuple_lock); + if (vmbuffer != InvalidBuffer) + ReleaseBuffer(vmbuffer); + tmfd->ctid = *otid; + tmfd->xmax = InvalidTransactionId; + tmfd->cmax = InvalidCommandId; + *update_indexes = TU_None; + + bms_free(hot_attrs); + bms_free(sum_attrs); + bms_free(key_attrs); + bms_free(id_attrs); + /* modified_attrs not yet initialized */ + bms_free(interesting_attrs); + return TM_Deleted; + } /* * Fill in enough data in oldtup for HeapDetermineColumnsInfo to work diff --git a/src/backend/utils/cache/inval.c b/src/backend/utils/cache/inval.c index f41d314..32cf28b 100644 --- a/src/backend/utils/cache/inval.c +++ b/src/backend/utils/cache/inval.c @@ -123,6 +123,7 @@ #include "storage/sinval.h" #include "storage/smgr.h" #include "utils/catcache.h" +#include "utils/injection_point.h" #include "utils/inval.h" #include "utils/memdebug.h" #include "utils/memutils.h" @@ -1134,6 +1135,8 @@ AtEOXact_Inval(bool isCommit) /* Must be at top of stack */ Assert(transInvalInfo->my_level == 1 && transInvalInfo->parent == NULL); + INJECTION_POINT("AtEOXact_Inval-with-transInvalInfo"); + if (isCommit) { /* diff --git a/src/include/access/tableam.h b/src/include/access/tableam.h index 09b9b39..131c050 100644 --- a/src/include/access/tableam.h +++ b/src/include/access/tableam.h @@ -136,7 +136,8 @@ typedef enum TU_UpdateIndexes * * xmax is the outdating transaction's XID. If the caller wants to visit the * replacement tuple, it must check that this matches before believing the - * replacement is really a match. + * replacement is really a match. This is InvalidTransactionId if the target + * was !LP_NORMAL (expected only for a TID retrieved from syscache). * * cmax is the outdating command's CID, but only when the failure code is * TM_SelfModified (i.e., something in the current transaction outdated the diff --git a/src/test/modules/injection_points/Makefile b/src/test/modules/injection_points/Makefile index 0753a9d..4f0161f 100644 --- a/src/test/modules/injection_points/Makefile +++ b/src/test/modules/injection_points/Makefile @@ -5,7 +5,8 @@ OBJS = \ $(WIN32RES) \ injection_points.o \ injection_stats.o \ - injection_stats_fixed.o + injection_stats_fixed.o \ + regress_injection.o EXTENSION = injection_points DATA = injection_points--1.0.sql PGFILEDESC = "injection_points - facility for injection points" @@ -13,7 +14,7 @@ PGFILEDESC = "injection_points - facility for injection points" REGRESS = injection_points reindex_conc REGRESS_OPTS = --dlpath=$(top_builddir)/src/test/regress -ISOLATION = basic inplace +ISOLATION = basic inplace syscache-update-pruned 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.out new file mode 100644 index 0000000..5dc5a1d --- /dev/null +++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out @@ -0,0 +1,87 @@ +Parsed test spec with 4 sessions + +starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 wakegrant4 +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +ERROR: tuple concurrently deleted +step wakegrant4: <... completed> + +starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 mkrels4 wakegrant4 +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step mkrels4: + SELECT FROM vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED + +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +ERROR: duplicate key value violates unique constraint "pg_class_oid_index" +step wakegrant4: <... completed> + +starting permutation: snap3 cachefill1 at2 mkrels4 r3 waitprunable4 vac4 grant1 wakeinval4 at4 wakegrant4 inspect4 +step snap3: BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT; +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step mkrels4: + SELECT FROM vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED + +step r3: ROLLBACK; +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step at4: ALTER TABLE vactest.child50 INHERIT vactest.orig50; +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +step wakegrant4: <... completed> +step inspect4: + SELECT relhastriggers, relhassubclass FROM pg_class + WHERE oid = 'vactest.orig50'::regclass; + +relhastriggers|relhassubclass +--------------+-------------- +f |f +(1 row) + 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.out new file mode 100644 index 0000000..b18857c --- /dev/null +++ b/src/test/modules/injection_points/expected/syscache-update-pruned_1.out @@ -0,0 +1,86 @@ +Parsed test spec with 4 sessions + +starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 wakegrant4 +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +step wakegrant4: <... completed> + +starting permutation: cachefill1 at2 waitprunable4 vac4 grant1 wakeinval4 mkrels4 wakegrant4 +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step mkrels4: + SELECT FROM vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED + +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +step wakegrant4: <... completed> + +starting permutation: snap3 cachefill1 at2 mkrels4 r3 waitprunable4 vac4 grant1 wakeinval4 at4 wakegrant4 inspect4 +step snap3: BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT; +step cachefill1: SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); +step at2: + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); + <waiting ...> +step mkrels4: + SELECT FROM vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED + +step r3: ROLLBACK; +step waitprunable4: CALL vactest.wait_prunable(); +step vac4: VACUUM pg_class; +step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> +step wakeinval4: + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); + <waiting ...> +step at2: <... completed> +step wakeinval4: <... completed> +step at4: ALTER TABLE vactest.child50 INHERIT vactest.orig50; +step wakegrant4: + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); + <waiting ...> +step grant1: <... completed> +ERROR: tuple concurrently updated +step wakegrant4: <... completed> +step inspect4: + SELECT relhastriggers, relhassubclass FROM pg_class + WHERE oid = 'vactest.orig50'::regclass; + +relhastriggers|relhassubclass +--------------+-------------- +t |t +(1 row) + diff --git a/src/test/modules/injection_points/injection_points--1.0.sql b/src/test/modules/injection_points/injection_points--1.0.sql index 6c81d55..c445bf6 100644 --- a/src/test/modules/injection_points/injection_points--1.0.sql +++ b/src/test/modules/injection_points/injection_points--1.0.sql @@ -97,3 +97,11 @@ CREATE FUNCTION injection_points_stats_fixed(OUT numattach int8, RETURNS record AS 'MODULE_PATHNAME', 'injection_points_stats_fixed' LANGUAGE C STRICT; + +-- +-- regress_injection.c functions +-- +CREATE FUNCTION removable_cutoff(rel regclass) +RETURNS xid8 +AS 'MODULE_PATHNAME' +LANGUAGE C CALLED ON NULL INPUT; diff --git a/src/test/modules/injection_points/meson.build b/src/test/modules/injection_points/meson.build index ebe79fe..259045e 100644 --- a/src/test/modules/injection_points/meson.build +++ b/src/test/modules/injection_points/meson.build @@ -8,6 +8,7 @@ injection_points_sources = files( 'injection_points.c', 'injection_stats.c', 'injection_stats_fixed.c', + 'regress_injection.c', ) if host_system == 'windows' @@ -44,8 +45,9 @@ tests += { 'specs': [ 'basic', 'inplace', + 'syscache-update-pruned', ], - 'runningcheck': false, # align with GNU make build system + 'runningcheck': false, # see syscache-update-pruned }, 'tap': { 'env': { diff --git a/src/test/modules/injection_points/regress_injection.c b/src/test/modules/injection_points/regress_injection.c new file mode 100644 index 0000000..422f416 --- /dev/null +++ b/src/test/modules/injection_points/regress_injection.c @@ -0,0 +1,71 @@ +/*-------------------------------------------------------------------------- + * + * regress_injection.c + * Functions supporting test-specific subject matter. + * + * Portions Copyright (c) 1996-2025, PostgreSQL Global Development Group + * Portions Copyright (c) 1994, Regents of the University of California + * + * IDENTIFICATION + * src/test/modules/injection_points/regress_injection.c + * + * ------------------------------------------------------------------------- + */ + +#include "postgres.h" + +#include "access/table.h" +#include "fmgr.h" +#include "miscadmin.h" +#include "storage/procarray.h" +#include "utils/xid8.h" + +/* + * removable_cutoff - for syscache-update-pruned.spec + * + * Wrapper around GetOldestNonRemovableTransactionId(). In general, this can + * move backward. runningcheck=false isolation tests can reasonably prevent + * that. For the causes of backward movement, see + * postgr.es/m/CAEze2Wj%2BV0kTx86xB_YbyaqTr5hnE_igdWAwuhSyjXBYscf5-Q%40mail.gmail.com + * and the header comment for ComputeXidHorizons(). One can assume this + * doesn't move backward if one arranges for concurrent activity not to reach + * AbortTransaction() and not to allocate an XID while connected to another + * database. Non-runningcheck tests can control most concurrent activity, + * except autovacuum and the isolationtester control connection. Neither + * allocates XIDs, and AbortTransaction() in those would justify test failure. + */ +PG_FUNCTION_INFO_V1(removable_cutoff); +Datum +removable_cutoff(PG_FUNCTION_ARGS) +{ + Relation rel = NULL; + TransactionId xid; + FullTransactionId next_fxid_before, + next_fxid; + + /* could take other relkinds callee takes, but we've not yet needed it */ + if (!PG_ARGISNULL(0)) + rel = table_open(PG_GETARG_OID(0), AccessShareLock); + + /* + * No lock or snapshot necessarily prevents oldestXid from advancing past + * "xid" while this function runs. That concerns us only in that we must + * not ascribe "xid" to the wrong epoch. (That may never arise in + * isolation testing, but let's set a good example.) As a crude solution, + * retry until nextXid doesn't change. + */ + next_fxid = ReadNextFullTransactionId(); + do + { + CHECK_FOR_INTERRUPTS(); + next_fxid_before = next_fxid; + xid = GetOldestNonRemovableTransactionId(rel); + next_fxid = ReadNextFullTransactionId(); + } while (!FullTransactionIdEquals(next_fxid, next_fxid_before)); + + if (rel) + table_close(rel, AccessShareLock); + + PG_RETURN_FULLTRANSACTIONID(FullTransactionIdFromAllowableAt(next_fxid, + xid)); +} diff --git a/src/test/modules/injection_points/specs/syscache-update-pruned.spec b/src/test/modules/injection_points/specs/syscache-update-pruned.spec new file mode 100644 index 0000000..b48e897 --- /dev/null +++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec @@ -0,0 +1,179 @@ +# 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, which exercises the corresponding +# race condition for inplace updates. + +# Despite local injection points, this is incompatible with runningcheck. +# First, removable_cutoff() could move backward, per its header comment. +# Second, other activity could trigger sinval queue overflow, negating our +# efforts to delay inval. Third, this deadlock emerges: +# +# - step at2 waits at an injection point, with interrupts held +# - an unrelated backend waits for at2 to do PROCSIGNAL_BARRIER_SMGRRELEASE +# - step waitprunable4 waits for the unrelated backend to release its xmin + +# The alternative expected output is for -DCATCACHE_FORCE_RELEASE, a setting +# that thwarts testing the race conditions this spec seeks. + + +# 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 +{ + CREATE EXTENSION injection_points; + CREATE SCHEMA vactest; + -- Ensure a leader RELOID catcache entry. PARALLEL RESTRICTED since a + -- parallel worker running pg_relation_filenode() would lack that effect. + CREATE FUNCTION vactest.reloid_catcache_set(regclass) RETURNS int + LANGUAGE sql PARALLEL RESTRICTED + AS 'SELECT 0 FROM pg_relation_filenode($1)'; + 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 + $$; + CREATE PROCEDURE vactest.wait_prunable() LANGUAGE plpgsql AS $$ + DECLARE + barrier xid8; + cutoff xid8; + BEGIN + barrier := pg_current_xact_id(); + -- autovacuum worker RelationCacheInitializePhase3() or the + -- isolationtester control connection might hold a snapshot that + -- limits pruning. Sleep until that clears. + LOOP + ROLLBACK; -- release MyProc->xmin, which could be the oldest + cutoff := removable_cutoff('pg_class'); + EXIT WHEN cutoff >= barrier; + RAISE LOG 'removable cutoff %; waiting for %', cutoff, barrier; + PERFORM pg_sleep(.1); + END LOOP; + END + $$; +} +setup { CALL vactest.wait_prunable(); -- maximize next two VACUUMs } +setup { VACUUM FULL pg_class; -- reduce free space } +setup { VACUUM FREEZE pg_class; -- populate fsm etc. } +setup +{ + SELECT FROM vactest.mkrels('orig', 1, 49); + CREATE TABLE vactest.orig50 (c int) WITH (autovacuum_enabled = off); + CREATE TABLE vactest.child50 (c int) WITH (autovacuum_enabled = off); + SELECT FROM vactest.mkrels('orig', 51, 100); +} +teardown +{ + DROP SCHEMA vactest CASCADE; + DROP EXTENSION injection_points; +} + +# Wait during GRANT. Disable debug_discard_caches, since we're here to +# exercise an outcome that happens under permissible cache staleness. +session s1 +setup { + SET debug_discard_caches = 0; + SELECT FROM injection_points_set_local(); + SELECT FROM injection_points_attach('heap_update-before-pin', 'wait'); +} +step cachefill1 { SELECT FROM vactest.reloid_catcache_set('vactest.orig50'); } +step grant1 { GRANT SELECT ON vactest.orig50 TO PUBLIC; } + +# Update of the tuple that grant1 will update. Wait before sending invals, so +# s1 will not get a cache miss. Choose the commands for making such updates +# 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 { + SELECT FROM injection_points_set_local(); + SELECT FROM + injection_points_attach('AtEOXact_Inval-with-transInvalInfo', 'wait'); +} +step at2 { + CREATE TRIGGER to_set_relhastriggers BEFORE UPDATE ON vactest.orig50 + FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); +} + +# Hold snapshot to block pruning. +session s3 +step snap3 { BEGIN ISOLATION LEVEL REPEATABLE READ; SELECT; } +step r3 { ROLLBACK; } + +# Non-blocking actions. +session s4 +step waitprunable4 { CALL vactest.wait_prunable(); } +step vac4 { VACUUM pg_class; } +# 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 FROM vactest.mkrels('intruder', 1, 100); -- repopulate LP_UNUSED +} +step wakegrant4 { + SELECT FROM injection_points_detach('heap_update-before-pin'); + SELECT FROM injection_points_wakeup('heap_update-before-pin'); +} +step at4 { ALTER TABLE vactest.child50 INHERIT vactest.orig50; } +step wakeinval4 { + SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); + SELECT FROM injection_points_wakeup('AtEOXact_Inval-with-transInvalInfo'); +} +# Witness effects of steps at2 and/or at4. +step inspect4 { + SELECT relhastriggers, relhassubclass FROM pg_class + WHERE oid = 'vactest.orig50'::regclass; +} + +# TID from syscache becomes LP_UNUSED. Before the bug fix, this permutation +# made s1 fail with "attempted to update invisible tuple" or an assert. +# However, suppose a pd_lsn value such that (pd_lsn.xlogid, pd_lsn.xrecoff) +# passed for (xmin, xmax) with xmin known-committed and xmax known-aborted. +# Persistent page header corruption ensued. For example, s1 overwrote +# pd_lower, pd_upper, and pd_special as though they were t_ctid. +permutation + cachefill1 # reads pg_class tuple T0, xmax invalid + at2 # T0 dead, T1 live + waitprunable4 # T0 prunable + vac4 # T0 becomes LP_UNUSED + grant1 # pauses at heap_update(T0) + wakeinval4(at2) # at2 sends inval message + wakegrant4(grant1) # s1 wakes: "tuple concurrently deleted" + +# add mkrels4: LP_UNUSED becomes a different rel's row +permutation + cachefill1 # reads pg_class tuple T0, xmax invalid + at2 # T0 dead, T1 live + waitprunable4 # T0 prunable + vac4 # T0 becomes LP_UNUSED + grant1 # pauses at heap_update(T0) + wakeinval4(at2) # at2 sends inval message + mkrels4 # T0 becomes a new rel + wakegrant4(grant1) # s1 wakes: "duplicate key value violates unique" + +# TID from syscache becomes LP_UNUSED, then becomes a newer version of the +# original rel's row. +permutation + snap3 # sets MyProc->xmin + cachefill1 # reads pg_class tuple T0, xmax invalid + at2 # T0 dead, T1 live + mkrels4 # T1's page becomes full + r3 # clears MyProc->xmin + waitprunable4 # T0 prunable + vac4 # T0 becomes LP_UNUSED + grant1 # pauses at heap_update(T0) + wakeinval4(at2) # at2 sends inval message + at4 # T1 dead, T0 live + wakegrant4(grant1) # s1 wakes: T0 dead, T2 live + inspect4 # observe loss of at2+at4 changes XXX is an extant bug
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2025-03-03 22:07  Andres Freund <andres@anarazel.de>
  parent: Noah Misch <noah@leadboat.com>
  0 siblings, 1 reply; 13+ messages in thread

From: Andres Freund @ 2025-03-03 22:07 UTC (permalink / raw)
  To: Noah Misch <noah@leadboat.com>; +Cc: Alexander Lakhin <exclusion@gmail.com>; Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; pgsql-bugs@lists.postgresql.org

Hi,

On 2025-01-22 18:13:49 -0800, Noah Misch wrote:
> Attached.  Outside of comments and tests, it's a simple 20-line patch.  Since
> only two weeks will remain before release freeze, in the absence of review, I
> would push this after 2025-01-25T16:00+0000.

I just fixed skink, the valgrind animal, so it runs not just the main
regression tests but all tests with a valgrind-ified postgres.  Unfortunately,
the next run triggered a failure in the test added in this thread:

https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&dt=2025-03-03%2019%3A52%3A38...

diff -U3 /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out
--- /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out	2025-01-25 19:30:50.005386842 +0000
+++ /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out	2025-03-03 21:08:02.025314915 +0000
@@ -75,6 +75,7 @@
 	SELECT FROM injection_points_wakeup('heap_update-before-pin');
  <waiting ...>
 step grant1: <... completed>
+ERROR:  tuple concurrently deleted
 step wakegrant4: <... completed>
 step inspect4:
 	SELECT relhastriggers, relhassubclass FROM pg_class
@@ -82,6 +83,6 @@

 relhastriggers|relhassubclass
 --------------+--------------
-f             |f
+t             |t
 (1 row)

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2025-03-04 03:34  Noah Misch <noah@leadboat.com>
  parent: Andres Freund <andres@anarazel.de>
  0 siblings, 1 reply; 13+ messages in thread

From: Noah Misch @ 2025-03-04 03:34 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Alexander Lakhin <exclusion@gmail.com>; Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; pgsql-bugs@lists.postgresql.org

On Mon, Mar 03, 2025 at 05:07:10PM -0500, Andres Freund wrote:
> On 2025-01-22 18:13:49 -0800, Noah Misch wrote:
> > Attached.  Outside of comments and tests, it's a simple 20-line patch.  Since
> > only two weeks will remain before release freeze, in the absence of review, I
> > would push this after 2025-01-25T16:00+0000.
> 
> I just fixed skink, the valgrind animal, so it runs not just the main
> regression tests but all tests with a valgrind-ified postgres.

Thanks.

> Unfortunately,
> the next run triggered a failure in the test added in this thread:
> 
> https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&dt=2025-03-03%2019%3A52%3A38...
> 
> diff -U3 /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out
> --- /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out	2025-01-25 19:30:50.005386842 +0000
> +++ /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out	2025-03-03 21:08:02.025314915 +0000
> @@ -75,6 +75,7 @@
>  	SELECT FROM injection_points_wakeup('heap_update-before-pin');
>   <waiting ...>
>  step grant1: <... completed>
> +ERROR:  tuple concurrently deleted
>  step wakegrant4: <... completed>
>  step inspect4:
>  	SELECT relhastriggers, relhassubclass FROM pg_class
> @@ -82,6 +83,6 @@
> 
>  relhastriggers|relhassubclass
>  --------------+--------------
> -f             |f
> +t             |t
>  (1 row)

That isolation permutation tests an unfixed bug.  Here, it's giving a result
as though the bug were fixed.  The suite passed the next two skink runs.  I'd
tend to defer debugging exactly what went wrong until the project to fix the
bug under test.  I could delete the permutation, or I could leave it awhile to
see how high-probability this failure is.  I'm inclined to leave it until it
gets four failures, then delete the permutation.





^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
@ 2025-04-02 17:04  Noah Misch <noah@leadboat.com>
  parent: Noah Misch <noah@leadboat.com>
  0 siblings, 0 replies; 13+ messages in thread

From: Noah Misch @ 2025-04-02 17:04 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Alexander Lakhin <exclusion@gmail.com>; Melanie Plageman <melanieplageman@gmail.com>; Heikki Linnakangas <hlinnaka@iki.fi>; pgsql-bugs@lists.postgresql.org

On Mon, Mar 03, 2025 at 07:34:42PM -0800, Noah Misch wrote:
> On Mon, Mar 03, 2025 at 05:07:10PM -0500, Andres Freund wrote:
> > I just fixed skink, the valgrind animal, so it runs not just the main
> > regression tests but all tests with a valgrind-ified postgres.
> 
> Thanks.
> 
> > Unfortunately,
> > the next run triggered a failure in the test added in this thread:
> > 
> > https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=skink&dt=2025-03-03%2019%3A52%3A38...
> > 
> > diff -U3 /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out
> > --- /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/modules/injection_points/expected/syscache-update-pruned.out	2025-01-25 19:30:50.005386842 +0000
> > +++ /home/bf/bf-build/skink-master/HEAD/pgsql.build/testrun/injection_points/isolation/results/syscache-update-pruned.out	2025-03-03 21:08:02.025314915 +0000
> > @@ -75,6 +75,7 @@
> >  	SELECT FROM injection_points_wakeup('heap_update-before-pin');
> >   <waiting ...>
> >  step grant1: <... completed>
> > +ERROR:  tuple concurrently deleted
> >  step wakegrant4: <... completed>
> >  step inspect4:
> >  	SELECT relhastriggers, relhassubclass FROM pg_class
> > @@ -82,6 +83,6 @@
> > 
> >  relhastriggers|relhassubclass
> >  --------------+--------------
> > -f             |f
> > +t             |t
> >  (1 row)
> 
> That isolation permutation tests an unfixed bug.  Here, it's giving a result
> as though the bug were fixed.  The suite passed the next two skink runs.  I'd
> tend to defer debugging exactly what went wrong until the project to fix the
> bug under test.  I could delete the permutation, or I could leave it awhile to
> see how high-probability this failure is.  I'm inclined to leave it until it
> gets four failures, then delete the permutation.

Alexander Lakhin shared a recipe that reproduced it.  I found permutation 2
also failed under that recipe, so removing permutation 3 got less attractive.

These tests need a concept of "wait until VACUUM definitely will prune a
particular tuple".  My removable_cutoff() header comment made an argument for
having achieved that, but it had two gaps.  The attached patch passes 1000
Valgrind iterations of the spec.  Without the patch, ~3% of iterations failed.

Commit c2dc1a7 added DISABLE_PAGE_SKIPPING to stop buffer pins thwarting other
VACUUM tests.  However, I suspect FREEZE is necessary and sufficient in all
these tests, since we need to coax this code to insist on the cleanup lock:

		/*
		 * If we didn't get the cleanup lock, we can still collect LP_DEAD
		 * items in the dead_items area for later vacuuming, count live and
		 * recently dead tuples for vacuum logging, and determine if this
		 * block could later be truncated. If we encounter any xid/mxids that
		 * require advancing the relfrozenxid/relminxid, we'll have to wait
		 * for a cleanup lock and call lazy_scan_prune().
		 */
		if (!got_cleanup_lock &&
			!lazy_scan_noprune(vacrel, buf, blkno, page, &has_lpdead_items))
		{
			/*
			 * lazy_scan_noprune could not do all required processing.  Wait
			 * for a cleanup lock, and call lazy_scan_prune in the usual way.
			 */
			Assert(vacrel->aggressive);
			LockBuffer(buf, BUFFER_LOCK_UNLOCK);
			LockBufferForCleanup(buf);
			got_cleanup_lock = true;
		}

FREEZE causes the VACUUM to "require advancing the relfrozenxid/relminxid",
hence the effectiveness of FREEZE for this purpose.  The code has moved
around, but I think the policy was the same at the time of that commit
c2dc1a7.  Per the doc for DISABLE_PAGE_SKIPPING, it's for working around a
corrupt vm, not for pin contention.  The spec still passes 1000 Valgrind
iterations if I remove DISABLE_PAGE_SKIPPING.
Author:     Noah Misch <noah@leadboat.com>
Commit:     Noah Misch <noah@leadboat.com>

    Fix test races between syscache-update-pruned.spec and autovacuum.
    
    This spec fails ~3% of my Valgrind runs, and the spec has failed on Valgrind
    buildfarm member skink at a similar rate.  Two problems contributed to that:
    
    - A competing buffer pin triggered VACUUM's lazy_scan_noprune() path, causing
      "tuples missed: 1 dead from 1 pages not removed due to cleanup lock
      contention".  FREEZE fixes that.
    
    - The spec ran lazy VACUUM immediately after VACUUM FULL.  The spec implicitly
      assumed lazy VACUUM prunes the one tuple that VACUUM FULL made dead.  First
      wait for old snapshots, making that assumption reliable.
    
    This also adds two forms of defense in depth:
    
    - Wait for snapshots using shared catalog pruning rules (VISHORIZON_SHARED).
      This avoids the removable cutoff moving backward when an XID-bearing
      autoanalyze process runs in another database.  That may never happen in this
      test, but it's cheap insurance.
    
    - Use lazy VACUUM option DISABLE_PAGE_SKIPPING.  Commit
      c2dc1a79767a0f947e1145f82eb65dfe4360d25f did this for a related requirement
      in other tests, but I suspect FREEZE is necessary and sufficient in all
      these tests.
    
    Back-patch to v17, where the test first appeared.
    
    Reviewed by FIXME.
    
    Discussion: https://postgr.es/m/sv3taq4e6ea4qckimien3nxp3sz4b6cw6sfcy4nhwl52zpur4g@h6i6tohxmizu

diff --git a/src/test/modules/injection_points/expected/syscache-update-pruned.out b/src/test/modules/injection_points/expected/syscache-update-pruned.out
index 5dc5a1d..9a9683b 100644
--- a/src/test/modules/injection_points/expected/syscache-update-pruned.out
+++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out
@@ -7,7 +7,7 @@ step at2:
 		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
  <waiting ...>
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
@@ -30,7 +30,7 @@ step at2:
 		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
  <waiting ...>
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
@@ -61,7 +61,7 @@ step mkrels4:
 
 step r3: ROLLBACK;
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
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.out
index b18857c..64c39d7 100644
--- a/src/test/modules/injection_points/expected/syscache-update-pruned_1.out
+++ b/src/test/modules/injection_points/expected/syscache-update-pruned_1.out
@@ -7,7 +7,7 @@ step at2:
 		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
  <waiting ...>
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
@@ -29,7 +29,7 @@ step at2:
 		FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger();
  <waiting ...>
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
@@ -59,7 +59,7 @@ step mkrels4:
 
 step r3: ROLLBACK;
 step waitprunable4: CALL vactest.wait_prunable();
-step vac4: VACUUM pg_class;
+step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;
 step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...>
 step wakeinval4: 
 	SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo');
diff --git a/src/test/modules/injection_points/regress_injection.c b/src/test/modules/injection_points/regress_injection.c
index 422f416..7bba1c9 100644
--- a/src/test/modules/injection_points/regress_injection.c
+++ b/src/test/modules/injection_points/regress_injection.c
@@ -17,7 +17,9 @@
 #include "access/table.h"
 #include "fmgr.h"
 #include "miscadmin.h"
+#include "postmaster/autovacuum.h"
 #include "storage/procarray.h"
+#include "utils/rel.h"
 #include "utils/xid8.h"
 
 /*
@@ -28,11 +30,12 @@
  * that.  For the causes of backward movement, see
  * postgr.es/m/CAEze2Wj%2BV0kTx86xB_YbyaqTr5hnE_igdWAwuhSyjXBYscf5-Q%40mail.gmail.com
  * and the header comment for ComputeXidHorizons().  One can assume this
- * doesn't move backward if one arranges for concurrent activity not to reach
- * AbortTransaction() and not to allocate an XID while connected to another
- * database.  Non-runningcheck tests can control most concurrent activity,
- * except autovacuum and the isolationtester control connection.  Neither
- * allocates XIDs, and AbortTransaction() in those would justify test failure.
+ * doesn't move backward if one (a) passes a shared catalog as the argument
+ * and (b) arranges for concurrent activity not to reach AbortTransaction().
+ * Non-runningcheck tests can control most concurrent activity, except
+ * autovacuum and the isolationtester control connection.  AbortTransaction()
+ * in those would justify test failure.  Seeing autoanalyze can allocate an
+ * XID in any database, (a) ensures we'll consistently not ignore those XIDs.
  */
 PG_FUNCTION_INFO_V1(removable_cutoff);
 Datum
@@ -47,6 +50,10 @@ removable_cutoff(PG_FUNCTION_ARGS)
 	if (!PG_ARGISNULL(0))
 		rel = table_open(PG_GETARG_OID(0), AccessShareLock);
 
+	if (!rel->rd_rel->relisshared && autovacuum_start_daemon)
+		elog(WARNING,
+			 "removable_cutoff(non-shared-rel) can move backward under autovacuum=on");
+
 	/*
 	 * No lock or snapshot necessarily prevents oldestXid from advancing past
 	 * "xid" while this function runs.  That concerns us only in that we must
diff --git a/src/test/modules/injection_points/specs/syscache-update-pruned.spec b/src/test/modules/injection_points/specs/syscache-update-pruned.spec
index b48e897..086d084 100644
--- a/src/test/modules/injection_points/specs/syscache-update-pruned.spec
+++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec
@@ -53,10 +53,12 @@ setup
 		barrier := pg_current_xact_id();
 		-- autovacuum worker RelationCacheInitializePhase3() or the
 		-- isolationtester control connection might hold a snapshot that
-		-- limits pruning.  Sleep until that clears.
+		-- limits pruning.  Sleep until that clears.  See comments at
+		-- removable_cutoff() for why we pass a shared catalog rather than
+		-- pg_class, the table we'll prune.
 		LOOP
 			ROLLBACK;  -- release MyProc->xmin, which could be the oldest
-			cutoff := removable_cutoff('pg_class');
+			cutoff := removable_cutoff('pg_database');
 			EXIT WHEN cutoff >= barrier;
 			RAISE LOG 'removable cutoff %; waiting for %', cutoff, barrier;
 			PERFORM pg_sleep(.1);
@@ -64,9 +66,24 @@ setup
 	END
 	$$;
 }
-setup	{ CALL vactest.wait_prunable();  -- maximize next two VACUUMs }
+# Eliminate HEAPTUPLE_DEAD and HEAPTUPLE_RECENTLY_DEAD from pg_class.
+# Minimize free space.
+#
+# If we kept HEAPTUPLE_RECENTLY_DEAD, step vac4 could prune what we missed,
+# breaking some permutation assumptions.  Specifically, the next pg_class
+# tuple could end up in free space we failed to liberate here, instead of
+# going in the specific free space vac4 intended to liberate for it.
+setup	{ CALL vactest.wait_prunable();  -- maximize VACUUM FULL }
 setup	{ VACUUM FULL pg_class;  -- reduce free space }
-setup	{ VACUUM FREEZE pg_class;  -- populate fsm etc. }
+# Remove the one tuple that VACUUM FULL makes dead, a tuple pertaining to
+# pg_class itself.  Populate the FSM for pg_class.
+#
+# wait_prunable waits for snapshots that would thwart pruning, while FREEZE
+# waits for buffer pins that would thwart pruning.  DISABLE_PAGE_SKIPPING
+# isn't actually needed, but other pruning-dependent tests use it.  If those
+# tests remove it, remove it here.
+setup	{ CALL vactest.wait_prunable();  -- maximize lazy VACUUM }
+setup	{ VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class;  -- fill fsm etc. }
 setup
 {
 	SELECT FROM vactest.mkrels('orig', 1, 49);
@@ -115,7 +132,8 @@ step r3		{ ROLLBACK; }
 # Non-blocking actions.
 session s4
 step waitprunable4	{ CALL vactest.wait_prunable(); }
-step vac4		{ VACUUM pg_class; }
+# Eliminate HEAPTUPLE_DEAD.  See above discussion of FREEZE.
+step vac4		{ VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; }
 # Reuse the lp that s1 is waiting to change.  I've observed reuse at the 1st
 # or 18th CREATE, so create excess.
 step mkrels4	{

Attachments:

update-unused-lp-60-dpageskip-v1.patch (text/plain, 9.2K) download Author: Noah Misch <noah@leadboat.com> Commit: Noah Misch <noah@leadboat.com> Fix test races between syscache-update-pruned.spec and autovacuum. This spec fails ~3% of my Valgrind runs, and the spec has failed on Valgrind buildfarm member skink at a similar rate. Two problems contributed to that: - A competing buffer pin triggered VACUUM's lazy_scan_noprune() path, causing "tuples missed: 1 dead from 1 pages not removed due to cleanup lock contention". FREEZE fixes that. - The spec ran lazy VACUUM immediately after VACUUM FULL. The spec implicitly assumed lazy VACUUM prunes the one tuple that VACUUM FULL made dead. First wait for old snapshots, making that assumption reliable. This also adds two forms of defense in depth: - Wait for snapshots using shared catalog pruning rules (VISHORIZON_SHARED). This avoids the removable cutoff moving backward when an XID-bearing autoanalyze process runs in another database. That may never happen in this test, but it's cheap insurance. - Use lazy VACUUM option DISABLE_PAGE_SKIPPING. Commit c2dc1a79767a0f947e1145f82eb65dfe4360d25f did this for a related requirement in other tests, but I suspect FREEZE is necessary and sufficient in all these tests. Back-patch to v17, where the test first appeared. Reviewed by FIXME. Discussion: https://postgr.es/m/sv3taq4e6ea4qckimien3nxp3sz4b6cw6sfcy4nhwl52zpur4g@h6i6tohxmizu diff --git a/src/test/modules/injection_points/expected/syscache-update-pruned.out b/src/test/modules/injection_points/expected/syscache-update-pruned.out index 5dc5a1d..9a9683b 100644 --- a/src/test/modules/injection_points/expected/syscache-update-pruned.out +++ b/src/test/modules/injection_points/expected/syscache-update-pruned.out @@ -7,7 +7,7 @@ step at2: FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); <waiting ...> step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); @@ -30,7 +30,7 @@ step at2: FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); <waiting ...> step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); @@ -61,7 +61,7 @@ step mkrels4: step r3: ROLLBACK; step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); 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.out index b18857c..64c39d7 100644 --- a/src/test/modules/injection_points/expected/syscache-update-pruned_1.out +++ b/src/test/modules/injection_points/expected/syscache-update-pruned_1.out @@ -7,7 +7,7 @@ step at2: FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); <waiting ...> step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); @@ -29,7 +29,7 @@ step at2: FOR EACH ROW EXECUTE PROCEDURE suppress_redundant_updates_trigger(); <waiting ...> step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); @@ -59,7 +59,7 @@ step mkrels4: step r3: ROLLBACK; step waitprunable4: CALL vactest.wait_prunable(); -step vac4: VACUUM pg_class; +step vac4: VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; step grant1: GRANT SELECT ON vactest.orig50 TO PUBLIC; <waiting ...> step wakeinval4: SELECT FROM injection_points_detach('AtEOXact_Inval-with-transInvalInfo'); diff --git a/src/test/modules/injection_points/regress_injection.c b/src/test/modules/injection_points/regress_injection.c index 422f416..7bba1c9 100644 --- a/src/test/modules/injection_points/regress_injection.c +++ b/src/test/modules/injection_points/regress_injection.c @@ -17,7 +17,9 @@ #include "access/table.h" #include "fmgr.h" #include "miscadmin.h" +#include "postmaster/autovacuum.h" #include "storage/procarray.h" +#include "utils/rel.h" #include "utils/xid8.h" /* @@ -28,11 +30,12 @@ * that. For the causes of backward movement, see * postgr.es/m/CAEze2Wj%2BV0kTx86xB_YbyaqTr5hnE_igdWAwuhSyjXBYscf5-Q%40mail.gmail.com * and the header comment for ComputeXidHorizons(). One can assume this - * doesn't move backward if one arranges for concurrent activity not to reach - * AbortTransaction() and not to allocate an XID while connected to another - * database. Non-runningcheck tests can control most concurrent activity, - * except autovacuum and the isolationtester control connection. Neither - * allocates XIDs, and AbortTransaction() in those would justify test failure. + * doesn't move backward if one (a) passes a shared catalog as the argument + * and (b) arranges for concurrent activity not to reach AbortTransaction(). + * Non-runningcheck tests can control most concurrent activity, except + * autovacuum and the isolationtester control connection. AbortTransaction() + * in those would justify test failure. Seeing autoanalyze can allocate an + * XID in any database, (a) ensures we'll consistently not ignore those XIDs. */ PG_FUNCTION_INFO_V1(removable_cutoff); Datum @@ -47,6 +50,10 @@ removable_cutoff(PG_FUNCTION_ARGS) if (!PG_ARGISNULL(0)) rel = table_open(PG_GETARG_OID(0), AccessShareLock); + if (!rel->rd_rel->relisshared && autovacuum_start_daemon) + elog(WARNING, + "removable_cutoff(non-shared-rel) can move backward under autovacuum=on"); + /* * No lock or snapshot necessarily prevents oldestXid from advancing past * "xid" while this function runs. That concerns us only in that we must diff --git a/src/test/modules/injection_points/specs/syscache-update-pruned.spec b/src/test/modules/injection_points/specs/syscache-update-pruned.spec index b48e897..086d084 100644 --- a/src/test/modules/injection_points/specs/syscache-update-pruned.spec +++ b/src/test/modules/injection_points/specs/syscache-update-pruned.spec @@ -53,10 +53,12 @@ setup barrier := pg_current_xact_id(); -- autovacuum worker RelationCacheInitializePhase3() or the -- isolationtester control connection might hold a snapshot that - -- limits pruning. Sleep until that clears. + -- limits pruning. Sleep until that clears. See comments at + -- removable_cutoff() for why we pass a shared catalog rather than + -- pg_class, the table we'll prune. LOOP ROLLBACK; -- release MyProc->xmin, which could be the oldest - cutoff := removable_cutoff('pg_class'); + cutoff := removable_cutoff('pg_database'); EXIT WHEN cutoff >= barrier; RAISE LOG 'removable cutoff %; waiting for %', cutoff, barrier; PERFORM pg_sleep(.1); @@ -64,9 +66,24 @@ setup END $$; } -setup { CALL vactest.wait_prunable(); -- maximize next two VACUUMs } +# Eliminate HEAPTUPLE_DEAD and HEAPTUPLE_RECENTLY_DEAD from pg_class. +# Minimize free space. +# +# If we kept HEAPTUPLE_RECENTLY_DEAD, step vac4 could prune what we missed, +# breaking some permutation assumptions. Specifically, the next pg_class +# tuple could end up in free space we failed to liberate here, instead of +# going in the specific free space vac4 intended to liberate for it. +setup { CALL vactest.wait_prunable(); -- maximize VACUUM FULL } setup { VACUUM FULL pg_class; -- reduce free space } -setup { VACUUM FREEZE pg_class; -- populate fsm etc. } +# Remove the one tuple that VACUUM FULL makes dead, a tuple pertaining to +# pg_class itself. Populate the FSM for pg_class. +# +# wait_prunable waits for snapshots that would thwart pruning, while FREEZE +# waits for buffer pins that would thwart pruning. DISABLE_PAGE_SKIPPING +# isn't actually needed, but other pruning-dependent tests use it. If those +# tests remove it, remove it here. +setup { CALL vactest.wait_prunable(); -- maximize lazy VACUUM } +setup { VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; -- fill fsm etc. } setup { SELECT FROM vactest.mkrels('orig', 1, 49); @@ -115,7 +132,8 @@ step r3 { ROLLBACK; } # Non-blocking actions. session s4 step waitprunable4 { CALL vactest.wait_prunable(); } -step vac4 { VACUUM pg_class; } +# Eliminate HEAPTUPLE_DEAD. See above discussion of FREEZE. +step vac4 { VACUUM (FREEZE, DISABLE_PAGE_SKIPPING) pg_class; } # Reuse the lp that s1 is waiting to change. I've observed reuse at the 1st # or 18th CREATE, so create excess. step mkrels4 {
^ permalink raw reply [nested|flat] 13+ messages in thread


end of thread, other threads:[~2025-04-02 17:04 UTC | newest]

Thread overview: 13+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-03-02 13:00 BUG #17821: Assertion failed in heap_update() due to heap pruning PG Bug reporting form <noreply@postgresql.org>
2023-03-04 06:00 ` Alexander Lakhin <exclusion@gmail.com>
2023-03-04 16:48   ` Andres Freund <andres@anarazel.de>
2023-10-07 08:00     ` Alexander Lakhin <exclusion@gmail.com>
2024-04-09 12:00       ` Alexander Lakhin <exclusion@gmail.com>
2024-04-09 17:41         ` Melanie Plageman <melanieplageman@gmail.com>
2024-04-09 19:00           ` Alexander Lakhin <exclusion@gmail.com>
2024-11-13 00:26             ` Noah Misch <noah@leadboat.com>
2025-01-11 21:44               ` Noah Misch <noah@leadboat.com>
2025-01-23 02:13                 ` Noah Misch <noah@leadboat.com>
2025-03-03 22:07                   ` Andres Freund <andres@anarazel.de>
2025-03-04 03:34                     ` Noah Misch <noah@leadboat.com>
2025-04-02 17:04                       ` Noah Misch <noah@leadboat.com>

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