public inbox for [email protected]
help / color / mirror / Atom feedFrom: Justin Pryzby <[email protected]>
To: [email protected]
Cc: [email protected]
Subject: Re: [PATCH] Add extra statistics to explain for Nested Loop
Date: Thu, 25 Mar 2021 10:30:31 -0500
Message-ID: <[email protected]> (raw)
In-Reply-To: <[email protected]>
References: <CAFj8pRA=wMP+yebbssQByL9nV5FJe6vnkw-ZB7zta1j2W9ftjg@mail.gmail.com>
<CAOBaU_YHfFcE3HPjW1Db-qOYNZuAMw3Cjv_pFRaRAQTQy+HE0g@mail.gmail.com>
<[email protected]>
<CAOBaU_Yj6gdcc7q_CYWWMByMSUt29pO2Vky6xk9eP2g1rw_Eww@mail.gmail.com>
<[email protected]>
<20201031012053.arjh7eehmlzud45p@development>
<[email protected]>
<[email protected]>
<CAOBaU_aN4oSGXJTrgN4k44g0Z1_2cASEnaGd2M3pdRdbiQdxuQ@mail.gmail.com>
<[email protected]>
> diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
> index afc45429ba4..723eccca013 100644
> --- a/src/backend/commands/explain.c
> +++ b/src/backend/commands/explain.c
> @@ -1589,29 +1589,82 @@ ExplainNode(PlanState *planstate, List *ancestors,
> double startup_ms = 1000.0 * planstate->instrument->startup / nloops;
> double total_ms = 1000.0 * planstate->instrument->total / nloops;
> double rows = planstate->instrument->ntuples / nloops;
> + double total_rows = planstate->instrument->ntuples;
> + double min_r = planstate->instrument->min_tuples;
> + double max_r = planstate->instrument->max_tuples;
> + double min_t_ms = 1000.0 * planstate->instrument->min_t;
> + double max_t_ms = 1000.0 * planstate->instrument->max_t;
>
> if (es->format == EXPLAIN_FORMAT_TEXT)
> {
> - if (es->timing)
> - appendStringInfo(es->str,
> - " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
> - startup_ms, total_ms, rows, nloops);
> + if (nloops > 1 && es->verbose)
> + {
> + if (es->timing)
> + {
> + appendStringInfo(es->str,
> + " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)\n",
> + startup_ms, total_ms, rows, nloops);
> + ExplainIndentText(es);
> + appendStringInfo(es->str,
> + "Loop: min_time=%.3f max_time=%.3f min_rows=%.0f max_rows=%.0f total_rows=%.0f",
> + min_t_ms, max_t_ms, min_r, max_r, total_rows);
Lines with "colon" format shouldn't use equal signs, and should use two spaces
between fields. See:
https://www.postgresql.org/message-id/[email protected]
https://www.postgresql.org/message-id/[email protected]
https://www.postgresql.org/message-id/20200407042521.GH2228%40telsasoft.com
> + }
> + else
> + {
> + appendStringInfo(es->str,
> + " (actual rows=%.0f loops=%.0f)\n",
> + rows, nloops);
> + ExplainIndentText(es);
> + appendStringInfo(es->str,
> + "Loop: min_rows=%.0f max_rows=%.0f total_rows=%.0f",
> + min_r, max_r, total_rows);
> + }
> + }
> else
> - appendStringInfo(es->str,
> - " (actual rows=%.0f loops=%.0f)",
> - rows, nloops);
> + {
> + if (es->timing)
> + appendStringInfo(es->str,
> + " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
> + startup_ms, total_ms, rows, nloops);
> + else
> + appendStringInfo(es->str,
> + " (actual rows=%.0f loops=%.0f)",
> + rows, nloops);
> + }
> }
> else
Since this is now on a separate line, the "if (nloops > 1 && es->verbose)"
can be after the existing "if (es->timing)", and shouldn't need its own
"if (es->timing)". It should conditionally add a separate line, rather than
duplicating the "(actual.*" line.
> - if (es->timing)
> + if (nloops > 1 && es->verbose)
In non-text mode, think you should not check "nloops > 1". Rather, print the
field as 0.
The whole logic is duplicated for parallel workers. This could instead be a
function, called from both places. I think this would handle the computation
as well as the output. This would make the patch shorter.
> + ExplainPropertyFloat("Min Time", "ms",
> + min_t_ms, 3, es);
> + ExplainPropertyFloat("Max Time", "ms",
> + max_t_ms, 3, es);
I think the labels in non-text format should say "Loop Min Time" or similar.
> diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
> index aa8eceda5f4..93ba7c83461 100644
> --- a/src/include/executor/instrument.h
> +++ b/src/include/executor/instrument.h
> @@ -66,7 +66,13 @@ typedef struct Instrumentation
> /* Accumulated statistics across all completed cycles: */
> double startup; /* total startup time (in seconds) */
> double total; /* total time (in seconds) */
> + double min_t; /* time of fastest loop (in seconds) */
> + double max_t; /* time of slowest loop (in seconds) */
> double ntuples; /* total tuples produced */
> + double min_tuples; /* min counter of produced tuples for all
> + * loops */
> + double max_tuples; /* max counter of produced tuples for all
> + * loops */
And these variables should have a loop_ prefix like loop_min_t ?
--
Justin
view thread (35+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected]
Subject: Re: [PATCH] Add extra statistics to explain for Nested Loop
In-Reply-To: <[email protected]>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox