explain-analyze-rows-only.diff

text/plain

Filename: explain-analyze-rows-only.diff
Type: text/plain
Part: 0
Message: WIP: explain analyze with 'rows' but not timing

Patch

Same data as JSON: GET /api/v1/attachments/:id/patch the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes. API reference →
Format: unified
File+
contrib/auto_explain/auto_explain.c 17 1
src/backend/commands/explain.c 26 7
src/backend/executor/instrument.c 23 13
src/include/commands/explain.h 1 0
src/include/executor/instrument.h 2 0
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index b320698..34015b8 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -23,6 +23,7 @@ static int	auto_explain_log_min_duration = -1; /* msec or -1 */
 static bool auto_explain_log_analyze = false;
 static bool auto_explain_log_verbose = false;
 static bool auto_explain_log_buffers = false;
+static bool auto_explain_log_rows_only = false;
 static int	auto_explain_log_format = EXPLAIN_FORMAT_TEXT;
 static bool auto_explain_log_nested_statements = false;
 
@@ -133,6 +134,17 @@ _PG_init(void)
 							 NULL,
 							 NULL);
 
+	DefineCustomBoolVariable("auto_explain.log_rows_only",
+							 "Do not collect timing data, just row number.",
+							 NULL,
+							 &auto_explain_log_rows_only,
+							 false,
+							 PGC_SUSET,
+							 0,
+							 NULL,
+							 NULL,
+							 NULL);
+
 	EmitWarningsOnPlaceholders("auto_explain");
 
 	/* Install hooks. */
@@ -170,7 +182,11 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
 		/* Enable per-node instrumentation iff log_analyze is required. */
 		if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
 		{
-			queryDesc->instrument_options |= INSTRUMENT_TIMER;
+			if (auto_explain_log_rows_only)
+				queryDesc->instrument_options |= INSTRUMENT_ROWS;
+			else
+				queryDesc->instrument_options |= (INSTRUMENT_TIMER | INSTRUMENT_ROWS);
+
 			if (auto_explain_log_buffers)
 				queryDesc->instrument_options |= INSTRUMENT_BUFFERS;
 		}
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index e38de5c..4e3f343 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -133,6 +133,8 @@ ExplainQuery(ExplainStmt *stmt, const char *queryString,
 			es.costs = defGetBoolean(opt);
 		else if (strcmp(opt->defname, "buffers") == 0)
 			es.buffers = defGetBoolean(opt);
+		else if (strcmp(opt->defname, "timing") == 0)
+			es.timing = defGetBoolean(opt);
 		else if (strcmp(opt->defname, "format") == 0)
 		{
 			char	   *p = defGetString(opt);
@@ -229,6 +231,7 @@ ExplainInitState(ExplainState *es)
 	/* Set default options. */
 	memset(es, 0, sizeof(ExplainState));
 	es->costs = true;
+	es->timing = true;
 	/* Prepare output buffer. */
 	es->str = makeStringInfo();
 }
@@ -355,8 +358,11 @@ ExplainOnePlan(PlannedStmt *plannedstmt, ExplainState *es,
 	int			eflags;
 	int			instrument_option = 0;
 
-	if (es->analyze)
+	if (es->analyze && es->timing)
 		instrument_option |= INSTRUMENT_TIMER;
+	else if (es->analyze)
+		instrument_option |= INSTRUMENT_ROWS;
+
 	if (es->buffers)
 		instrument_option |= INSTRUMENT_BUFFERS;
 
@@ -951,29 +957,42 @@ ExplainNode(PlanState *planstate, List *ancestors,
 
 		if (es->format == EXPLAIN_FORMAT_TEXT)
 		{
-			appendStringInfo(es->str,
-							 " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
-							 startup_sec, total_sec, rows, nloops);
+			if (planstate->instrument->need_timer)
+				appendStringInfo(es->str,
+								 " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
+								 startup_sec, total_sec, rows, nloops);
+			else
+				appendStringInfo(es->str,
+								 " (actual rows=%.0f loops=%.0f)",
+								 rows, nloops);
 		}
 		else
 		{
-			ExplainPropertyFloat("Actual Startup Time", startup_sec, 3, es);
-			ExplainPropertyFloat("Actual Total Time", total_sec, 3, es);
+			if (planstate->instrument->need_timer)
+			{
+				ExplainPropertyFloat("Actual Startup Time", startup_sec, 3, es);
+				ExplainPropertyFloat("Actual Total Time", total_sec, 3, es);
+			}
 			ExplainPropertyFloat("Actual Rows", rows, 0, es);
 			ExplainPropertyFloat("Actual Loops", nloops, 0, es);
 		}
 	}
 	else if (es->analyze)
 	{
+
 		if (es->format == EXPLAIN_FORMAT_TEXT)
 			appendStringInfo(es->str, " (never executed)");
-		else
+		else if (planstate->instrument->need_timer)
 		{
 			ExplainPropertyFloat("Actual Startup Time", 0.0, 3, es);
 			ExplainPropertyFloat("Actual Total Time", 0.0, 3, es);
+		}
+		else
+		{
 			ExplainPropertyFloat("Actual Rows", 0.0, 0, es);
 			ExplainPropertyFloat("Actual Loops", 0.0, 0, es);
 		}
+
 	}
 
 	/* in text format, first line ends here */
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 9d30200..982a961 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -29,17 +29,21 @@ InstrAlloc(int n, int instrument_options)
 {
 	Instrumentation *instr;
 
-	/* timer is always required for now */
-	Assert(instrument_options & INSTRUMENT_TIMER);
-
 	/* initialize all fields to zeroes, then modify as needed */
 	instr = palloc0(n * sizeof(Instrumentation));
-	if (instrument_options & INSTRUMENT_BUFFERS)
+	if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
 	{
 		int			i;
+		bool		need_buffers = instrument_options & INSTRUMENT_BUFFERS;
+		bool		need_timer = instrument_options & INSTRUMENT_TIMER;
+
+		elog(WARNING, "need_timer = %d", need_timer ? 1 : 0);
 
 		for (i = 0; i < n; i++)
-			instr[i].need_bufusage = true;
+		{
+			instr[i].need_bufusage = need_buffers;
+			instr[i].need_timer = need_timer;
+		}
 	}
 
 	return instr;
@@ -49,7 +53,7 @@ InstrAlloc(int n, int instrument_options)
 void
 InstrStartNode(Instrumentation *instr)
 {
-	if (INSTR_TIME_IS_ZERO(instr->starttime))
+	if (instr->need_timer && INSTR_TIME_IS_ZERO(instr->starttime))
 		INSTR_TIME_SET_CURRENT(instr->starttime);
 	else
 		elog(DEBUG2, "InstrStartNode called twice in a row");
@@ -68,16 +72,22 @@ InstrStopNode(Instrumentation *instr, double nTuples)
 	/* count the returned tuples */
 	instr->tuplecount += nTuples;
 
-	if (INSTR_TIME_IS_ZERO(instr->starttime))
+	/* let's update the time only if the timer was requested */
+	if (instr->need_timer)
 	{
-		elog(DEBUG2, "InstrStopNode called without start");
-		return;
-	}
 
-	INSTR_TIME_SET_CURRENT(endtime);
-	INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
+		if (INSTR_TIME_IS_ZERO(instr->starttime))
+		{
+			elog(DEBUG2, "InstrStopNode called without start");
+			return;
+		}
 
-	INSTR_TIME_SET_ZERO(instr->starttime);
+		INSTR_TIME_SET_CURRENT(endtime);
+		INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
+
+		INSTR_TIME_SET_ZERO(instr->starttime);
+
+	}
 
 	/* Add delta of buffer usage since entry to node's totals */
 	if (instr->need_bufusage)
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index d7998c3..1c80bf3 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -31,6 +31,7 @@ typedef struct ExplainState
 	bool		analyze;		/* print actual times */
 	bool		costs;			/* print costs */
 	bool		buffers;		/* print buffer usage */
+	bool		timing;			/* print timing */
 	ExplainFormat format;		/* output format */
 	/* other states */
 	PlannedStmt *pstmt;			/* top of plan */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 22c3106..2904d10 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -33,12 +33,14 @@ typedef enum InstrumentOption
 {
 	INSTRUMENT_TIMER = 1 << 0,	/* needs timer */
 	INSTRUMENT_BUFFERS = 1 << 1,	/* needs buffer usage */
+	INSTRUMENT_ROWS = 1 << 2,	/* needs row count */
 	INSTRUMENT_ALL = 0x7FFFFFFF
 } InstrumentOption;
 
 typedef struct Instrumentation
 {
 	/* Parameters set at node creation: */
+	bool		need_timer;	    /* TRUE if we need timer data */
 	bool		need_bufusage;	/* TRUE if we need buffer usage data */
 	/* Info about current plan cycle: */
 	bool		running;		/* TRUE if we've completed first tuple */