Hi,
while adding EXPLAIN support for JITing (displaying time spent etc), I
got annoyed by the amount of duplication required. There's a fair amount
of
if (es->format == EXPLAIN_FORMAT_TEXT)
appendStringInfo(es->str, "Execution time: %.3f ms\n",
1000.0 * totaltime);
else
ExplainPropertyFloat("Execution Time", 1000.0 * totaltime,
which is fairly redundant.
In the attached *POC* patch I've added a 'unit' parameter to the numeric
ExplainProperty* functions, which EXPLAIN_FORMAT_TEXT adds to the
output. This can avoid the above and other similar branches (of which
the JIT patch would add a number).
The most valid counterargument I see is that in many cases, particularly
inside plans, we have more specific output for text mode anyway. Which
means there we'll not benefit much. But I think that's a) considerably
done due to backward compatibility concerns b) verbosity concerns inside
plans, which obviously can be complicated. Therefore I think it's
perfectly reasonable to avoid specific branches for data that's only
going to be displayed once per plan?
We also could add separate ExplainProperty*Unit(...) functions, but I
don't really see a need.
Comments?
Greetings,
Andres Freund
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 900fa74e85e..d5d1363d8e1 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -123,8 +123,8 @@ static void ExplainSubPlans(List *plans, List *ancestors,
const char *relationship, ExplainState *es);
static void ExplainCustomChildren(CustomScanState *css,
List *ancestors, ExplainState *es);
-static void ExplainProperty(const char *qlabel, const char *value,
- bool numeric, ExplainState *es);
+static void ExplainProperty(const char *qlabel, const char *unit,
+ const char *value, bool numeric, ExplainState *es);
static void ExplainDummyGroup(const char *objtype, const char *labelname,
ExplainState *es);
static void ExplainXMLTag(const char *tagname, int flags, ExplainState *es);
@@ -549,11 +549,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
{
double plantime = INSTR_TIME_GET_DOUBLE(*planduration);
- if (es->format == EXPLAIN_FORMAT_TEXT)
- appendStringInfo(es->str, "Planning time: %.3f ms\n",
- 1000.0 * plantime);
- else
- ExplainPropertyFloat("Planning Time", 1000.0 * plantime, 3, es);
+ ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
}
/* Print info about runtime of triggers */
@@ -585,14 +581,8 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
* the output). By default, ANALYZE sets SUMMARY to true.
*/
if (es->summary && es->analyze)
- {
- if (es->format == EXPLAIN_FORMAT_TEXT)
- appendStringInfo(es->str, "Execution time: %.3f ms\n",
- 1000.0 * totaltime);
- else
- ExplainPropertyFloat("Execution Time", 1000.0 * totaltime,
- 3, es);
- }
+ ExplainPropertyFloat("Execution Time", "ms", 1000.0 * totaltime, 3,
+ es);
ExplainCloseGroup("Query", NULL, true, es);
}
@@ -764,8 +754,9 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
ExplainPropertyText("Constraint Name", conname, es);
ExplainPropertyText("Relation", relname, es);
if (es->timing)
- ExplainPropertyFloat("Time", 1000.0 * instr->total, 3, es);
- ExplainPropertyFloat("Calls", instr->ntuples, 0, es);
+ ExplainPropertyFloat("Time", "ms", 1000.0 * instr->total, 3,
+ es);
+ ExplainPropertyFloat("Calls", NULL, instr->ntuples, 0, es);
}
if (conname)
@@ -1280,10 +1271,10 @@ ExplainNode(PlanState *planstate, List *ancestors,
}
else
{
- ExplainPropertyFloat("Startup Cost", plan->startup_cost, 2, es);
- ExplainPropertyFloat("Total Cost", plan->total_cost, 2, es);
- ExplainPropertyFloat("Plan Rows", plan->plan_rows, 0, es);
- ExplainPropertyInteger("Plan Width", plan->plan_width, es);
+ ExplainPropertyFloat("Startup Cost", NULL, plan->startup_cost, 2, es);
+ ExplainPropertyFloat("Total Cost", NULL, plan->total_cost, 2, es);
+ ExplainPropertyFloat("Plan Rows", NULL, plan->plan_rows, 0, es);
+ ExplainPropertyInteger("Plan Width", NULL, plan->plan_width, es);
}
}
@@ -1323,11 +1314,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
{
if (es->timing)
{
- ExplainPropertyFloat("Actual Startup Time", startup_sec, 3, es);
- ExplainPropertyFloat("Actual Total Time", total_sec, 3, es);
+ ExplainPropertyFloat("Actual Startup Time", NULL, startup_sec, 3, es);
+ ExplainPropertyFloat("Actual Total Time", NULL, total_sec, 3, es);
}
- ExplainPropertyFloat("Actual Rows", rows, 0, es);
- ExplainPropertyFloat("Actual Loops", nloops, 0, es);
+ ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+ ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
}
}
else if (es->analyze)
@@ -1338,11 +1329,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
{
if (es->timing)
{
- ExplainPropertyFloat("Actual Startup Time", 0.0, 3, es);
- ExplainPropertyFloat("Actual Total Time", 0.0, 3, es);
+ ExplainPropertyFloat("Actual Startup Time", "ms", 0.0, 3, es);
+ ExplainPropertyFloat("Actual Total Time", "ms", 0.0, 3, es);
}
- ExplainPropertyFloat("Actual Rows", 0.0, 0, es);
- ExplainPropertyFloat("Actual Loops", 0.0, 0, es);
+ ExplainPropertyFloat("Actual Rows", NULL, 0.0, 0, es);
+ ExplainPropertyFloat("Actual Loops", NULL, 0.0, 0, es);
}
}
@@ -1400,7 +1391,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
show_instrumentation_count("Rows Removed by Filter", 1,
planstate, es);
if (es->analyze)
- ExplainPropertyLong("Heap Fetches",
+ ExplainPropertyLong("Heap Fetches", NULL,
((IndexOnlyScanState *) planstate)->ioss_HeapFetches, es);
break;
case T_BitmapIndexScan:
@@ -1443,7 +1434,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
if (plan->qual)
show_instrumentation_count("Rows Removed by Filter", 1,
planstate, es);
- ExplainPropertyInteger("Workers Planned",
+ ExplainPropertyInteger("Workers Planned", NULL,
gather->num_workers, es);
/* Show params evaluated at gather node */
@@ -1455,7 +1446,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
int nworkers;
nworkers = ((GatherState *) planstate)->nworkers_launched;
- ExplainPropertyInteger("Workers Launched",
+ ExplainPropertyInteger("Workers Launched", NULL,
nworkers, es);
}
if (gather->single_copy || es->format != EXPLAIN_FORMAT_TEXT)
@@ -1470,7 +1461,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
if (plan->qual)
show_instrumentation_count("Rows Removed by Filter", 1,
planstate, es);
- ExplainPropertyInteger("Workers Planned",
+ ExplainPropertyInteger("Workers Planned", NULL,
gm->num_workers, es);
/* Show params evaluated at gather-merge node */
@@ -1482,7 +1473,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
int nworkers;
nworkers = ((GatherMergeState *) planstate)->nworkers_launched;
- ExplainPropertyInteger("Workers Launched",
+ ExplainPropertyInteger("Workers Launched", NULL,
nworkers, es);
}
}
@@ -1687,15 +1678,15 @@ ExplainNode(PlanState *planstate, List *ancestors,
opened_group = true;
}
ExplainOpenGroup("Worker", NULL, true, es);
- ExplainPropertyInteger("Worker Number", n, es);
+ ExplainPropertyInteger("Worker Number", NULL, n, es);
if (es->timing)
{
- ExplainPropertyFloat("Actual Startup Time", startup_sec, 3, es);
- ExplainPropertyFloat("Actual Total Time", total_sec, 3, es);
+ ExplainPropertyFloat("Actual Startup Time", "ms", startup_sec, 3, es);
+ ExplainPropertyFloat("Actual Total Time", "ms", total_sec, 3, es);
}
- ExplainPropertyFloat("Actual Rows", rows, 0, es);
- ExplainPropertyFloat("Actual Loops", nloops, 0, es);
+ ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+ ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
if (es->buffers)
show_buffer_usage(es, &instrument->bufusage);
@@ -2325,7 +2316,7 @@ show_sort_info(SortState *sortstate, ExplainState *es)
else
{
ExplainPropertyText("Sort Method", sortMethod, es);
- ExplainPropertyLong("Sort Space Used", spaceUsed, es);
+ ExplainPropertyLong("Sort Space Used", NULL, spaceUsed, es);
ExplainPropertyText("Sort Space Type", spaceType, es);
}
}
@@ -2364,9 +2355,9 @@ show_sort_info(SortState *sortstate, ExplainState *es)
opened_group = true;
}
ExplainOpenGroup("Worker", NULL, true, es);
- ExplainPropertyInteger("Worker Number", n, es);
+ ExplainPropertyInteger("Worker Number", NULL, n, es);
ExplainPropertyText("Sort Method", sortMethod, es);
- ExplainPropertyLong("Sort Space Used", spaceUsed, es);
+ ExplainPropertyLong("Sort Space Used", NULL, spaceUsed, es);
ExplainPropertyText("Sort Space Type", spaceType, es);
ExplainCloseGroup("Worker", NULL, true, es);
}
@@ -2445,13 +2436,16 @@ show_hash_info(HashState *hashstate, ExplainState *es)
if (es->format != EXPLAIN_FORMAT_TEXT)
{
- ExplainPropertyLong("Hash Buckets", hinstrument.nbuckets, es);
- ExplainPropertyLong("Original Hash Buckets",
+ ExplainPropertyLong("Hash Buckets", NULL,
+ hinstrument.nbuckets, es);
+ ExplainPropertyLong("Original Hash Buckets", NULL,
hinstrument.nbuckets_original, es);
- ExplainPropertyLong("Hash Batches", hinstrument.nbatch, es);
- ExplainPropertyLong("Original Hash Batches",
+ ExplainPropertyLong("Hash Batches", NULL,
+ hinstrument.nbatch, es);
+ ExplainPropertyLong("Original Hash Batches", NULL,
hinstrument.nbatch_original, es);
- ExplainPropertyLong("Peak Memory Usage", spacePeakKb, es);
+ ExplainPropertyLong("Peak Memory Usage", NULL,
+ spacePeakKb, es);
}
else if (hinstrument.nbatch_original != hinstrument.nbatch ||
hinstrument.nbuckets_original != hinstrument.nbuckets)
@@ -2484,8 +2478,10 @@ show_tidbitmap_info(BitmapHeapScanState *planstate, ExplainState *es)
{
if (es->format != EXPLAIN_FORMAT_TEXT)
{
- ExplainPropertyLong("Exact Heap Blocks", planstate->exact_pages, es);
- ExplainPropertyLong("Lossy Heap Blocks", planstate->lossy_pages, es);
+ ExplainPropertyLong("Exact Heap Blocks", NULL,
+ planstate->exact_pages, es);
+ ExplainPropertyLong("Lossy Heap Blocks", NULL,
+ planstate->lossy_pages, es);
}
else
{
@@ -2527,9 +2523,9 @@ show_instrumentation_count(const char *qlabel, int which,
if (nfiltered > 0 || es->format != EXPLAIN_FORMAT_TEXT)
{
if (nloops > 0)
- ExplainPropertyFloat(qlabel, nfiltered / nloops, 0, es);
+ ExplainPropertyFloat(qlabel, NULL, nfiltered / nloops, 0, es);
else
- ExplainPropertyFloat(qlabel, 0.0, 0, es);
+ ExplainPropertyFloat(qlabel, NULL, 0.0, 0, es);
}
}
@@ -2695,20 +2691,30 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
else
{
- ExplainPropertyLong("Shared Hit Blocks", usage->shared_blks_hit, es);
- ExplainPropertyLong("Shared Read Blocks", usage->shared_blks_read, es);
- ExplainPropertyLong("Shared Dirtied Blocks", usage->shared_blks_dirtied, es);
- ExplainPropertyLong("Shared Written Blocks", usage->shared_blks_written, es);
- ExplainPropertyLong("Local Hit Blocks", usage->local_blks_hit, es);
- ExplainPropertyLong("Local Read Blocks", usage->local_blks_read, es);
- ExplainPropertyLong("Local Dirtied Blocks", usage->local_blks_dirtied, es);
- ExplainPropertyLong("Local Written Blocks", usage->local_blks_written, es);
- ExplainPropertyLong("Temp Read Blocks", usage->temp_blks_read, es);
- ExplainPropertyLong("Temp Written Blocks", usage->temp_blks_written, es);
+ ExplainPropertyLong("Shared Hit Blocks", NULL,
+ usage->shared_blks_hit, es);
+ ExplainPropertyLong("Shared Read Blocks", NULL,
+ usage->shared_blks_read, es);
+ ExplainPropertyLong("Shared Dirtied Blocks", NULL,
+ usage->shared_blks_dirtied, es);
+ ExplainPropertyLong("Shared Written Blocks", NULL,
+ usage->shared_blks_written, es);
+ ExplainPropertyLong("Local Hit Blocks", NULL,
+ usage->local_blks_hit, es);
+ ExplainPropertyLong("Local Read Blocks", NULL,
+ usage->local_blks_read, es);
+ ExplainPropertyLong("Local Dirtied Blocks", NULL,
+ usage->local_blks_dirtied, es);
+ ExplainPropertyLong("Local Written Blocks", NULL,
+ usage->local_blks_written, es);
+ ExplainPropertyLong("Temp Read Blocks", NULL,
+ usage->temp_blks_read, es);
+ ExplainPropertyLong("Temp Written Blocks", NULL,
+ usage->temp_blks_written, es);
if (track_io_timing)
{
- ExplainPropertyFloat("I/O Read Time", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
- ExplainPropertyFloat("I/O Write Time", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
+ ExplainPropertyFloat("I/O Read Time", "ms", INSTR_TIME_GET_MILLISEC(usage->blk_read_time), 3, es);
+ ExplainPropertyFloat("I/O Write Time", "ms", INSTR_TIME_GET_MILLISEC(usage->blk_write_time), 3, es);
}
}
}
@@ -3008,7 +3014,7 @@ show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
if (node->onConflictAction != ONCONFLICT_NONE)
{
- ExplainProperty("Conflict Resolution",
+ ExplainProperty("Conflict Resolution", NULL,
node->onConflictAction == ONCONFLICT_NOTHING ?
"NOTHING" : "UPDATE",
false, es);
@@ -3042,8 +3048,10 @@ show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
other_path = mtstate->ps.instrument->nfiltered2;
insert_path = total - other_path;
- ExplainPropertyFloat("Tuples Inserted", insert_path, 0, es);
- ExplainPropertyFloat("Conflicting Tuples", other_path, 0, es);
+ ExplainPropertyFloat("Tuples Inserted", NULL,
+ insert_path, 0, es);
+ ExplainPropertyFloat("Conflicting Tuples", NULL,
+ other_path, 0, es);
}
}
@@ -3250,14 +3258,17 @@ ExplainPropertyListNested(const char *qlabel, List *data, ExplainState *es)
* specific routines ExplainPropertyText, ExplainPropertyInteger, etc.
*/
static void
-ExplainProperty(const char *qlabel, const char *value, bool numeric,
- ExplainState *es)
+ExplainProperty(const char *qlabel, const char *unit, const char *value,
+ bool numeric, ExplainState *es)
{
switch (es->format)
{
case EXPLAIN_FORMAT_TEXT:
appendStringInfoSpaces(es->str, es->indent * 2);
- appendStringInfo(es->str, "%s: %s\n", qlabel, value);
+ if (unit)
+ appendStringInfo(es->str, "%s: %s %s\n", qlabel, value, unit);
+ else
+ appendStringInfo(es->str, "%s: %s\n", qlabel, value);
break;
case EXPLAIN_FORMAT_XML:
@@ -3302,31 +3313,33 @@ ExplainProperty(const char *qlabel, const char *value, bool numeric,
void
ExplainPropertyText(const char *qlabel, const char *value, ExplainState *es)
{
- ExplainProperty(qlabel, value, false, es);
+ ExplainProperty(qlabel, NULL, value, false, es);
}
/*
* Explain an integer-valued property.
*/
void
-ExplainPropertyInteger(const char *qlabel, int value, ExplainState *es)
+ExplainPropertyInteger(const char *qlabel, const char *unit, int value,
+ ExplainState *es)
{
char buf[32];
snprintf(buf, sizeof(buf), "%d", value);
- ExplainProperty(qlabel, buf, true, es);
+ ExplainProperty(qlabel, unit, buf, true, es);
}
/*
* Explain a long-integer-valued property.
*/
void
-ExplainPropertyLong(const char *qlabel, long value, ExplainState *es)
+ExplainPropertyLong(const char *qlabel, const char *unit, long value,
+ ExplainState *es)
{
char buf[32];
snprintf(buf, sizeof(buf), "%ld", value);
- ExplainProperty(qlabel, buf, true, es);
+ ExplainProperty(qlabel, unit, buf, true, es);
}
/*
@@ -3334,13 +3347,13 @@ ExplainPropertyLong(const char *qlabel, long value, ExplainState *es)
* fractional digits.
*/
void
-ExplainPropertyFloat(const char *qlabel, double value, int ndigits,
- ExplainState *es)
+ExplainPropertyFloat(const char *qlabel, const char *unit, double value,
+ int ndigits, ExplainState *es)
{
char buf[256];
snprintf(buf, sizeof(buf), "%.*f", ndigits, value);
- ExplainProperty(qlabel, buf, true, es);
+ ExplainProperty(qlabel, unit, buf, true, es);
}
/*
@@ -3349,7 +3362,7 @@ ExplainPropertyFloat(const char *qlabel, double value, int ndigits,
void
ExplainPropertyBool(const char *qlabel, bool value, ExplainState *es)
{
- ExplainProperty(qlabel, value ? "true" : "false", true, es);
+ ExplainProperty(qlabel, NULL, value ? "true" : "false", true, es);
}
/*
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 0c3986ae17b..1cf4eae2b3a 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -93,12 +93,12 @@ extern void ExplainPropertyListNested(const char *qlabel, List *data,
ExplainState *es);
extern void ExplainPropertyText(const char *qlabel, const char *value,
ExplainState *es);
-extern void ExplainPropertyInteger(const char *qlabel, int value,
- ExplainState *es);
-extern void ExplainPropertyLong(const char *qlabel, long value,
- ExplainState *es);
-extern void ExplainPropertyFloat(const char *qlabel, double value, int ndigits,
- ExplainState *es);
+extern void ExplainPropertyInteger(const char *qlabel, const char *unit,
+ int value, ExplainState *es);
+extern void ExplainPropertyLong(const char *qlabel, const char *unit,
+ long value, ExplainState *es);
+extern void ExplainPropertyFloat(const char *qlabel, const char *unit,
+ double value, int ndigits, ExplainState *es);
extern void ExplainPropertyBool(const char *qlabel, bool value,
ExplainState *es);
