Re: server log inflates due to pg_logical_slot_peek_changes/pg_logical_slot_get_changes calls

From: Ashutosh Bapat <ashutosh(dot)bapat(dot)oss(at)gmail(dot)com>
To: Jeevan Ladhe <jeevanladhe(dot)os(at)gmail(dot)com>
Cc: pgsql-hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: server log inflates due to pg_logical_slot_peek_changes/pg_logical_slot_get_changes calls
Date: 2023-03-20 10:36:27
Message-ID: CAExHW5voVUbctUDgeQ-r+D6sFzeQ8070ACh3rBuk4vsSVgo7mw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On Sun, Mar 19, 2023 at 4:59 PM Jeevan Ladhe <jeevanladhe(dot)os(at)gmail(dot)com> wrote:
>
> Hi,
>
> I observed absurd behaviour while using pg_logical_slot_peek_changes()
> and pg_logical_slot_get_changes(). Whenever any of these two functions
> are called to read the changes using a decoder plugin, the following
> messages are printed in the log for every single such call.
>
> 2023-03-19 16:36:06.040 IST [30099] LOG: starting logical decoding for slot "test_slot1"
> 2023-03-19 16:36:06.040 IST [30099] DETAIL: Streaming transactions committing after 0/851DFD8, reading WAL from 0/851DFA0.
> 2023-03-19 16:36:06.040 IST [30099] STATEMENT: SELECT data FROM pg_logical_slot_get_changes('test_slot1', NULL, NULL, 'format-version', '2');
> 2023-03-19 16:36:06.040 IST [30099] LOG: logical decoding found consistent point at 0/851DFA0
> 2023-03-19 16:36:06.040 IST [30099] DETAIL: There are no running transactions.
> 2023-03-19 16:36:06.040 IST [30099] STATEMENT: SELECT data FROM pg_logical_slot_get_changes('test_slot1', NULL, NULL, 'format-version', '2');
>
> This log is printed on every single call to peek/get functions and bloats
> the server log file by a huge amount when called in the loop for reading
> the changes.
>
> IMHO, printing the message every time we create the context for
> decoding a slot using pg_logical_slot_get_changes() seems over-burn.
> Wondering if instead of LOG messages, should we mark these as
> DEBUG1 in SnapBuildFindSnapshot() and CreateDecodingContext()
> respectively? I can produce a patch for the same if we agree.
>

I think those messages are useful when debugging logical replication
problems (imagine missing transaction or inconsistent data between
publisher and subscriber). I don't think pg_logical_slot_get_changes()
or pg_logical_slot_peek_changes() are expected to be called frequently
in a loop. Instead you should open a replication connection to
continue to receive logical changes ... forever.

Why do you need to call pg_logical_slot_peek_changes() and
pg_logical_slot_get_changes() frequently?

--
Best Wishes,
Ashutosh Bapat

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Josef Šimánek 2023-03-20 10:44:15 Re: Ignoring BRIN for HOT updates (was: -udpates seems broken)
Previous Message Matthias van de Meent 2023-03-20 10:24:20 Re: Ignoring BRIN for HOT updates (was: -udpates seems broken)