Re: Minimal logical decoding on standbys

Bertrand Drouvot <bertranddrouvot.pg@gmail.com>

From: "Drouvot, Bertrand" <bertranddrouvot.pg@gmail.com>
To: Noah Misch <noah@leadboat.com>, Andres Freund <andres@anarazel.de>
Cc: Amit Kapila <amit.kapila16@gmail.com>, Alvaro Herrera <alvherre@alvh.no-ip.org>, Jeff Davis <pgsql@j-davis.com>, Robert Haas <robertmhaas@gmail.com>, Thomas Munro <thomas.munro@gmail.com>, Ibrar Ahmed <ibrar.ahmad@gmail.com>, Amit Khandekar <amitdkhan.pg@gmail.com>, fabriziomello@gmail.com, tushar <tushar.ahuja@enterprisedb.com>, Rahila Syed <rahila.syed@2ndquadrant.com>, pgsql-hackers <pgsql-hackers@postgresql.org>
Date: 2023-04-11T08:55:43Z
Lists: pgsql-hackers

Commits

Same data as JSON: GET /api/v1/messages/:b64id/commits the thread's linked commits as JSON, with link sources. API reference →
  1. Reduce the log level in 035_standby_logical_decoding.pl.

  2. 035_standby_logical_decoding: Add missing waits for replication

  3. For cascading replication, wake physical and logical walsenders separately

  4. Handle logical slot conflicts on standby

  5. Support invalidating replication slots due to horizon and wal_level

  6. Prevent use of invalidated logical slot in CreateDecodingContext()

  7. Replace replication slot's invalidated_at LSN with an enum

  8. Pass down table relation into more index relation functions

  9. Assert only valid flag bits are passed to visibilitymap_set()

  10. Remove unused _bt_delitems_delete() argument.

  11. Add xl_btree_delete optimization.

Attachments

Hi,

On 4/11/23 10:20 AM, Drouvot, Bertrand wrote:
> Hi,
> 
> On 4/11/23 7:36 AM, Noah Misch wrote:
>> On Fri, Apr 07, 2023 at 11:12:26AM -0700, Andres Freund wrote:
>>> --- /dev/null
>>> +++ b/src/test/recovery/t/035_standby_logical_decoding.pl
>>> @@ -0,0 +1,720 @@
>>> +# logical decoding on standby : test logical decoding,
>>> +# recovery conflict and standby promotion.
>> ...
>>> +$node_primary->append_conf('postgresql.conf', q{
>>> +wal_level = 'logical'
>>> +max_replication_slots = 4
>>> +max_wal_senders = 4
>>> +log_min_messages = 'debug2'
>>> +log_error_verbosity = verbose
>>> +});
>>
>> Buildfarm member hoverfly stopped reporting in when this test joined the tree.
>> It's currently been stuck here for 140 minutes:
>>
> 
> Thanks for the report!
> 
> It's looping on:
> 
> 2023-04-11 02:57:52.516 UTC [62718288:5] 035_standby_logical_decoding.pl LOG:  00000: statement: SELECT restart_lsn IS NOT NULL
>                          FROM pg_catalog.pg_replication_slots WHERE slot_name = 'promotion_inactiveslot'
> 
> And the reason is that the slot is not being created:
> 
> $ grep "CREATE_REPLICATION_SLOT" 035_standby_logical_decoding_standby.log | tail -2
> 2023-04-11 02:57:47.287 UTC [9241178:15] 035_standby_logical_decoding.pl STATEMENT:  CREATE_REPLICATION_SLOT "otherslot" LOGICAL "test_decoding" ( SNAPSHOT 'nothing')
> 2023-04-11 02:57:47.622 UTC [9241178:23] 035_standby_logical_decoding.pl STATEMENT:  CREATE_REPLICATION_SLOT "otherslot" LOGICAL "test_decoding" ( SNAPSHOT 'nothing')
> 
> Not sure why the slot is not being created.
> 
> There is also "replication apply delay" increasing:
> 
> 2023-04-11 02:57:49.183 UTC [13304488:253] DEBUG:  00000: sendtime 2023-04-11 02:57:49.111363+00 receipttime 2023-04-11 02:57:49.183512+00 replication apply delay 644 ms transfer latency 73 ms
> 2023-04-11 02:57:49.184 UTC [13304488:259] DEBUG:  00000: sendtime 2023-04-11 02:57:49.183461+00 receipttime 2023-04-11 02:57:49.1842+00 replication apply delay 645 ms transfer latency 1 ms
> 2023-04-11 02:57:49.221 UTC [13304488:265] DEBUG:  00000: sendtime 2023-04-11 02:57:49.184166+00 receipttime 2023-04-11 02:57:49.221059+00 replication apply delay 682 ms transfer latency 37 ms
> 2023-04-11 02:57:49.222 UTC [13304488:271] DEBUG:  00000: sendtime 2023-04-11 02:57:49.221003+00 receipttime 2023-04-11 02:57:49.222144+00 replication apply delay 683 ms transfer latency 2 ms
> 2023-04-11 02:57:49.222 UTC [13304488:277] DEBUG:  00000: sendtime 2023-04-11 02:57:49.222095+00 receipttime 2023-04-11 02:57:49.2228+00 replication apply delay 684 ms transfer latency 1 ms
> 
> Noah, I think hoverfly is yours, would it be possible to have access (I'm not an AIX expert though) or check if you see a slot creation hanging and if so why?
> 

Well, we can see in 035_standby_logical_decoding_standby.log:

2023-04-11 02:57:49.180 UTC [62718258:5] [unknown] FATAL:  3D000: database "testdb" does not exist

While, on the primary:

2023-04-11 02:57:48.505 UTC [62718254:5] 035_standby_logical_decoding.pl LOG:  00000: statement: CREATE DATABASE testdb

The TAP test is doing:

"
##################################################
# Test standby promotion and logical decoding behavior
# after the standby gets promoted.
##################################################

$node_standby->reload;

$node_primary->psql('postgres', q[CREATE DATABASE testdb]);
$node_primary->safe_psql('testdb', qq[CREATE TABLE decoding_test(x integer, y text);]);

# create the logical slots
create_logical_slots($node_standby, 'promotion_');
"

I think we might want to add:

$node_primary->wait_for_replay_catchup($node_standby);

before calling the slot creation.

It's done in the attached, would it be possible to give it a try please?

Regards,

-- 
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com