Re: I don't understand that EXPLAIN PLAN timings

From: David Rowley <dgrowleyml(at)gmail(dot)com>
To: Jean-Christophe Boggio <postgresql(at)thefreecat(dot)org>
Cc: pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: Re: I don't understand that EXPLAIN PLAN timings
Date: 2024-01-25 21:11:46
Message-ID: CAApHDvqoP04PS3g6+Wc4LvMEcvbre+iRiVmyph1U2jVJtTJBng@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

On Fri, 26 Jan 2024 at 02:31, Jean-Christophe Boggio
<postgresql(at)thefreecat(dot)org> wrote:
> You are absolutely correct : the EXPLAIN without ANALYZE gives about the same results. Also, minimizing the amount of workmem in postgresql.conf changes drastically the timings. So that means memory allocation is eating up a lot of time _PER_QUERY_ ?

We do reuse pallocs to create memory context, but only for I believe
1k and 8k blocks. That likely allows most small allocations in the
executor to be done without malloc. Speaking in vague terms as I
don't have the exact numbers to hand, but larger allocations will go
directly to malloc.

There was a bug fixed in [1] that did cause behaviour like this, but
you seem to be on 14.10 which will have that fix. Also, the 2nd plan
you sent has no Memoize nodes.

I do wonder now if it was a bad idea to make Memoize build the hash
table on plan startup rather than delaying that until we fetch the
first tuple. I see Hash Join only builds its table during executor
run.

> Since we have quite some RAM on our machines, I dedicated as much as possible to workmem (initially I was allocating 1GB) but this looks quite counterproductive (I didn't think that memory was allocated every time, I thought it was "available" for the current query but not necessarily used). Is this an issue specific to that version of PostgreSQL? (I guess no) Or can this be hardware-related? Or OS-related (both systems on which I have done tests are running Ubuntu, I will try on Debian)?

It would be good to narrow down which plan node is causing this. Can
you try disabling various planner enable_* GUCs before running EXPLAIN
(SUMMARY ON) <your query> with \timing on and see if you can find
which enable_* GUC causes the EXPLAIN to run more quickly? Just watch
out for variations in the timing of "Planning Time:". You're still
looking for a large portion of time not accounted for by planning
time.

I'd start with:

SET enable_memoize=0;
EXPLAIN (SUMMARY ON) <your query>;
RESET enable_memoize;

SET enable_hashjoin=0;
EXPLAIN (SUMMARY ON) <your query>;
RESET enable_hashjoin;

The following will show others that you could try.
select name,setting from pg_settings where name like 'enable%';

David

[1] https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=1e731ed12aa

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2024-01-25 21:32:27 Re: I don't understand that EXPLAIN PLAN timings
Previous Message Jean-Christophe Boggio 2024-01-25 13:31:17 Re: I don't understand that EXPLAIN PLAN timings