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
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);
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 */
-- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers