Re: EXPLAIN BUFFERS

On Sun, Dec 13, 2009 at 11:49 PM, Takahiro Itagaki
<itagaki.takahiro@oss.ntt.co.jp> wrote:
>
> Robert Haas <robertmhaas@gmail.com> wrote:
>
>> Well, I think we need to do something.  I don't really want to tack
>> another 5-6% overhead onto EXPLAIN ANALYZE.  Maybe we could recast the
>> doInstrument argument as a set of OR'd flags?
>
> I'm thinking the same thing (OR'd flags) right now.
>
> The attached patch adds INSTRUMENT_TIMER and INSTRUMENT_BUFFERS flags.
> The types of QueryDesc.doInstrument (renamed to instrument_options) and
> EState.es_instrument are changed from bool to int, and they store
> OR of InstrumentOption flags. INSTRUMENT_TIMER is always enabled when
> instrumetations are initialized, but INSTRUMENT_BUFFERS is enabled only if
> we use EXPLAIN BUFFERS. I think the flag options are not so bad idea because
> of extensibility. For example, we could support EXPLAIN CPU_USAGE someday.
>
> One issue is in the top-level instrumentation (queryDesc->totaltime).
> Since the field might be used by multiple plugins, the first initializer
> need to initialize the counter with all options. I used INSTRUMENT_ALL
> for it in the patch.
>
> =# EXPLAIN (ANALYZE) SELECT * FROM pgbench_accounts;
>                                                           QUERY PLAN
>
--------------------------------------------------------------------------------------------------------------------------------
>  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=97) (actual time=0.003..572.126
rows=10000000loops=1) 
>  Total runtime: 897.729 ms
>
> =# EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM pgbench_accounts;
>                                                           QUERY PLAN
>
--------------------------------------------------------------------------------------------------------------------------------
>  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=97) (actual time=0.002..580.642
rows=10000000loops=1) 
>   Buffers: shared hit=163935
>  Total runtime: 955.744 ms

That seems very promising, but it's almost midnight here so I have to
turn in for now.  I'll take another look at this tomorrow.

...Robert