On Tue, Mar 10, 2020 at 10:44 PM Tomas Vondra
<[email protected]> 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.
James
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f12d7fa5535 in __GI_abort () at abort.c:79
#2 0x0000556dfbafe5d8 in ExceptionalCondition
(conditionName=conditionName@entry=0x556dfbcaceb0 "total_allocated ==
context->mem_allocated",
errorType=errorType@entry=0x556dfbb54028 "FailedAssertion",
fileName=fileName@entry=0x556dfbcacc33 "aset.c",
lineNumber=lineNumber@entry=1541)
at assert.c:67
#3 0x0000556dfbb23761 in AllocSetCheck (context=context@entry=0x556dfdd5cf40)
at aset.c:1541
#4 0x0000556dfbb238aa in AllocSetDelete (context=0x556dfdd5cf40) at aset.c:655
#5 0x0000556dfbb2a8e0 in MemoryContextDelete (context=0x556dfdd5cf40) at
mcxt.c:245
#6 0x0000556dfbb0b6e0 in hash_destroy (hashp=hashp@entry=0x556dfdd6bf68) at
dynahash.c:829
#7 0x0000556dfba9ca90 in set_rtable_names (dpns=dpns@entry=0x7ffeb9b1ad50,
parent_namespaces=parent_namespaces@entry=0x0, rels_used=0x556dfdd3b590)
at ruleutils.c:3578
#8 0x0000556dfbaa0343 in select_rtable_names_for_explain (rtable=<optimized
out>, rels_used=<optimized out>) at ruleutils.c:3418
#9 0x0000556dfb7d994e in ExplainPrintPlan (es=es@entry=0x556dfdc75d10,
queryDesc=queryDesc@entry=0x556dfdd3b4f8) at explain.c:702
#10 0x0000556dfb7d9fe1 in ExplainOnePlan
(plannedstmt=plannedstmt@entry=0x556dfdd3b3e0, into=into@entry=0x0,
es=es@entry=0x556dfdc75d10,
queryString=queryString@entry=0x556dfdc51690 "EXPLAIN ANALYZE 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;", params=params@entry=0x0, queryEnv=queryEnv@entry=0x0,
planduration=0x7ffeb9b1aeb0) at explain.c:564
#11 0x0000556dfb7da1e2 in ExplainOneQuery (query=<optimized out>,
cursorOptions=cursorOptions@entry=256, into=into@entry=0x0,
es=es@entry=0x556dfdc75d10,
queryString=0x556dfdc51690 "EXPLAIN ANALYZE 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;", params=params@entry=0x0, queryEnv=0x0) at explain.c:388
#12 0x0000556dfb7dab4c in ExplainQuery (pstate=pstate@entry=0x556dfdc74e80,
stmt=stmt@entry=0x556dfdc534c8, params=params@entry=0x0,
dest=dest@entry=0x556dfdc75c78) at ../../../src/include/nodes/nodes.h:594
#13 0x0000556dfb9e2ca1 in standard_ProcessUtility (pstmt=0x556dfdcfca78,
queryString=0x556dfdc51690 "EXPLAIN ANALYZE 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;", context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0,
dest=0x556dfdc75c78, qc=0x7ffeb9b1b080) at utility.c:827
#14 0x0000556dfb9e31f2 in ProcessUtility (pstmt=pstmt@entry=0x556dfdcfca78,
queryString=<optimized out>, context=<optimized out>, params=<optimized out>,
queryEnv=<optimized out>, dest=dest@entry=0x556dfdc75c78,
qc=0x7ffeb9b1b080) at utility.c:522
#15 0x0000556dfb9df742 in PortalRunUtility (portal=portal@entry=0x556dfdcb9b40,
pstmt=0x556dfdcfca78, isTopLevel=<optimized out>,
setHoldSnapshot=setHoldSnapshot@entry=true, dest=dest@entry=0x556dfdc75c78,
qc=qc@entry=0x7ffeb9b1b080) at pquery.c:1157
#16 0x0000556dfb9e0526 in FillPortalStore (portal=portal@entry=0x556dfdcb9b40,
isTopLevel=isTopLevel@entry=true) at ../../../src/include/nodes/nodes.h:594
#17 0x0000556dfb9e1051 in PortalRun (portal=portal@entry=0x556dfdcb9b40,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true,
run_once=run_once@entry=true, dest=dest@entry=0x556dfdcfe4c8,
altdest=altdest@entry=0x556dfdcfe4c8, qc=0x7ffeb9b1b280) at pquery.c:751
#18 0x0000556dfb9dd218 in exec_simple_query (
query_string=query_string@entry=0x556dfdc51690 "EXPLAIN ANALYZE 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
#19 0x0000556dfb9df2a2 in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x556dfdc7dc10, dbname=<optimized out>, username=<optimized
out>)
at postgres.c:4295
#20 0x0000556dfb951258 in BackendRun (port=port@entry=0x556dfdc77490) at
postmaster.c:4510
#21 0x0000556dfb9544e2 in BackendStartup (port=port@entry=0x556dfdc77490) at
postmaster.c:4202
#22 0x0000556dfb954705 in ServerLoop () at postmaster.c:1727
#23 0x0000556dfb955cb1 in PostmasterMain (argc=<optimized out>, argv=<optimized
out>) at postmaster.c:1400
#24 0x0000556dfb8a40b1 in main (argc=3, argv=0x556dfdc4a9b0) at main.c:210
