Excessive LOG messages from replication slot sync worker - Mailing list pgsql-hackers
From | Fujii Masao |
---|---|
Subject | Excessive LOG messages from replication slot sync worker |
Date | |
Msg-id | CAHGQGwHuHPB-ucAk_Tq3uSs4Fdziu1Jp_AA_RD3m5Ycky7m48w@mail.gmail.com Whole thread Raw |
Responses |
Re: Excessive LOG messages from replication slot sync worker
|
List | pgsql-hackers |
Hi, While testing the replication slot synchronization feature, I set up three instances on the same machine: - Physical replication primary (also Logical replication publisher) - Physical replication standby - Logical replication subscriber ---------------------------------------- initdb -D pri --encoding=UTF8 --locale=C cat <<EOF >> pri/postgresql.conf wal_level = logical log_line_prefix = '%m [pri][%b] ' logging_collector = on EOF pg_ctl -D pri start pgbench -i cat <<EOF | psql CREATE PUBLICATION mypub FOR ALL TABLES; SELECT pg_create_physical_replication_slot('pslot'); EOF cat <<EOF >> pri/postgresql.conf synchronized_standby_slots = 'pslot' EOF pg_ctl -D pri reload pg_basebackup -D sby -c fast touch sby/standby.signal cat <<EOF >> sby/postgresql.conf port = 5433 primary_conninfo = 'host=localhost port=5432 dbname=postgres' primary_slot_name = 'pslot' sync_replication_slots = on hot_standby_feedback = on log_line_prefix = '%m [sby][%b] ' EOF pg_ctl -D sby start initdb -D sub --encoding=UTF8 --locale=C cat <<EOF >> sub/postgresql.conf port = 5434 wal_level = logical log_line_prefix = '%m [sub][%b] ' logging_collector = on EOF pg_ctl -D sub start pgbench -i -Itp -p 5434 cat <<EOF | psql -p 5434 CREATE SUBSCRIPTION mysub CONNECTION 'host=localhost port=5432 dbname=postgres' PUBLICATION mypub WITH (failover); EOF ---------------------------------------- I noticed that the replication slot sync worker on the standby generates a large number of LOG messages, about two per 200–300 ms, during pgbench runs (pgbench -c 10 -j 10 -T 60). For example, ---------------------------------------- 2025-08-12 11:48:21.067 JST [sby][slotsync worker] LOG: starting logical decoding for slot "mysub" 2025-08-12 11:48:21.067 JST [sby][slotsync worker] DETAIL: Streaming transactions committing after 0/04F317B8, reading WAL from 0/04006FC0. 2025-08-12 11:48:21.067 JST [sby][slotsync worker] LOG: logical decoding found consistent point at 0/04006FC0 2025-08-12 11:48:21.067 JST [sby][slotsync worker] DETAIL: There are no running transactions. 2025-08-12 11:48:21.296 JST [sby][slotsync worker] LOG: starting logical decoding for slot "mysub" 2025-08-12 11:48:21.296 JST [sby][slotsync worker] DETAIL: Streaming transactions committing after 0/04F9DC90, reading WAL from 0/04006FC0. 2025-08-12 11:48:21.297 JST [sby][slotsync worker] LOG: logical decoding found consistent point at 0/04006FC0 2025-08-12 11:48:21.297 JST [sby][slotsync worker] DETAIL: There are no running transactions. 2025-08-12 11:48:21.526 JST [sby][slotsync worker] LOG: starting logical decoding for slot "mysub" 2025-08-12 11:48:21.526 JST [sby][slotsync worker] DETAIL: Streaming transactions committing after 0/0506A5C0, reading WAL from 0/04006FC0. 2025-08-12 11:48:21.527 JST [sby][slotsync worker] LOG: logical decoding found consistent point at 0/04006FC0 2025-08-12 11:48:21.527 JST [sby][slotsync worker] DETAIL: There are no running transactions. 2025-08-12 11:48:21.762 JST [sby][slotsync worker] LOG: starting logical decoding for slot "mysub" 2025-08-12 11:48:21.762 JST [sby][slotsync worker] DETAIL: Streaming transactions committing after 0/050C7F70, reading WAL from 0/04006FC0. 2025-08-12 11:48:21.763 JST [sby][slotsync worker] LOG: logical decoding found consistent point at 0/04006FC0 2025-08-12 11:48:21.763 JST [sby][slotsync worker] DETAIL: There are no running transactions. 2025-08-12 11:48:21.999 JST [sby][slotsync worker] LOG: starting logical decoding for slot "mysub" 2025-08-12 11:48:21.999 JST [sby][slotsync worker] DETAIL: Streaming transactions committing after 0/05111420, reading WAL from 0/04006FC0. 2025-08-12 11:48:21.999 JST [sby][slotsync worker] LOG: logical decoding found consistent point at 0/04006FC0 2025-08-12 11:48:21.999 JST [sby][slotsync worker] DETAIL: There are no running transactions. ---------------------------------------- Is this expected behavior, a configuration mistake on my side, or perhaps an oversight in the commit of the replication slot synchronization feature? This seems more like debug output left over from development rather than something useful for users. If this is true, would it make sense to change these messages from LOG to DEBUG? Regards, -- Fujii Masao
pgsql-hackers by date: