Thread: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
Bowen Shi
Date:
Dears,

Recently I found a PG16 walsender hanging in the huge loop when I used the subscription. This problem can reproduce with following steps:

1. create a partition table;
2. create a publication & subscription;
3. alter partition table with 'add column col varchar(10) NOT NULL DEFAULT ''::character varying' ;
4. insert/update 10000000 rows into partition table;

Then we can find the walsender process hang in the loop with stack:

#0  ResourceArrayAdd (resarr=0x2dfc048, value=140175392354560)
#1  ResourceArrayEnlarge (resarr=0x2dfc048)
#2  ResourceOwnerEnlargeTupleDescs (owner=0x2dfbf68)
#3  IncrTupleDescRefCount (tupdesc=0x7f7d2077b100)
#4  MakeTupleTableSlot (tupleDesc=0x7f7d2077b100, tts_ops=0xd237a0 <TTSOpsVirtual>)
#5  pgoutput_change (ctx=0x2eb1e68, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138)
#6  change_cb_wrapper (cache=0x2eb3e78, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138)
#7  ReorderBufferApplyChange (rb=0x2eb3e78, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138, streaming=false)
#8  ReorderBufferProcessTXN (rb=0x2eb3e78, txn=0x2edfec0, commit_lsn=4675920936, snapshot_now=0x2ec82d0, command_id=0, streaming=false)
#9  ReorderBufferReplay (txn=0x2edfec0, rb=0x2eb3e78, xid=758, commit_lsn=4675920936, end_lsn=4675920984, commit_time=772615467516504, origin_id=0, origin_lsn=0)
#10 ReorderBufferCommit (rb=0x2eb3e78, xid=758, commit_lsn=4675920936, end_lsn=4675920984, commit_time=772615467516504, origin_id=0, origin_lsn=0)
#11 DecodeCommit (ctx=0x2eb1e68, buf=0x7ffe83c408f0, parsed=0x7ffe83c406f0, xid=758, two_phase=false)
#12 xact_decode (ctx=0x2eb1e68, buf=0x7ffe83c408f0)
#13 LogicalDecodingProcessRecord (ctx=0x2eb1e68, record=0x2eb2200)
#14 XLogSendLogical ()
#15 WalSndLoop (send_data=0x95b183 <XLogSendLogical>)
#16 StartLogicalReplication (cmd=0x2e8fcd0)
#17 exec_replication_command (cmd_string=0x2dc3dc8 "START_REPLICATION SLOT \"sub_t\" LOGICAL 0/0 (proto_version '4', origin 'any', publication_names '\"pub_t\"')")
#18 PostgresMain (dbname=0x2dfa7c8 "tdts", username=0x2dfa7a8 "postgres")
#19 BackendRun (port=0x2dedd60)
#20 BackendStartup (port=0x2dedd60)
#21 ServerLoop ()
#22 PostmasterMain (argc=3, argv=0x2dbe920)

In pgoutput.c , I found some reasons:
1. In init_tuple_slot() function, we will build an attrmap when we publish a partition table (entry->publish_as_relid != RelationGetRelid(relation)) and alter missing column into partition table with alter table statement;
2. In pgoutput_change(), we would convert the tuple if needed using MakeTupleTableSlot() function;
3. When we update 30000000 rows,  MakeTupleTableSlot->PinTupleDesc->IncrTupleDescRefCount->ResourceOwnerEnlargeTupleDescs->ResourceArrayEnlarge, we would call ResourceArrayAdd function too many times and cause the problem.

Regards,
Bowen Shi

RE: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
"Zhijie Hou (Fujitsu)"
Date:
On Tuesday, June 25, 2024 3:53 PM Bowen Shi <zxwsbg12138@gmail.com>  wrote:

Hi,

> 1. create a partition table;
> 2. create a publication & subscription;
> 3. alter partition table with 'add column col varchar(10) NOT NULL DEFAULT ''::character varying' ;
> 4. insert/update 10000000 rows into partition table;
> 
> Then we can find the walsender process hang in the loop with stack:
> 
> #0  ResourceArrayAdd (resarr=0x2dfc048, value=140175392354560)
> #1  ResourceArrayEnlarge (resarr=0x2dfc048)
> #2  ResourceOwnerEnlargeTupleDescs (owner=0x2dfbf68)
> #3  IncrTupleDescRefCount (tupdesc=0x7f7d2077b100)
> #4  MakeTupleTableSlot (tupleDesc=0x7f7d2077b100, tts_ops=0xd237a0 <TTSOpsVirtual>) 
> #5  pgoutput_change (ctx=0x2eb1e68, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138) 
> #6  change_cb_wrapper (cache=0x2eb3e78, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138) 
> #7  ReorderBufferApplyChange (rb=0x2eb3e78, txn=0x2edfec0, relation=0x7f7d2077e120, change=0x2f35138,
streaming=false)
 
> #8  ReorderBufferProcessTXN (rb=0x2eb3e78, txn=0x2edfec0, commit_lsn=4675920936, snapshot_now=0x2ec82d0,
command_id=0,streaming=false)
 
> #9  ReorderBufferReplay (txn=0x2edfec0, rb=0x2eb3e78, xid=758, commit_lsn=4675920936, end_lsn=4675920984,
commit_time=772615467516504,origin_id=0, origin_lsn=0) 
 
> #10 ReorderBufferCommit (rb=0x2eb3e78, xid=758, commit_lsn=4675920936, end_lsn=4675920984,
commit_time=772615467516504,origin_id=0, origin_lsn=0) 
 
> #11 DecodeCommit (ctx=0x2eb1e68, buf=0x7ffe83c408f0, parsed=0x7ffe83c406f0, xid=758, two_phase=false)
> #12 xact_decode (ctx=0x2eb1e68, buf=0x7ffe83c408f0)
> #13 LogicalDecodingProcessRecord (ctx=0x2eb1e68, record=0x2eb2200) 
> #14 XLogSendLogical ()
> #15 WalSndLoop (send_data=0x95b183 <XLogSendLogical>) 
> #16 StartLogicalReplication (cmd=0x2e8fcd0)
> #17 exec_replication_command (cmd_string=0x2dc3dc8 "START_REPLICATION SLOT \"sub_t\" LOGICAL 0/0 (proto_version '4',
origin'any', publication_names '\"pub_t\"')")
 
> #18 PostgresMain (dbname=0x2dfa7c8 "tdts", username=0x2dfa7a8 "postgres")
> #19 BackendRun (port=0x2dedd60)
> #20 BackendStartup (port=0x2dedd60)
> #21 ServerLoop ()
> #22 PostmasterMain (argc=3, argv=0x2dbe920)
> 
> In pgoutput.c , I found some reasons:
> 1. In init_tuple_slot() function, we will build an attrmap when we publish a partition table (entry->publish_as_relid
!=RelationGetRelid(relation)) and alter missing column into partition table with alter table statement;
 
> 2. In pgoutput_change(), we would convert the tuple if needed using MakeTupleTableSlot() function;
> 3. When we update 30000000 rows,
MakeTupleTableSlot->PinTupleDesc->IncrTupleDescRefCount->ResourceOwnerEnlargeTupleDescs->ResourceArrayEnlarge,we would
callResourceArrayAdd function too many times and cause the problem.
 

Thanks for reporting and analyzing the issue !

You analysis looks good to me, I think I missed to drop the newly created
slot when changing the logic to support row filter. Here is a small patch
to drop the slots in each cycle, it can fix the issue on my machine.

IIUC, the issue exists from PG15~HEAD. The current patch can apply
on PG16~HEAD, If it looks ok, I will test and prepare the patch for the
other branch.

Best Regards,
Hou zj

Attachment

Re: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
Amit Kapila
Date:
On Tue, Jun 25, 2024 at 5:17 PM Zhijie Hou (Fujitsu)
<houzj.fnst@fujitsu.com> wrote:
>
> On Tuesday, June 25, 2024 3:53 PM Bowen Shi <zxwsbg12138@gmail.com>  wrote:
>
> Thanks for reporting and analyzing the issue !
>
> You analysis looks good to me, I think I missed to drop the newly created
> slot when changing the logic to support row filter. Here is a small patch
> to drop the slots in each cycle, it can fix the issue on my machine.
>
> IIUC, the issue exists from PG15~HEAD. The current patch can apply
> on PG16~HEAD, If it looks ok, I will test and prepare the patch for the
> other branch.
>

IIUC, the relevant code was added in commit
da324d6cd45bbbcc1682cc2fcbc4f575281916af. This is a PG16 commit, so
how can the problem occur in PG15?

BTW, can we think of a resource owner for managing pgoutput resources
similar to the memory context we have in PGOutputData? This will avoid
allocating the resources in Xact or other resource owners. This will
make resource management local to pgoutput similar to what we have for
memory context in PGOutputData. I suggest having a separate resource
owner only for the HEAD branch (which will be PG18).

--
With Regards,
Amit Kapila.



Re: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
Amit Kapila
Date:
On Wed, Jun 26, 2024 at 10:35 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Tue, Jun 25, 2024 at 5:17 PM Zhijie Hou (Fujitsu)
> <houzj.fnst@fujitsu.com> wrote:
> >
> > On Tuesday, June 25, 2024 3:53 PM Bowen Shi <zxwsbg12138@gmail.com>  wrote:
> >
> > Thanks for reporting and analyzing the issue !
> >
> > You analysis looks good to me, I think I missed to drop the newly created
> > slot when changing the logic to support row filter. Here is a small patch
> > to drop the slots in each cycle, it can fix the issue on my machine.
> >
> > IIUC, the issue exists from PG15~HEAD. The current patch can apply
> > on PG16~HEAD, If it looks ok, I will test and prepare the patch for the
> > other branch.
> >
>
> IIUC, the relevant code was added in commit
> da324d6cd45bbbcc1682cc2fcbc4f575281916af. This is a PG16 commit, so
> how can the problem occur in PG15?
>

I see that originally the slot allocation code was introduced in
commit 52e4f0cd472d39d07732b99559989ea3b615be78 but later the code
refactored in da324d6cd45bbbcc1682cc2fcbc4f575281916af. So, I agree
that we must also fix this in PG15.

--
With Regards,
Amit Kapila.



Hi,

On Tue, Jun 25, 2024 at 7:47 PM Zhijie Hou (Fujitsu) <houzj.fnst@fujitsu.com> wrote:
You analysis looks good to me, I think I missed to drop the newly created
slot when changing the logic to support row filter. Here is a small patch
to drop the slots in each cycle, it can fix the issue on my machine.

IIUC, the issue exists from PG15~HEAD. The current patch can apply
on PG16~HEAD, If it looks ok, I will test and prepare the patch for the
other branch.
 
This patch looks good to me. I tested again and didn't reproduce the problem.

Regards,
Bowen Shi

RE: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
"Zhijie Hou (Fujitsu)"
Date:
On Wednesday, June 26, 2024 1:25 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> 
> On Wed, Jun 26, 2024 at 10:35 AM Amit Kapila <amit.kapila16@gmail.com>
> wrote:
> >
> > On Tue, Jun 25, 2024 at 5:17 PM Zhijie Hou (Fujitsu)
> > <houzj.fnst@fujitsu.com> wrote:
> > >
> > > On Tuesday, June 25, 2024 3:53 PM Bowen Shi
> <zxwsbg12138@gmail.com>  wrote:
> > >
> > > Thanks for reporting and analyzing the issue !
> > >
> > > You analysis looks good to me, I think I missed to drop the newly
> > > created slot when changing the logic to support row filter. Here is
> > > a small patch to drop the slots in each cycle, it can fix the issue on my
> machine.
> > >
> > > IIUC, the issue exists from PG15~HEAD. The current patch can apply
> > > on PG16~HEAD, If it looks ok, I will test and prepare the patch for
> > > the other branch.
> > >
> >
> > IIUC, the relevant code was added in commit
> > da324d6cd45bbbcc1682cc2fcbc4f575281916af. This is a PG16 commit, so
> > how can the problem occur in PG15?
> >
> 
> I see that originally the slot allocation code was introduced in commit
> 52e4f0cd472d39d07732b99559989ea3b615be78 but later the code refactored in
> da324d6cd45bbbcc1682cc2fcbc4f575281916af. So, I agree that we must also
> fix this in PG15.

Thanks for confirming! Here are the patches for all branches.
I am researching the comment for resource owner and will reply later.

Best Regards,
Hou zj

Attachment

Re: PG16 walsender hangs in ResourceArrayEnlarge using pgoutput

From
Amit Kapila
Date:
On Thu, Jun 27, 2024 at 9:01 AM Zhijie Hou (Fujitsu)
<houzj.fnst@fujitsu.com> wrote:
>
> On Wednesday, June 26, 2024 1:25 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > IIUC, the relevant code was added in commit
> > > da324d6cd45bbbcc1682cc2fcbc4f575281916af. This is a PG16 commit, so
> > > how can the problem occur in PG15?
> > >
> >
> > I see that originally the slot allocation code was introduced in commit
> > 52e4f0cd472d39d07732b99559989ea3b615be78 but later the code refactored in
> > da324d6cd45bbbcc1682cc2fcbc4f575281916af. So, I agree that we must also
> > fix this in PG15.
>
> Thanks for confirming! Here are the patches for all branches.
>

Pushed.

--
With Regards,
Amit Kapila.