Trigger information for auto_explain.
Hello,
Now explain can show trigger statistics (from when?).
=# create table t (a int, b int);
=# create or replace function hoge() returns trigger as 'begin new.b = new.a; return new; end;' language plpgsql;
=# create trigger ins_hoge before insert or update on t for each row execute procedure hoge();
Explain analyze shows trigger information.
=# explain analyze insert into t (select a from generate_series(0, 100) a);
| QUERY PLAN
|----------------------------------------------------------------
| Insert on t (cost=0.00..10.00 rows=1000 width=4) (actual time=2.712.....
| -> Function Scan on generate_series a (cost=0.00..10.00 rows=1000 width=4)
| (actual time=0.047..0.147 rows=101 loops=1)
| Trigger ins_hoge: time=1.881 calls=101
| Total runtime: 3.009 ms
On the other hand, auto_explain doesn't.
=# load auto_explain;
=# set auto_explain.log_min_duration = 0;
=# set auto_explain.log_analyze = 'yes';
=# insert into t (select a from generate_series(0, 100) a);
|LOG: duration: 2.871 ms plan:
| Query Text: insert into t (select a from generate_series(0, 100) a);
| Insert on t (cost=0.00..10.00 rows=1000 width=4)
| -> Function Scan on generate_series a (cost=0.00..10.00 ...
auto_explain will show trigger infos with this patch like this.
=# set auto_explain.log_triggers = 'yes';
=# insert into t (select a from generate_series(0, 100) a);
| LOG: duration: 2.098 ms plan:
| Query Text: insert into t (select a from generate_series(0, 100) a);
| Insert on t (cost=0.00..10.00 rows=1000 width=4) (actual time=2.097..2.097 rows=0 loops=1)
| -> Function Scan on generate_series a (cost=0.00..10.00 rows=1000 width=4) (actual time=0.044..0.123 rows=101 loops=1)
| Trigger ins_hoge: time=1.452 calls=101
This patch consists of two parts,
0001_expose_explain_triggers_v1_20140114.patch
Expose the code to print out trigger information currently
hidden in ExplainOnePlan().
0002_auto_explain_triggers_v1_20140114.patch
Enable auto_explain to output trigger information.
Documentation will be added later..
regards,
--
Kyotaro Horiguchi
NTT Open Source Software Center
Attachments:
0001_expose_explain_triggers_v1_20140114.patchtext/x-patch; charset=us-asciiDownload
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 9969a25..45beb5b 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -484,29 +484,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* Print info about runtime of triggers */
if (es->analyze)
- {
- ResultRelInfo *rInfo;
- bool show_relname;
- int numrels = queryDesc->estate->es_num_result_relations;
- List *targrels = queryDesc->estate->es_trig_target_relations;
- int nr;
- ListCell *l;
-
- ExplainOpenGroup("Triggers", "Triggers", false, es);
-
- show_relname = (numrels > 1 || targrels != NIL);
- rInfo = queryDesc->estate->es_result_relations;
- for (nr = 0; nr < numrels; rInfo++, nr++)
- report_triggers(rInfo, show_relname, es);
-
- foreach(l, targrels)
- {
- rInfo = (ResultRelInfo *) lfirst(l);
- report_triggers(rInfo, show_relname, es);
- }
-
- ExplainCloseGroup("Triggers", "Triggers", false, es);
- }
+ ExplainPrintTriggers(es, queryDesc);
/*
* Close down the query and free resources. Include time for this in the
@@ -563,6 +541,42 @@ ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc)
}
/*
+ * ExplainPrintTriggers -
+
+ * convert a QueryDesc's trigger statistics to text and append it to
+ * es->str
+ *
+ * The caller should have set up the options fields of *es, as well as
+ * initializing the output buffer es->str. Other fields in *es are
+ * initialized here.
+ */
+void
+ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc)
+{
+ ResultRelInfo *rInfo;
+ bool show_relname;
+ int numrels = queryDesc->estate->es_num_result_relations;
+ List *targrels = queryDesc->estate->es_trig_target_relations;
+ int nr;
+ ListCell *l;
+
+ ExplainOpenGroup("Triggers", "Triggers", false, es);
+
+ show_relname = (numrels > 1 || targrels != NIL);
+ rInfo = queryDesc->estate->es_result_relations;
+ for (nr = 0; nr < numrels; rInfo++, nr++)
+ report_triggers(rInfo, show_relname, es);
+
+ foreach(l, targrels)
+ {
+ rInfo = (ResultRelInfo *) lfirst(l);
+ report_triggers(rInfo, show_relname, es);
+ }
+
+ ExplainCloseGroup("Triggers", "Triggers", false, es);
+}
+
+/*
* ExplainQueryText -
* add a "Query Text" node that contains the actual text of the query
*
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index ca213d7..4c4226d 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -71,6 +71,7 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
const char *queryString, ParamListInfo params);
extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc);
+extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc);
extern void ExplainQueryText(ExplainState *es, QueryDesc *queryDesc);
0002_auto_explain_triggers_v1_20140114.patchtext/x-patch; charset=us-asciiDownload
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index 57dfbe2..ec80132 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -25,6 +25,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_triggers = false;
static bool auto_explain_log_timing = false;
static int auto_explain_log_format = EXPLAIN_FORMAT_TEXT;
static bool auto_explain_log_nested_statements = false;
@@ -113,6 +114,17 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("auto_explain.log_triggers",
+ "Collect trigger stats, avaialble when log_analyze.",
+ NULL,
+ &auto_explain_log_triggers,
+ true,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
DefineCustomEnumVariable("auto_explain.log_format",
"EXPLAIN format to be used for plan logging.",
NULL,
@@ -295,6 +307,8 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
ExplainBeginOutput(&es);
ExplainQueryText(&es, queryDesc);
ExplainPrintPlan(&es, queryDesc);
+ if (es.analyze && auto_explain_log_triggers)
+ ExplainPrintTriggers(&es, queryDesc);
ExplainEndOutput(&es);
/* Remove last line break */
On Tue, Jan 14, 2014 at 4:25 AM, Kyotaro HORIGUCHI
<horiguchi.kyotaro@lab.ntt.co.jp> wrote:
This patch consists of two parts,
0001_expose_explain_triggers_v1_20140114.patch
Expose the code to print out trigger information currently
hidden in ExplainOnePlan().0002_auto_explain_triggers_v1_20140114.patch
Enable auto_explain to output trigger information.
Documentation will be added later..
Hi,
I think documentation is the only thing that stops this patch to be
commitable... can you add it?
--
Jaime Casanova www.2ndQuadrant.com
Professional PostgreSQL: Soporte 24x7 y capacitación
Phone: +593 4 5107566 Cell: +593 987171157
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Jaime Casanova wrote:
On Tue, Jan 14, 2014 at 4:25 AM, Kyotaro HORIGUCHI
<horiguchi.kyotaro@lab.ntt.co.jp> wrote:This patch consists of two parts,
0001_expose_explain_triggers_v1_20140114.patch
0002_auto_explain_triggers_v1_20140114.patch
Documentation will be added later..
I think documentation is the only thing that stops this patch to be
commitable... can you add it?
Agreed. I have pushed patch 0001 for now.
--
�lvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Hello,
This patch consists of two parts,
0001_expose_explain_triggers_v1_20140114.patch
0002_auto_explain_triggers_v1_20140114.patch
Documentation will be added later..
I think documentation is the only thing that stops this patch to be
commitable... can you add it?Agreed. I have pushed patch 0001 for now.
Thank you, I'll put it sooner.
--
Kyotaro Horiguchi
NTT Open Source Software Center
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Hello, I came back with doc patch and revised 0002 patch.
I think documentation is the only thing that stops this patch to be
commitable... can you add it?Agreed. I have pushed patch 0001 for now.
Thank you, I'll put it sooner.
I found the default setting for log_triggers was true in the last
patch while writing doc but it's better be false ragarding
backward compatibility. The 0002 patch attached has been changed
there.
- 0002_auto_explain_triggers_v2_20140122.patch
default value for log_triggers from 'true' to 'false'. As added
documents says.
- 0003_auto_explain_triggers_doc_v1_20140122.patch
documentation.
regards,
--
Kyotaro Horiguchi
NTT Open Source Software Center
Attachments:
0003_auto_explain_triggers_doc_v1_20140122.patchtext/x-patch; charset=us-asciiDownload
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index c9b8192..53f38cb 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -124,6 +124,24 @@ LOAD 'auto_explain';
<varlistentry>
<term>
+ <varname>auto_explain.log_triggers</varname> (<type>boolean</type>)
+ </term>
+ <indexterm>
+ <primary><varname>auto_explain.log_triggers</> configuration parameter</primary>
+ </indexterm>
+ <listitem>
+ <para>
+ <varname>auto_explain.log_triggers</varname> causes additional trigger
+ statistics output to be printed when an execution plan is logged. This
+ parameter is off by default. Only superusers can change this
+ setting. This parameter has no effect
+ unless <varname>auto_explain.log_analyze</> parameter is set.
+ </para>
+ </listitem>
+ </varlistentry>
+
+ <varlistentry>
+ <term>
<varname>auto_explain.log_format</varname> (<type>enum</type>)
</term>
<indexterm>
0002_auto_explain_triggers_v2_20140122.patchtext/x-patch; charset=us-asciiDownload
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index af68479..2354327 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -25,6 +25,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_triggers = false;
static bool auto_explain_log_timing = false;
static int auto_explain_log_format = EXPLAIN_FORMAT_TEXT;
static bool auto_explain_log_nested_statements = false;
@@ -113,6 +114,17 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("auto_explain.log_triggers",
+ "Collect trigger stats, avaialble when log_analyze.",
+ NULL,
+ &auto_explain_log_triggers,
+ false,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
DefineCustomEnumVariable("auto_explain.log_format",
"EXPLAIN format to be used for plan logging.",
NULL,
@@ -295,6 +307,8 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
ExplainBeginOutput(&es);
ExplainQueryText(&es, queryDesc);
ExplainPrintPlan(&es, queryDesc);
+ if (es.analyze && auto_explain_log_triggers)
+ ExplainPrintTriggers(&es, queryDesc);
ExplainEndOutput(&es);
/* Remove last line break */
Hi, I saw this patch has been moved into "committed patches" but
only the first part (0001_..) for the core is committed as of
32001ab but the rest for extension side seem not to have been
committed.
Would you mind taking a look on that, Álvaro?
regards,
At Wed, 22 Jan 2014 17:28:27 +0900, Kyotaro HORIGUCHI wrote
me> Hello, I came back with doc patch and revised 0002 patch.
me>
me> > > > I think documentation is the only thing that stops this patch to be
me> > > > commitable... can you add it?
me> > >
me> > > Agreed. I have pushed patch 0001 for now.
me> >
me> > Thank you, I'll put it sooner.
me>
me> I found the default setting for log_triggers was true in the last
me> patch while writing doc but it's better be false ragarding
me> backward compatibility. The 0002 patch attached has been changed
me> there.
me>
me> - 0002_auto_explain_triggers_v2_20140122.patch
me>
me> default value for log_triggers from 'true' to 'false'. As added
me> documents says.
me>
me> - 0003_auto_explain_triggers_doc_v1_20140122.patch
me>
me> documentation.
--
Kyotaro Horiguchi
NTT Open Source Software Center
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Kyotaro HORIGUCHI wrote:
Hi, I saw this patch has been moved into "committed patches" but
only the first part (0001_..) for the core is committed as of
32001ab but the rest for extension side seem not to have been
committed.Would you mind taking a look on that, �lvaro?
Yep, pushed.
--
�lvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Hello,
Kyotaro HORIGUCHI wrote:
Hi, I saw this patch has been moved into "committed patches" but
only the first part (0001_..) for the core is committed as of
32001ab but the rest for extension side seem not to have been
committed.Would you mind taking a look on that, Álvaro?
Yep, pushed.
Thank you.
--
Kyotaro Horiguchi
NTT Open Source Software Center
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers