Re: EXPLAIN BUFFERS and I/O timing accounting questions

Hi,

Migrating to -hackers, this seems clearly suboptimal. and confusing.

The original thread is at
https://www.postgresql.org/message-id/20191025003834.2rswu7smheaddag3%40alap3.anarazel.de

On 2019-10-24 17:38:34 -0700, Andres Freund wrote:
> Perhaps you could send me the full plan and query privately? And, if you
> have access to that, the plain text explain?

Maciek did, and I think I see what's going on...

(I asked whether it's ok to include the query)
On 2019-10-24 18:58:27 -0700, Maciek Sakrejda wrote:
> Thanks for your help. Here is the query text:
>
> WITH q AS (
> DELETE FROM queries WHERE last_occurred_at < now() - '60 days'::interval
> RETURNING queries.id
> ),
> t1 AS (DELETE FROM query_fingerprints WHERE query_id IN (SELECT id FROM q)),
> t2 as (DELETE FROM query_table_associations WHERE query_id IN
> (SELECT id FROM q))
> SELECT COUNT(id) FROM q

Note that t1 and t2 CTEs are not referenced in the query
itself. Normally that would mean that they're simply not evaluated - but
for CTE that include DML we force evaluation, as the result would
otherwise be inconsistent.

But that forcing happens not from within the normal query (the SELECT
COUNT(id) FROM q), but from the main executor. As the attribution of
child executor nodes to the layer above happens when the execution of a
node ends (see ExecProcNodeInstr()), the work of completing wCTEs is not
associated to any single node.

void
standard_ExecutorFinish(QueryDesc *queryDesc)
...
/* Run ModifyTable nodes to completion */
ExecPostprocessPlan(estate);

static void
ExecPostprocessPlan(EState *estate)
..
/*
* Run any secondary ModifyTable nodes to completion, in case the main
* query did not fetch all rows from them. (We do this to ensure that
* such nodes have predictable results.)
*/
foreach(lc, estate->es_auxmodifytables)
...
slot = ExecProcNode(ps);

in contrast to e.g. AFTER triggers, which also get executed at the end
of the query, we do not associate the cost of running this post
processing work with any superior node.

Which is quite confusing, because the DML nodes do look like
they're subsidiary to another node.

I think we ought to either attribute the cost of ExecPostprocessPlan()
to a separate instrumentation that we display at the end of the explain
plan when not zero, or at least associate the cost with the parent node.

Greetings,

Andres Freund