Обсуждение: Non working timeout detection in logical worker

Hello,

Jehan-Guillaume (in Cc) reported me today a problem with logical
replication, where in case of network issue the walsender is correctly
terminating at the given wal_sender_timeout but the logical worker
kept waiting indefinitely.

The issue is apparently a simple thinko, the timestamp of the last
received activity being unconditionally set at the beginning of the
main processing loop, making any reasonable timeout setting
ineffective.  Trivial patch to fix the problem attached.

On Thu, Oct 17, 2019 at 08:00:15PM +0200, Julien Rouhaud wrote:
> Jehan-Guillaume (in Cc) reported me today a problem with logical
> replication, where in case of network issue the walsender is correctly
> terminating at the given wal_sender_timeout but the logical worker
> kept waiting indefinitely.
>
> The issue is apparently a simple thinko, the timestamp of the last
> received activity being unconditionally set at the beginning of the
> main processing loop, making any reasonable timeout setting
> ineffective.  Trivial patch to fix the problem attached.

Right, good catch.  That's indeed incorrect.  The current code would
just keep resetting the timeout if walrcv_receive() returns 0 roughly
once per NAPTIME_PER_CYCLE.  The ping sent to the server once reaching
half of wal_receiver_timeout was also broken because of that.

In short, applied and back-patched down to 10.
--
Michael

On Fri, Oct 18, 2019 at 7:32 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Thu, Oct 17, 2019 at 08:00:15PM +0200, Julien Rouhaud wrote:
> > Jehan-Guillaume (in Cc) reported me today a problem with logical
> > replication, where in case of network issue the walsender is correctly
> > terminating at the given wal_sender_timeout but the logical worker
> > kept waiting indefinitely.
> >
> > The issue is apparently a simple thinko, the timestamp of the last
> > received activity being unconditionally set at the beginning of the
> > main processing loop, making any reasonable timeout setting
> > ineffective.  Trivial patch to fix the problem attached.
>
> Right, good catch.  That's indeed incorrect.  The current code would
> just keep resetting the timeout if walrcv_receive() returns 0 roughly
> once per NAPTIME_PER_CYCLE.  The ping sent to the server once reaching
> half of wal_receiver_timeout was also broken because of that.
>
> In short, applied and back-patched down to 10.

Thanks Michael!

On Fri, 18 Oct 2019 07:47:13 +0200
Julien Rouhaud <rjuju123@gmail.com> wrote:

> On Fri, Oct 18, 2019 at 7:32 AM Michael Paquier <michael@paquier.xyz> wrote:
> >
> > On Thu, Oct 17, 2019 at 08:00:15PM +0200, Julien Rouhaud wrote:  
> > > Jehan-Guillaume (in Cc) reported me today a problem with logical
> > > replication, where in case of network issue the walsender is correctly
> > > terminating at the given wal_sender_timeout but the logical worker
> > > kept waiting indefinitely.
> > >
> > > The issue is apparently a simple thinko, the timestamp of the last
> > > received activity being unconditionally set at the beginning of the
> > > main processing loop, making any reasonable timeout setting
> > > ineffective.  Trivial patch to fix the problem attached.  
> >
> > Right, good catch.  That's indeed incorrect.  The current code would
> > just keep resetting the timeout if walrcv_receive() returns 0 roughly
> > once per NAPTIME_PER_CYCLE.  The ping sent to the server once reaching
> > half of wal_receiver_timeout was also broken because of that.
> >
> > In short, applied and back-patched down to 10.  
> 
> Thanks Michael!

Thank you both guys!