On Fri, Mar 13, 2020 at 2:23 PM James Coleman <jtc...@gmail.com> wrote:
>
> On Tue, Mar 10, 2020 at 10:44 PM Tomas Vondra
> <tomas.von...@2ndquadrant.com> wrote:
> > 3) Most of the execution plans look reasonable, except that some of the
> > plans look like this:
> >
> >
> > QUERY PLAN
> > ---------------------------------------------------------
> > Limit
> > -> GroupAggregate
> > Group Key: t.a, t.b, t.c, t.d
> > -> Incremental Sort
> > Sort Key: t.a, t.b, t.c, t.d
> > Presorted Key: t.a, t.b, t.c
> > -> Incremental Sort
> > Sort Key: t.a, t.b, t.c
> > Presorted Key: t.a, t.b
> > -> Index Scan using t_a_b_idx on t
> > (10 rows)
> >
> > i.e. there are two incremental sorts on top of each other, with
> > different prefixes. But this this is not a new issue - it happens with
> > queries like this:
> >
> > SELECT a, b, c, d, count(*) FROM (
> > SELECT * FROM t ORDER BY a, b, c
> > ) foo GROUP BY a, b, c, d limit 1000;
> >
> > i.e. there's a subquery with a subset of pathkeys. Without incremental
> > sort the plan looks like this:
> >
> > QUERY PLAN
> > ---------------------------------------------
> > Limit
> > -> GroupAggregate
> > Group Key: t.a, t.b, t.c, t.d
> > -> Sort
> > Sort Key: t.a, t.b, t.c, t.d
> > -> Sort
> > Sort Key: t.a, t.b, t.c
> > -> Seq Scan on t
> > (8 rows)
> >
> > so essentially the same plan shape. What bugs me though is that there
> > seems to be some sort of memory leak, so that this query consumes
> > gigabytes os RAM before it gets killed by OOM. But the memory seems not
> > to be allocated in any memory context (at least MemoryContextStats don't
> > show anything like that), so I'm not sure what's going on.
> >
> > Reproducing it is fairly simple:
> >
> > CREATE TABLE t (a bigint, b bigint, c bigint, d bigint);
> > INSERT INTO t SELECT
> > 1000*random(), 1000*random(), 1000*random(), 1000*random()
> > FROM generate_series(1,10000000) s(i);
> > CREATE INDEX idx ON t(a,b);
> > ANALYZE t;
> >
> > EXPLAIN ANALYZE SELECT a, b, c, d, count(*)
> > FROM (SELECT * FROM t ORDER BY a, b, c) foo GROUP BY a, b, c, d
> > LIMIT 100;
>
> While trying to reproduce this, instead of lots of memory usage, I got
> the attached assertion failure instead.
And, without the EXPLAIN ANALYZE was able to get this one, which will
probably be a lot more helpful.
James
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f15f92dd535 in __GI_abort () at abort.c:79
#2 0x00005620946125d8 in ExceptionalCondition
(conditionName=conditionName@entry=0x5620947c0eb0 "total_allocated ==
context->mem_allocated",
errorType=errorType@entry=0x562094668028 "FailedAssertion",
fileName=fileName@entry=0x5620947c0c33 "aset.c",
lineNumber=lineNumber@entry=1541)
at assert.c:67
#3 0x0000562094637761 in AllocSetCheck (context=context@entry=0x562096344590)
at aset.c:1541
#4 0x00005620946378aa in AllocSetDelete (context=0x562096344590) at aset.c:655
#5 0x000056209463e8e0 in MemoryContextDelete (context=0x562096344590) at
mcxt.c:245
#6 0x000056209463e96f in MemoryContextDeleteChildren
(context=context@entry=0x562096350610) at mcxt.c:265
#7 0x000056209463e9c0 in MemoryContextReset (context=0x562096350610) at
mcxt.c:142
#8 0x0000562094647bac in tuplesort_free (state=state@entry=0x56209633e680) at
tuplesort.c:1327
#9 0x000056209464ceb4 in tuplesort_reset (state=state@entry=0x56209633e680) at
tuplesort.c:1406
#10 0x000056209438596f in ExecIncrementalSort (pstate=0x56209631e550) at
nodeIncrementalSort.c:584
#11 0x0000562094385b76 in ExecProcNode (node=0x56209631e550) at
../../../src/include/executor/executor.h:245
#12 ExecIncrementalSort (pstate=0x56209631e338) at nodeIncrementalSort.c:638
#13 0x000056209437432c in ExecProcNode (node=0x56209631e338) at
../../../src/include/executor/executor.h:245
#14 fetch_input_tuple (aggstate=aggstate@entry=0x56209631df38) at nodeAgg.c:411
#15 0x0000562094376eb6 in agg_retrieve_direct
(aggstate=aggstate@entry=0x56209631df38) at nodeAgg.c:1877
#16 0x00005620943770e0 in ExecAgg (pstate=0x56209631df38) at nodeAgg.c:1597
#17 0x00005620943897db in ExecProcNode (node=0x56209631df38) at
../../../src/include/executor/executor.h:245
#18 ExecLimit (pstate=0x56209631dd30) at nodeLimit.c:149
#19 0x00005620943615c4 in ExecProcNode (node=0x56209631dd30) at
../../../src/include/executor/executor.h:245
#20 ExecutePlan (estate=estate@entry=0x56209631daf0, planstate=0x56209631dd30,
use_parallel_mode=<optimized out>, operation=operation@entry=CMD_SELECT,
sendTuples=sendTuples@entry=true, numberTuples=numberTuples@entry=0,
direction=ForwardScanDirection, dest=0x56209632b248, execute_once=true)
at execMain.c:1646
#21 0x0000562094362294 in standard_ExecutorRun (queryDesc=0x562096320b10,
direction=ForwardScanDirection, count=0, execute_once=<optimized out>)
at execMain.c:364
#22 0x000056209436234f in ExecutorRun
(queryDesc=queryDesc@entry=0x562096320b10,
direction=direction@entry=ForwardScanDirection, count=count@entry=0,
execute_once=<optimized out>) at execMain.c:308
#23 0x00005620944f39c8 in PortalRunSelect (portal=portal@entry=0x5620962b6ff0,
forward=forward@entry=true, count=0, count@entry=9223372036854775807,
dest=dest@entry=0x56209632b248) at pquery.c:912
#24 0x00005620944f5013 in PortalRun (portal=portal@entry=0x5620962b6ff0,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true,
run_once=run_once@entry=true, dest=dest@entry=0x56209632b248,
altdest=altdest@entry=0x56209632b248, qc=0x7fffb66b9e00) at pquery.c:756
#25 0x00005620944f1218 in exec_simple_query (
query_string=query_string@entry=0x56209624eb40 "SELECT a, b, c, d,
count(*)\n FROM (SELECT * FROM t ORDER BY a, b, c) foo GROUP BY a, b, c, d\n
LIMIT 100;") at postgres.c:1236
#26 0x00005620944f32a2 in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x56209627b0f8, dbname=<optimized out>, username=<optimized
out>)
at postgres.c:4295
#27 0x0000562094465258 in BackendRun (port=port@entry=0x5620962744d0) at
postmaster.c:4510
#28 0x00005620944684e2 in BackendStartup (port=port@entry=0x5620962744d0) at
postmaster.c:4202
#29 0x0000562094468705 in ServerLoop () at postmaster.c:1727
#30 0x0000562094469cb1 in PostmasterMain (argc=<optimized out>, argv=<optimized
out>) at postmaster.c:1400
#31 0x00005620943b80b1 in main (argc=3, argv=0x562096247af0) at main.c:210
