pg.ddx.io pgsql-bugs@postgresql.org mailing list archive help / color / mirror / Atom feed From: hubert depesz lubaczewski <depesz@depesz.com>
To: pgsql-bugs mailing list <pgsql-bugs@postgresql.org>
Subject: Re: Logical replication stops dropping used initial-sync replication slots
Date: Fri, 18 Mar 2022 13:27:58 +0100
Message-ID: <20220318122758.GA25022@depesz.com> (raw )
In-Reply-To: <20220317142426.GA727@depesz.com >
References: <20220317142426.GA727@depesz.com >
On Thu, Mar 17, 2022 at 03:24:26PM +0100, hubert depesz lubaczewski wrote:
> Hi,
> I have following case:
>
> Primary: Ubuntu Bionic with Pg 12.9, and ~ 60k tables.
> Replica: Ubuntu Focal with Pg 14.2.
Upgraded primary to 12.10, redid everything. Same problem.
Interestingly, now when I look at pg_replication_slots, I see:
#v+
slot_name | plugin | slot_type | datoid | database | temporary | active | active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
---------------------------------------------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+--------------+---------------------
focal14 | pgoutput | logical | 16606 | dbname | f | f | | | 160417199 | 8FA/F601EF68 | 8FA/F87F13E8
pg_6169636_sync_5600099_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17696 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5762839_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17697 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5953088_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17698 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5735455_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17699 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5873494_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3008 | 8FA/F88F3040
pg_6169636_sync_5913846_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17700 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5664472_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17701 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5944971_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17702 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5887578_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17707 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5597814_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17703 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5706390_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | t | 17706 | | 160478361 | 9C5/E5C65BD0 | 9C5/FF470D58
pg_6169636_sync_5900789_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3158 | 8FA/F88F3190
pg_6169636_sync_5719614_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3190 | 8FA/F88F31C8
pg_6169636_sync_5754127_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F31C8 | 8FA/F88F3200
pg_6169636_sync_5667313_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3200 | 8FA/F88F3238
pg_6169636_sync_5904579_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3238 | 8FA/F88F3270
pg_6169636_sync_5922710_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3270 | 8FA/F88F32A8
pg_6169636_sync_5698143_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F32A8 | 8FA/F88F32E0
pg_6169636_sync_5579916_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F32E0 | 8FA/F88F3318
pg_6169636_sync_5938883_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3318 | 8FA/F88F3350
pg_6169636_sync_5654015_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3350 | 8FA/F88F3388
pg_6169636_sync_5762125_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3388 | 8FA/F88F33C0
pg_6169636_sync_5760797_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F33C0 | 8FA/F88F33F8
pg_6169636_sync_5851313_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F33F8 | 8FA/F88F3430
pg_6169636_sync_5916213_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3430 | 8FA/F88F3468
pg_6169636_sync_5999341_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3468 | 8FA/F88F34A0
pg_6169636_sync_5896729_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F34A0 | 8FA/F88F34D8
pg_6169636_sync_5748694_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F34A0 | 8FA/F88F34D8
pg_6169636_sync_5603063_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/782067B8 | 8FB/782067F0
pg_6169636_sync_5859189_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3510 | 8FA/F88F3548
pg_6169636_sync_5740988_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/782067F0 | 8FB/78206828
pg_6169636_sync_5780890_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/78206828 | 8FB/78206860
pg_6169636_sync_5900300_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/78206860 | 8FB/78206898
pg_6169636_sync_5983861_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/78609D40 | 8FB/7A9D6028
pg_6169636_sync_5704266_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417359 | 8FB/7A5C90B0 | 8FB/7A9D6028
pg_6169636_sync_5950291_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD60C0 | 8FB/7AAD60F8
pg_6169636_sync_5687359_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD60F8 | 8FB/7AAD6130
pg_6169636_sync_5591454_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F37B8 | 8FA/F88F37F0
pg_6169636_sync_5695446_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F37F0 | 8FA/F88F3828
pg_6169636_sync_5654295_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3828 | 8FA/F88F3860
pg_6169636_sync_5959324_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3828 | 8FA/F88F3860
pg_6169636_sync_5653706_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F3898 | 8FA/F88F38D0
pg_6169636_sync_5625296_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417208 | 8FA/F88F38D0 | 8FA/F88F3908
pg_6169636_sync_5599947_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD6130 | 8FB/7AAD6168
pg_6169636_sync_5900341_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD6168 | 8FB/7AAD61A0
pg_6169636_sync_5657835_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD61A0 | 8FB/7AAD61D8
pg_6169636_sync_5929106_7073527418723003846 | pgoutput | logical | 16606 | dbname | f | f | | | 160417362 | 8FB/7AAD61D8 | 8FB/7AAD6210
(48 rows)
#v-
These 10 "active" slots. When I checked their data in pg_stat_activity, it looks that these are stuck in "START_REPLICATION SLOT":
#v+
=# select pid, application_name, backend_start, xact_start, query_start, state_change, wait_event_type, wait_event, state, backend_xid, backend_xmin, query, backend_type from pg_stat_activity where pid in (select active_pid from pg_replication_slots where active);
pid │ application_name │ backend_start │ xact_start │ query_start │ state_change │ wait_event_type │ wait_event │ state │ backend_xid │ backend_xmin │ query │ backend_type
═══════╪═════════════════════════════════════════════╪═══════════════════════════════╪════════════╪═══════════════════════════════╪═══════════════════════════════╪═════════════════╪═════════════════════╪════════╪═════════════╪══════════════╪══════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════╪══════════════
17696 │ pg_6169636_sync_5600099_7073527418723003846 │ 2022-03-17 18:28:53.83822+00 │ [null] │ 2022-03-17 18:28:54.178221+00 │ 2022-03-17 18:28:54.178229+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5600099_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17697 │ pg_6169636_sync_5762839_7073527418723003846 │ 2022-03-17 18:28:53.840978+00 │ [null] │ 2022-03-17 18:28:54.182595+00 │ 2022-03-17 18:28:54.182605+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5762839_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17698 │ pg_6169636_sync_5953088_7073527418723003846 │ 2022-03-17 18:28:53.851774+00 │ [null] │ 2022-03-17 18:28:54.182806+00 │ 2022-03-17 18:28:54.182813+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5953088_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17699 │ pg_6169636_sync_5735455_7073527418723003846 │ 2022-03-17 18:28:53.862408+00 │ [null] │ 2022-03-17 18:28:54.181037+00 │ 2022-03-17 18:28:54.181046+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5735455_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17700 │ pg_6169636_sync_5913846_7073527418723003846 │ 2022-03-17 18:28:53.872853+00 │ [null] │ 2022-03-17 18:28:54.179817+00 │ 2022-03-17 18:28:54.179825+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5913846_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17701 │ pg_6169636_sync_5664472_7073527418723003846 │ 2022-03-17 18:28:53.883557+00 │ [null] │ 2022-03-17 18:28:54.175043+00 │ 2022-03-17 18:28:54.175053+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5664472_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17707 │ pg_6169636_sync_5887578_7073527418723003846 │ 2022-03-17 18:28:53.948718+00 │ [null] │ 2022-03-17 18:28:54.176391+00 │ 2022-03-17 18:28:54.1764+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5887578_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17702 │ pg_6169636_sync_5944971_7073527418723003846 │ 2022-03-17 18:28:53.894247+00 │ [null] │ 2022-03-17 18:28:54.177971+00 │ 2022-03-17 18:28:54.177979+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5944971_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17703 │ pg_6169636_sync_5597814_7073527418723003846 │ 2022-03-17 18:28:53.90505+00 │ [null] │ 2022-03-17 18:28:54.183205+00 │ 2022-03-17 18:28:54.183213+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5597814_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
17706 │ pg_6169636_sync_5706390_7073527418723003846 │ 2022-03-17 18:28:53.915736+00 │ [null] │ 2022-03-17 18:28:54.186649+00 │ 2022-03-17 18:28:54.186658+00 │ Client │ WalSenderWaitForWAL │ active │ [null] │ [null] │ START_REPLICATION SLOT "pg_6169636_sync_5706390_7073527418723003846" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '"focal14"') │ walsender
(10 rows)
#v-
Please note that now() when I run these queries is ~ 2022-03-18 12:19:36.902819+00
Which means that these backends are stuck for ~ 18 hours now.
Description of wait event "WalSenderWaitForWAL" "Waiting for WAL to be flushed
in WAL sender process." doesn't seem to be OK, WAL writes are working OK:
#v+
=# select *, pg_current_wal_lsn() from pg_control_checkpoint() \gx
─[ RECORD 1 ]────────┬─────────────────────────
checkpoint_lsn │ 9C7/3E1568B0
redo_lsn │ 9C7/1F7988D0
redo_wal_file │ 00000002000009C70000001F
timeline_id │ 2
prev_timeline_id │ 2
full_page_writes │ t
next_xid │ 0:160478730
next_oid │ 310866725
next_multixact_id │ 167477
next_multi_offset │ 501565
oldest_xid │ 479
oldest_xid_dbid │ 13398
oldest_active_xid │ 160478730
oldest_multi_xid │ 1
oldest_multi_dbid │ 16606
oldest_commit_ts_xid │ 602
newest_commit_ts_xid │ 160478729
checkpoint_time │ 2022-03-18 12:17:03+00
pg_current_wal_lsn │ 9C8/4EFC31E0
#v-
Archiving works, all seems to be well. But replication slots froze, and then
replica started bunch more.
If that would help I can find all things related to these pids (of active
slots), but it might be too much. For now, one, random, pid:
#v+
2022-03-17 18:16:54.684 UTC,,,17706,"10.2.210.180:44612",62337b16.452a,1,"",2022-03-17 18:16:54 UTC,,0,LOG,00000,"connection received: host=10.2.210.180 port=44612",,,,,,,,,""
2022-03-17 18:16:54.691 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,2,"authentication",2022-03-17 18:16:54 UTC,11/57844,0,LOG,00000,"replication connection authorized: user=lrep_user application_name=pg_6169636_sync_5581717_7073527418723003846 SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256, compression=off)",,,,,,,,,""
2022-03-17 18:16:54.693 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,3,"SELECT",2022-03-17 18:16:54 UTC,11/0,0,LOG,00000,"duration: 0.395 ms statement: SELECT pg_catalog.set_config('search_path', '', false);",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.694 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,4,"BEGIN",2022-03-17 18:16:54 UTC,11/57846,0,LOG,00000,"duration: 0.050 ms statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.710 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,5,"idle in transaction",2022-03-17 18:16:54 UTC,11/57846,0,LOG,00000,"logical decoding found consistent point at 8F8/8CAB5958","There are no running transactions.",,,,,"CREATE_REPLICATION_SLOT ""pg_6169636_sync_5581717_7073527418723003846"" LOGICAL pgoutput USE_SNAPSHOT",,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.715 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,6,"SELECT",2022-03-17 18:16:54 UTC,11/57846,0,LOG,00000,"duration: 1.130 ms statement: SELECT c.oid, c.relreplident, c.relkind FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'shard_abcde' AND c.relname = 'alerts_data'",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.720 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,7,"SELECT",2022-03-17 18:16:54 UTC,11/57846,0,LOG,00000,"duration: 4.753 ms statement: SELECT a.attname, a.atttypid, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(164329186)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attgenerated = '' AND a.attrelid = 164329186 ORDER BY a.attnum",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.723 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,8,"COPY",2022-03-17 18:16:54 UTC,11/57846,0,LOG,00000,"duration: 1.878 ms statement: COPY shard_abcde.alerts_data TO STDOUT",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.723 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,9,"COMMIT",2022-03-17 18:16:54 UTC,11/0,0,LOG,00000,"duration: 0.037 ms statement: COMMIT",,,,,,,,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.788 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,10,"idle",2022-03-17 18:16:54 UTC,11/0,0,LOG,00000,"starting logical decoding for slot ""pg_6169636_sync_5581717_7073527418723003846""","Streaming transactions committing after 8F8/8CAB5990, reading WAL from 8F8/8CAB5958.",,,,,"START_REPLICATION SLOT ""pg_6169636_sync_5581717_7073527418723003846"" LOGICAL 8F8/8CAB5990 (proto_version '1', publication_names '""focal14""')",,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:16:54.788 UTC,"lrep_user","dbname",17706,"10.2.210.180:44612",62337b16.452a,11,"idle",2022-03-17 18:16:54 UTC,11/0,0,LOG,00000,"logical decoding found consistent point at 8F8/8CAB5958","There are no running transactions.",,,,,"START_REPLICATION SLOT ""pg_6169636_sync_5581717_7073527418723003846"" LOGICAL 8F8/8CAB5990 (proto_version '1', publication_names '""focal14""')",,,"pg_6169636_sync_5581717_7073527418723003846"
2022-03-17 18:28:53.915 UTC,,,17706,"10.2.210.180:35794",62337de5.452a,1,"",2022-03-17 18:28:53 UTC,,0,LOG,00000,"connection received: host=10.2.210.180 port=35794",,,,,,,,,""
2022-03-17 18:28:53.923 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,2,"authentication",2022-03-17 18:28:53 UTC,16/17576,0,LOG,00000,"replication connection authorized: user=lrep_user application_name=pg_6169636_sync_5706390_7073527418723003846 SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256, compression=off)",,,,,,,,,""
2022-03-17 18:28:53.925 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,3,"SELECT",2022-03-17 18:28:53 UTC,16/0,0,LOG,00000,"duration: 0.421 ms statement: SELECT pg_catalog.set_config('search_path', '', false);",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:53.925 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,4,"idle",2022-03-17 18:28:53 UTC,16/0,0,ERROR,42704,"replication slot ""pg_6169636_sync_5706390_7073527418723003846"" does not exist",,,,,,"DROP_REPLICATION_SLOT pg_6169636_sync_5706390_7073527418723003846 WAIT",,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:53.926 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,5,"BEGIN",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"duration: 0.039 ms statement: BEGIN READ ONLY ISOLATION LEVEL REPEATABLE READ",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:53.958 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,6,"idle in transaction",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"logical decoding found initial starting point at 8FB/83FCA7D8","Waiting for transactions (approximately 1) older than 160417372 to end.",,,,,"CREATE_REPLICATION_SLOT ""pg_6169636_sync_5706390_7073527418723003846"" LOGICAL pgoutput USE_SNAPSHOT",,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.154 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,7,"idle in transaction",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"logical decoding found consistent point at 8FB/84D20960","There are no running transactions.",,,,,"CREATE_REPLICATION_SLOT ""pg_6169636_sync_5706390_7073527418723003846"" LOGICAL pgoutput USE_SNAPSHOT",,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.169 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,8,"SELECT",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"duration: 1.184 ms statement: SELECT c.oid, c.relreplident, c.relkind FROM pg_catalog.pg_class c INNER JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) WHERE n.nspname = 'shard_qwerty' AND c.relname = 'sessions'",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.173 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,9,"SELECT",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"duration: 2.354 ms statement: SELECT a.attname, a.atttypid, a.attnum = ANY(i.indkey) FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_index i ON (i.indexrelid = pg_get_replica_identity_index(163887255)) WHERE a.attnum > 0::pg_catalog.int2 AND NOT a.attisdropped AND a.attgenerated = '' AND a.attrelid = 163887255 ORDER BY a.attnum",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.185 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,10,"COPY",2022-03-17 18:28:53 UTC,16/17578,0,LOG,00000,"duration: 11.738 ms statement: COPY shard_qwerty.sessions TO STDOUT",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.186 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,11,"COMMIT",2022-03-17 18:28:53 UTC,16/0,0,LOG,00000,"duration: 0.039 ms statement: COMMIT",,,,,,,,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.186 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,12,"idle",2022-03-17 18:28:53 UTC,16/0,0,LOG,00000,"starting logical decoding for slot ""pg_6169636_sync_5706390_7073527418723003846""","Streaming transactions committing after 8FB/84D20998, reading WAL from 8FB/83EB4658.",,,,,"START_REPLICATION SLOT ""pg_6169636_sync_5706390_7073527418723003846"" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '""focal14""')",,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.189 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,13,"idle",2022-03-17 18:28:53 UTC,16/0,0,LOG,00000,"logical decoding found initial starting point at 8FB/83FCA7D8","Waiting for transactions (approximately 1) older than 160417372 to end.",,,,,"START_REPLICATION SLOT ""pg_6169636_sync_5706390_7073527418723003846"" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '""focal14""')",,,"pg_6169636_sync_5706390_7073527418723003846"
2022-03-17 18:28:54.251 UTC,"lrep_user","dbname",17706,"10.2.210.180:35794",62337de5.452a,14,"idle",2022-03-17 18:28:53 UTC,16/0,0,LOG,00000,"logical decoding found consistent point at 8FB/84D20960","There are no running transactions.",,,,,"START_REPLICATION SLOT ""pg_6169636_sync_5706390_7073527418723003846"" LOGICAL 8FB/84D20998 (proto_version '1', publication_names '""focal14""')",,,"pg_6169636_sync_5706390_7073527418723003846"
#v-
What can I do about it?
Best regards,
depesz
view thread (12+ messages) latest in thread
Message-ID: <20220318122758.GA25022@depesz.com>
Permalink: ../20220318122758.GA25022@depesz.com/
Also on: postgresql.org/message-id/20220318122758.GA25022@depesz.com
copy link · copy postgr.es
reply 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: depesz@depesz.com
Subject: Re: Logical replication stops dropping used initial-sync replication slots
In-Reply-To: <20220318122758.GA25022@depesz.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