Add an EXPLAIN (BUFFERS) option to show buffer-usage statistics.
authorRobert Haas <rhaas@postgresql.org>
Tue, 15 Dec 2009 04:57:48 +0000 (04:57 +0000)
committerRobert Haas <rhaas@postgresql.org>
Tue, 15 Dec 2009 04:57:48 +0000 (04:57 +0000)
This patch also removes buffer-usage statistics from the track_counts
output, since this (or the global server statistics) is deemed to be a better
interface to this information.

Itagaki Takahiro, reviewed by Euler Taveira de Oliveira.

25 files changed:
contrib/auto_explain/auto_explain.c
contrib/pg_stat_statements/pg_stat_statements.c
doc/src/sgml/auto-explain.sgml
doc/src/sgml/ref/explain.sgml
src/backend/commands/copy.c
src/backend/commands/explain.c
src/backend/commands/tablecmds.c
src/backend/executor/execMain.c
src/backend/executor/execProcnode.c
src/backend/executor/functions.c
src/backend/executor/instrument.c
src/backend/executor/spi.c
src/backend/storage/buffer/buf_init.c
src/backend/storage/buffer/bufmgr.c
src/backend/storage/buffer/localbuf.c
src/backend/storage/file/buffile.c
src/backend/tcop/postgres.c
src/backend/tcop/pquery.c
src/include/commands/explain.h
src/include/executor/execdesc.h
src/include/executor/executor.h
src/include/executor/instrument.h
src/include/nodes/execnodes.h
src/include/storage/buf_internals.h
src/include/storage/bufmgr.h

index 88d40c718870e2d6700cf0b6200ed8e6602197c2..47fde6d66997858c1858e1cbfc3b375ce0f569e6 100644 (file)
@@ -6,7 +6,7 @@
  * Copyright (c) 2008-2009, PostgreSQL Global Development Group
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/contrib/auto_explain/auto_explain.c,v 1.9 2009/12/12 00:35:33 rhaas Exp $
+ *   $PostgreSQL: pgsql/contrib/auto_explain/auto_explain.c,v 1.10 2009/12/15 04:57:46 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -22,6 +22,7 @@ PG_MODULE_MAGIC;
 static int auto_explain_log_min_duration = -1; /* msec or -1 */
 static bool auto_explain_log_analyze = false;
 static bool auto_explain_log_verbose = false;
+static bool auto_explain_log_buffers = false;
 static int auto_explain_log_format = EXPLAIN_FORMAT_TEXT;
 static bool auto_explain_log_nested_statements = false;
 
@@ -93,6 +94,16 @@ _PG_init(void)
                             NULL,
                             NULL);
 
+   DefineCustomBoolVariable("auto_explain.log_buffers",
+                            "Log buffers usage.",
+                            NULL,
+                            &auto_explain_log_buffers,
+                            false,
+                            PGC_SUSET,
+                            0,
+                            NULL,
+                            NULL);
+
    DefineCustomEnumVariable("auto_explain.log_format",
                             "EXPLAIN format to be used for plan logging.",
                             NULL,
@@ -147,7 +158,11 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
    {
        /* Enable per-node instrumentation iff log_analyze is required. */
        if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
-           queryDesc->doInstrument = true;
+       {
+           queryDesc->instrument_options |= INSTRUMENT_TIMER;
+           if (auto_explain_log_buffers)
+               queryDesc->instrument_options |= INSTRUMENT_BUFFERS;
+       }
    }
 
    if (prev_ExecutorStart)
@@ -167,7 +182,7 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
            MemoryContext oldcxt;
 
            oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
-           queryDesc->totaltime = InstrAlloc(1);
+           queryDesc->totaltime = InstrAlloc(1, INSTRUMENT_ALL);
            MemoryContextSwitchTo(oldcxt);
        }
    }
@@ -219,8 +234,9 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
            ExplainState    es;
 
            ExplainInitState(&es);
-           es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
+           es.analyze = (queryDesc->instrument_options && auto_explain_log_analyze);
            es.verbose = auto_explain_log_verbose;
+           es.buffers = (es.analyze && auto_explain_log_buffers);
            es.format = auto_explain_log_format;
 
            ExplainBeginOutput(&es);
index a877e637406d628cd658325d5458c2dbb8732af5..01e4b5e5938c21dfffb5fc10a26fa9839f1318c6 100644 (file)
@@ -14,7 +14,7 @@
  * Copyright (c) 2008-2009, PostgreSQL Global Development Group
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.7 2009/12/01 02:31:11 momjian Exp $
+ *   $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.8 2009/12/15 04:57:46 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -495,7 +495,7 @@ pgss_ExecutorStart(QueryDesc *queryDesc, int eflags)
            MemoryContext oldcxt;
 
            oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
-           queryDesc->totaltime = InstrAlloc(1);
+           queryDesc->totaltime = InstrAlloc(1, INSTRUMENT_ALL);
            MemoryContextSwitchTo(oldcxt);
        }
    }
index 39c7bc20f592b01940c06742169f8c33e890233b..f332321ccb71b3c0f4301c125a5212eedd87960d 100644 (file)
@@ -1,4 +1,4 @@
-<!-- $PostgreSQL: pgsql/doc/src/sgml/auto-explain.sgml,v 1.5 2009/12/11 01:33:35 adunstan Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/auto-explain.sgml,v 1.6 2009/12/15 04:57:47 rhaas Exp $ -->
 
 <sect1 id="auto-explain">
  <title>auto_explain</title>
@@ -102,6 +102,25 @@ LOAD 'auto_explain';
     </listitem>
    </varlistentry>
 
+   <varlistentry>
+    <term>
+     <varname>auto_explain.log_buffers</varname> (<type>boolean</type>)
+    </term>
+    <indexterm>
+     <primary><varname>auto_explain.log_buffers</> configuration parameter</primary>
+    </indexterm>
+    <listitem>
+     <para>
+      <varname>auto_explain.log_buffers</varname> causes <command>EXPLAIN
+      (ANALYZE, BUFFERS)</> output, rather than just <command>EXPLAIN</> 
+      output, to be printed when an execution plan is logged. This parameter is 
+      off by default. Only superusers can change this setting. This
+      parameter has no effect unless <varname>auto_explain.log_analyze</>
+      parameter is set.
+     </para>
+    </listitem>
+   </varlistentry>
+
    <varlistentry>
     <term>
      <varname>auto_explain.log_format</varname> (<type>enum</type>)
index 4de5a4aba63f083af6e65597085c57176a5e5cf5..2f6aaf427a82d01f2510007518c87a9d3316c8ac 100644 (file)
@@ -1,5 +1,5 @@
 <!--
-$PostgreSQL: pgsql/doc/src/sgml/ref/explain.sgml,v 1.47 2009/12/11 01:33:35 adunstan Exp $
+$PostgreSQL: pgsql/doc/src/sgml/ref/explain.sgml,v 1.48 2009/12/15 04:57:47 rhaas Exp $
 PostgreSQL documentation
 -->
 
@@ -31,7 +31,7 @@ PostgreSQL documentation
 
  <refsynopsisdiv>
 <synopsis>
-EXPLAIN [ ( { ANALYZE <replaceable class="parameter">boolean</replaceable> | VERBOSE <replaceable class="parameter">boolean</replaceable> | COSTS <replaceable class="parameter">boolean</replaceable> | FORMAT { TEXT | XML | JSON | YAML } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
+EXPLAIN [ ( { ANALYZE <replaceable class="parameter">boolean</replaceable> | VERBOSE <replaceable class="parameter">boolean</replaceable> | COSTS <replaceable class="parameter">boolean</replaceable> | BUFFERS <replaceable class="parameter">boolean</replaceable> | FORMAT { TEXT | XML | JSON | YAML } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
 EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
 </synopsis>
  </refsynopsisdiv>
@@ -139,6 +139,24 @@ ROLLBACK;
     </listitem>
    </varlistentry>
 
+   <varlistentry>
+    <term><literal>BUFFERS</literal></term>
+    <listitem>
+     <para>
+      Include information on buffer usage. Specifically, include the number of
+      shared blocks hits, reads, and writes, the number of local blocks hits,
+      reads, and writes, and the number of temp blocks reads and writes.
+      Shared blocks, local blocks, and temp blocks contain tables and indexes,
+      temporary tables and temporary indexes, and disk blocks used in sort and
+      materialized plans, respectively. The number of blocks shown for an
+      upper-level node includes those used by all its child nodes.  In text
+      format, only non-zero values are printed.  This parameter may only be
+      used with <literal>ANALYZE</literal> parameter.  It defaults to
+      <literal>FALSE</literal>.
+     </para>
+    </listitem>
+   </varlistentry>
+
    <varlistentry>
     <term><literal>FORMAT</literal></term>
     <listitem>
index 4ad49409c55b60c10e18649a308432079129df97..521f2828b8c9dc0d483acdea7898deb6cf8ee0d1 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/commands/copy.c,v 1.318 2009/11/20 20:38:10 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/commands/copy.c,v 1.319 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -1094,7 +1094,7 @@ DoCopy(const CopyStmt *stmt, const char *queryString)
        cstate->queryDesc = CreateQueryDesc(plan, queryString,
                                            GetActiveSnapshot(),
                                            InvalidSnapshot,
-                                           dest, NULL, false);
+                                           dest, NULL, 0);
 
        /*
         * Call ExecutorStart to prepare the plan for execution.
index c34b5751e463ad9fe8bd5b315efb9f599e5ea197..e63b8579d84ce340a708462c4513f6a1250d7e32 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1994-5, Regents of the University of California
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.195 2009/12/12 00:35:33 rhaas Exp $
+ *   $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.196 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -125,6 +125,8 @@ ExplainQuery(ExplainStmt *stmt, const char *queryString,
            es.verbose = defGetBoolean(opt);
        else if (strcmp(opt->defname, "costs") == 0)
            es.costs = defGetBoolean(opt);
+       else if (strcmp(opt->defname, "buffers") == 0)
+           es.buffers = defGetBoolean(opt);
        else if (strcmp(opt->defname, "format") == 0)
        {
            char   *p = defGetString(opt);
@@ -150,6 +152,11 @@ ExplainQuery(ExplainStmt *stmt, const char *queryString,
                            opt->defname)));
    }
 
+   if (es.buffers && !es.analyze)
+       ereport(ERROR,
+           (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+            errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+
    /*
     * Run parse analysis and rewrite.  Note this also acquires sufficient
     * locks on the source table(s).
@@ -339,6 +346,12 @@ ExplainOnePlan(PlannedStmt *plannedstmt, ExplainState *es,
    instr_time  starttime;
    double      totaltime = 0;
    int         eflags;
+   int         instrument_option = 0;
+
+   if (es->analyze)
+       instrument_option |= INSTRUMENT_TIMER;
+   if (es->buffers)
+       instrument_option |= INSTRUMENT_BUFFERS;
 
    /*
     * Use a snapshot with an updated command ID to ensure this query sees
@@ -349,7 +362,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, ExplainState *es,
    /* Create a QueryDesc requesting no output */
    queryDesc = CreateQueryDesc(plannedstmt, queryString,
                                GetActiveSnapshot(), InvalidSnapshot,
-                               None_Receiver, params, es->analyze);
+                               None_Receiver, params, instrument_option);
 
    INSTR_TIME_SET_CURRENT(starttime);
 
@@ -1042,6 +1055,84 @@ ExplainNode(Plan *plan, PlanState *planstate,
            break;
    }
 
+   /* Show buffer usage */
+   if (es->buffers)
+   {
+       const BufferUsage *usage = &planstate->instrument->bufusage;
+
+       if (es->format == EXPLAIN_FORMAT_TEXT)
+       {
+           bool    has_shared = (usage->shared_blks_hit > 0 ||
+                                 usage->shared_blks_read > 0 ||
+                                 usage->shared_blks_written);
+           bool    has_local = (usage->local_blks_hit > 0 ||
+                                usage->local_blks_read > 0 ||
+                                usage->local_blks_written);
+           bool    has_temp = (usage->temp_blks_read > 0 ||
+                               usage->temp_blks_written);
+
+           /* Show only positive counter values. */
+           if (has_shared || has_local || has_temp)
+           {
+               appendStringInfoSpaces(es->str, es->indent * 2);
+               appendStringInfoString(es->str, "Buffers:");
+
+               if (has_shared)
+               {
+                   appendStringInfoString(es->str, " shared");
+                   if (usage->shared_blks_hit > 0)
+                       appendStringInfo(es->str, " hit=%ld",
+                           usage->shared_blks_hit);
+                   if (usage->shared_blks_read > 0)
+                       appendStringInfo(es->str, " read=%ld",
+                           usage->shared_blks_read);
+                   if (usage->shared_blks_written > 0)
+                       appendStringInfo(es->str, " written=%ld",
+                           usage->shared_blks_written);
+                   if (has_local || has_temp)
+                       appendStringInfoChar(es->str, ',');
+               }
+               if (has_local)
+               {
+                   appendStringInfoString(es->str, " local");
+                   if (usage->local_blks_hit > 0)
+                       appendStringInfo(es->str, " hit=%ld",
+                           usage->local_blks_hit);
+                   if (usage->local_blks_read > 0)
+                       appendStringInfo(es->str, " read=%ld",
+                           usage->local_blks_read);
+                   if (usage->local_blks_written > 0)
+                       appendStringInfo(es->str, " written=%ld",
+                           usage->local_blks_written);
+                   if (has_temp)
+                       appendStringInfoChar(es->str, ',');
+               }
+               if (has_temp)
+               {
+                   appendStringInfoString(es->str, " temp");
+                   if (usage->temp_blks_read > 0)
+                       appendStringInfo(es->str, " read=%ld",
+                           usage->temp_blks_read);
+                   if (usage->temp_blks_written > 0)
+                       appendStringInfo(es->str, " written=%ld",
+                           usage->temp_blks_written);
+               }
+               appendStringInfoChar(es->str, '\n');
+           }
+       }
+       else
+       {
+           ExplainPropertyLong("Shared Hit Blocks", usage->shared_blks_hit, es);
+           ExplainPropertyLong("Shared Read Blocks", usage->shared_blks_read, es);
+           ExplainPropertyLong("Shared Written Blocks", usage->shared_blks_written, es);
+           ExplainPropertyLong("Local Hit Blocks", usage->local_blks_hit, es);
+           ExplainPropertyLong("Local Read Blocks", usage->local_blks_read, es);
+           ExplainPropertyLong("Local Written Blocks", usage->local_blks_written, es);
+           ExplainPropertyLong("Temp Read Blocks", usage->temp_blks_read, es);
+           ExplainPropertyLong("Temp Written Blocks", usage->temp_blks_written, es);
+       }
+   }
+
    /* Get ready to display the child plans */
    haschildren = plan->initPlan ||
        outerPlan(plan) ||
index 2344b79547b9abb0ac0b8b589483aa1c0ab7d4e6..d7b6d9bc2e517d8281dac6c6731a0f049290b9e6 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/commands/tablecmds.c,v 1.309 2009/12/11 03:34:55 itagaki Exp $
+ *   $PostgreSQL: pgsql/src/backend/commands/tablecmds.c,v 1.310 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -936,7 +936,7 @@ ExecuteTruncate(TruncateStmt *stmt)
                          rel,
                          0,    /* dummy rangetable index */
                          CMD_DELETE,   /* don't need any index info */
-                         false);
+                         0);
        resultRelInfo++;
    }
    estate->es_result_relations = resultRelInfos;
index ebb6d8ea82c71a1246ab9adfda6be0653cd76813..25d26f8446835345e3e50a3cda17b3b18e364150 100644 (file)
@@ -26,7 +26,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/executor/execMain.c,v 1.337 2009/12/11 18:14:43 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/executor/execMain.c,v 1.338 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -180,7 +180,7 @@ standard_ExecutorStart(QueryDesc *queryDesc, int eflags)
     */
    estate->es_snapshot = RegisterSnapshot(queryDesc->snapshot);
    estate->es_crosscheck_snapshot = RegisterSnapshot(queryDesc->crosscheck_snapshot);
-   estate->es_instrument = queryDesc->doInstrument;
+   estate->es_instrument = queryDesc->instrument_options;
 
    /*
     * Initialize the plan state tree
@@ -859,7 +859,7 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
                  Relation resultRelationDesc,
                  Index resultRelationIndex,
                  CmdType operation,
-                 bool doInstrument)
+                 int instrument_options)
 {
    /*
     * Check valid relkind ... parser and/or planner should have noticed this
@@ -914,10 +914,8 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
            palloc0(n * sizeof(FmgrInfo));
        resultRelInfo->ri_TrigWhenExprs = (List **)
            palloc0(n * sizeof(List *));
-       if (doInstrument)
-           resultRelInfo->ri_TrigInstrument = InstrAlloc(n);
-       else
-           resultRelInfo->ri_TrigInstrument = NULL;
+       if (instrument_options)
+           resultRelInfo->ri_TrigInstrument = InstrAlloc(n, instrument_options);
    }
    else
    {
index 21b973d3f8966e1350776e88c9480cfd93806162..ee867d9ddea768d35d1eba7ae7ddca7e9a17021e 100644 (file)
@@ -12,7 +12,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/executor/execProcnode.c,v 1.68 2009/10/12 18:10:41 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/executor/execProcnode.c,v 1.69 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -321,7 +321,7 @@ ExecInitNode(Plan *node, EState *estate, int eflags)
 
    /* Set up instrumentation for this node if requested */
    if (estate->es_instrument)
-       result->instrument = InstrAlloc(1);
+       result->instrument = InstrAlloc(1, estate->es_instrument);
 
    return result;
 }
index 7a9c319c7b46b93afaa94d36c918a122a372970c..8ac98236ec384cac2298d50b1367ac142fe96a31 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/executor/functions.c,v 1.137 2009/12/14 02:15:51 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/executor/functions.c,v 1.138 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -414,7 +414,7 @@ postquel_start(execution_state *es, SQLFunctionCachePtr fcache)
                                 fcache->src,
                                 snapshot, InvalidSnapshot,
                                 dest,
-                                fcache->paramLI, false);
+                                fcache->paramLI, 0);
    else
        es->qd = CreateUtilityQueryDesc(es->stmt,
                                        fcache->src,
index eeac0d0d955cd660ba8e8172510621d7928fd61f..cd76698ea2634f4f9bddfc4d9bd29d212ae22d37 100644 (file)
@@ -7,7 +7,7 @@
  * Copyright (c) 2001-2009, PostgreSQL Global Development Group
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/executor/instrument.c,v 1.22 2009/01/01 17:23:41 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/executor/instrument.c,v 1.23 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
 
 #include "executor/instrument.h"
 
+BufferUsage            pgBufferUsage;
+
+static void BufferUsageAccumDiff(BufferUsage *dst,
+       const BufferUsage *add, const BufferUsage *sub);
 
 /* Allocate new instrumentation structure(s) */
 Instrumentation *
-InstrAlloc(int n)
+InstrAlloc(int n, int instrument_options)
 {
-   Instrumentation *instr = palloc0(n * sizeof(Instrumentation));
+   Instrumentation *instr;
+
+   /* timer is always required for now */
+   Assert(instrument_options & INSTRUMENT_TIMER);
 
-   /* we don't need to do any initialization except zero 'em */
+   instr = palloc0(n * sizeof(Instrumentation));
+   if (instrument_options & INSTRUMENT_BUFFERS)
+   {
+       int     i;
+
+       for (i = 0; i < n; i++)
+           instr[i].needs_bufusage = true;
+   }
 
    return instr;
 }
@@ -37,6 +51,10 @@ InstrStartNode(Instrumentation *instr)
        INSTR_TIME_SET_CURRENT(instr->starttime);
    else
        elog(DEBUG2, "InstrStartNode called twice in a row");
+
+   /* initialize buffer usage per plan node */
+   if (instr->needs_bufusage)
+       instr->bufusage_start = pgBufferUsage;
 }
 
 /* Exit from a plan node */
@@ -59,6 +77,11 @@ InstrStopNode(Instrumentation *instr, double nTuples)
 
    INSTR_TIME_SET_ZERO(instr->starttime);
 
+   /* Adds delta of buffer usage to node's count. */
+   if (instr->needs_bufusage)
+       BufferUsageAccumDiff(&instr->bufusage,
+           &pgBufferUsage, &instr->bufusage_start);
+
    /* Is this the first tuple of this cycle? */
    if (!instr->running)
    {
@@ -95,3 +118,19 @@ InstrEndLoop(Instrumentation *instr)
    instr->firsttuple = 0;
    instr->tuplecount = 0;
 }
+
+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;
+   dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
+   dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
+   dst->local_blks_written += add->local_blks_written - sub->local_blks_written;
+   dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
+   dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written;
+}
index fcea0a1e62386005503b64bcce1de123af2811d5..09644950c1d72d55eb67ad24df9cabba4d8b2a9a 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.211 2009/11/04 22:26:06 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.212 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -1908,7 +1908,7 @@ _SPI_execute_plan(SPIPlanPtr plan, ParamListInfo paramLI,
                                        plansource->query_string,
                                        snap, crosscheck_snapshot,
                                        dest,
-                                       paramLI, false);
+                                       paramLI, 0);
                res = _SPI_pquery(qdesc, fire_triggers,
                                  canSetTag ? tcount : 0);
                FreeQueryDesc(qdesc);
index 2f20d96f094986da7cc77dc4ccb7931173f027f5..53a3b2fd6c96ec42a15b712d3b41e63704b4df65 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/buffer/buf_init.c,v 1.82 2009/01/01 17:23:47 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/buffer/buf_init.c,v 1.83 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -22,16 +22,6 @@ BufferDesc *BufferDescriptors;
 char      *BufferBlocks;
 int32     *PrivateRefCount;
 
-/* statistics counters */
-long int   ReadBufferCount;
-long int   ReadLocalBufferCount;
-long int   BufferHitCount;
-long int   LocalBufferHitCount;
-long int   BufferFlushCount;
-long int   LocalBufferFlushCount;
-long int   BufFileReadCount;
-long int   BufFileWriteCount;
-
 
 /*
  * Data Structures:
index be4c86bd3824e865c3e66391867c3bd6a6ce01ac..315493ad2a5cc4a2299f0ea61417e7b3f595746c 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.252 2009/06/11 14:49:01 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.253 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -34,6 +34,7 @@
 #include <unistd.h>
 
 #include "catalog/catalog.h"
+#include "executor/instrument.h"
 #include "miscadmin.h"
 #include "pg_trace.h"
 #include "pgstat.h"
@@ -300,22 +301,23 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, ForkNumber forkNum,
 
    if (isLocalBuf)
    {
-       ReadLocalBufferCount++;
        bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
        if (found)
-           LocalBufferHitCount++;
+           pgBufferUsage.local_blks_hit++;
+       else
+           pgBufferUsage.local_blks_read++;
    }
    else
    {
-       ReadBufferCount++;
-
        /*
         * lookup the buffer.  IO_IN_PROGRESS is set if the requested block is
         * not currently in memory.
         */
        bufHdr = BufferAlloc(smgr, forkNum, blockNum, strategy, &found);
        if (found)
-           BufferHitCount++;
+           pgBufferUsage.shared_blks_hit++;
+       else
+           pgBufferUsage.shared_blks_read++;
    }
 
    /* At this point we do NOT hold any locks. */
@@ -1610,54 +1612,6 @@ SyncOneBuffer(int buf_id, bool skip_recently_used)
 }
 
 
-/*
- * Return a palloc'd string containing buffer usage statistics.
- */
-char *
-ShowBufferUsage(void)
-{
-   StringInfoData str;
-   float       hitrate;
-   float       localhitrate;
-
-   initStringInfo(&str);
-
-   if (ReadBufferCount == 0)
-       hitrate = 0.0;
-   else
-       hitrate = (float) BufferHitCount *100.0 / ReadBufferCount;
-
-   if (ReadLocalBufferCount == 0)
-       localhitrate = 0.0;
-   else
-       localhitrate = (float) LocalBufferHitCount *100.0 / ReadLocalBufferCount;
-
-   appendStringInfo(&str,
-   "!\tShared blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
-               ReadBufferCount - BufferHitCount, BufferFlushCount, hitrate);
-   appendStringInfo(&str,
-   "!\tLocal  blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
-                    ReadLocalBufferCount - LocalBufferHitCount, LocalBufferFlushCount, localhitrate);
-   appendStringInfo(&str,
-                    "!\tDirect blocks: %10ld read, %10ld written\n",
-                    BufFileReadCount, BufFileWriteCount);
-
-   return str.data;
-}
-
-void
-ResetBufferUsage(void)
-{
-   BufferHitCount = 0;
-   ReadBufferCount = 0;
-   BufferFlushCount = 0;
-   LocalBufferHitCount = 0;
-   ReadLocalBufferCount = 0;
-   LocalBufferFlushCount = 0;
-   BufFileReadCount = 0;
-   BufFileWriteCount = 0;
-}
-
 /*
  *     AtEOXact_Buffers - clean up at end of transaction.
  *
@@ -1916,7 +1870,7 @@ FlushBuffer(volatile BufferDesc *buf, SMgrRelation reln)
              (char *) BufHdrGetBlock(buf),
              false);
 
-   BufferFlushCount++;
+   pgBufferUsage.shared_blks_written++;
 
    /*
     * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
index 3caa42a1a68cdbf3bc06a5be1281e7d9645b3088..10e5025cf83aa493abd4b4f57a41d11f2b6fe776 100644 (file)
@@ -9,13 +9,14 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/buffer/localbuf.c,v 1.87 2009/06/11 14:49:01 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/buffer/localbuf.c,v 1.88 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
 #include "postgres.h"
 
 #include "catalog/catalog.h"
+#include "executor/instrument.h"
 #include "storage/buf_internals.h"
 #include "storage/bufmgr.h"
 #include "storage/smgr.h"
@@ -209,7 +210,7 @@ LocalBufferAlloc(SMgrRelation smgr, ForkNumber forkNum, BlockNumber blockNum,
        /* Mark not-dirty now in case we error out below */
        bufHdr->flags &= ~BM_DIRTY;
 
-       LocalBufferFlushCount++;
+       pgBufferUsage.local_blks_written++;
    }
 
    /*
index 9516c88acdbbee1dbdfa28212fa20da78dc7fa4b..b5806c59804fe066fcba09a0919771775023e957 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1994, Regents of the University of California
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/storage/file/buffile.c,v 1.34 2009/06/11 14:49:01 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/storage/file/buffile.c,v 1.35 2009/12/15 04:57:47 rhaas Exp $
  *
  * NOTES:
  *
@@ -34,6 +34,7 @@
 
 #include "postgres.h"
 
+#include "executor/instrument.h"
 #include "storage/fd.h"
 #include "storage/buffile.h"
 #include "storage/buf_internals.h"
@@ -240,7 +241,7 @@ BufFileLoadBuffer(BufFile *file)
    file->offsets[file->curFile] += file->nbytes;
    /* we choose not to advance curOffset here */
 
-   BufFileReadCount++;
+   pgBufferUsage.temp_blks_read++;
 }
 
 /*
@@ -304,7 +305,7 @@ BufFileDumpBuffer(BufFile *file)
        file->curOffset += bytestowrite;
        wpos += bytestowrite;
 
-       BufFileWriteCount++;
+       pgBufferUsage.temp_blks_written++;
    }
    file->dirty = false;
 
index b6a892a30f558b30532ec73cacbe54b27373d3a4..71ae42dab705f9af39ed9427845447e5c1e768d1 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.575 2009/11/04 22:26:06 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.576 2009/12/15 04:57:47 rhaas Exp $
  *
  * NOTES
  *   this is the "main" module of the postgres backend and
@@ -3901,7 +3901,6 @@ ResetUsage(void)
 {
    getrusage(RUSAGE_SELF, &Save_r);
    gettimeofday(&Save_t, NULL);
-   ResetBufferUsage();
 }
 
 void
@@ -3912,7 +3911,6 @@ ShowUsage(const char *title)
                sys;
    struct timeval elapse_t;
    struct rusage r;
-   char       *bufusage;
 
    getrusage(RUSAGE_SELF, &r);
    gettimeofday(&elapse_t, NULL);
@@ -3986,10 +3984,6 @@ ShowUsage(const char *title)
                     r.ru_nvcsw, r.ru_nivcsw);
 #endif   /* HAVE_GETRUSAGE */
 
-   bufusage = ShowBufferUsage();
-   appendStringInfo(&str, "! buffer usage stats:\n%s", bufusage);
-   pfree(bufusage);
-
    /* remove trailing newline */
    if (str.data[str.len - 1] == '\n')
        str.data[--str.len] = '\0';
index f07bb49b539213a633bf88873eb2d37aebfe8025..aabaa9edf3041120b77ca910ae7f70770e9505c3 100644 (file)
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/tcop/pquery.c,v 1.132 2009/10/10 01:43:49 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/tcop/pquery.c,v 1.133 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -67,7 +67,7 @@ CreateQueryDesc(PlannedStmt *plannedstmt,
                Snapshot crosscheck_snapshot,
                DestReceiver *dest,
                ParamListInfo params,
-               bool doInstrument)
+               int instrument_options)
 {
    QueryDesc  *qd = (QueryDesc *) palloc(sizeof(QueryDesc));
 
@@ -80,7 +80,7 @@ CreateQueryDesc(PlannedStmt *plannedstmt,
    qd->crosscheck_snapshot = RegisterSnapshot(crosscheck_snapshot);
    qd->dest = dest;            /* output dest */
    qd->params = params;        /* parameter values passed into query */
-   qd->doInstrument = doInstrument;    /* instrumentation wanted? */
+   qd->instrument_options = instrument_options;    /* instrumentation wanted? */
 
    /* null these fields until set by ExecutorStart */
    qd->tupDesc = NULL;
@@ -111,7 +111,7 @@ CreateUtilityQueryDesc(Node *utilitystmt,
    qd->crosscheck_snapshot = InvalidSnapshot;  /* RI check snapshot */
    qd->dest = dest;            /* output dest */
    qd->params = params;        /* parameter values passed into query */
-   qd->doInstrument = false;   /* uninteresting for utilities */
+   qd->instrument_options = false; /* uninteresting for utilities */
 
    /* null these fields until set by ExecutorStart */
    qd->tupDesc = NULL;
@@ -178,7 +178,7 @@ ProcessQuery(PlannedStmt *plan,
     */
    queryDesc = CreateQueryDesc(plan, sourceText,
                                GetActiveSnapshot(), InvalidSnapshot,
-                               dest, params, false);
+                               dest, params, 0);
 
    /*
     * Set up to collect AFTER triggers
@@ -515,7 +515,7 @@ PortalStart(Portal portal, ParamListInfo params, Snapshot snapshot)
                                            InvalidSnapshot,
                                            None_Receiver,
                                            params,
-                                           false);
+                                           0);
 
                /*
                 * We do *not* call AfterTriggerBeginQuery() here.  We assume
index 75b5ed3d3c7e6c70e341669288a337a74f286006..d0b4c15e2c44490cdd7d2a5ddbaa2ea20e2d47d3 100644 (file)
@@ -6,7 +6,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994-5, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/commands/explain.h,v 1.43 2009/12/12 00:35:34 rhaas Exp $
+ * $PostgreSQL: pgsql/src/include/commands/explain.h,v 1.44 2009/12/15 04:57:47 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -30,6 +30,7 @@ typedef struct ExplainState
    bool        verbose;        /* be verbose */
    bool        analyze;        /* print actual times */
    bool        costs;          /* print costs */
+   bool        buffers;        /* print buffer usage */
    ExplainFormat format;       /* output format */
    /* other states */
    PlannedStmt *pstmt;         /* top of plan */
index 9682c4b73ad694c7f238a26b72759541b2aa3839..46df1bf6bd2a7307b179e51e27f5fd53d6726abf 100644 (file)
@@ -8,7 +8,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/executor/execdesc.h,v 1.40 2009/01/02 20:42:00 tgl Exp $
+ * $PostgreSQL: pgsql/src/include/executor/execdesc.h,v 1.41 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -42,7 +42,7 @@ typedef struct QueryDesc
    Snapshot    crosscheck_snapshot;    /* crosscheck for RI update/delete */
    DestReceiver *dest;         /* the destination for tuple output */
    ParamListInfo params;       /* param values being passed in */
-   bool        doInstrument;   /* TRUE requests runtime instrumentation */
+   int         instrument_options;     /* OR of InstrumentOption flags */
 
    /* These fields are set by ExecutorStart */
    TupleDesc   tupDesc;        /* descriptor for result tuples */
@@ -60,7 +60,7 @@ extern QueryDesc *CreateQueryDesc(PlannedStmt *plannedstmt,
                Snapshot crosscheck_snapshot,
                DestReceiver *dest,
                ParamListInfo params,
-               bool doInstrument);
+               int instrument_options);
 
 extern QueryDesc *CreateUtilityQueryDesc(Node *utilitystmt,
                       const char *sourceText,
index 76c075f75f949b5ab784ce2a5cee68ebc5325d41..98f8063601ae8c13a26c65d4aac9a3c97c9f9242 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/executor/executor.h,v 1.164 2009/12/07 05:22:23 tgl Exp $
+ * $PostgreSQL: pgsql/src/include/executor/executor.h,v 1.165 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -161,7 +161,7 @@ extern void InitResultRelInfo(ResultRelInfo *resultRelInfo,
                  Relation resultRelationDesc,
                  Index resultRelationIndex,
                  CmdType operation,
-                 bool doInstrument);
+                 int instrument_options);
 extern ResultRelInfo *ExecGetTriggerResultRel(EState *estate, Oid relid);
 extern bool ExecContextForcesOids(PlanState *planstate, bool *hasoids);
 extern void ExecConstraints(ResultRelInfo *resultRelInfo,
index 1ae6eebe8d303d6ec9a6c91fb74626ee987179a3..5eea68d2feeee307069528027e4fd81dd0d39274 100644 (file)
@@ -6,7 +6,7 @@
  *
  * Copyright (c) 2001-2009, PostgreSQL Global Development Group
  *
- * $PostgreSQL: pgsql/src/include/executor/instrument.h,v 1.20 2009/01/01 17:23:59 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/executor/instrument.h,v 1.21 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
 #include "portability/instr_time.h"
 
 
+typedef struct BufferUsage
+{
+   long    shared_blks_hit;        /* # of shared buffer hits */
+   long    shared_blks_read;       /* # of shared disk blocks read */
+   long    shared_blks_written;    /* # of shared disk blocks written */
+   long    local_blks_hit;         /* # of local buffer hits */
+   long    local_blks_read;        /* # of local disk blocks read */
+   long    local_blks_written;     /* # of local disk blocks written */
+   long    temp_blks_read;         /* # of temp blocks read */
+   long    temp_blks_written;      /* # of temp blocks written */
+} BufferUsage;
+
+typedef enum InstrumentOption
+{
+   INSTRUMENT_TIMER    = 1 << 0,       /* needs timer */
+   INSTRUMENT_BUFFERS  = 1 << 1,       /* needs buffer usage */
+   INSTRUMENT_ALL      = 0x7FFFFFFF
+} InstrumentOption;
+
 typedef struct Instrumentation
 {
    /* 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 */
    double      tuplecount;     /* Tuples emitted so far this cycle */
+   BufferUsage bufusage_start; /* Buffer usage at start */
    /* Accumulated statistics across all completed cycles: */
    double      startup;        /* Total startup time (in seconds) */
    double      total;          /* Total total time (in seconds) */
    double      ntuples;        /* Total tuples produced */
    double      nloops;         /* # of run cycles for this node */
+   BufferUsage bufusage;       /* Total buffer usage */
 } Instrumentation;
 
-extern Instrumentation *InstrAlloc(int n);
+extern BufferUsage     pgBufferUsage;
+
+extern Instrumentation *InstrAlloc(int n, int instrument_options);
 extern void InstrStartNode(Instrumentation *instr);
 extern void InstrStopNode(Instrumentation *instr, double nTuples);
 extern void InstrEndLoop(Instrumentation *instr);
index 7e4cfe9d71fc3a25522a6986a084aa95b123daf4..ac11b496fcfc58eb4779fda1d08728119e61f341 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/nodes/execnodes.h,v 1.213 2009/12/07 05:22:23 tgl Exp $
+ * $PostgreSQL: pgsql/src/include/nodes/execnodes.h,v 1.214 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -370,7 +370,7 @@ typedef struct EState
    uint32      es_processed;   /* # of tuples processed */
    Oid         es_lastoid;     /* last oid processed (by INSERT) */
 
-   bool        es_instrument;  /* true requests runtime instrumentation */
+   int         es_instrument;  /* OR of InstrumentOption flags */
    bool        es_select_into; /* true if doing SELECT INTO */
    bool        es_into_oids;   /* true to generate OIDs in SELECT INTO */
 
index 7084343037395dcdb8af43605773169019132361..e38017e5751cb929e3d0adcf3f17d425a77d32cc 100644 (file)
@@ -8,7 +8,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/storage/buf_internals.h,v 1.102 2009/06/11 14:49:12 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/storage/buf_internals.h,v 1.103 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -173,16 +173,6 @@ extern PGDLLIMPORT BufferDesc *BufferDescriptors;
 /* in localbuf.c */
 extern BufferDesc *LocalBufferDescriptors;
 
-/* event counters in buf_init.c */
-extern long int ReadBufferCount;
-extern long int ReadLocalBufferCount;
-extern long int BufferHitCount;
-extern long int LocalBufferHitCount;
-extern long int BufferFlushCount;
-extern long int LocalBufferFlushCount;
-extern long int BufFileReadCount;
-extern long int BufFileWriteCount;
-
 
 /*
  * Internal routines: only called by bufmgr
index af3562a79dfc5a01da848e2d3ba7a88063cd7774..8fdb22f0fa904cc0437e4f8216a2ad90d4213f32 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2009, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/storage/bufmgr.h,v 1.121 2009/06/11 14:49:12 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/storage/bufmgr.h,v 1.122 2009/12/15 04:57:48 rhaas Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -173,8 +173,6 @@ extern Buffer ReleaseAndReadBuffer(Buffer buffer, Relation relation,
 extern void InitBufferPool(void);
 extern void InitBufferPoolAccess(void);
 extern void InitBufferPoolBackend(void);
-extern char *ShowBufferUsage(void);
-extern void ResetBufferUsage(void);
 extern void AtEOXact_Buffers(bool isCommit);
 extern void PrintBufferLeakWarning(Buffer buffer);
 extern void CheckPointBuffers(int flags);