Files
bsdports/data/postgresql11/files/patch-s00008-planner_timing.patch
2019-12-26 07:26:06 +00:00

107 lines
3.3 KiB
Diff

diff --git a/contrib/auto_explain/auto_explain.c contrib/auto_explain/auto_explain.c
index a47e7f0c295..b00e1a0ec5d 100644
--- a/contrib/auto_explain/auto_explain.c
+++ contrib/auto_explain/auto_explain.c
@@ -18,6 +18,7 @@
#include "commands/explain.h"
#include "executor/instrument.h"
#include "jit/jit.h"
+#include "optimizer/planner.h"
#include "utils/guc.h"
PG_MODULE_MAGIC;
@@ -335,6 +336,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
if (msec >= auto_explain_log_min_duration)
{
ExplainState *es = NewExplainState();
+ instr_time planduration = queryDesc->plannedstmt->planDuration;
es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze);
es->verbose = auto_explain_log_verbose;
@@ -370,8 +372,9 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
* often result in duplication.
*/
ereport(LOG,
- (errmsg("duration: %.3f ms plan:\n%s",
- msec, es->str->data),
+ (errmsg("duration: %.3f ms planning: %.3f ms plan:\n%s",
+ msec, 1000 * INSTR_TIME_GET_DOUBLE(planduration),
+ es->str->data),
errhidestmt(true)));
pfree(es->str->data);
diff --git a/src/backend/commands/explain.c src/backend/commands/explain.c
index 799a22e9d55..670c2d6ceb7 100644
--- a/src/backend/commands/explain.c
+++ src/backend/commands/explain.c
@@ -356,20 +356,13 @@ ExplainOneQuery(Query *query, int cursorOptions,
else
{
PlannedStmt *plan;
- instr_time planstart,
- planduration;
-
- INSTR_TIME_SET_CURRENT(planstart);
/* plan the query */
plan = pg_plan_query(query, cursorOptions, params);
- INSTR_TIME_SET_CURRENT(planduration);
- INSTR_TIME_SUBTRACT(planduration, planstart);
-
/* run it (if needed) and produce output */
ExplainOnePlan(plan, into, es, queryString, params, queryEnv,
- &planduration);
+ &plan->planDuration);
}
}
diff --git a/src/backend/optimizer/plan/planner.c src/backend/optimizer/plan/planner.c
index 6a3f4667e89..caac90bfac0 100644
--- a/src/backend/optimizer/plan/planner.c
+++ src/backend/optimizer/plan/planner.c
@@ -256,11 +256,22 @@ PlannedStmt *
planner(Query *parse, int cursorOptions, ParamListInfo boundParams)
{
PlannedStmt *result;
+ instr_time planstart,
+ planduration;
+
+ INSTR_TIME_SET_CURRENT(planstart);
if (planner_hook)
result = (*planner_hook) (parse, cursorOptions, boundParams);
else
result = standard_planner(parse, cursorOptions, boundParams);
+
+ INSTR_TIME_SET_CURRENT(planduration);
+ INSTR_TIME_SUBTRACT(planduration, planstart);
+
+ /* Record time spent on hooks and standard_planner() */
+ result->planDuration = planduration;
+
return result;
}
diff --git a/src/include/nodes/plannodes.h src/include/nodes/plannodes.h
index fae16500fe2..ca2bedc89d2 100644
--- a/src/include/nodes/plannodes.h
+++ src/include/nodes/plannodes.h
@@ -20,6 +20,7 @@
#include "nodes/bitmapset.h"
#include "nodes/lockoptions.h"
#include "nodes/primnodes.h"
+#include "portability/instr_time.h"
/* ----------------------------------------------------------------
@@ -96,6 +97,8 @@ typedef struct PlannedStmt
Node *utilityStmt; /* non-null if this is utility stmt */
+ instr_time planDuration; /* time spent on planning */
+
/* statement location in source string (copied from Query) */
int stmt_location; /* start location, or -1 if unknown */
int stmt_len; /* length in bytes; 0 means "rest of string" */