Hi,
Here's a patch for showing in EXPLAIN ANALYZE the number of rows a plan
qual filtered from a node's input. The output looks like this:
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------
Subquery Scan on ss (cost=0.00..50.00 rows=267 width=4) (actual
time=0.035..0.088 rows=5 filtered=3 loops=1)
Filter: (ss.a < 6)
-> Limit (cost=0.00..40.00 rows=800 width=4) (actual
time=0.031..0.067 rows=8 filtered=0 loops=1)
-> Seq Scan on foo (cost=0.00..40.00 rows=800 width=4)
(actual time=0.027..0.040 rows=8 filtered=2 loops=1)
Filter: (a < 9)
Total runtime: 0.146 ms
(6 rows)
It might be better if the output was on the Filter: line but this was
just the result of a quick idea and I wanted to see how much work the
actual implementation would be.
Any suggestions and comments on the output format, the patch and the
idea are welcome.
Regards,
Marko Tiikkaja
*** a/src/backend/commands/explain.c
--- b/src/backend/commands/explain.c
***************
*** 975,992 **** ExplainNode(PlanState *planstate, List *ancestors,
double startup_sec = 1000.0 *
planstate->instrument->startup / nloops;
double total_sec = 1000.0 *
planstate->instrument->total / nloops;
double rows = planstate->instrument->ntuples / nloops;
if (es->format == EXPLAIN_FORMAT_TEXT)
{
appendStringInfo(es->str,
! " (actual
time=%.3f..%.3f rows=%.0f loops=%.0f)",
! startup_sec,
total_sec, rows, nloops);
}
else
{
ExplainPropertyFloat("Actual Startup Time",
startup_sec, 3, es);
ExplainPropertyFloat("Actual Total Time", total_sec, 3,
es);
ExplainPropertyFloat("Actual Rows", rows, 0, es);
ExplainPropertyFloat("Actual Loops", nloops, 0, es);
}
}
--- 975,994 ----
double startup_sec = 1000.0 *
planstate->instrument->startup / nloops;
double total_sec = 1000.0 *
planstate->instrument->total / nloops;
double rows = planstate->instrument->ntuples / nloops;
+ double filtered = planstate->instrument->nfiltered /
nloops;
if (es->format == EXPLAIN_FORMAT_TEXT)
{
appendStringInfo(es->str,
! " (actual
time=%.3f..%.3f rows=%.0f filtered=%.0f loops=%.0f)",
! startup_sec,
total_sec, rows, filtered, nloops);
}
else
{
ExplainPropertyFloat("Actual Startup Time",
startup_sec, 3, es);
ExplainPropertyFloat("Actual Total Time", total_sec, 3,
es);
ExplainPropertyFloat("Actual Rows", rows, 0, es);
+ ExplainPropertyFloat("Rows Filtered", rows, 0, es);
ExplainPropertyFloat("Actual Loops", nloops, 0, es);
}
}
***************
*** 999,1004 **** ExplainNode(PlanState *planstate, List *ancestors,
--- 1001,1007 ----
ExplainPropertyFloat("Actual Startup Time", 0.0, 3, es);
ExplainPropertyFloat("Actual Total Time", 0.0, 3, es);
ExplainPropertyFloat("Actual Rows", 0.0, 0, es);
+ ExplainPropertyFloat("Rows Filtered", 0.0, 0, es);
ExplainPropertyFloat("Actual Loops", 0.0, 0, es);
}
}
*** a/src/backend/executor/execScan.c
--- b/src/backend/executor/execScan.c
***************
*** 19,24 ****
--- 19,25 ----
#include "postgres.h"
#include "executor/executor.h"
+ #include "executor/instrument.h"
#include "miscadmin.h"
#include "utils/memutils.h"
***************
*** 221,226 **** ExecScan(ScanState *node,
--- 222,229 ----
* Tuple fails qual, so free per-tuple memory and try again.
*/
ResetExprContext(econtext);
+ if (node->ps.instrument)
+ node->ps.instrument->nfiltered += 1;;
}
}
*** a/src/include/executor/instrument.h
--- b/src/include/executor/instrument.h
***************
*** 49,54 **** typedef struct Instrumentation
--- 49,55 ----
double startup; /* Total startup time (in
seconds) */
double total; /* Total total time (in
seconds) */
double ntuples; /* Total tuples produced */
+ double nfiltered; /* Total tuples filtered by
qual */
double nloops; /* # of run cycles for this
node */
BufferUsage bufusage; /* Total buffer usage */
} Instrumentation;
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
