Re: Logical replication CPU-bound with TRUNCATE/DROP/CREATE many tables

On Thu, Oct 8, 2020 at 2:17 PM Dilip Kumar <dilipbalaut(at)gmail(dot)com> wrote:
>
> On Thu, Oct 8, 2020 at 2:05 PM Keisuke Kuroda
> <keisuke(dot)kuroda(dot)3862(at)gmail(dot)com> wrote:
> >
> > Hi Dilip,
> >
> > > I could not see this issue even without the patch, it is taking less
> > > than 1s even without the patch. See below results
> > >
> > > 2020-10-08 13:00:49 BEGIN 509
> > > 2020-10-08 13:00:49 table nsp_001.part_0001: INSERT:...
> > > 2020-10-08 13:00:49 COMMIT 509 (at 2020-10-08 13:00:48.741986+05:30)
> > >
> > > Am I missing something?
> >
> > Thanks for running the tests.
> > It is the TRUNCATE decoding that takes time.
> > INSERT decoding is fast, even before the patch is applied.
> >
> > 2020-10-02 14:55:48 BEGIN 508
> > 2020-10-02 14:55:48 table nsp_001.part_0001: INSERT ...
> > 2020-10-02 14:55:49 COMMIT 508 (at 2020-10-02 14:55:48.744019+09)
> >
> > However, TRUNCATE decode is slow
> > and take 222s in my environment.
> >
> > 2020-10-02 14:55:50 BEGIN 509
> > 2020-10-02 14:59:42 table nsp_001.tbl_001 ... ns p_001.part_1000:
> > TRUNCATE: (no-flags)
> > 2020-10-02 14:59:42 COMMIT 509 (at 2020-10-02 14:55:50.349219+09)
> >
> > This script will wait 10 seconds after INSERT exits
> > before executing TRUNCATE, please wait for it to run.
> >
> > When TRUNCATE completes,
> > the walsender process should be at 100% CPU.
>
> Okay, thanks for the info, I will run again and see this.
>

Now, I can see the truncate time reduced from 5mins to just 1 sec

Before patch

2020-10-08 14:18:48 BEGIN 510
2020-10-08 14:23:02 COMMIT 510 (at 2020-10-08 14:18:48.88462+05:30)

truncate time: ~5mins

After patch :

2020-10-08 14:30:22 BEGIN 510
2020-10-08 14:30:22 COMMIT 510 (at 2020-10-08 14:30:22.766092+05:30)

truncate time: < 1s

--
Regards,
Dilip Kumar
EnterpriseDB: http://www.enterprisedb.com