From a60c742e4b3ede8676ad70b0e1657f12b8a0aa5e Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sun, 30 Sep 2018 22:24:20 -0700 Subject: [PATCH] Fix display of JIT statistics in EXPLAIN for non-parallel queries This bug was introduced by e63441c3f5ca4a3cdb47f9c7fed9e61dde17b60d since ExecutorEnd is only called after the query plan is being output by EXPLAIN/auto_explain. Instead, introduce a new ExplainPrintJITSummary method that takes care of the summarization and then outputs the stats. In passing also fix outdated JIT documentation that was still using the old JIT statistics format. --- contrib/auto_explain/auto_explain.c | 3 +-- doc/src/sgml/jit.sgml | 8 ++------ src/backend/commands/explain.c | 30 +++++++++++++++++++++++++++-- src/backend/executor/execMain.c | 15 --------------- src/include/commands/explain.h | 1 + 5 files changed, 32 insertions(+), 25 deletions(-) diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index b9c0896433..03be05129f 100644 --- a/contrib/auto_explain/auto_explain.c +++ b/contrib/auto_explain/auto_explain.c @@ -336,8 +336,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc) if (es->analyze && auto_explain_log_triggers) ExplainPrintTriggers(es, queryDesc); if (es->costs) - ExplainPrintJIT(es, queryDesc->estate->es_jit_flags, - queryDesc->estate->es_jit_combined_instr, -1); + ExplainPrintJITSummary(es, queryDesc); ExplainEndOutput(es); /* Remove last line break */ diff --git a/doc/src/sgml/jit.sgml b/doc/src/sgml/jit.sgml index 8387a4f6be..a21a07ef71 100644 --- a/doc/src/sgml/jit.sgml +++ b/doc/src/sgml/jit.sgml @@ -169,12 +169,8 @@ SET Planning Time: 0.133 ms JIT: Functions: 3 - Generation Time: 1.259 ms - Inlining: false - Inlining Time: 0.000 ms - Optimization: false - Optimization Time: 0.797 ms - Emission Time: 5.048 ms + Options: Inlining false, Optimization false, Expressions true, Deforming true + Timing: Generation 1.259 ms, Inlining 0.000 ms, Optimization 0.797 ms, Emission 5.048 ms, Total 7.104 ms Execution Time: 7.416 ms As visible here, JIT was used, but inlining and diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index ed6afe79a9..32df216f2c 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -564,8 +564,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, * at a later stage. */ if (es->costs) - ExplainPrintJIT(es, queryDesc->estate->es_jit_flags, - queryDesc->estate->es_jit_combined_instr, -1); + ExplainPrintJITSummary(es, queryDesc); /* * Close down the query and free resources. Include time for this in the @@ -688,6 +687,33 @@ ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc) ExplainCloseGroup("Triggers", "Triggers", false, es); } +/* + * ExplainPrintJITSummary - + * Print summarized JIT instrumentation from leader and workers + */ +void +ExplainPrintJITSummary(ExplainState *es, QueryDesc *queryDesc) +{ + JitInstrumentation ji; + + if (!queryDesc->estate->es_jit) + return; + + memset(&ji, 0, sizeof(JitInstrumentation)); + + /* + * Work with a copy instead of modifying the leader state, since this + * function may be called twice + */ + InstrJitAgg(&ji, &queryDesc->estate->es_jit->instr); + + /* If this process has done JIT in parallel workers, merge stats */ + if (queryDesc->estate->es_jit_combined_instr) + InstrJitAgg(&ji, queryDesc->estate->es_jit_combined_instr); + + ExplainPrintJIT(es, queryDesc->estate->es_jit_flags, &ji, -1); +} + /* * ExplainPrintJIT - * Append information about JITing to es->str. diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c index 04f14c9178..572506e7c2 100644 --- a/src/backend/executor/execMain.c +++ b/src/backend/executor/execMain.c @@ -495,21 +495,6 @@ standard_ExecutorEnd(QueryDesc *queryDesc) ExecEndPlan(queryDesc->planstate, estate); - /* - * If this process has done JIT, either merge stats into worker stats, or - * use this process' stats as the global stats if no parallelism was used - * / no workers did JIT. - */ - if (estate->es_instrument && queryDesc->estate->es_jit) - { - if (queryDesc->estate->es_jit_combined_instr) - InstrJitAgg(queryDesc->estate->es_jit_combined_instr, - &queryDesc->estate->es_jit->instr); - else - queryDesc->estate->es_jit_combined_instr = - &queryDesc->estate->es_jit->instr; - } - /* do away with our snapshots */ UnregisterSnapshot(estate->es_snapshot); UnregisterSnapshot(estate->es_crosscheck_snapshot); diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index b0b6f1e15a..d3f70fda08 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -81,6 +81,7 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc); extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc); +extern void ExplainPrintJITSummary(ExplainState *es, QueryDesc *queryDesc); extern void ExplainPrintJIT(ExplainState *es, int jit_flags, struct JitInstrumentation *jit_instr, int worker_i); -- 2.19.0