MIME-Version: 1.0
References: 
 <CAHGQGwF6zG9Z8ws1yb3hY1VqV-WT7hR0qyXCn2HdbjvZQKufDw@mail.gmail.com>
 <CAA4eK1KLk+TWyNPJ=z6SzQQXySc-N9Gs3eR-QKfV+MX7vfJWiw@mail.gmail.com>
 <CAHGQGwG1br8SQQnBieyJeRAmnMejEtJrVmurfTPxNouLHSW=jA@mail.gmail.com>
In-Reply-To: 
 <CAHGQGwG1br8SQQnBieyJeRAmnMejEtJrVmurfTPxNouLHSW=jA@mail.gmail.com>
From: Amit Kapila <amit.kapila16@gmail.com>
Date: Sat, 21 Mar 2026 23:16:36 +0530
Message-ID: 
 <CAA4eK1KB6geysORVyOh-dJ+9U57CBC30K2XD3fQ6SKZc0Hsi3Q@mail.gmail.com>
Subject: Re: Fix slotsync worker busy loop causing repeated log messages
To: Fujii Masao <masao.fujii@gmail.com>
Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Archived-At: 
 <https://www.postgresql.org/message-id/CAA4eK1KB6geysORVyOh-dJ%2B9U57CBC30K2XD3fQ6SKZc0Hsi3Q%40mail.gmail.com>
Precedence: bulk

On Thu, Mar 19, 2026 at 7:08=E2=80=AFPM Fujii Masao <masao.fujii@gmail.com>=
 wrote:
>
> On Sat, Feb 28, 2026 at 2:03=E2=80=AFPM Amit Kapila <amit.kapila16@gmail.=
com> wrote:
> >
> > On Fri, Feb 27, 2026 at 8:34=E2=80=AFPM Fujii Masao <masao.fujii@gmail.=
com> wrote:
> > >
> > > Normally, the slotsync worker updates the standby slot using the prim=
ary's slot
> > > state. However, when confirmed_flush_lsn matches but restart_lsn does=
 not,
> > > the worker does not actually update the standby slot. Despite that, t=
he current
> > > code of update_local_synced_slot() appears to treat this situation as=
 if
> > > an update occurred. As a result, the worker sleeps only for the minim=
um
> > > interval (200 ms) before retrying. In the next cycle, it again assume=
s
> > > an update happened, and continues looping with the short sleep interv=
al,
> > > causing the repeated logical decoding log messages. Based on a quick =
analysis,
> > > this seems to be the root cause.
> > >
> > > I think update_local_synced_slot() should return false (i.e., no upda=
te
> > > happened) when confirmed_flush_lsn is equal but restart_lsn differs b=
etween
> > > primary and standby.
> > >
> >
> > We expect that in such a case update_local_synced_slot() should
> > advance local_slot's 'restart_lsn' via
> > LogicalSlotAdvanceAndCheckSnapState(), otherwise, it won't go in the
> > cheap code path next time. Normally, restart_lsn advancement should
> > happen when we process XLOG_RUNNING_XACTS and call
> > SnapBuildProcessRunningXacts(). In this particular case as both
> > restart_lsn and confirmed_flush_lsn are the same (0/03000140), the
> > machinery may not be processing XLOG_RUNNING_XACTS record. I have not
> > debugged the exact case yet but you can try by emitting some more
> > records on publisher, it should let the standby advance the slot. It
> > is possible that we can do something like you are proposing to silence
> > the LOG messages but we should know what is going on here.
>
> I agree it's important to investigate why restart_lsn doesn't advance
> in that case and fix that issue.
>
> Separately, I think mistreating the slot as updated is another problem:
> the local slot is treated as updated even when it isn't, which causes
> the slotsync worker to use the minimum sleep interval. We should
> address this independently.
>
> LogicalSlotAdvanceAndCheckSnapState() doesn't always update the local slo=
t,
> but update_local_synced_slot() currently assumes it does. That seems to b=
e
> the root cause. The attached 0001 patch makes
> LogicalSlotAdvanceAndCheckSnapState() return whether the slot was actuall=
y
> updated, and updates update_local_synced_slot() to act based on that resu=
lt.
>
> I've also attached 0002, which reduces the log level of some logical deco=
ding
> messages (e.g., "logical decoding found consistent point") from LOG to
> DEBUG1. These are low-level, developer-oriented messages and can be noisy
> when they occur regularly. This is the same issue I reported earlier at [=
1].
>
> How about applying these patches while we continue working on
> the restart_lsn issue?
>

*
@@ -2174,7 +2193,10 @@ LogicalSlotAdvanceAndCheckSnapState(XLogRecPtr movet=
o,

  if (XLogRecPtrIsValid(ctx->reader->EndRecPtr))
  {
- LogicalConfirmReceivedLocation(moveto);
+ bool slot_updated =3D LogicalConfirmReceivedLocation(moveto);
+
+ if (updated_xmin_or_lsn)
+ *updated_xmin_or_lsn =3D slot_updated;

BTW, LogicalSlotAdvanceAndCheckSnapState() could also advance slot
while processing running_xact record, so not sure we can rely only on
the explicit call LogicalConfirmReceivedLocation() above to ascertain
the same.

Sorry, I couldn't get the chance to look at the patches proposed by
Hou-san to fix this issue but I'll look at it after the feature
freeze.

* For 0002, I think the current log_level is used since logical
decoding is introduced, so if we want to change those, we should start
a separate thread. BTW, as a developer, I find those LOG level
messages quite useful while debugging issues, so I am in favor of
keeping those as it is. However, if the consensus is otherwise, we can
change them as well.

--=20
With Regards,
Amit Kapila.