Re: PATCH: logical_work_mem and logical streaming of large in-progress transactions

On Fri, 24 Apr 2020 at 11:55, Dilip Kumar <dilipbalaut(at)gmail(dot)com> wrote:
>
> On Thu, Apr 23, 2020 at 2:28 PM Erik Rijkers <er(at)xs4all(dot)nl> wrote:
> >
> > On 2020-04-23 05:24, Dilip Kumar wrote:
> > > On Wed, Apr 22, 2020 at 9:31 PM Erik Rijkers <er(at)xs4all(dot)nl> wrote:
> > >>
> > >> The 'ddl' one is apparently not quite fixed - I get this in (cd
> > >> contrib; make check)' (in both assert-enabled and non-assert-enabled
> > >> build)
> > >
> > > Can you send me the contrib/test_decoding/regression.diffs file?
> >
> > Attached.
>
> So from regression.diff, it appears that in failing in memory
> allocation (+ERROR: invalid memory alloc request size
> 94119198201896). My colleague tried to reproduce this in a different
> environment but there is no success so far. One more thing surprises
> me is that after
> (v15-0011-Provide-new-api-to-get-the-streaming-changes.patch)
> actually, it should never go for the streaming path. However, we can
> not ignore the fact that some of the changes might impact the
> non-streaming path as well. Is it possible for you to somehow stop or
> break the code and send the stack trace? One idea is by seeing the
> log we can see from where the error is raised i.e MemoryContextAlloc
> or palloc or some other similar function. Once we know that we can
> convert that error to an assert and find the call stack.
>
> --

Thanks Erik for reporting this issue.

I am able to reproduce this issue(+ERROR: invalid memory alloc
request size) on the top of v16 patch set. I applied all patches(12
patches) of v16 series and then I fired "make check -i" from
"contrib/test_decoding" folder. Below is stack trace of error:

#0 0x0000560b1350902d in MemoryContextAlloc (context=0x560b14188d70,
size=94605581787992) at mcxt.c:806
#1 0x0000560b130f0ad5 in ReorderBufferRestoreChange
(rb=0x560b14188e90, txn=0x560b141baf08, data=0x560b1418a5e8 "K") at
reorderbuffer.c:3680
#2 0x0000560b130f0662 in ReorderBufferRestoreChanges
(rb=0x560b14188e90, txn=0x560b141baf08, file=0x560b1418ad10,
segno=0x560b1418ad20) at reorderbuffer.c:3564
#3 0x0000560b130e918a in ReorderBufferIterTXNInit (rb=0x560b14188e90,
txn=0x560b141baf08, iter_state=0x7ffef18b1600) at reorderbuffer.c:1186
#4 0x0000560b130eaee1 in ReorderBufferProcessTXN (rb=0x560b14188e90,
txn=0x560b141baf08, commit_lsn=25986584, snapshot_now=0x560b141b74d8,
command_id=0, streaming=false)
at reorderbuffer.c:1785
#5 0x0000560b130ecae1 in ReorderBufferCommit (rb=0x560b14188e90,
xid=508, commit_lsn=25986584, end_lsn=25989088,
commit_time=641449268431600, origin_id=0, origin_lsn=0)
at reorderbuffer.c:2315
#6 0x0000560b130d14a1 in DecodeCommit (ctx=0x560b1416ea80,
buf=0x7ffef18b19b0, parsed=0x7ffef18b1850, xid=508) at decode.c:654
#7 0x0000560b130cff98 in DecodeXactOp (ctx=0x560b1416ea80,
buf=0x7ffef18b19b0) at decode.c:261
#8 0x0000560b130cf99a in LogicalDecodingProcessRecord
(ctx=0x560b1416ea80, record=0x560b1416ee00) at decode.c:130
#9 0x0000560b130dbbbc in pg_logical_slot_get_changes_guts
(fcinfo=0x560b1417ee50, confirm=true, binary=false, streaming=false)
at logicalfuncs.c:285
#10 0x0000560b130dbe71 in pg_logical_slot_get_changes
(fcinfo=0x560b1417ee50) at logicalfuncs.c:354
#11 0x0000560b12e294d4 in ExecMakeTableFunctionResult
(setexpr=0x560b14177838, econtext=0x560b14177748,
argContext=0x560b1417ed30, expectedDesc=0x560b141814a0,
randomAccess=false) at execSRF.c:234
#12 0x0000560b12e5490f in FunctionNext (node=0x560b14177630) at
nodeFunctionscan.c:94
#13 0x0000560b12e2c108 in ExecScanFetch (node=0x560b14177630,
accessMtd=0x560b12e54836 <FunctionNext>, recheckMtd=0x560b12e54e15
<FunctionRecheck>) at execScan.c:133
#14 0x0000560b12e2c227 in ExecScan (node=0x560b14177630,
accessMtd=0x560b12e54836 <FunctionNext>, recheckMtd=0x560b12e54e15
<FunctionRecheck>) at execScan.c:199
#15 0x0000560b12e54e9b in ExecFunctionScan (pstate=0x560b14177630) at
nodeFunctionscan.c:270
#16 0x0000560b12e24e23 in ExecProcNodeFirst (node=0x560b14177630) at
execProcnode.c:450
#17 0x0000560b12e3e172 in ExecProcNode (node=0x560b14177630) at
../../../src/include/executor/executor.h:245
#18 0x0000560b12e3e998 in fetch_input_tuple (aggstate=0x560b14176f40)
at nodeAgg.c:566
#19 0x0000560b12e4398f in agg_fill_hash_table
(aggstate=0x560b14176f40) at nodeAgg.c:2518
#20 0x0000560b12e42c9a in ExecAgg (pstate=0x560b14176f40) at nodeAgg.c:2139
#21 0x0000560b12e24e23 in ExecProcNodeFirst (node=0x560b14176f40) at
execProcnode.c:450
#22 0x0000560b12e8bb58 in ExecProcNode (node=0x560b14176f40) at
../../../src/include/executor/executor.h:245
#23 0x0000560b12e8bd59 in ExecSort (pstate=0x560b14176d28) at nodeSort.c:108
#24 0x0000560b12e24e23 in ExecProcNodeFirst (node=0x560b14176d28) at
execProcnode.c:450
#25 0x0000560b12e10e71 in ExecProcNode (node=0x560b14176d28) at
../../../src/include/executor/executor.h:245
#26 0x0000560b12e15c4c in ExecutePlan (estate=0x560b14176af0,
planstate=0x560b14176d28, use_parallel_mode=false,
operation=CMD_SELECT, sendTuples=true, numberTuples=0,
direction=ForwardScanDirection, dest=0x560b1419d188,
execute_once=true) at execMain.c:1646
#27 0x0000560b12e11a19 in standard_ExecutorRun
(queryDesc=0x560b1412db10, direction=ForwardScanDirection, count=0,
execute_once=true) at execMain.c:364
#28 0x0000560b12e116e1 in ExecutorRun (queryDesc=0x560b1412db10,
direction=ForwardScanDirection, count=0, execute_once=true) at
execMain.c:308
#29 0x0000560b131f2177 in PortalRunSelect (portal=0x560b140db860,
forward=true, count=0, dest=0x560b1419d188) at pquery.c:912
#30 0x0000560b131f1b14 in PortalRun (portal=0x560b140db860,
count=9223372036854775807, isTopLevel=true, run_once=true,
dest=0x560b1419d188, altdest=0x560b1419d188,
qc=0x7ffef18b2350) at pquery.c:756
#31 0x0000560b131e550b in exec_simple_query (
query_string=0x560b14076720 "/ display results, but hide most of the
output /\nSELECT count(*), min(data), max(data)\nFROM
pg_logical_slot_get_changes('regression_slot', NULL, NULL,
'include-xids', '0', 'skip-empty-xacts', '1')\nG"...) at
postgres.c:1239
#32 0x0000560b131ee343 in PostgresMain (argc=1, argv=0x560b1409faa0,
dbname=0x560b1409f858 "contrib_regression", username=0x560b1409f830
"mahendrathalor") at postgres.c:4315
#33 0x0000560b130a325b in BackendRun (port=0x560b14096880) at postmaster.c:4510
#34 0x0000560b130a22c3 in BackendStartup (port=0x560b14096880) at
postmaster.c:4202
#35 0x0000560b1309a5cc in ServerLoop () at postmaster.c:1727
#36 0x0000560b130997c9 in PostmasterMain (argc=8, argv=0x560b1406f010)
at postmaster.c:1400
#37 0x0000560b12ee9530 in main (argc=8, argv=0x560b1406f010) at main.c:210

I have Ubuntu setup. I think, this is reproducing into Ubuntu only. I
am looking into this issue with Dilip.

--
Thanks and Regards
Mahendra Singh Thalor
EnterpriseDB: http://www.enterprisedb.com