From: Alexander Lakhin <exclusion@gmail.com>
To: pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
Date: Sat, 4 Mar 2023 09:00:00 +0300
Message-ID: <13d30799-0107-6502-c81c-39ff5f1e7eb0@gmail.com> (raw)
In-Reply-To: <17821-dd8c334263399284@postgresql.org>
References: <17821-dd8c334263399284@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
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-bugs@postgresql.org
Cc: exclusion@gmail.com, pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #17821: Assertion failed in heap_update() due to heap pruning
In-Reply-To: <13d30799-0107-6502-c81c-39ff5f1e7eb0@gmail.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox