Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mlE8L-0003lY-R4 for pgsql-hackers@arkaria.postgresql.org; Thu, 11 Nov 2021 17:45:09 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1mlE8K-0007vJ-DQ for pgsql-hackers@arkaria.postgresql.org; Thu, 11 Nov 2021 17:45:08 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mlE8K-0007vA-14 for pgsql-hackers@lists.postgresql.org; Thu, 11 Nov 2021 17:45:08 +0000 Received: from mail-oi1-x22f.google.com ([2607:f8b0:4864:20::22f]) by magus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1mlE8G-00043h-LS for pgsql-hackers@lists.postgresql.org; Thu, 11 Nov 2021 17:45:07 +0000 Received: by mail-oi1-x22f.google.com with SMTP id 7so2762339oip.12 for ; Thu, 11 Nov 2021 09:45:04 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=hWSz/1ShpyPS0BUlMnkttai8uzW0A4otWtwIdha/Lqk=; b=NLVRUMCwoE2i/Hg6u9vQh1Au4+z7QhD5h7D7q4p4KRdy/oxZqXbS6j/Ef6KCQz3M1I lnsFkUxRoUxLIysStUO4Y4sBipaWM4Tk859uhru7zk3/uqGSX82MxtKIOu3KA52rrGeB 4qTtnJNkLg+FIQQjlHR5JMIHZ2GEwBt0yBUpcC/8Mn1SnnR7CSw9z1JN6vYFsKXVGU2f 3n7SapRu5yqRLQmvMiDG0EwUvFeLFrvzqzNk22U2H9lyC3wwHK+S2dvNToCtRMD4Baur /TXYgC3HSMHL7Z41EReRJpfhIXz9lAZj22Ep2fqEydC16P4AG7cO0fkMsARZv6Sk7bTc hyDw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=hWSz/1ShpyPS0BUlMnkttai8uzW0A4otWtwIdha/Lqk=; b=KHi4DhF9ROZ0qo4VjM2qHm54a0VOxuL7ffXhnpYmJmJ9w0lOs0qFunB7353Qmvy1St px36MqaxoFH0JWEdKMnb3o0mKWKTR2WSXspQd62LLy+9VHeSYEipW2JpH1AmrPiztgWQ Q/fLeGjZb3nFCfp5GvoVCWQTOVlBYgQ5p79s6tb+vQNmZ67Taoh9UjhpYF4mtPHw2L44 GHBFS/2/E2lBLPX3/1B4bcR6TWBGnqf1EaoxTcDoUrjhTLFSt480PIhGXifVTWGrbwIu r+5C8ohda+sa4v9uuFl4KQhpN/Z8gnHceCmM6MT4huZcTWAYzxMaUkMNceE4WF/cCC6x e6ug== X-Gm-Message-State: AOAM530BQp5uBSRJZyRNVCD9jP62bx698amdQuaKYilqMq8abniw/fFB at5S3lqHUHnKWnX+i7b9laxCzj6CE1rym1UEj2c= X-Google-Smtp-Source: ABdhPJzH2nzbGcyJ7Ta3IDsyPkjdYv9mQIJ6AVIQ7sA+pkeB8wRwicCGYxka9X3q+tEGCuoSXXUPcGEVjWJqISNjhHI= X-Received: by 2002:aca:30c5:: with SMTP id w188mr7218337oiw.35.1636652702809; Thu, 11 Nov 2021 09:45:02 -0800 (PST) MIME-Version: 1.0 References: In-Reply-To: From: Fabrice Chapuis Date: Thu, 11 Nov 2021 18:44:51 +0100 Message-ID: Subject: Re: Logical replication timeout problem To: =?UTF-8?B?VGFuZywgSGFpeWluZy/llJAg5rW36Iux?= Cc: Amit Kapila , PostgreSQL Hackers Content-Type: multipart/alternative; boundary="000000000000f8c26c05d086e6cd" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000f8c26c05d086e6cd Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Hello, Our lab is ready now. Amit, I compile Postgres 10.18 with your patch.Tang, I used your script to configure logical replication between 2 databases and to generate 10 million entries in an unreplicated foo table. On a standalone instance no error message appears in log. I activate the physical replication between 2 nodes, and I got following error: 2021-11-10 10:49:12.297 CET [12126] LOG: attempt to send keep alive messag= e 2021-11-10 10:49:12.297 CET [12126] STATEMENT: START_REPLICATION 0/3000000 TIMELINE 1 2021-11-10 10:49:15.127 CET [12064] FATAL: terminating logical replication worker due to administrator command 2021-11-10 10:49:15.127 CET [12036] LOG: worker process: logical replication worker for subscription 16413 (PID 12064) exited with exit code 1 2021-11-10 10:49:15.155 CET [12126] LOG: attempt to send keep alive messag= e This message look like strange because no admin command have been executed during data load. I did not find any error related to the timeout. The message coming from the modification made with the patch comes back all the time: attempt to send keep alive message. But there is no "sent keep alive message". Why logical replication worker exit when physical replication is configured= ? Thanks for your help Fabrice On Fri, Oct 8, 2021 at 9:33 AM Fabrice Chapuis wrote: > Thanks Tang for your script. > Our debugging environment will be ready soon. I will test your script and > we will try to reproduce the problem by integrating the patch provided by > Amit. As soon as I have results I will let you know. > > Regards > > Fabrice > > On Thu, Sep 30, 2021 at 3:15 AM Tang, Haiying/=E5=94=90 =E6=B5=B7=E8=8B= =B1 < > tanghy.fnst@fujitsu.com> wrote: > >> On Friday, September 24, 2021 12:04 AM, Fabrice Chapuis < >> fabrice636861@gmail.com> wrote: >> >> > >> >> > Thanks for your patch, we are going to set up a lab in order to debug >> the function. >> >> >> >> Hi >> >> >> >> I tried to reproduce this timeout problem on version10.18 but failed. >> >> In my trial, I inserted large amounts of data at publisher, which took >> more than 1 minute to replicate. >> >> And with the patch provided by Amit, I saw that the frequency of invokin= g >> >> WalSndKeepaliveIfNecessary function is raised after I inserted data. >> >> >> >> The test script is attached. Maybe you can try it on your machine and >> check if this problem could happen. >> >> If I miss something in the script, please let me know. >> >> Of course, it will be better if you can provide your script to reproduce >> the problem. >> >> >> >> Regards >> >> Tang >> >> --000000000000f8c26c05d086e6cd Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hello,
Our lab is ready now. Amit,=C2=A0 I compile Pos= tgres 10.18 with your patch.Tang, I used your script to configure logical r= eplication between 2 databases and to generate 10 million entries in an unr= eplicated foo table. On a standalone instance no error message appears in l= og.
I activate the physical replication between 2 nodes, and I got follo= wing error:

2021-11-10 10:49:12.297 CET [12126] LOG: =C2=A0at= tempt to send keep alive message
2021-11-10 10:49:12.297 CET [12126] STA= TEMENT: =C2=A0START_REPLICATION 0/3000000 TIMELINE 1
2021-11-10 10:49:15= .127 CET [12064] FATAL: =C2=A0terminating logical replication worker due to= administrator command
2021-11-10 10:49:15.127 CET [12036] LOG: =C2=A0wo= rker process: logical replication worker for subscription 16413 (PID 12064)= exited with exit code 1
2021-11-10 10:49:15.155 CET [12126] LOG: =C2=A0= attempt to send keep alive message

This messag= e look like strange because no admin command have been executed during data= load.
I did not find any error related to the timeout.
=
The message coming from the modification made with the patch comes bac= k all the time: attempt to send keep alive message. But there is no "s= ent keep alive message".

Why logical repl= ication worker=C2=A0exit when physical replication is configured?

Thanks for your help

Fabrice
=




On Friday, September 24, 2021 12:04 AM, Fabrice Cha= puis <fabri= ce636861@gmail.com> wrote:

>

> Thanks for your patch, we are going to set up = a lab in order to debug the function.

=C2=A0

Hi

=C2=A0

I tried to reproduce this timeout problem on versio= n10.18 but failed.

In my trial, I inserted large amounts of data at pu= blisher, which took more than 1 minute to replicate.

And with the patch provided by Amit, I saw that the= frequency of invoking

WalSndKeepaliveIfNecessary function is raised after= I inserted data.

=C2=A0

The test script is attached. Maybe you can try it o= n your machine and check if this problem could happen.

If I miss something in the script, please let me kn= ow.

Of course, it will be better if you can provide you= r script to reproduce the problem.<= /p>

=C2=A0

Regards

Tang

--000000000000f8c26c05d086e6cd--