Re: Auto-explain patch - Mailing list pgsql-hackers

Here is a contrib version of auto-explain.
I'd like to add it the next commit-fest in September.

I set a high value on logging, not on interactive responce because
I think it's enough if we use EXPLAIN ANALYZE directly in psql or
set min_client_messages to LOG.

The module consists of one contrib directory and three patches:

* export_explain.patch
    It exports an internal routine in explain.c as ExplainOneResult().
    Auto-explain module requires it.

* custom_guc_flags.patch
    It enables to use guc flags in custom guc variables.
    Auto-explain module works better with it because there is a millisecond
    unit variable (explain.log_min_duration) in the module.

* psql_ignore_notices.patch
    It suppress notice messages during psql tab-completion and
    \d commands. I extracted it from Dean's patch.
    Auto-explain module does not always need the patch, but I think
    this feature is useful even if we don't use auto-explain.
    psql will ignore annoying messages on non-user SQLs when we set
    min_client_messages to lower level and enable some of log_* or
    debug_* options.

* auto_explain.tgz
    A contrib module version of auto-explain.
    An arguable part is initializing instruments in ExecutorRun_hook.
    The initialization should be done in ExecutorStart normally, but
    it is too late in the hook. Is it safe? or are there any better idea?
    README is a plain-text for now, and I'll rewrite it in sgml if needed.

Comments welcome.


(Here is a copy of README)

auto_explain
------------
Log query plans that execution times are longer than configuration.

Usage
-----
#= LOAD 'auto_explain';
#= SET explain.log_min_duration = 0;
#= SET explain.log_analyze = true;
#= SELECT count(*)
     FROM pg_class, pg_index
    WHERE oid = indrelid AND indisunique;

LOG:  duration: 0.457 ms  plan:
        Aggregate  (cost=14.90..14.91 rows=1 width=0) (actual time=0.444..0.445 rows=1 loops=1)
          ->  Hash Join  (cost=3.91..14.70 rows=81 width=0) (actual time=0.147..0.402 rows=81 loops=1)
                Hash Cond: (pg_class.oid = pg_index.indrelid)
                ->  Seq Scan on pg_class  (cost=0.00..8.27 rows=227 width=4) (actual time=0.011..0.135 rows=227
loops=1)
                ->  Hash  (cost=2.90..2.90 rows=81 width=4) (actual time=0.104..0.104 rows=81 loops=1)
                      ->  Seq Scan on pg_index  (cost=0.00..2.90 rows=81 width=4) (actual time=0.008..0.056 rows=81
loops=1)
                            Filter: indisunique
STATEMENT:  SELECT count(*)
          FROM pg_class, pg_index
         WHERE oid = indrelid AND indisunique;

GUC variables
-------------
* explain.log_min_duration (= -1)
        Sets the minimum execution time above which plans will be logged.
        Zero prints all plans. -1 turns this feature off.

* explain.log_analyze (= false)
        Use EXPLAIN ANALYZE for plan logging.

* explain.log_verbose (= false)
        Use EXPLAIN VERBOSE for plan logging.

You can use shared_preload_libraries or local_preload_libraries to
load the module automatically. If you do so, you also need to add
"explain" in custom_variable_classes and define explain.* variables
in your postgresql.conf.

Regards,
---
ITAGAKI Takahiro
NTT Open Source Software Center