On 2020/08/19 19:39, David Rowley wrote:
On Wed, 19 Aug 2020 at 21:05, Julien Rouhaud <rjuju...@gmail.com> wrote:
On Wed, Aug 19, 2020 at 08:49:48PM +1200, David Rowley wrote:
However, I'm not quite sure how we should handle if someone does:
EXPLAIN (BUFFERS on, SUMMARY off). Without the summary, there's no
place to print the buffers, which seems bad as they asked for buffers.
But this won't be as much a problem if ANALYZE is asked, and having different
behaviors isn't appealing. So maybe it's better to let people get what they
asked for even if that's contradictory?
I'd say BUFFERS on, BUFFERS off is contradictory. I don't think
BUFFERS, SUMMARY OFF is. It's just that we show the buffer details for
the planner in the summary. Since "summary" is not exactly a word
that describes what you're asking EXPLAIN to do, I wouldn't blame
users if they got confused as to why their BUFFERS on request was not
displayed.
Displaying the planner's buffer usage under summary is the root cause of
the confusion? If so, what about displaying that outside summary?
Attached is the POC patch that I'm just thinking.
With the patch, for example, whatever "summary" settng is, "buffers on"
displays the planner's buffer usage if it happens.
=# explain (buffers on, summary off) select * from t;
QUERY PLAN
-----------------------------------------------------
Seq Scan on t (cost=0.00..32.60 rows=2260 width=8)
Planning:
Buffers: shared hit=16 read=6
(3 rows)
If "summary" is enabled, the planning time is also displayed.
=# explain (buffers on, summary on) select * from t;
QUERY PLAN
-----------------------------------------------------
Seq Scan on t (cost=0.00..32.60 rows=2260 width=8)
Planning:
Buffers: shared hit=16 read=6
Planning Time: 0.904 ms
(4 rows)
If the planner's buffer usage doesn't happen, it's not displayed
(in text format).
=# explain (buffers on, summary on) select * from t;
QUERY PLAN
-----------------------------------------------------
Seq Scan on t (cost=0.00..32.60 rows=2260 width=8)
Planning Time: 0.064 ms
(2 rows)
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 30e0a7ee7f..c98c9b5547 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -116,7 +116,8 @@ static void show_instrumentation_count(const char *qlabel,
int which,
static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
static void show_eval_params(Bitmapset *bms_params, ExplainState *es);
static const char *explain_get_index_name(Oid indexId);
-static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
+static void show_buffer_usage(ExplainState *es, const BufferUsage *usage,
+ bool planning);
static void show_wal_usage(ExplainState *es, const WalUsage *usage);
static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
ExplainState *es);
@@ -221,11 +222,6 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
parser_errposition(pstate,
opt->location)));
}
- if (es->buffers && !es->analyze)
- ereport(ERROR,
- (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
- errmsg("EXPLAIN option BUFFERS requires
ANALYZE")));
-
if (es->wal && !es->analyze)
ereport(ERROR,
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
@@ -586,8 +582,13 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
ExplainState *es,
/* Create textual dump of plan tree */
ExplainPrintPlan(es, queryDesc);
- if (es->summary && (planduration || bufusage))
+ /* Show buffer usage in planning */
+ if (bufusage)
+ {
ExplainOpenGroup("Planning", "Planning", true, es);
+ show_buffer_usage(es, bufusage, true);
+ ExplainCloseGroup("Planning", "Planning", true, es);
+ }
if (es->summary && planduration)
{
@@ -596,19 +597,6 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
ExplainState *es,
ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime,
3, es);
}
- /* Show buffer usage */
- if (es->summary && bufusage)
- {
- if (es->format == EXPLAIN_FORMAT_TEXT)
- es->indent++;
- show_buffer_usage(es, bufusage);
- if (es->format == EXPLAIN_FORMAT_TEXT)
- es->indent--;
- }
-
- if (es->summary && (planduration || bufusage))
- ExplainCloseGroup("Planning", "Planning", true, es);
-
/* Print info about runtime of triggers */
if (es->analyze)
ExplainPrintTriggers(es, queryDesc);
@@ -1996,7 +1984,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
/* Show buffer/WAL usage */
if (es->buffers && planstate->instrument)
- show_buffer_usage(es, &planstate->instrument->bufusage);
+ show_buffer_usage(es, &planstate->instrument->bufusage, false);
if (es->wal && planstate->instrument)
show_wal_usage(es, &planstate->instrument->walusage);
@@ -2015,7 +2003,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
ExplainOpenWorker(n, es);
if (es->buffers)
- show_buffer_usage(es, &instrument->bufusage);
+ show_buffer_usage(es, &instrument->bufusage,
false);
if (es->wal)
show_wal_usage(es, &instrument->walusage);
ExplainCloseWorker(n, es);
@@ -3301,7 +3289,7 @@ explain_get_index_name(Oid indexId)
* Show buffer usage details.
*/
static void
-show_buffer_usage(ExplainState *es, const BufferUsage *usage)
+show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
{
if (es->format == EXPLAIN_FORMAT_TEXT)
{
@@ -3317,6 +3305,15 @@ show_buffer_usage(ExplainState *es, const BufferUsage
*usage)
usage->temp_blks_written > 0);
bool has_timing =
(!INSTR_TIME_IS_ZERO(usage->blk_read_time) ||
!INSTR_TIME_IS_ZERO(usage->blk_write_time));
+ bool show_planning = (planning && (has_shared ||
+
has_local || has_temp || has_timing));
+
+ if (show_planning)
+ {
+ ExplainIndentText(es);
+ appendStringInfoString(es->str, "Planning:\n");
+ es->indent++;
+ }
/* Show only positive counter values. */
if (has_shared || has_local || has_temp)
@@ -3386,6 +3383,9 @@ show_buffer_usage(ExplainState *es, const BufferUsage
*usage)
INSTR_TIME_GET_MILLISEC(usage->blk_write_time));
appendStringInfoChar(es->str, '\n');
}
+
+ if (show_planning)
+ es->indent--;
}
else
{
