Re: Add a perl function in Cluster.pm to generate WAL

From: Alexander Lakhin <exclusion(at)gmail(dot)com>
To: Bertrand Drouvot <bertranddrouvot(dot)pg(at)gmail(dot)com>, Michael Paquier <michael(at)paquier(dot)xyz>
Cc: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, Euler Taveira <euler(at)eulerto(dot)com>, Bharath Rupireddy <bharath(dot)rupireddyforpostgres(at)gmail(dot)com>, Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>, Alvaro Herrera <alvherre(at)alvh(dot)no-ip(dot)org>, Andrew Dunstan <andrew(at)dunslane(dot)net>, pgsql-hackers(at)lists(dot)postgresql(dot)org, Andres Freund <andres(at)anarazel(dot)de>
Subject: Re: Add a perl function in Cluster.pm to generate WAL
Date: 2024-01-08 17:00:00
Message-ID: 4fd52508-54d7-0202-5bd3-546c2295967f@gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

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 Content-Type Size
035-sld.tar.gz application/gzip 31.8 KB

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Nathan Bossart 2024-01-08 17:16:27 Re: introduce dynamic shared memory registry
Previous Message Dagfinn Ilmari Mannsåker 2024-01-08 16:58:02 Re: Adding a pg_get_owned_sequence function?