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);