extra_statistics_v2.patch

From 148b0792b8eed1527ee3266e7e627b3c75effb9e Mon Sep 17 00:00:00 2001
From: Ekaterina Sokolova <e.sokolova@postgrespro.ru>
Date: Thu, 12 Nov 2020 22:06:41 +0300
Subject: [PATCH] extra_statistics_v2

---
 src/backend/commands/explain.c                | 141 ++++++++++++++----
 src/backend/executor/instrument.c             |  27 ++++
 src/include/executor/instrument.h             |   6 +
 src/test/regress/expected/explain.out         |   8 +
 src/test/regress/expected/partition_prune.out |   2 +
 src/test/regress/expected/timetz.out          |   8 +-
 src/test/regress/sql/partition_prune.sql      |   2 +
 7 files changed, 161 insertions(+), 33 deletions(-)

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 41317f18374..b525b12b1d6 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -1568,29 +1568,68 @@ 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		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 min_time=%.3f max_time=%.3f min_rows=%.0f rows=%.0f max_rows=%.0f loops=%.0f)",
+									 startup_ms, total_ms, min_t_ms, max_t_ms, min_r, rows, max_r, nloops);
+				else
+					appendStringInfo(es->str,
+									 " (actual min_rows=%.0f rows=%.0f max_rows=%.0f loops=%.0f)",
+									 min_r, rows, max_r, nloops);
+			}
 			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
 		{
-			if (es->timing)
+			if (nloops > 1 && es->verbose)
+			{
+				if (es->timing)
+				{
+					ExplainPropertyFloat("Actual Startup Time", "s", startup_ms,
+										 3, es);
+					ExplainPropertyFloat("Actual Total Time", "s", total_ms,
+										 3, es);
+					ExplainPropertyFloat("Min Time", "s", min_t_ms,
+										 3, es);
+					ExplainPropertyFloat("Max Time", "s", max_t_ms,
+										 3, es);
+				}
+				ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+				ExplainPropertyFloat("Min Rows", NULL, rows, 0, es);
+				ExplainPropertyFloat("Max Rows", NULL, rows, 0, es);
+				ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+			}
+			else
 			{
-				ExplainPropertyFloat("Actual Startup Time", "s", startup_ms,
-									 3, es);
-				ExplainPropertyFloat("Actual Total Time", "s", total_ms,
-									 3, es);
+				if (es->timing)
+				{
+					ExplainPropertyFloat("Actual Startup Time", "s", startup_ms,
+										 3, es);
+					ExplainPropertyFloat("Actual Total Time", "s", total_ms,
+										 3, es);
+				}
+				ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+				ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
 			}
-			ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
-			ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
 		}
 	}
 	else if (es->analyze)
@@ -1599,6 +1638,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
 			appendStringInfoString(es->str, " (never executed)");
 		else
 		{
+			/* without min and max values because actual result is 0 */
 			if (es->timing)
 			{
 				ExplainPropertyFloat("Actual Startup Time", "ms", 0.0, 3, es);
@@ -1624,39 +1664,82 @@ ExplainNode(PlanState *planstate, List *ancestors,
 			double		nloops = instrument->nloops;
 			double		startup_ms;
 			double		total_ms;
+			double		min_t_ms;
+			double		max_t_ms;
 			double		rows;
+			double		min_r;
+			double		max_r;
 
 			if (nloops <= 0)
 				continue;
 			startup_ms = 1000.0 * instrument->startup / nloops;
 			total_ms = 1000.0 * instrument->total / nloops;
+			min_t_ms = 1000.0 * instrument->min_t;
+			max_t_ms = 1000.0 * instrument->max_t;
 			rows = instrument->ntuples / nloops;
+			min_r = instrument->min_tuples;
+			max_r = instrument->max_tuples;
 
 			ExplainOpenWorker(n, es);
 
 			if (es->format == EXPLAIN_FORMAT_TEXT)
 			{
 				ExplainIndentText(es);
-				if (es->timing)
-					appendStringInfo(es->str,
-									 "actual time=%.3f..%.3f rows=%.0f loops=%.0f\n",
-									 startup_ms, total_ms, rows, nloops);
+				if (nloops > 1)
+				{
+					if (es->timing)
+						appendStringInfo(es->str,
+										 "actual time=%.3f..%.3f min_time=%.3f  max_time=%.3f min_rows=%.0f rows=%.0f max_rows=%.0f loops=%.0f\n",
+										 startup_ms, total_ms, min_t_ms, max_t_ms, min_r, rows, max_r, nloops);
+					else
+						appendStringInfo(es->str,
+										 "actual min_rows=%.0f rows=%.0f max_rows=%.0f loops=%.0f\n",
+										 min_r, rows, max_r, nloops);
+				}
 				else
-					appendStringInfo(es->str,
-									 "actual rows=%.0f loops=%.0f\n",
-									 rows, nloops);
+				{
+					if (es->timing)
+						appendStringInfo(es->str,
+										 "actual time=%.3f..%.3f rows=%.0f loops=%.0f\n",
+										 startup_ms, total_ms, rows, nloops);
+					else
+						appendStringInfo(es->str,
+										 "actual rows=%.0f loops=%.0f\n",
+										 rows, nloops);
+				}
 			}
 			else
 			{
-				if (es->timing)
+				if (nloops > 1)
 				{
-					ExplainPropertyFloat("Actual Startup Time", "ms",
-										 startup_ms, 3, es);
-					ExplainPropertyFloat("Actual Total Time", "ms",
-										 total_ms, 3, es);
+					if (es->timing)
+					{
+						ExplainPropertyFloat("Actual Startup Time", "ms",
+											 startup_ms, 3, es);
+						ExplainPropertyFloat("Actual Total Time", "ms",
+											 total_ms, 3, es);
+						ExplainPropertyFloat("Min Time", "ms",
+											 min_t_ms, 3, es);
+						ExplainPropertyFloat("Max Time", "ms",
+											 max_t_ms, 3, es);
+					}
+					ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+					ExplainPropertyFloat("Min Rows", NULL, rows, 0, es);
+					ExplainPropertyFloat("Max Rows", NULL, rows, 0, es);
+					ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+				}
+				else
+				{
+					if (es->timing)
+					{
+						ExplainPropertyFloat("Actual Startup Time", "ms",
+											 startup_ms, 3, es);
+						ExplainPropertyFloat("Actual Total Time", "ms",
+											 total_ms, 3, es);
+					}
+					ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+					ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
 				}
-				ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
-				ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
 			}
 
 			ExplainCloseWorker(n, es);
@@ -3094,7 +3177,7 @@ show_hashagg_info(AggState *aggstate, ExplainState *es)
 			if (aggstate->hash_batches_used > 1)
 			{
 				appendStringInfo(es->str, "  Disk Usage: " UINT64_FORMAT "kB",
-					aggstate->hash_disk_used);
+								 aggstate->hash_disk_used);
 			}
 		}
 
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index fbedb5aaf60..db1be682e1c 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -134,7 +134,34 @@ InstrEndLoop(Instrumentation *instr)
 
 	instr->startup += instr->firsttuple;
 	instr->total += totaltime;
+
+	/*
+	 * this is first loop
+	 *
+	 * We only initialize the min values. We don't need to bother with the
+	 * max, because those are 0 and the non-zero values will get updated a
+	 * couple lines later.
+	 */
+	if (instr->nloops == 0)
+	{
+		instr->min_t = totaltime;
+		instr->min_tuples = instr->tuplecount;
+	}
+
+	if (instr->min_t > totaltime)
+		instr->min_t = totaltime;
+
+	if (instr->max_t < totaltime)
+		instr->max_t = totaltime;
+
 	instr->ntuples += instr->tuplecount;
+
+	if (instr->min_tuples > instr->tuplecount)
+		instr->min_tuples = instr->tuplecount;
+
+	if (instr->max_tuples < instr->tuplecount)
+		instr->max_tuples = instr->tuplecount;
+
 	instr->nloops += 1;
 
 	/* Reset for next cycle (if any) */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 9dc3ecb07d7..a458b566e0d 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 */
 	double		ntuples2;		/* secondary node-specific tuple counter */
 	double		nloops;			/* # of run cycles for this node */
 	double		nfiltered1;		/* # of tuples removed by scanqual or joinqual */
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index dc7ab2ce8bf..aa3955ad1fc 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -341,6 +341,10 @@ select jsonb_pretty(
                                  "string4"                  +
                              ],                             +
                              "Schema": "public",            +
+                             "Max Rows": 0,                 +
+                             "Max Time": 0.0,               +
+                             "Min Rows": 0,                 +
+                             "Min Time": 0.0,               +
                              "Node Type": "Seq Scan",       +
                              "Plan Rows": 0,                +
                              "Plan Width": 0,               +
@@ -383,6 +387,10 @@ select jsonb_pretty(
                          "stringu2",                        +
                          "string4"                          +
                      ],                                     +
+                     "Max Rows": 0,                         +
+                     "Max Time": 0.0,                       +
+                     "Min Rows": 0,                         +
+                     "Min Time": 0.0,                       +
                      "Sort Key": [                          +
                          "tenk1.tenthous"                   +
                      ],                                     +
diff --git a/src/test/regress/expected/partition_prune.out b/src/test/regress/expected/partition_prune.out
index 50d2a7e4b97..2d8ad48ff09 100644
--- a/src/test/regress/expected/partition_prune.out
+++ b/src/test/regress/expected/partition_prune.out
@@ -1929,6 +1929,8 @@ begin
     loop
         ln := regexp_replace(ln, 'Workers Launched: \d+', 'Workers Launched: N');
         ln := regexp_replace(ln, 'actual rows=\d+ loops=\d+', 'actual rows=N loops=N');
+        ln := regexp_replace(ln, 'actual min_rows=\d+ rows=\d+ max_rows=\d+ loops=\d+',
+				 'actual min_rows=N rows=N max_rows=N loops=N');
         ln := regexp_replace(ln, 'Rows Removed by Filter: \d+', 'Rows Removed by Filter: N');
         return next ln;
     end loop;
diff --git a/src/test/regress/expected/timetz.out b/src/test/regress/expected/timetz.out
index 038bb5fa094..5294179aa45 100644

diff --git a/src/test/regress/sql/partition_prune.sql b/src/test/regress/sql/partition_prune.sql
index 1e904a8c5b7..20688561614 100644
--- a/src/test/regress/sql/partition_prune.sql
+++ b/src/test/regress/sql/partition_prune.sql
@@ -452,6 +452,8 @@ begin
     loop
         ln := regexp_replace(ln, 'Workers Launched: \d+', 'Workers Launched: N');
         ln := regexp_replace(ln, 'actual rows=\d+ loops=\d+', 'actual rows=N loops=N');
+        ln := regexp_replace(ln, 'actual min_rows=\d+ rows=\d+ max_rows=\d+ loops=\d+',
+				 'actual min_rows=N rows=N max_rows=N loops=N');
         ln := regexp_replace(ln, 'Rows Removed by Filter: \d+', 'Rows Removed by Filter: N');
         return next ln;
     end loop;
-- 
2.26.0