diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 6408d1653b33706be0780aac3b4a9558d12c9056..cd9fc929232b0eb721dd68e3d7a32b9216e5df91 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -18,7 +18,6 @@ #include "commands/defrem.h" #include "commands/prepare.h" #include "executor/hashjoin.h" -#include "executor/instrument.h" #include "foreign/fdwapi.h" #include "optimizer/clauses.h" #include "parser/parsetree.h" @@ -76,6 +75,8 @@ static void show_sort_keys_common(PlanState *planstate, List *ancestors, ExplainState *es); static void show_sort_info(SortState *sortstate, ExplainState *es); static void show_hash_info(HashState *hashstate, ExplainState *es); +static void show_instrumentation_count(const char *qlabel, int which, + PlanState *planstate, ExplainState *es); static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es); static const char *explain_get_index_name(Oid indexId); static void ExplainScanTarget(Scan *plan, ExplainState *es); @@ -1000,9 +1001,15 @@ ExplainNode(PlanState *planstate, List *ancestors, case T_IndexScan: show_scan_qual(((IndexScan *) plan)->indexqualorig, "Index Cond", planstate, ancestors, es); + if (((IndexScan *) plan)->indexqualorig) + show_instrumentation_count("Rows Removed by Index Recheck", 2, + planstate, es); show_scan_qual(((IndexScan *) plan)->indexorderbyorig, "Order By", planstate, ancestors, es); show_scan_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); break; case T_BitmapIndexScan: show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig, @@ -1011,6 +1018,9 @@ ExplainNode(PlanState *planstate, List *ancestors, case T_BitmapHeapScan: show_scan_qual(((BitmapHeapScan *) plan)->bitmapqualorig, "Recheck Cond", planstate, ancestors, es); + if (((BitmapHeapScan *) plan)->bitmapqualorig) + show_instrumentation_count("Rows Removed by Index Recheck", 2, + planstate, es); /* FALL THRU */ case T_SeqScan: case T_ValuesScan: @@ -1018,6 +1028,9 @@ ExplainNode(PlanState *planstate, List *ancestors, case T_WorkTableScan: case T_SubqueryScan: show_scan_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); break; case T_FunctionScan: if (es->verbose) @@ -1025,6 +1038,9 @@ ExplainNode(PlanState *planstate, List *ancestors, "Function Call", planstate, ancestors, es->verbose, es); show_scan_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); break; case T_TidScan: { @@ -1038,34 +1054,61 @@ ExplainNode(PlanState *planstate, List *ancestors, tidquals = list_make1(make_orclause(tidquals)); show_scan_qual(tidquals, "TID Cond", planstate, ancestors, es); show_scan_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); } break; case T_ForeignScan: show_scan_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); show_foreignscan_info((ForeignScanState *) planstate, es); break; case T_NestLoop: show_upper_qual(((NestLoop *) plan)->join.joinqual, "Join Filter", planstate, ancestors, es); + if (((NestLoop *) plan)->join.joinqual) + show_instrumentation_count("Rows Removed by Join Filter", 1, + planstate, es); show_upper_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 2, + planstate, es); break; case T_MergeJoin: show_upper_qual(((MergeJoin *) plan)->mergeclauses, "Merge Cond", planstate, ancestors, es); show_upper_qual(((MergeJoin *) plan)->join.joinqual, "Join Filter", planstate, ancestors, es); + if (((MergeJoin *) plan)->join.joinqual) + show_instrumentation_count("Rows Removed by Join Filter", 1, + planstate, es); show_upper_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 2, + planstate, es); break; case T_HashJoin: show_upper_qual(((HashJoin *) plan)->hashclauses, "Hash Cond", planstate, ancestors, es); show_upper_qual(((HashJoin *) plan)->join.joinqual, "Join Filter", planstate, ancestors, es); + if (((HashJoin *) plan)->join.joinqual) + show_instrumentation_count("Rows Removed by Join Filter", 1, + planstate, es); show_upper_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 2, + planstate, es); break; case T_Agg: case T_Group: show_upper_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); break; case T_Sort: show_sort_keys((SortState *) planstate, ancestors, es); @@ -1079,6 +1122,9 @@ ExplainNode(PlanState *planstate, List *ancestors, show_upper_qual((List *) ((Result *) plan)->resconstantqual, "One-Time Filter", planstate, ancestors, es); show_upper_qual(plan->qual, "Filter", planstate, ancestors, es); + if (plan->qual) + show_instrumentation_count("Rows Removed by Filter", 1, + planstate, es); break; case T_Hash: show_hash_info((HashState *) planstate, es); @@ -1508,6 +1554,37 @@ show_hash_info(HashState *hashstate, ExplainState *es) } } +/* + * If it's EXPLAIN ANALYZE, show instrumentation information for a plan node + * + * "which" identifies which instrumentation counter to print + */ +static void +show_instrumentation_count(const char *qlabel, int which, + PlanState *planstate, ExplainState *es) +{ + double nfiltered; + double nloops; + + if (!es->analyze || !planstate->instrument) + return; + + if (which == 2) + nfiltered = planstate->instrument->nfiltered2; + else + nfiltered = planstate->instrument->nfiltered1; + nloops = planstate->instrument->nloops; + + /* In text mode, suppress zero counts; they're not interesting enough */ + if (nfiltered > 0 || es->format != EXPLAIN_FORMAT_TEXT) + { + if (nloops > 0) + ExplainPropertyFloat(qlabel, nfiltered / nloops, 0, es); + else + ExplainPropertyFloat(qlabel, 0.0, 0, es); + } +} + /* * Show extra information for a ForeignScan node. */ diff --git a/src/backend/commands/trigger.c b/src/backend/commands/trigger.c index 680962aa44499b67478075ad62cc9c0f8e079e0b..06d368e07736f73529797df31a4f143a784202b9 100644 --- a/src/backend/commands/trigger.c +++ b/src/backend/commands/trigger.c @@ -29,7 +29,6 @@ #include "commands/defrem.h" #include "commands/trigger.h" #include "executor/executor.h" -#include "executor/instrument.h" #include "miscadmin.h" #include "nodes/bitmapset.h" #include "nodes/makefuncs.h" diff --git a/src/backend/executor/execAmi.c b/src/backend/executor/execAmi.c index ffdcc966ee60a3b0edbf5ea26241e0f47d903663..711e8c778664123d996c69f62196d0e5247c28b9 100644 --- a/src/backend/executor/execAmi.c +++ b/src/backend/executor/execAmi.c @@ -13,7 +13,6 @@ #include "postgres.h" #include "executor/execdebug.h" -#include "executor/instrument.h" #include "executor/nodeAgg.h" #include "executor/nodeAppend.h" #include "executor/nodeBitmapAnd.h" diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c index 1dfe8b9ac7823f8c92468178991107931a858ff5..fd7a9ed0339eed73b1523d84cacb8e8df55eb3f5 100644 --- a/src/backend/executor/execMain.c +++ b/src/backend/executor/execMain.c @@ -47,7 +47,6 @@ #include "commands/tablespace.h" #include "commands/trigger.h" #include "executor/execdebug.h" -#include "executor/instrument.h" #include "miscadmin.h" #include "optimizer/clauses.h" #include "parser/parse_clause.h" diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c index 17788761d7f101319388f8ad7a6cb964efe140f3..8bdfad2222380c9b7c4e88919267116f231d1d20 100644 --- a/src/backend/executor/execProcnode.c +++ b/src/backend/executor/execProcnode.c @@ -77,7 +77,6 @@ #include "postgres.h" #include "executor/executor.h" -#include "executor/instrument.h" #include "executor/nodeAgg.h" #include "executor/nodeAppend.h" #include "executor/nodeBitmapAnd.h" diff --git a/src/backend/executor/execScan.c b/src/backend/executor/execScan.c index e90058847d9de9bb8554dd5548607429b1694b1d..d4ed2358564de38201e0cef120d98b3315be794a 100644 --- a/src/backend/executor/execScan.c +++ b/src/backend/executor/execScan.c @@ -219,6 +219,8 @@ ExecScan(ScanState *node, return slot; } } + else + InstrCountFiltered1(node, 1); /* * Tuple fails qual, so free per-tuple memory and try again. diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c index bf9bf12ab6a3bf9cbc764a704971cdc47dccaef2..9d30200ab3c311928e35b1748bfee037d8d097a1 100644 --- a/src/backend/executor/instrument.c +++ b/src/backend/executor/instrument.c @@ -22,6 +22,7 @@ BufferUsage pgBufferUsage; static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub); + /* Allocate new instrumentation structure(s) */ Instrumentation * InstrAlloc(int n, int instrument_options) @@ -31,13 +32,14 @@ InstrAlloc(int n, int instrument_options) /* timer is always required for now */ Assert(instrument_options & INSTRUMENT_TIMER); + /* initialize all fields to zeroes, then modify as needed */ instr = palloc0(n * sizeof(Instrumentation)); if (instrument_options & INSTRUMENT_BUFFERS) { int i; for (i = 0; i < n; i++) - instr[i].needs_bufusage = true; + instr[i].need_bufusage = true; } return instr; @@ -52,8 +54,8 @@ InstrStartNode(Instrumentation *instr) else elog(DEBUG2, "InstrStartNode called twice in a row"); - /* initialize buffer usage per plan node */ - if (instr->needs_bufusage) + /* save buffer usage totals at node entry, if needed */ + if (instr->need_bufusage) instr->bufusage_start = pgBufferUsage; } @@ -77,8 +79,8 @@ InstrStopNode(Instrumentation *instr, double nTuples) INSTR_TIME_SET_ZERO(instr->starttime); - /* Adds delta of buffer usage to node's count. */ - if (instr->needs_bufusage) + /* Add delta of buffer usage since entry to node's totals */ + if (instr->need_bufusage) BufferUsageAccumDiff(&instr->bufusage, &pgBufferUsage, &instr->bufusage_start); @@ -119,12 +121,12 @@ InstrEndLoop(Instrumentation *instr) instr->tuplecount = 0; } +/* dst += add - sub */ static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub) { - /* dst += add - sub */ dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit; dst->shared_blks_read += add->shared_blks_read - sub->shared_blks_read; dst->shared_blks_written += add->shared_blks_written - sub->shared_blks_written; diff --git a/src/backend/executor/nodeAgg.c b/src/backend/executor/nodeAgg.c index 13d7723480144575103dc2efb42c10296dd565f8..e769d6d012c4422ee905c6417375e4d629316f26 100644 --- a/src/backend/executor/nodeAgg.c +++ b/src/backend/executor/nodeAgg.c @@ -1204,6 +1204,8 @@ agg_retrieve_direct(AggState *aggstate) return result; } } + else + InstrCountFiltered1(aggstate, 1); } /* No more groups */ @@ -1354,6 +1356,8 @@ agg_retrieve_hash_table(AggState *aggstate) return result; } } + else + InstrCountFiltered1(aggstate, 1); } /* No more groups */ diff --git a/src/backend/executor/nodeBitmapAnd.c b/src/backend/executor/nodeBitmapAnd.c index 82308cba2609251ff045089dad20d8892b67b79b..5f318c31e7796e9f477bf217da214171cfcd1231 100644 --- a/src/backend/executor/nodeBitmapAnd.c +++ b/src/backend/executor/nodeBitmapAnd.c @@ -29,7 +29,6 @@ #include "postgres.h" #include "executor/execdebug.h" -#include "executor/instrument.h" #include "executor/nodeBitmapAnd.h" diff --git a/src/backend/executor/nodeBitmapHeapscan.c b/src/backend/executor/nodeBitmapHeapscan.c index 8e50fb1aaef4ba8a0418da5f8d077058c5a71ce2..4a8920e6ce842eb7d027f7415d3c415e7d8d00b8 100644 --- a/src/backend/executor/nodeBitmapHeapscan.c +++ b/src/backend/executor/nodeBitmapHeapscan.c @@ -278,6 +278,7 @@ BitmapHeapNext(BitmapHeapScanState *node) if (!ExecQual(node->bitmapqualorig, econtext, false)) { /* Fails recheck, so drop it and loop back for another */ + InstrCountFiltered2(node, 1); ExecClearTuple(slot); continue; } diff --git a/src/backend/executor/nodeBitmapIndexscan.c b/src/backend/executor/nodeBitmapIndexscan.c index 9a56fd4b9fda06666fb3e42d6c8e7a306e81b44d..8e1df079b3728d69cdcae13b1eeec538bb469311 100644 --- a/src/backend/executor/nodeBitmapIndexscan.c +++ b/src/backend/executor/nodeBitmapIndexscan.c @@ -22,7 +22,6 @@ #include "postgres.h" #include "executor/execdebug.h" -#include "executor/instrument.h" #include "executor/nodeBitmapIndexscan.h" #include "executor/nodeIndexscan.h" #include "miscadmin.h" diff --git a/src/backend/executor/nodeBitmapOr.c b/src/backend/executor/nodeBitmapOr.c index 4b064b79a96234ca44de20077936b478cef0f2b2..d2453d5a4f0a5a96df1d7041f22c14cf11027082 100644 --- a/src/backend/executor/nodeBitmapOr.c +++ b/src/backend/executor/nodeBitmapOr.c @@ -29,7 +29,6 @@ #include "postgres.h" #include "executor/execdebug.h" -#include "executor/instrument.h" #include "executor/nodeBitmapOr.h" #include "miscadmin.h" diff --git a/src/backend/executor/nodeGroup.c b/src/backend/executor/nodeGroup.c index fa403e5406c04f68afefcee8322ddeeb6c7dd74f..7bef8bbe8b9c074c6b8fd22dc5e7ec720020b78b 100644 --- a/src/backend/executor/nodeGroup.c +++ b/src/backend/executor/nodeGroup.c @@ -118,6 +118,8 @@ ExecGroup(GroupState *node) return result; } } + else + InstrCountFiltered1(node, 1); } /* @@ -179,6 +181,8 @@ ExecGroup(GroupState *node) return result; } } + else + InstrCountFiltered1(node, 1); } /* NOTREACHED */ diff --git a/src/backend/executor/nodeHash.c b/src/backend/executor/nodeHash.c index 2ade2d7fad6b3f190cb0c9d17117b4d140c32d8d..e72a71bf51bf71e6b3c9a300e17fa8875e8e78e8 100644 --- a/src/backend/executor/nodeHash.c +++ b/src/backend/executor/nodeHash.c @@ -28,7 +28,6 @@ #include "commands/tablespace.h" #include "executor/execdebug.h" #include "executor/hashjoin.h" -#include "executor/instrument.h" #include "executor/nodeHash.h" #include "executor/nodeHashjoin.h" #include "miscadmin.h" diff --git a/src/backend/executor/nodeHashjoin.c b/src/backend/executor/nodeHashjoin.c index 3a6698105f278398a2317555cf0731a24cf9b106..c3c4db4bc2ce047d1db36b4894e6d591a0d97305 100644 --- a/src/backend/executor/nodeHashjoin.c +++ b/src/backend/executor/nodeHashjoin.c @@ -325,7 +325,11 @@ ExecHashJoin(HashJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); } + else + InstrCountFiltered1(node, 1); break; case HJ_FILL_OUTER_TUPLE: @@ -360,6 +364,8 @@ ExecHashJoin(HashJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); } break; @@ -397,6 +403,8 @@ ExecHashJoin(HashJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); break; case HJ_NEED_NEW_BATCH: diff --git a/src/backend/executor/nodeIndexscan.c b/src/backend/executor/nodeIndexscan.c index 955008e012d56d0a8bb42c0c78719944fe41c7d1..da25384e860df509cc40921911b5d84b95ec9f21 100644 --- a/src/backend/executor/nodeIndexscan.c +++ b/src/backend/executor/nodeIndexscan.c @@ -96,7 +96,11 @@ IndexNext(IndexScanState *node) econtext->ecxt_scantuple = slot; ResetExprContext(econtext); if (!ExecQual(node->indexqualorig, econtext, false)) - continue; /* nope, so ask index for another one */ + { + /* Fails recheck, so drop it and loop back for another */ + InstrCountFiltered2(node, 1); + continue; + } } return slot; diff --git a/src/backend/executor/nodeMergejoin.c b/src/backend/executor/nodeMergejoin.c index e23dd6c9f540c279314a888e544310e08763d514..deaa79ed9fbddfa5397887439085f499a5981259 100644 --- a/src/backend/executor/nodeMergejoin.c +++ b/src/backend/executor/nodeMergejoin.c @@ -505,6 +505,8 @@ MJFillOuter(MergeJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); return NULL; } @@ -544,6 +546,8 @@ MJFillInner(MergeJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); return NULL; } @@ -893,7 +897,11 @@ ExecMergeJoin(MergeJoinState *node) return result; } } + else + InstrCountFiltered2(node, 1); } + else + InstrCountFiltered1(node, 1); break; /* diff --git a/src/backend/executor/nodeNestloop.c b/src/backend/executor/nodeNestloop.c index e98bc0f5a308bd27bd624c6342e4a22fffe530a7..49b880d0caf013e18a3a5c2e2677069bef9568d1 100644 --- a/src/backend/executor/nodeNestloop.c +++ b/src/backend/executor/nodeNestloop.c @@ -214,6 +214,8 @@ ExecNestLoop(NestLoopState *node) return result; } } + else + InstrCountFiltered2(node, 1); } /* @@ -270,7 +272,11 @@ ExecNestLoop(NestLoopState *node) return result; } } + else + InstrCountFiltered2(node, 1); } + else + InstrCountFiltered1(node, 1); /* * Tuple fails qual, so free per-tuple memory and try again. diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h index 286cd540632258855e31ab9ae3fbd391576d4b97..22c310694365056a4aca06a3c71a5538bd9c21f7 100644 --- a/src/include/executor/instrument.h +++ b/src/include/executor/instrument.h @@ -28,6 +28,7 @@ typedef struct BufferUsage long temp_blks_written; /* # of temp blocks written */ } BufferUsage; +/* Flag bits included in InstrAlloc's instrument_options bitmask */ typedef enum InstrumentOption { INSTRUMENT_TIMER = 1 << 0, /* needs timer */ @@ -37,9 +38,10 @@ typedef enum InstrumentOption typedef struct Instrumentation { + /* Parameters set at node creation: */ + bool need_bufusage; /* TRUE if we need buffer usage data */ /* Info about current plan cycle: */ bool running; /* TRUE if we've completed first tuple */ - bool needs_bufusage; /* TRUE if we need buffer usage */ instr_time starttime; /* Start time of current iteration of node */ instr_time counter; /* Accumulated runtime for this node */ double firsttuple; /* Time for first tuple of this cycle */ @@ -50,6 +52,8 @@ typedef struct Instrumentation double total; /* Total total time (in seconds) */ double ntuples; /* Total tuples produced */ double nloops; /* # of run cycles for this node */ + double nfiltered1; /* # tuples removed by scanqual or joinqual */ + double nfiltered2; /* # tuples removed by "other" quals */ BufferUsage bufusage; /* Total buffer usage */ } Instrumentation; diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h index b3eed7d189cb81b61c84b18157fa3fcdd5b19456..c8a0b5986457f2b4e323934ff101876766ddca59 100644 --- a/src/include/nodes/execnodes.h +++ b/src/include/nodes/execnodes.h @@ -16,6 +16,7 @@ #include "access/genam.h" #include "access/heapam.h" +#include "executor/instrument.h" #include "nodes/params.h" #include "nodes/plannodes.h" #include "utils/reltrigger.h" @@ -314,7 +315,7 @@ typedef struct ResultRelInfo TriggerDesc *ri_TrigDesc; FmgrInfo *ri_TrigFunctions; List **ri_TrigWhenExprs; - struct Instrumentation *ri_TrigInstrument; + Instrumentation *ri_TrigInstrument; List **ri_ConstraintExprs; JunkFilter *ri_junkFilter; ProjectionInfo *ri_projectReturning; @@ -967,8 +968,7 @@ typedef struct PlanState * nodes point to one EState for the whole * top-level plan */ - struct Instrumentation *instrument; /* Optional runtime stats for this - * plan node */ + Instrumentation *instrument; /* Optional runtime stats for this node */ /* * Common structural data for all Plan types. These links to subsidiary @@ -1008,6 +1008,18 @@ typedef struct PlanState #define innerPlanState(node) (((PlanState *)(node))->righttree) #define outerPlanState(node) (((PlanState *)(node))->lefttree) +/* Macros for inline access to certain instrumentation counters */ +#define InstrCountFiltered1(node, delta) \ + do { \ + if (((PlanState *)(node))->instrument) \ + ((PlanState *)(node))->instrument->nfiltered1 += (delta); \ + } while(0) +#define InstrCountFiltered2(node, delta) \ + do { \ + if (((PlanState *)(node))->instrument) \ + ((PlanState *)(node))->instrument->nfiltered2 += (delta); \ + } while(0) + /* * EPQState is state for executing an EvalPlanQual recheck on a candidate * tuple in ModifyTable or LockRows. The estate and planstate fields are