diff --git a/contrib/auto_explain/Makefile b/contrib/auto_explain/Makefile
index fcf36c5ab0..db61901830 100644
--- a/contrib/auto_explain/Makefile
+++ b/contrib/auto_explain/Makefile
@@ -4,6 +4,8 @@ MODULE_big = auto_explain
OBJS = auto_explain.o $(WIN32RES)
PGFILEDESC = "auto_explain - logging facility for execution plans"
+REGRESS = auto_explain
+
ifdef USE_PGXS
PG_CONFIG = pg_config
PGXS := $(shell $(PG_CONFIG) --pgxs)
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index ea4f957cfa..5723e4383a 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -27,6 +27,7 @@ static bool auto_explain_log_verbose = false;
static bool auto_explain_log_buffers = false;
static bool auto_explain_log_triggers = false;
static bool auto_explain_log_timing = true;
+static bool auto_explain_log_costs = true;
static int auto_explain_log_format = EXPLAIN_FORMAT_TEXT;
static bool auto_explain_log_nested_statements = false;
static double auto_explain_sample_rate = 1;
@@ -129,6 +130,17 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("auto_explain.log_costs",
+ "Include costs in plans.",
+ NULL,
+ &auto_explain_log_costs,
+ true,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
DefineCustomEnumVariable("auto_explain.log_format",
"EXPLAIN format to be used for plan logging.",
NULL,
@@ -309,6 +321,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
if (queryDesc->totaltime && auto_explain_enabled() && current_query_sampled)
{
double msec;
+ StringInfoData buf;
/*
* Make sure stats accumulation is done. (Note: it's okay if several
@@ -328,6 +341,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
es->timing = (es->analyze && auto_explain_log_timing);
es->summary = es->analyze;
es->format = auto_explain_log_format;
+ es->costs = auto_explain_log_costs;
ExplainBeginOutput(es);
ExplainQueryText(es, queryDesc);
@@ -347,18 +361,24 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
es->str->data[es->str->len - 1] = '}';
}
+ initStringInfo(&buf);
+
+ if (es->analyze || auto_explain_log_timing)
+ appendStringInfo(&buf, "duration: %.3f ms ", msec);
+
/*
* Note: we rely on the existing logging of context or
* debug_query_string to identify just which statement is being
* reported. This isn't ideal but trying to do it here would
* often result in duplication.
*/
ereport(auto_explain_log_level,
- (errmsg("duration: %.3f ms plan:\n%s",
- msec, es->str->data),
+ (errmsg("%splan:\n%s",
+ buf.data, es->str->data),
errhidestmt(true)));
pfree(es->str->data);
+ pfree(buf.data);
}
}
diff --git a/contrib/auto_explain/expected/auto_explain.out b/contrib/auto_explain/expected/auto_explain.out
new file mode 100644
index 0000000000..070d28b667
--- /dev/null
+++ b/contrib/auto_explain/expected/auto_explain.out
@@ -0,0 +1,67 @@
+LOAD 'auto_explain';
+SET auto_explain.log_min_duration = 0;
+SET auto_explain.log_level = NOTICE;
+SET auto_explain.log_timing = off;
+SET auto_explain.log_costs = off;
+-- Should log
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+NOTICE: plan:
+Query Text: SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+Index Only Scan using pg_class_relname_nsp_index on pg_class
+ Index Cond: (relname = 'pg_class'::name)
+ ?column?
+----------
+
+(1 row)
+
+SET auto_explain.log_verbose = on;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+NOTICE: plan:
+Query Text: SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+Index Only Scan using pg_class_relname_nsp_index on pg_catalog.pg_class
+ Output: NULL::text
+ Index Cond: (pg_class.relname = 'pg_class'::name)
+ ?column?
+----------
+
+(1 row)
+
+SET auto_explain.log_format = json;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+NOTICE: plan:
+{
+ "Query Text": "SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';",
+ "Plan": {
+ "Node Type": "Index Only Scan",
+ "Parallel Aware": false,
+ "Scan Direction": "Forward",
+ "Index Name": "pg_class_relname_nsp_index",
+ "Relation Name": "pg_class",
+ "Schema": "pg_catalog",
+ "Alias": "pg_class",
+ "Output": ["NULL::text"],
+ "Index Cond": "(pg_class.relname = 'pg_class'::name)"
+ }
+}
+ ?column?
+----------
+
+(1 row)
+
+-- Shouldn't log due to too high loglevel
+SET auto_explain.log_level = DEBUG5;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+ ?column?
+----------
+
+(1 row)
+
+-- Shouldn't log due to query being too fast
+SET auto_explain.log_level = NOTICE;
+SET auto_explain.log_min_duration = 1000;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+ ?column?
+----------
+
+(1 row)
+
diff --git a/contrib/auto_explain/sql/auto_explain.sql b/contrib/auto_explain/sql/auto_explain.sql
new file mode 100644
index 0000000000..8f7b05274e
--- /dev/null
+++ b/contrib/auto_explain/sql/auto_explain.sql
@@ -0,0 +1,25 @@
+LOAD 'auto_explain';
+
+SET auto_explain.log_min_duration = 0;
+SET auto_explain.log_level = NOTICE;
+SET auto_explain.log_timing = off;
+SET auto_explain.log_costs = off;
+
+-- Should log
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+
+SET auto_explain.log_verbose = on;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+
+SET auto_explain.log_format = json;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+
+-- Shouldn't log due to too high loglevel
+SET auto_explain.log_level = DEBUG5;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+
+-- Shouldn't log due to query being too fast
+SET auto_explain.log_level = NOTICE;
+SET auto_explain.log_min_duration = 1000;
+SELECT NULL FROM pg_catalog.pg_class WHERE relname = 'pg_class';
+
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index 08b67f2600..25f445e1bb 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -108,6 +108,24 @@ LOAD 'auto_explain';
+
+
+ auto_explain.log_costs (boolean)
+
+ auto_explain.log_costs configuration parameter
+
+
+
+
+ auto_explain.log_costs controls whether per node costs
+ are printed when an execution plan is logged; it's
+ equivalent to the COSTS option of EXPLAIN.
+ This parameter is on by default.
+ Only superusers can change this setting.
+
+
+
+
auto_explain.log_timing (boolean)
@@ -124,8 +142,8 @@ LOAD 'auto_explain';
queries significantly on some systems, so it may be useful to set this
parameter to off when only actual row counts, and not exact times, are
needed.
- This parameter has no effect
- unless auto_explain.log_analyze is enabled.
+ This parameter has turns on printing the duration of the plan if
+ auto_explain.log_analyze is disabled.
This parameter is on by default.
Only superusers can change this setting.