Re: Extremely slow HashAggregate in simple UNION query

2019-08-24 Thread Andres Freund
Hi,

On August 24, 2019 12:41:03 PM PDT, Tom Lane  wrote:
>Jeff Janes  writes:
>> Most of the time is not after the clock stops, but before the
>stepwise
>> ANALYZE clock starts.  If you just do an EXPLAIN rather than EXPLAIN
>> ANALYZE, that is also slow.  The giant hash table is created during
>the
>> planning step (or somewhere around there
>
>It's in executor startup, I believe.

I'm sure personally interested in doing so, but it'd not be hard to measure the 
executor startup time separately. And display it either on a per node basis, or 
as a total number.

Quite unconvinced this thread is a convincing reason to do so (or really do 
anything). But for some other workloads executor startup is a very large 
fraction of the total time, without massive misestimations. Optimizing that 
could be easier with that information available.

Andres
-- 
Sent from my Android device with K-9 Mail. Please excuse my brevity.




Re: Extremely slow HashAggregate in simple UNION query

2019-08-24 Thread Tom Lane
Jeff Janes  writes:
> Most of the time is not after the clock stops, but before the stepwise
> ANALYZE clock starts.  If you just do an EXPLAIN rather than EXPLAIN
> ANALYZE, that is also slow.  The giant hash table is created during the
> planning step (or somewhere around there

It's in executor startup, I believe.

regards, tom lane




Re: Extremely slow HashAggregate in simple UNION query

2019-08-24 Thread Jeff Janes
On Thu, Aug 22, 2019 at 1:09 AM Pavel Stehule 
wrote:

> čt 22. 8. 2019 v 3:11 odesílatel Jeff Janes  napsal:
>
>> ...


> But the same advance in v12 which makes it harder to fool with your test
>> case also opens the possibility of fixing your real case.
>>
>
> I think so much more interesting should be long time after query
> processing - last row was processed in 13ms, but Execution Time was 69ms ..
> so some cleaning is 56ms - that is pretty long.
>

Most of the time is not after the clock stops, but before the stepwise
ANALYZE clock starts.  If you just do an EXPLAIN rather than EXPLAIN
ANALYZE, that is also slow.  The giant hash table is created during the
planning step (or somewhere around there--I notice that EXPLAIN ANALYZE
output doesn't count it in what it labels as the planning step--but it is
some step that EXPLAIN without ANALYZE does execute, which to me makes it a
planning step).

For me, "perf top" shows kernel's __do_page_fault as the top
function.  tuplehash_iterate does show up at 20% (which I think is
overattributed, considering how little the speedup is when dropping
ANALYZE), but everything else just looks like kernel memory management code.

Cheers,

Jeff


Re: Out of Memory errors are frustrating as heck!

2019-08-24 Thread Gunther
Thanks Tom, yes I'd say it's using a lot of memory, but wouldn't call it 
"leak" as it doesn't grow during the 30 min or so that this query runs. 
It explodes to 4GB and then stays flat until done.


Yes, and this time the query is super complicated with many joins and 
tables involved. The query plan has 100 lines. Not easy to share for 
reproduce and I have my issue under control by adding some swap just in 
case. The swap space was never actually used.


thanks,
-Gunther

On 8/23/2019 10:20, Tom Lane wrote:

Gunther  writes:

Hi all, I am connecting to a discussion back from April this year. My
data has grown and now I am running into new out of memory situations.

It doesn't look like this has much of anything to do with the hash-table
discussion.  The big hog is an ExprContext:


ExprContext: 1107296256 total in 142 blocks; 6328 free (101 chunks);
1107289928 used

So there's something leaking in there, but this isn't enough info
to guess what.

regards, tom lane