Add 'unit' parameter to ExplainProperty{Integer,Float}.

This allows to deduplicate some existing code, but mainly avoids some
duplication in upcoming commits.

In passing, fix variable names indicating wrong unit (seconds instead
of ms).

Author: Andres Freund
Discussion: https://postgr.es/m/20180314002740.cah3mdsonz5mxney@alap3.anarazel.de
This commit is contained in:
Andres Freund 2018-03-16 23:13:12 -07:00
parent f3e4b95edb
commit 7a50bb690b
3 changed files with 113 additions and 96 deletions

View File

@ -622,7 +622,7 @@ fileExplainForeignScan(ForeignScanState *node, ExplainState *es)
if (!is_program &&
stat(filename, &stat_buf) == 0)
ExplainPropertyInteger("Foreign File Size",
ExplainPropertyInteger("Foreign File Size", "b",
(int64) stat_buf.st_size, es);
}
}

View File

@ -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,14 @@ 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);
}
}
@ -1304,8 +1299,8 @@ ExplainNode(PlanState *planstate, List *ancestors,
planstate->instrument && planstate->instrument->nloops > 0)
{
double nloops = planstate->instrument->nloops;
double startup_sec = 1000.0 * planstate->instrument->startup / nloops;
double total_sec = 1000.0 * planstate->instrument->total / nloops;
double startup_ms = 1000.0 * planstate->instrument->startup / nloops;
double total_ms = 1000.0 * planstate->instrument->total / nloops;
double rows = planstate->instrument->ntuples / nloops;
if (es->format == EXPLAIN_FORMAT_TEXT)
@ -1313,7 +1308,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
if (es->timing)
appendStringInfo(es->str,
" (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
startup_sec, total_sec, rows, nloops);
startup_ms, total_ms, rows, nloops);
else
appendStringInfo(es->str,
" (actual rows=%.0f loops=%.0f)",
@ -1323,11 +1318,13 @@ 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", "s", startup_ms,
3, es);
ExplainPropertyFloat("Actual Total Time", "s", total_ms,
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 +1335,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,9 +1397,12 @@ ExplainNode(PlanState *planstate, List *ancestors,
show_instrumentation_count("Rows Removed by Filter", 1,
planstate, es);
if (es->analyze)
ExplainPropertyInteger("Heap Fetches",
((IndexOnlyScanState *) planstate)->ioss_HeapFetches,
es);
{
long heapFetches =
((IndexOnlyScanState *) planstate)->ioss_HeapFetches;
ExplainPropertyInteger("Heap Fetches", NULL, heapFetches, es);
}
break;
case T_BitmapIndexScan:
show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig,
@ -1444,7 +1444,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 */
@ -1456,7 +1456,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)
@ -1471,7 +1471,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 */
@ -1483,7 +1483,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
int nworkers;
nworkers = ((GatherMergeState *) planstate)->nworkers_launched;
ExplainPropertyInteger("Workers Launched",
ExplainPropertyInteger("Workers Launched", NULL,
nworkers, es);
}
}
@ -1653,14 +1653,14 @@ ExplainNode(PlanState *planstate, List *ancestors,
{
Instrumentation *instrument = &w->instrument[n];
double nloops = instrument->nloops;
double startup_sec;
double total_sec;
double startup_ms;
double total_ms;
double rows;
if (nloops <= 0)
continue;
startup_sec = 1000.0 * instrument->startup / nloops;
total_sec = 1000.0 * instrument->total / nloops;
startup_ms = 1000.0 * instrument->startup / nloops;
total_ms = 1000.0 * instrument->total / nloops;
rows = instrument->ntuples / nloops;
if (es->format == EXPLAIN_FORMAT_TEXT)
@ -1670,7 +1670,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
if (es->timing)
appendStringInfo(es->str,
"actual time=%.3f..%.3f rows=%.0f loops=%.0f\n",
startup_sec, total_sec, rows, nloops);
startup_ms, total_ms, rows, nloops);
else
appendStringInfo(es->str,
"actual rows=%.0f loops=%.0f\n",
@ -1688,15 +1688,17 @@ 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_ms, 3, es);
ExplainPropertyFloat("Actual Total Time", "ms",
total_ms, 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);
@ -2326,7 +2328,7 @@ show_sort_info(SortState *sortstate, ExplainState *es)
else
{
ExplainPropertyText("Sort Method", sortMethod, es);
ExplainPropertyInteger("Sort Space Used", spaceUsed, es);
ExplainPropertyInteger("Sort Space Used", "kB", spaceUsed, es);
ExplainPropertyText("Sort Space Type", spaceType, es);
}
}
@ -2365,9 +2367,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);
ExplainPropertyInteger("Sort Space Used", spaceUsed, es);
ExplainPropertyInteger("Sort Space Used", "kB", spaceUsed, es);
ExplainPropertyText("Sort Space Type", spaceType, es);
ExplainCloseGroup("Worker", NULL, true, es);
}
@ -2446,13 +2448,16 @@ show_hash_info(HashState *hashstate, ExplainState *es)
if (es->format != EXPLAIN_FORMAT_TEXT)
{
ExplainPropertyInteger("Hash Buckets", hinstrument.nbuckets, es);
ExplainPropertyInteger("Original Hash Buckets",
hinstrument.nbuckets_original, es);
ExplainPropertyInteger("Hash Batches", hinstrument.nbatch, es);
ExplainPropertyInteger("Original Hash Batches",
hinstrument.nbatch_original, es);
ExplainPropertyInteger("Peak Memory Usage", spacePeakKb, es);
ExplainPropertyInteger("Hash Buckets", NULL,
hinstrument.nbuckets, es);
ExplainPropertyInteger("Original Hash Buckets", NULL,
hinstrument.nbuckets_original, es);
ExplainPropertyInteger("Hash Batches", NULL,
hinstrument.nbatch, es);
ExplainPropertyInteger("Original Hash Batches", NULL,
hinstrument.nbatch_original, es);
ExplainPropertyInteger("Peak Memory Usage", "kB",
spacePeakKb, es);
}
else if (hinstrument.nbatch_original != hinstrument.nbatch ||
hinstrument.nbuckets_original != hinstrument.nbuckets)
@ -2485,9 +2490,9 @@ show_tidbitmap_info(BitmapHeapScanState *planstate, ExplainState *es)
{
if (es->format != EXPLAIN_FORMAT_TEXT)
{
ExplainPropertyInteger("Exact Heap Blocks",
ExplainPropertyInteger("Exact Heap Blocks", NULL,
planstate->exact_pages, es);
ExplainPropertyInteger("Lossy Heap Blocks",
ExplainPropertyInteger("Lossy Heap Blocks", NULL,
planstate->lossy_pages, es);
}
else
@ -2530,9 +2535,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);
}
}
@ -2698,30 +2703,34 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
else
{
ExplainPropertyInteger("Shared Hit Blocks",
ExplainPropertyInteger("Shared Hit Blocks", NULL,
usage->shared_blks_hit, es);
ExplainPropertyInteger("Shared Read Blocks",
ExplainPropertyInteger("Shared Read Blocks", NULL,
usage->shared_blks_read, es);
ExplainPropertyInteger("Shared Dirtied Blocks",
ExplainPropertyInteger("Shared Dirtied Blocks", NULL,
usage->shared_blks_dirtied, es);
ExplainPropertyInteger("Shared Written Blocks",
ExplainPropertyInteger("Shared Written Blocks", NULL,
usage->shared_blks_written, es);
ExplainPropertyInteger("Local Hit Blocks",
ExplainPropertyInteger("Local Hit Blocks", NULL,
usage->local_blks_hit, es);
ExplainPropertyInteger("Local Read Blocks",
ExplainPropertyInteger("Local Read Blocks", NULL,
usage->local_blks_read, es);
ExplainPropertyInteger("Local Dirtied Blocks",
ExplainPropertyInteger("Local Dirtied Blocks", NULL,
usage->local_blks_dirtied, es);
ExplainPropertyInteger("Local Written Blocks",
ExplainPropertyInteger("Local Written Blocks", NULL,
usage->local_blks_written, es);
ExplainPropertyInteger("Temp Read Blocks",
ExplainPropertyInteger("Temp Read Blocks", NULL,
usage->temp_blks_read, es);
ExplainPropertyInteger("Temp Written Blocks",
ExplainPropertyInteger("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);
}
}
}
@ -3021,10 +3030,10 @@ show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
if (node->onConflictAction != ONCONFLICT_NONE)
{
ExplainProperty("Conflict Resolution",
node->onConflictAction == ONCONFLICT_NOTHING ?
"NOTHING" : "UPDATE",
false, es);
ExplainPropertyText("Conflict Resolution",
node->onConflictAction == ONCONFLICT_NOTHING ?
"NOTHING" : "UPDATE",
es);
/*
* Don't display arbiter indexes at all when DO NOTHING variant
@ -3055,8 +3064,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);
}
}
@ -3259,18 +3270,23 @@ ExplainPropertyListNested(const char *qlabel, List *data, ExplainState *es)
* If "numeric" is true, the value is a number (or other value that
* doesn't need quoting in JSON).
*
* If unit is is non-NULL the text format will display it after the value.
*
* This usually should not be invoked directly, but via one of the datatype
* 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:
@ -3315,19 +3331,20 @@ 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, int64 value, ExplainState *es)
ExplainPropertyInteger(const char *qlabel, const char *unit, int64 value,
ExplainState *es)
{
char buf[32];
snprintf(buf, sizeof(buf), INT64_FORMAT, value);
ExplainProperty(qlabel, buf, true, es);
ExplainProperty(qlabel, unit, buf, true, es);
}
/*
@ -3335,13 +3352,13 @@ ExplainPropertyInteger(const char *qlabel, int64 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;
buf = psprintf("%.*f", ndigits, value);
ExplainProperty(qlabel, buf, true, es);
ExplainProperty(qlabel, unit, buf, true, es);
pfree(buf);
}
@ -3351,7 +3368,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);
}
/*

View File

@ -93,10 +93,10 @@ 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, int64 value,
ExplainState *es);
extern void ExplainPropertyFloat(const char *qlabel, double value, int ndigits,
ExplainState *es);
extern void ExplainPropertyInteger(const char *qlabel, const char *unit,
int64 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);