Hello Bertrand,

08.01.2024 10:34, Bertrand Drouvot wrote:
If one is able to reproduce, would it be possible to change the test and launch
the vacuum in verbose mode? That way, we could see if this is somehow due to [1]
(means something holding global xmin).

Yes, I've added (VERBOSE) and also cut down the test to catch the failure 
faster.
The difference between a successful and a failed run:
2024-01-08 11:58:30.679 UTC [668363] 035_standby_logical_decoding.pl INFO:  vacuuming 
"testdb.pg_catalog.pg_authid"
2024-01-08 11:58:30.679 UTC [668363] 035_standby_logical_decoding.pl INFO:  finished vacuuming "testdb.pg_catalog.pg_authid": index scans: 1
        pages: 0 removed, 1 remain, 1 scanned (100.00% of total)
        tuples: 1 removed, 15 remain, 0 are dead but not yet removable
        removable cutoff: 767, which was 0 XIDs old when operation ended
        new relfrozenxid: 767, which is 39 XIDs ahead of previous value
        frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
        index scan needed: 1 pages from table (100.00% of total) had 1 dead 
item identifiers removed
---
2024-01-08 12:00:59.903 UTC [669119] 035_standby_logical_decoding.pl LOG:  
statement: VACUUM (VERBOSE) pg_authid;
2024-01-08 12:00:59.904 UTC [669119] 035_standby_logical_decoding.pl INFO:  vacuuming 
"testdb.pg_catalog.pg_authid"
2024-01-08 12:00:59.904 UTC [669119] 035_standby_logical_decoding.pl INFO:  finished vacuuming "testdb.pg_catalog.pg_authid": index scans: 0
        pages: 0 removed, 1 remain, 1 scanned (100.00% of total)
        tuples: 0 removed, 16 remain, 1 are dead but not yet removable
        removable cutoff: 766, which was 1 XIDs old when operation ended
        new relfrozenxid: 765, which is 37 XIDs ahead of previous value
        frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
        index scan not needed: 0 pages from table (0.00% of total) had 0 dead 
item identifiers removed

The difference in WAL is essentially the same as I observed before [1].
rmgr: Transaction len (rec/tot):     82/    82, tx:        766, lsn: 0/0403D418, prev 0/0403D3D8, desc: COMMIT 2024-01-08 11:58:30.679035 UTC; inval msgs: catcache 11 catcache 10 rmgr: Heap2       len (rec/tot):     57/    57, tx:          0, lsn: 0/0403D470, prev 0/0403D418, desc: PRUNE snapshotConflictHorizon: 766, nredirected: 0, ndead: 1, isCatalogRel: T, nunused: 0, redirected: [], dead: [16], unused: [], blkref #0: rel 1664/0/1260 blk 0 rmgr: Btree       len (rec/tot):     52/    52, tx:          0, lsn: 0/0403D4B0, prev 0/0403D470, desc: VACUUM ndeleted: 1, nupdated: 0, deleted: [1], updated: [], blkref #0: rel 1664/0/2676 blk 1 rmgr: Btree       len (rec/tot):     52/    52, tx:          0, lsn: 0/0403D4E8, prev 0/0403D4B0, desc: VACUUM ndeleted: 1, nupdated: 0, deleted: [16], updated: [], blkref #0: rel 1664/0/2677 blk 1 rmgr: Heap2       len (rec/tot):     50/    50, tx:          0, lsn: 0/0403D520, prev 0/0403D4E8, desc: VACUUM nunused: 1, unused: [16], blkref #0: rel 1664/0/1260 blk 0 rmgr: Heap2       len (rec/tot):     64/  8256, tx:          0, lsn: 0/0403D558, prev 0/0403D520, desc: VISIBLE snapshotConflictHorizon: 0, flags: 0x07, blkref #0: rel 1664/0/1260 fork vm blk 0 FPW, blkref #1: rel 1664/0/1260 blk 0 rmgr: Heap        len (rec/tot):    225/   225, tx:          0, lsn: 0/0403F5B0, prev 0/0403D558, desc: INPLACE off: 26, blkref #0: rel 1663/16384/16410 blk 4
vs
rmgr: Transaction len (rec/tot):     82/    82, tx:        766, lsn: 0/0403F480, prev 0/0403F440, desc: COMMIT 2024-01-08 12:00:59.901582 UTC; inval msgs: catcache 11 catcache 10 rmgr: XLOG        len (rec/tot):     49/  8241, tx:          0, lsn: 0/0403F4D8, prev 0/0403F480, desc: FPI_FOR_HINT , blkref #0: rel 1664/0/1260 fork fsm blk 2 FPW rmgr: XLOG        len (rec/tot):     49/  8241, tx:          0, lsn: 0/04041528, prev 0/0403F4D8, desc: FPI_FOR_HINT , blkref #0: rel 1664/0/1260 fork fsm blk 1 FPW rmgr: XLOG        len (rec/tot):     49/  8241, tx:          0, lsn: 0/04043578, prev 0/04041528, desc: FPI_FOR_HINT , blkref #0: rel 1664/0/1260 fork fsm blk 0 FPW rmgr: Heap        len (rec/tot):    225/   225, tx:          0, lsn: 0/040455C8, prev 0/04043578, desc: INPLACE off: 26, blkref #0: rel 1663/16384/16410 blk 4

(Complete logs and the modified test are attached.)

With FREEZE, 10 iterations with 20 tests in parallel succeeded for me
(while without it, I get failures on iterations 1,2).

[1] 
https://www.postgresql.org/message-id/b2a1f7d0-7629-72c0-2da7-e9c4e336b010%40gmail.com

Best regards,
Alexander

Attachment: 035-sld.tar.gz
Description: application/gzip

Reply via email to