Buffer usage in EXPLAIN and pg_stat_statements (review)

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-08-10 14:46:49.000000000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-10-01 11:17:24.503897062 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 220,225 ****
--- 231,237 ----
  			ExplainInitState(&es);
  			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/contrib/pg_stat_statements/pg_stat_statements.c work/contrib/pg_stat_statements/pg_stat_statements.c
*** head/contrib/pg_stat_statements/pg_stat_statements.c	2009-07-27 13:09:55.000000000 +0900
--- work/contrib/pg_stat_statements/pg_stat_statements.c	2009-10-01 11:17:24.504906936 +0900
***************
*** 26,31 ****
--- 26,32 ----
  #include "catalog/pg_type.h"
  #include "executor/executor.h"
  #include "executor/instrument.h"
+ #include "funcapi.h"
  #include "mb/pg_wchar.h"
  #include "miscadmin.h"
  #include "pgstat.h"
*************** PG_MODULE_MAGIC;
*** 43,49 ****
  #define PGSS_DUMP_FILE	"global/pg_stat_statements.stat"
  
  /* This constant defines the magic number in the stats file header */
! static const uint32 PGSS_FILE_HEADER = 0x20081202;
  
  /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */
  #define USAGE_EXEC(duration)	(1.0)
--- 44,50 ----
  #define PGSS_DUMP_FILE	"global/pg_stat_statements.stat"
  
  /* This constant defines the magic number in the stats file header */
! static const uint32 PGSS_FILE_HEADER = 0x20090928;
  
  /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */
  #define USAGE_EXEC(duration)	(1.0)
*************** typedef struct Counters
*** 77,82 ****
--- 78,86 ----
  	int64		calls;			/* # of times executed */
  	double		total_time;		/* total execution time in seconds */
  	int64		rows;			/* total # of retrieved or affected rows */
+ 	int64		hit;			/* total # of buffer hits */
+ 	int64		read;			/* total # of disk blocks read */
+ 	int64		temp;			/* total # of local buffer read */
  	double		usage;			/* usage factor */
  } Counters;
  
*************** pgss_store(const char *query, const Inst
*** 633,638 ****
--- 637,645 ----
  		e->counters.calls += 1;
  		e->counters.total_time += instr->total;
  		e->counters.rows += rows;
+ 		e->counters.hit += instr->buffers_hit;
+ 		e->counters.read += instr->buffers_read;
+ 		e->counters.temp += instr->buffers_temp;
  		e->counters.usage += usage;
  		SpinLockRelease(&e->mutex);
  	}
*************** pg_stat_statements_reset(PG_FUNCTION_ARG
*** 654,660 ****
  	PG_RETURN_VOID();
  }
  
! #define PG_STAT_STATEMENTS_COLS		6
  
  /*
   * Retrieve statement statistics.
--- 661,667 ----
  	PG_RETURN_VOID();
  }
  
! #define PG_STAT_STATEMENTS_COLS		9
  
  /*
   * Retrieve statement statistics.
*************** pg_stat_statements(PG_FUNCTION_ARGS)
*** 688,709 ****
  				 errmsg("materialize mode required, but it is not " \
  						"allowed in this context")));
  
  	per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
  	oldcontext = MemoryContextSwitchTo(per_query_ctx);
  
! 	tupdesc = CreateTemplateTupleDesc(PG_STAT_STATEMENTS_COLS, false);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 1, "userid",
! 					   OIDOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 2, "dbid",
! 					   OIDOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 3, "query",
! 					   TEXTOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 4, "calls",
! 					   INT8OID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 5, "total_time",
! 					   FLOAT8OID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 6, "rows",
! 					   INT8OID, -1, 0);
  
  	tupstore = tuplestore_begin_heap(true, false, work_mem);
  	rsinfo->returnMode = SFRM_Materialize;
--- 695,708 ----
  				 errmsg("materialize mode required, but it is not " \
  						"allowed in this context")));
  
+ 	/* Build a tuple descriptor for our result type */
+ 	if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
+ 		elog(ERROR, "return type must be a row type");
+ 
  	per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
  	oldcontext = MemoryContextSwitchTo(per_query_ctx);
  
! 	tupdesc = CreateTupleDescCopy(tupdesc);
  
  	tupstore = tuplestore_begin_heap(true, false, work_mem);
  	rsinfo->returnMode = SFRM_Materialize;
*************** pg_stat_statements(PG_FUNCTION_ARGS)
*** 757,762 ****
--- 756,764 ----
  		values[i++] = Int64GetDatumFast(tmp.calls);
  		values[i++] = Float8GetDatumFast(tmp.total_time);
  		values[i++] = Int64GetDatumFast(tmp.rows);
+ 		values[i++] = Int64GetDatumFast(tmp.hit);
+ 		values[i++] = Int64GetDatumFast(tmp.read);
+ 		values[i++] = Int64GetDatumFast(tmp.temp);
  
  		Assert(i == PG_STAT_STATEMENTS_COLS);
  
diff -cprN head/contrib/pg_stat_statements/pg_stat_statements.sql.in work/contrib/pg_stat_statements/pg_stat_statements.sql.in
*** head/contrib/pg_stat_statements/pg_stat_statements.sql.in	2009-01-05 07:19:59.000000000 +0900
--- work/contrib/pg_stat_statements/pg_stat_statements.sql.in	2009-10-01 11:17:24.504906936 +0900
*************** CREATE FUNCTION pg_stat_statements(
*** 15,21 ****
      OUT query text,
      OUT calls int8,
      OUT total_time float8,
!     OUT rows int8
  )
  RETURNS SETOF record
  AS 'MODULE_PATHNAME'
--- 15,24 ----
      OUT query text,
      OUT calls int8,
      OUT total_time float8,
!     OUT rows int8,
!     OUT bufs_hit int8,
!     OUT bufs_read int8,
!     OUT bufs_temp int8
  )
  RETURNS SETOF record
  AS 'MODULE_PATHNAME'
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-10-01 11:17:24.505661275 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/pgstatstatements.sgml work/doc/src/sgml/pgstatstatements.sgml
*** head/doc/src/sgml/pgstatstatements.sgml	2009-05-18 20:08:24.000000000 +0900
--- work/doc/src/sgml/pgstatstatements.sgml	2009-10-01 11:17:24.505661275 +0900
***************
*** 85,90 ****
--- 85,111 ----
        <entry>Total number of rows retrieved or affected by the statement</entry>
       </row>
  
+      <row>
+       <entry><structfield>bufs_hit</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of buffer hits by the statement</entry>
+      </row>
+ 
+      <row>
+       <entry><structfield>bufs_read</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of disk blocks read by the statement</entry>
+      </row>
+ 
+      <row>
+       <entry><structfield>bufs_temp</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of local buffer read by the statement</entry>
+      </row>
+ 
      </tbody>
     </tgroup>
    </table>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-10-01 11:17:24.505661275 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,157 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. Specifically, include the number of
+       buffer hits, number of disc blocks read, and number of local buffer read.
+       This parameter should be used with <literal>ANALYZE</literal> parameter.
+       Also, this parameter defaults to <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-08-22 11:06:32.000000000 +0900
--- work/src/backend/commands/explain.c	2009-10-01 11:17:24.506655332 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 127,132 ****
--- 127,134 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 150,155 ****
--- 152,162 ----
  							opt->defname)));
  	}
  
+ 	if (es.buffers && !es.analyze)
+ 		ereport(ERROR,
+ 			(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ 			 errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+ 
  	/* Convert parameter type data to the form parser wants */
  	getParamListTypes(params, &param_types, &num_params);
  
*************** ExplainNode(Plan *plan, PlanState *plans
*** 923,928 ****
--- 930,954 ----
  			ExplainPropertyFloat("Actual Rows", rows, 0, es);
  			ExplainPropertyFloat("Actual Loops", nloops, 0, es);
  		}
+ 
+ 		if (es->buffers)
+ 		{
+ 			long	num_hit = planstate->instrument->buffers_hit;
+ 			long	num_read = planstate->instrument->buffers_read;
+ 			long	num_temp = planstate->instrument->buffers_temp;
+ 
+ 			if (es->format == EXPLAIN_FORMAT_TEXT)
+ 			{
+ 				appendStringInfo(es->str, " (hit=%ld read=%ld temp=%ld)",
+ 					num_hit, num_read, num_temp);
+ 			}
+ 			else
+ 			{
+ 				ExplainPropertyLong("Hit Buffers", num_hit, es);
+ 				ExplainPropertyLong("Read Buffers", num_read, es);
+ 				ExplainPropertyLong("Temp Buffers", num_temp, es);
+ 			}
+ 		}
  	}
  	else if (es->analyze)
  	{
diff -cprN head/src/backend/executor/execMain.c work/src/backend/executor/execMain.c
*** head/src/backend/executor/execMain.c	2009-09-28 05:09:57.000000000 +0900
--- work/src/backend/executor/execMain.c	2009-10-01 11:17:24.507627637 +0900
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 267,272 ****
--- 267,273 ----
  	DestReceiver *dest;
  	bool		sendTuples;
  	MemoryContext oldcontext;
+ 	Instrumentation *save_TopInstrument = NULL;
  
  	/* sanity checks */
  	Assert(queryDesc != NULL);
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 282,288 ****
--- 283,293 ----
  
  	/* Allow instrumentation of ExecutorRun overall runtime */
  	if (queryDesc->totaltime)
+ 	{
  		InstrStartNode(queryDesc->totaltime);
+ 		save_TopInstrument = TopInstrument;
+ 		TopInstrument = queryDesc->totaltime;
+ 	}
  
  	/*
  	 * extract information from the query descriptor and the query feature.
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 320,326 ****
--- 325,340 ----
  		(*dest->rShutdown) (dest);
  
  	if (queryDesc->totaltime)
+ 	{
  		InstrStopNode(queryDesc->totaltime, estate->es_processed);
+ 		if (save_TopInstrument)
+ 		{
+ 			save_TopInstrument->buffers_hit += queryDesc->totaltime->buffers_hit;
+ 			save_TopInstrument->buffers_read += queryDesc->totaltime->buffers_read;
+ 			save_TopInstrument->buffers_temp += queryDesc->totaltime->buffers_temp;
+ 		}
+ 		TopInstrument = save_TopInstrument;
+ 	}
  
  	MemoryContextSwitchTo(oldcontext);
  }
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-02 02:23:41.000000000 +0900
--- work/src/backend/executor/instrument.c	2009-10-01 11:19:17.666239902 +0900
***************
*** 16,22 ****
--- 16,26 ----
  #include <unistd.h>
  
  #include "executor/instrument.h"
+ #include "storage/buf_internals.h"
+ #include "storage/bufmgr.h"
  
+ Instrumentation *CurrentInstrument = NULL;
+ Instrumentation *TopInstrument = NULL;
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,50 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* push stack */
+ 	instr->prev = CurrentInstrument;
+ 	CurrentInstrument = instr;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 45,50 ****
--- 53,88 ----
  {
  	instr_time	endtime;
  
+ 	if (instr == CurrentInstrument)
+ 	{
+ 		long	num_get = ReadBufferCount + ReadLocalBufferCount;
+ 		long	num_hit = BufferHitCount + LocalBufferHitCount;
+ 		long	num_read = num_get - num_hit;
+ 		long	num_temp = BufFileReadCount;
+ 
+ 		/* count buffer usage per plan node */
+ 		instr->buffers_hit += num_hit;
+ 		instr->buffers_read += num_read;
+ 		instr->buffers_temp += num_temp;
+ 
+ 		/* accumulate per-node buffer statistics into top node */
+ 		if (TopInstrument && TopInstrument != CurrentInstrument)
+ 		{
+ 			TopInstrument->buffers_hit += num_hit;
+ 			TopInstrument->buffers_read += num_read;
+ 			TopInstrument->buffers_temp += num_temp;
+ 		}
+ 
+ 		/* reset buffer usage and pop stack */
+ 		ResetLocalBufferUsage();
+ 		CurrentInstrument = instr->prev;
+ 	}
+ 	else
+ 	{
+ 		elog(DEBUG2, "Instrumentation stack is broken");
+ 		return;
+ 	}
+ 
  	/* count the returned tuples */
  	instr->tuplecount += nTuples;
  
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-10-01 11:17:24.508671491 +0900
*************** static bool IsForInput;
*** 79,84 ****
--- 79,94 ----
  /* local state for LockBufferForCleanup */
  static volatile BufferDesc *PinCountWaitBuf = NULL;
  
+ /* statistics counters for log_[parser|planner|executor|statement]_stats */
+ static long GlobalReadBufferCount;
+ static long GlobalReadLocalBufferCount;
+ static long GlobalBufferHitCount;
+ static long GlobalLocalBufferHitCount;
+ static long GlobalBufferFlushCount;
+ static long GlobalLocalBufferFlushCount;
+ static long GlobalBufFileReadCount;
+ static long GlobalBufFileWriteCount;
+ 
  
  static Buffer ReadBuffer_common(SMgrRelation reln, bool isLocalBuf,
  				  ForkNumber forkNum, BlockNumber blockNum,
*************** ShowBufferUsage(void)
*** 1620,1646 ****
  	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;
  }
--- 1630,1658 ----
  	float		hitrate;
  	float		localhitrate;
  
+ 	ResetLocalBufferUsage();
+ 
  	initStringInfo(&str);
  
! 	if (GlobalReadBufferCount == 0)
  		hitrate = 0.0;
  	else
! 		hitrate = (float) GlobalBufferHitCount *100.0 / GlobalReadBufferCount;
  
! 	if (GlobalReadLocalBufferCount == 0)
  		localhitrate = 0.0;
  	else
! 		localhitrate = (float) GlobalLocalBufferHitCount *100.0 / GlobalReadLocalBufferCount;
  
  	appendStringInfo(&str,
  	"!\tShared blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
! 		GlobalReadBufferCount - GlobalBufferHitCount, GlobalBufferFlushCount, hitrate);
  	appendStringInfo(&str,
  	"!\tLocal  blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
! 		GlobalReadLocalBufferCount - GlobalLocalBufferHitCount, GlobalLocalBufferFlushCount, localhitrate);
  	appendStringInfo(&str,
  					 "!\tDirect blocks: %10ld read, %10ld written\n",
! 					 GlobalBufFileReadCount, GlobalBufFileWriteCount);
  
  	return str.data;
  }
*************** ResetBufferUsage(void)
*** 1656,1661 ****
--- 1668,1704 ----
  	LocalBufferFlushCount = 0;
  	BufFileReadCount = 0;
  	BufFileWriteCount = 0;
+ 
+ 	GlobalBufferHitCount = 0;
+ 	GlobalReadBufferCount = 0;
+ 	GlobalBufferFlushCount = 0;
+ 	GlobalLocalBufferHitCount = 0;
+ 	GlobalReadLocalBufferCount = 0;
+ 	GlobalLocalBufferFlushCount = 0;
+ 	GlobalBufFileReadCount = 0;
+ 	GlobalBufFileWriteCount = 0;
+ }
+ 
+ void
+ ResetLocalBufferUsage(void)
+ {
+ 	BufferHitCount = 0;
+ 	ReadBufferCount = 0;
+ 	BufferFlushCount = 0;
+ 	LocalBufferHitCount = 0;
+ 	ReadLocalBufferCount = 0;
+ 	LocalBufferFlushCount = 0;
+ 	BufFileReadCount = 0;
+ 	BufFileWriteCount = 0;
+ 
+ 	GlobalReadBufferCount += ReadBufferCount;
+ 	GlobalReadLocalBufferCount += ReadLocalBufferCount;
+ 	GlobalBufferHitCount += BufferHitCount;
+ 	GlobalLocalBufferHitCount += LocalBufferHitCount;
+ 	GlobalBufferFlushCount += BufferFlushCount;
+ 	GlobalLocalBufferFlushCount += LocalBufferFlushCount;
+ 	GlobalBufFileReadCount += BufFileReadCount;
+ 	GlobalBufFileWriteCount += BufFileWriteCount;
  }
  
  /*
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-09-01 11:54:51.000000000 +0900
--- work/src/backend/tcop/postgres.c	2009-10-01 11:17:24.510655527 +0900
***************
*** 44,49 ****
--- 44,50 ----
  #include "catalog/pg_type.h"
  #include "commands/async.h"
  #include "commands/prepare.h"
+ #include "executor/instrument.h"
  #include "libpq/libpq.h"
  #include "libpq/pqformat.h"
  #include "libpq/pqsignal.h"
*************** PostgresMain(int argc, char *argv[], con
*** 3482,3487 ****
--- 3483,3492 ----
  		 */
  		doing_extended_query_message = false;
  
+ 		/* Reset buffer usage counters */
+ 		CurrentInstrument = TopInstrument = NULL;
+ 		ResetLocalBufferUsage();
+ 
  		/*
  		 * Release storage left over from prior query cycle, and create a new
  		 * query input buffer in the cleared MessageContext.
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-08-10 14:46:50.000000000 +0900
--- work/src/include/commands/explain.h	2009-10-01 11:17:24.510655527 +0900
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-02 02:23:59.000000000 +0900
--- work/src/include/executor/instrument.h	2009-10-01 11:17:24.510655527 +0900
*************** typedef struct Instrumentation
*** 29,36 ****
--- 29,45 ----
  	double		total;			/* Total total time (in seconds) */
  	double		ntuples;		/* Total tuples produced */
  	double		nloops;			/* # of run cycles for this node */
+ 	/* Buffer usage */
+ 	long		buffers_hit;	/* # of buffer hits */
+ 	long		buffers_read;	/* # of disk blocks read */
+ 	long		buffers_temp;	/* # of local buffer read */
+ 	/* previous node in stack */
+ 	struct Instrumentation *prev;
  } Instrumentation;
  
+ extern Instrumentation *CurrentInstrument;
+ extern Instrumentation *TopInstrument;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/bufmgr.h	2009-10-01 11:17:24.511663344 +0900
*************** extern void InitBufferPoolAccess(void);
*** 175,180 ****
--- 175,181 ----
  extern void InitBufferPoolBackend(void);
  extern char *ShowBufferUsage(void);
  extern void ResetBufferUsage(void);
+ extern void ResetLocalBufferUsage(void);
  extern void AtEOXact_Buffers(bool isCommit);
  extern void PrintBufferLeakWarning(Buffer buffer);
  extern void CheckPointBuffers(int flags);

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	Mon Aug 10 14:46:49 2009
--- work/contrib/auto_explain/auto_explain.c	Mon Oct  5 11:50:46 2009
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 220,225 ****
--- 231,237 ----
  			ExplainInitState(&es);
  			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/contrib/pg_stat_statements/pg_stat_statements.c work/contrib/pg_stat_statements/pg_stat_statements.c
*** head/contrib/pg_stat_statements/pg_stat_statements.c	Mon Jul 27 13:09:55 2009
--- work/contrib/pg_stat_statements/pg_stat_statements.c	Mon Oct  5 14:13:16 2009
***************
*** 26,31 ****
--- 26,32 ----
  #include "catalog/pg_type.h"
  #include "executor/executor.h"
  #include "executor/instrument.h"
+ #include "funcapi.h"
  #include "mb/pg_wchar.h"
  #include "miscadmin.h"
  #include "pgstat.h"
*************** PG_MODULE_MAGIC;
*** 43,49 ****
  #define PGSS_DUMP_FILE	"global/pg_stat_statements.stat"
  
  /* This constant defines the magic number in the stats file header */
! static const uint32 PGSS_FILE_HEADER = 0x20081202;
  
  /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */
  #define USAGE_EXEC(duration)	(1.0)
--- 44,50 ----
  #define PGSS_DUMP_FILE	"global/pg_stat_statements.stat"
  
  /* This constant defines the magic number in the stats file header */
! static const uint32 PGSS_FILE_HEADER = 0x20090928;
  
  /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */
  #define USAGE_EXEC(duration)	(1.0)
*************** typedef struct Counters
*** 77,82 ****
--- 78,86 ----
  	int64		calls;			/* # of times executed */
  	double		total_time;		/* total execution time in seconds */
  	int64		rows;			/* total # of retrieved or affected rows */
+ 	int64		blks_hit;		/* total # of buffer hits */
+ 	int64		blks_read;		/* total # of disk blocks read */
+ 	int64		temp_blks_read;	/* total # of temp blocks read */
  	double		usage;			/* usage factor */
  } Counters;
  
*************** pgss_store(const char *query, const Inst
*** 633,638 ****
--- 637,645 ----
  		e->counters.calls += 1;
  		e->counters.total_time += instr->total;
  		e->counters.rows += rows;
+ 		e->counters.blks_hit += instr->blks_hit;
+ 		e->counters.blks_read += instr->blks_read;
+ 		e->counters.temp_blks_read += instr->temp_blks_read;
  		e->counters.usage += usage;
  		SpinLockRelease(&e->mutex);
  	}
*************** pg_stat_statements_reset(PG_FUNCTION_ARG
*** 654,660 ****
  	PG_RETURN_VOID();
  }
  
! #define PG_STAT_STATEMENTS_COLS		6
  
  /*
   * Retrieve statement statistics.
--- 661,667 ----
  	PG_RETURN_VOID();
  }
  
! #define PG_STAT_STATEMENTS_COLS		9
  
  /*
   * Retrieve statement statistics.
*************** pg_stat_statements(PG_FUNCTION_ARGS)
*** 688,709 ****
  				 errmsg("materialize mode required, but it is not " \
  						"allowed in this context")));
  
  	per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
  	oldcontext = MemoryContextSwitchTo(per_query_ctx);
  
! 	tupdesc = CreateTemplateTupleDesc(PG_STAT_STATEMENTS_COLS, false);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 1, "userid",
! 					   OIDOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 2, "dbid",
! 					   OIDOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 3, "query",
! 					   TEXTOID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 4, "calls",
! 					   INT8OID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 5, "total_time",
! 					   FLOAT8OID, -1, 0);
! 	TupleDescInitEntry(tupdesc, (AttrNumber) 6, "rows",
! 					   INT8OID, -1, 0);
  
  	tupstore = tuplestore_begin_heap(true, false, work_mem);
  	rsinfo->returnMode = SFRM_Materialize;
--- 695,708 ----
  				 errmsg("materialize mode required, but it is not " \
  						"allowed in this context")));
  
+ 	/* Build a tuple descriptor for our result type */
+ 	if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
+ 		elog(ERROR, "return type must be a row type");
+ 
  	per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
  	oldcontext = MemoryContextSwitchTo(per_query_ctx);
  
! 	tupdesc = CreateTupleDescCopy(tupdesc);
  
  	tupstore = tuplestore_begin_heap(true, false, work_mem);
  	rsinfo->returnMode = SFRM_Materialize;
*************** pg_stat_statements(PG_FUNCTION_ARGS)
*** 757,762 ****
--- 756,764 ----
  		values[i++] = Int64GetDatumFast(tmp.calls);
  		values[i++] = Float8GetDatumFast(tmp.total_time);
  		values[i++] = Int64GetDatumFast(tmp.rows);
+ 		values[i++] = Int64GetDatumFast(tmp.blks_hit);
+ 		values[i++] = Int64GetDatumFast(tmp.blks_read);
+ 		values[i++] = Int64GetDatumFast(tmp.temp_blks_read);
  
  		Assert(i == PG_STAT_STATEMENTS_COLS);
  
diff -cprN head/contrib/pg_stat_statements/pg_stat_statements.sql.in work/contrib/pg_stat_statements/pg_stat_statements.sql.in
*** head/contrib/pg_stat_statements/pg_stat_statements.sql.in	Mon Jan  5 07:19:59 2009
--- work/contrib/pg_stat_statements/pg_stat_statements.sql.in	Mon Oct  5 14:12:51 2009
*************** CREATE FUNCTION pg_stat_statements(
*** 15,21 ****
      OUT query text,
      OUT calls int8,
      OUT total_time float8,
!     OUT rows int8
  )
  RETURNS SETOF record
  AS 'MODULE_PATHNAME'
--- 15,24 ----
      OUT query text,
      OUT calls int8,
      OUT total_time float8,
!     OUT rows int8,
!     OUT blks_hit int8,
!     OUT blks_read int8,
!     OUT temp_blks_read int8
  )
  RETURNS SETOF record
  AS 'MODULE_PATHNAME'
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	Mon Aug 10 14:46:50 2009
--- work/doc/src/sgml/auto-explain.sgml	Mon Oct  5 11:50:46 2009
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/pgstatstatements.sgml work/doc/src/sgml/pgstatstatements.sgml
*** head/doc/src/sgml/pgstatstatements.sgml	Mon May 18 20:08:24 2009
--- work/doc/src/sgml/pgstatstatements.sgml	Mon Oct  5 14:12:51 2009
***************
*** 85,90 ****
--- 85,111 ----
        <entry>Total number of rows retrieved or affected by the statement</entry>
       </row>
  
+      <row>
+       <entry><structfield>blks_hit</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of buffer hits by the statement</entry>
+      </row>
+ 
+      <row>
+       <entry><structfield>blks_read</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of disk blocks read by the statement</entry>
+      </row>
+ 
+      <row>
+       <entry><structfield>temp_blks_read</structfield></entry>
+       <entry><type>bigint</type></entry>
+       <entry></entry>
+       <entry>Total number of temp blocks read by the statement</entry>
+      </row>
+ 
      </tbody>
     </tgroup>
    </table>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	Mon Aug 10 14:46:50 2009
--- work/doc/src/sgml/ref/explain.sgml	Mon Oct  5 13:11:22 2009
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,157 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. Specifically, include the number of
+       buffer hits, number of disk blocks read, and number of local buffer read.
+       This parameter should be used with <literal>ANALYZE</literal> parameter.
+       Also, this parameter defaults to <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	Sat Aug 22 11:06:32 2009
--- work/src/backend/commands/explain.c	Mon Oct  5 14:16:02 2009
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 127,132 ****
--- 127,134 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 150,155 ****
--- 152,162 ----
  							opt->defname)));
  	}
  
+ 	if (es.buffers && !es.analyze)
+ 		ereport(ERROR,
+ 			(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ 			 errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+ 
  	/* Convert parameter type data to the form parser wants */
  	getParamListTypes(params, &param_types, &num_params);
  
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1019,1024 ****
--- 1026,1052 ----
  			break;
  	}
  
+ 	/* Show buffer usage */
+ 	if (es->buffers)
+ 	{
+ 		long	num_hit = planstate->instrument->blks_hit;
+ 		long	num_read = planstate->instrument->blks_read;
+ 		long	num_temp_read = planstate->instrument->temp_blks_read;
+ 
+ 		if (es->format == EXPLAIN_FORMAT_TEXT)
+ 		{
+ 			appendStringInfoSpaces(es->str, es->indent * 2);
+ 			appendStringInfo(es->str, "Blocks Hit: %ld  Read: %ld  Temp Read: %ld\n",
+ 							 num_hit, num_read, num_temp_read);
+ 		}
+ 		else
+ 		{
+ 			ExplainPropertyLong("Hit Blocks", num_hit, es);
+ 			ExplainPropertyLong("Read Blocks", num_read, es);
+ 			ExplainPropertyLong("Temp Read Blocks", num_temp_read, es);
+ 		}
+ 	}
+ 
  	/* Get ready to display the child plans */
  	haschildren = plan->initPlan ||
  		outerPlan(plan) ||
diff -cprN head/src/backend/executor/execMain.c work/src/backend/executor/execMain.c
*** head/src/backend/executor/execMain.c	Mon Sep 28 05:09:57 2009
--- work/src/backend/executor/execMain.c	Mon Oct  5 14:12:52 2009
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 267,272 ****
--- 267,273 ----
  	DestReceiver *dest;
  	bool		sendTuples;
  	MemoryContext oldcontext;
+ 	Instrumentation *save_TopInstrument = NULL;
  
  	/* sanity checks */
  	Assert(queryDesc != NULL);
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 282,288 ****
--- 283,293 ----
  
  	/* Allow instrumentation of ExecutorRun overall runtime */
  	if (queryDesc->totaltime)
+ 	{
  		InstrStartNode(queryDesc->totaltime);
+ 		save_TopInstrument = TopInstrument;
+ 		TopInstrument = queryDesc->totaltime;
+ 	}
  
  	/*
  	 * extract information from the query descriptor and the query feature.
*************** standard_ExecutorRun(QueryDesc *queryDes
*** 320,326 ****
--- 325,340 ----
  		(*dest->rShutdown) (dest);
  
  	if (queryDesc->totaltime)
+ 	{
  		InstrStopNode(queryDesc->totaltime, estate->es_processed);
+ 		if (save_TopInstrument)
+ 		{
+ 			save_TopInstrument->blks_hit += queryDesc->totaltime->blks_hit;
+ 			save_TopInstrument->blks_read += queryDesc->totaltime->blks_read;
+ 			save_TopInstrument->temp_blks_read += queryDesc->totaltime->temp_blks_read;
+ 		}
+ 		TopInstrument = save_TopInstrument;
+ 	}
  
  	MemoryContextSwitchTo(oldcontext);
  }
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	Fri Jan  2 02:23:41 2009
--- work/src/backend/executor/instrument.c	Mon Oct  5 14:13:52 2009
***************
*** 16,22 ****
--- 16,26 ----
  #include <unistd.h>
  
  #include "executor/instrument.h"
+ #include "storage/buf_internals.h"
+ #include "storage/bufmgr.h"
  
+ Instrumentation *CurrentInstrument = NULL;
+ Instrumentation *TopInstrument = NULL;
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,50 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* push stack */
+ 	instr->prev = CurrentInstrument;
+ 	CurrentInstrument = instr;
  }
  
  /* Exit from a plan node */
*************** void
*** 44,49 ****
--- 52,85 ----
  InstrStopNode(Instrumentation *instr, double nTuples)
  {
  	instr_time	endtime;
+ 	long		num_get;
+ 	long		num_hit;
+ 	long		num_read;
+ 	long		num_temp_read;
+ 
+ 	Assert(instr == CurrentInstrument);
+ 
+ 	num_get = ReadBufferCount + ReadLocalBufferCount;
+ 	num_hit = BufferHitCount + LocalBufferHitCount;
+ 	num_read = num_get - num_hit;
+ 	num_temp_read = BufFileReadCount;
+ 
+ 	/* count buffer usage per plan node */
+ 	instr->blks_hit += num_hit;
+ 	instr->blks_read += num_read;
+ 	instr->temp_blks_read += num_temp_read;
+ 
+ 	/* accumulate per-node buffer statistics into top node */
+ 	if (TopInstrument && TopInstrument != CurrentInstrument)
+ 	{
+ 		TopInstrument->blks_hit += num_hit;
+ 		TopInstrument->blks_read += num_read;
+ 		TopInstrument->temp_blks_read += num_temp_read;
+ 	}
+ 
+ 	/* reset buffer usage and pop stack */
+ 	ResetLocalBufferUsage();
+ 	CurrentInstrument = instr->prev;
  
  	/* count the returned tuples */
  	instr->tuplecount += nTuples;
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	Thu Jun 11 23:49:01 2009
--- work/src/backend/storage/buffer/bufmgr.c	Mon Oct  5 13:59:31 2009
*************** static bool IsForInput;
*** 79,84 ****
--- 79,94 ----
  /* local state for LockBufferForCleanup */
  static volatile BufferDesc *PinCountWaitBuf = NULL;
  
+ /* statistics counters for log_[parser|planner|executor|statement]_stats */
+ static long GlobalReadBufferCount;
+ static long GlobalReadLocalBufferCount;
+ static long GlobalBufferHitCount;
+ static long GlobalLocalBufferHitCount;
+ static long GlobalBufferFlushCount;
+ static long GlobalLocalBufferFlushCount;
+ static long GlobalBufFileReadCount;
+ static long GlobalBufFileWriteCount;
+ 
  
  static Buffer ReadBuffer_common(SMgrRelation reln, bool isLocalBuf,
  				  ForkNumber forkNum, BlockNumber blockNum,
*************** ShowBufferUsage(void)
*** 1620,1646 ****
  	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;
  }
--- 1630,1658 ----
  	float		hitrate;
  	float		localhitrate;
  
+ 	ResetLocalBufferUsage();
+ 
  	initStringInfo(&str);
  
! 	if (GlobalReadBufferCount == 0)
  		hitrate = 0.0;
  	else
! 		hitrate = (float) GlobalBufferHitCount *100.0 / GlobalReadBufferCount;
  
! 	if (GlobalReadLocalBufferCount == 0)
  		localhitrate = 0.0;
  	else
! 		localhitrate = (float) GlobalLocalBufferHitCount *100.0 / GlobalReadLocalBufferCount;
  
  	appendStringInfo(&str,
  	"!\tShared blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
! 		GlobalReadBufferCount - GlobalBufferHitCount, GlobalBufferFlushCount, hitrate);
  	appendStringInfo(&str,
  	"!\tLocal  blocks: %10ld read, %10ld written, buffer hit rate = %.2f%%\n",
! 		GlobalReadLocalBufferCount - GlobalLocalBufferHitCount, GlobalLocalBufferFlushCount, localhitrate);
  	appendStringInfo(&str,
  					 "!\tDirect blocks: %10ld read, %10ld written\n",
! 					 GlobalBufFileReadCount, GlobalBufFileWriteCount);
  
  	return str.data;
  }
*************** ResetBufferUsage(void)
*** 1656,1661 ****
--- 1668,1704 ----
  	LocalBufferFlushCount = 0;
  	BufFileReadCount = 0;
  	BufFileWriteCount = 0;
+ 
+ 	GlobalBufferHitCount = 0;
+ 	GlobalReadBufferCount = 0;
+ 	GlobalBufferFlushCount = 0;
+ 	GlobalLocalBufferHitCount = 0;
+ 	GlobalReadLocalBufferCount = 0;
+ 	GlobalLocalBufferFlushCount = 0;
+ 	GlobalBufFileReadCount = 0;
+ 	GlobalBufFileWriteCount = 0;
+ }
+ 
+ void
+ ResetLocalBufferUsage(void)
+ {
+ 	GlobalReadBufferCount += ReadBufferCount;
+ 	GlobalReadLocalBufferCount += ReadLocalBufferCount;
+ 	GlobalBufferHitCount += BufferHitCount;
+ 	GlobalLocalBufferHitCount += LocalBufferHitCount;
+ 	GlobalBufferFlushCount += BufferFlushCount;
+ 	GlobalLocalBufferFlushCount += LocalBufferFlushCount;
+ 	GlobalBufFileReadCount += BufFileReadCount;
+ 	GlobalBufFileWriteCount += BufFileWriteCount;
+ 
+ 	BufferHitCount = 0;
+ 	ReadBufferCount = 0;
+ 	BufferFlushCount = 0;
+ 	LocalBufferHitCount = 0;
+ 	ReadLocalBufferCount = 0;
+ 	LocalBufferFlushCount = 0;
+ 	BufFileReadCount = 0;
+ 	BufFileWriteCount = 0;
  }
  
  /*
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	Tue Sep  1 11:54:51 2009
--- work/src/backend/tcop/postgres.c	Mon Oct  5 11:50:46 2009
***************
*** 44,49 ****
--- 44,50 ----
  #include "catalog/pg_type.h"
  #include "commands/async.h"
  #include "commands/prepare.h"
+ #include "executor/instrument.h"
  #include "libpq/libpq.h"
  #include "libpq/pqformat.h"
  #include "libpq/pqsignal.h"
*************** PostgresMain(int argc, char *argv[], con
*** 3482,3487 ****
--- 3483,3492 ----
  		 */
  		doing_extended_query_message = false;
  
+ 		/* Reset buffer usage counters */
+ 		CurrentInstrument = TopInstrument = NULL;
+ 		ResetLocalBufferUsage();
+ 
  		/*
  		 * Release storage left over from prior query cycle, and create a new
  		 * query input buffer in the cleared MessageContext.
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	Mon Aug 10 14:46:50 2009
--- work/src/include/commands/explain.h	Mon Oct  5 11:50:46 2009
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	Fri Jan  2 02:23:59 2009
--- work/src/include/executor/instrument.h	Mon Oct  5 14:14:25 2009
*************** typedef struct Instrumentation
*** 29,36 ****
--- 29,45 ----
  	double		total;			/* Total total time (in seconds) */
  	double		ntuples;		/* Total tuples produced */
  	double		nloops;			/* # of run cycles for this node */
+ 	/* Buffer usage */
+ 	long		blks_hit;		/* # of buffer hits */
+ 	long		blks_read;		/* # of disk blocks read */
+ 	long		temp_blks_read;	/* # of temp blocks read */
+ 	/* previous node in stack */
+ 	struct Instrumentation *prev;
  } Instrumentation;
  
+ extern Instrumentation *CurrentInstrument;
+ extern Instrumentation *TopInstrument;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	Thu Jun 11 23:49:12 2009
--- work/src/include/storage/bufmgr.h	Mon Oct  5 11:50:46 2009
*************** extern void InitBufferPoolAccess(void);
*** 175,180 ****
--- 175,181 ----
  extern void InitBufferPoolBackend(void);
  extern char *ShowBufferUsage(void);
  extern void ResetBufferUsage(void);
+ extern void ResetLocalBufferUsage(void);
  extern void AtEOXact_Buffers(bool isCommit);
  extern void PrintBufferLeakWarning(Buffer buffer);
  extern void CheckPointBuffers(int flags);

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-08-11 09:26:35.209377000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-10-15 20:05:16.109810412 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 218,225 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
--- 229,238 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument &&
! 				(auto_explain_log_analyze || auto_explain_log_buffers));
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-08-11 09:26:35.209377000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-10-15 20:04:10.963807103 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-08-11 09:26:35.209377000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-10-15 20:04:10.963807103 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,157 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. Specifically, include the number of
+       buffer hits, number of disk blocks read, and number of local buffer read.
+       This parameter should be used with <literal>ANALYZE</literal> parameter.
+       Also, this parameter defaults to <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-10-13 09:24:03.097662000 +0900
--- work/src/backend/commands/explain.c	2009-10-15 20:04:10.964808301 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 127,132 ****
--- 127,134 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 150,155 ****
--- 152,162 ----
  							opt->defname)));
  	}
  
+ 	if (es.buffers && !es.analyze)
+ 		ereport(ERROR,
+ 			(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ 			 errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+ 
  	/* Convert parameter type data to the form parser wants */
  	getParamListTypes(params, &param_types, &num_params);
  
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1043,1048 ****
--- 1050,1079 ----
  			break;
  	}
  
+ 	/* Show buffer usage */
+ 	if (es->buffers)
+ 	{
+ 		const BufferUsage *usage = &planstate->instrument->bufusage;
+ 
+ 		if (es->format == EXPLAIN_FORMAT_TEXT)
+ 		{
+ 			appendStringInfoSpaces(es->str, es->indent * 2);
+ 			appendStringInfo(es->str, "Blocks Hit: %ld  Read: %ld  Temp Read: %ld\n",
+ 				usage->blks_hit, usage->blks_read, usage->temp_blks_read);
+ 		}
+ 		else
+ 		{
+ 			ExplainPropertyLong("Hit Blocks", usage->blks_hit, es);
+ 			ExplainPropertyLong("Read Blocks", usage->blks_read, es);
+ 			ExplainPropertyLong("Written Blocks", usage->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) ||
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-05 00:22:25.168790000 +0900
--- work/src/backend/executor/instrument.c	2009-10-15 20:10:08.807120586 +0900
***************
*** 17,22 ****
--- 17,26 ----
  
  #include "executor/instrument.h"
  
+ BufferUsage			pgBufferUsage;
+ 
+ static void BufferUsageAccumDiff(BufferUsage *dst,
+ 		const BufferUsage *add, const BufferUsage *sub);
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,49 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* initialize buffer usage per plan node */
+ 	instr->bufusage_start = pgBufferUsage;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 66,79 ----
  
  	INSTR_TIME_SET_ZERO(instr->starttime);
  
+ 	/*
+ 	 * Adds delta of buffer usage to node's count and resets counter to start
+ 	 * so that the counters are not double counted by parent nodes.
+ 	 */
+ 	BufferUsageAccumDiff(&instr->bufusage,
+ 		&pgBufferUsage, &instr->bufusage_start);
+ 	pgBufferUsage = instr->bufusage_start;
+ 
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 110,128 ----
  	instr->firsttuple = 0;
  	instr->tuplecount = 0;
  }
+ 
+ static void
+ BufferUsageAccumDiff(BufferUsage *dst,
+ 					 const BufferUsage *add,
+ 					 const BufferUsage *sub)
+ {
+ 	/* dst += add - sub */
+ 	dst->blks_hit += add->blks_hit - sub->blks_hit;
+ 	dst->blks_read += add->blks_read - sub->blks_read;
+ 	dst->blks_written += add->blks_written - sub->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;
+ }
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	2009-01-05 00:22:25.168790000 +0900
--- work/src/backend/storage/buffer/buf_init.c	2009-10-15 20:04:10.965870810 +0900
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-10-15 20:04:10.966906779 +0900
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.blks_hit++;
! 		else
! 			pgBufferUsage.blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/buffer/localbuf.c	2009-10-15 20:04:10.966906779 +0900
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/file/buffile.c	2009-10-15 20:04:10.966906779 +0900
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-10-13 09:24:03.097662000 +0900
--- work/src/backend/tcop/postgres.c	2009-10-15 20:04:10.967906967 +0900
*************** ResetUsage(void)
*** 3850,3856 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3850,3855 ----
*************** ShowUsage(const char *title)
*** 3861,3867 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3860,3865 ----
*************** ShowUsage(const char *title)
*** 3935,3944 ****
  					 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';
--- 3933,3938 ----
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-08-11 09:26:35.209377000 +0900
--- work/src/include/commands/explain.h	2009-10-15 20:04:10.968906657 +0900
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-05 00:22:25.168790000 +0900
--- work/src/include/executor/instrument.h	2009-10-15 20:09:54.963808044 +0900
***************
*** 16,21 ****
--- 16,33 ----
  #include "portability/instr_time.h"
  
  
+ typedef struct BufferUsage
+ {
+ 	long	blks_hit;			/* # of buffer hits at start */
+ 	long	blks_read;			/* # of disk blocks read at start */
+ 	long	blks_written;		/* # of disk blocks written at start */
+ 	long	local_blks_hit;		/* # of buffer hits at start */
+ 	long	local_blks_read;	/* # of disk blocks read at start */
+ 	long	local_blks_written;	/* # of disk blocks written at start */
+ 	long	temp_blks_read;		/* # of temp blocks read at start */
+ 	long	temp_blks_written;	/* # of temp blocks written at start */
+ } BufferUsage;
+ 
  typedef struct Instrumentation
  {
  	/* Info about current plan cycle: */
*************** typedef struct Instrumentation
*** 24,36 ****
--- 36,52 ----
  	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 BufferUsage		pgBufferUsage;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	2009-06-12 09:52:43.356212000 +0900
--- work/src/include/storage/buf_internals.h	2009-10-15 20:04:10.968906657 +0900
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-12 09:52:43.356212000 +0900
--- work/src/include/storage/bufmgr.h	2009-10-15 20:04:10.968906657 +0900
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-08-10 14:46:49.000000000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-11-24 10:04:50.868963605 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 218,225 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
--- 229,238 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument &&
! 				(auto_explain_log_analyze || auto_explain_log_buffers));
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-11-24 10:04:50.868963605 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-11-24 10:04:50.870421302 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,157 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. Specifically, include the number of
+       buffer hits, number of disk blocks read, and number of local buffer read.
+       This parameter should be used with <literal>ANALYZE</literal> parameter.
+       Also, this parameter defaults to <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-11-05 07:26:04.000000000 +0900
--- work/src/backend/commands/explain.c	2009-11-24 10:06:53.073015629 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 125,130 ****
--- 125,132 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 147,152 ****
--- 149,159 ----
  					 errmsg("unrecognized EXPLAIN option \"%s\"",
  							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
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1040,1045 ****
--- 1047,1076 ----
  			break;
  	}
  
+ 	/* Show buffer usage */
+ 	if (es->buffers)
+ 	{
+ 		const BufferUsage *usage = &planstate->instrument->bufusage;
+ 
+ 		if (es->format == EXPLAIN_FORMAT_TEXT)
+ 		{
+ 			appendStringInfoSpaces(es->str, es->indent * 2);
+ 			appendStringInfo(es->str, "Blocks Hit: %ld  Read: %ld  Temp Read: %ld\n",
+ 				usage->blks_hit, usage->blks_read, usage->temp_blks_read);
+ 		}
+ 		else
+ 		{
+ 			ExplainPropertyLong("Hit Blocks", usage->blks_hit, es);
+ 			ExplainPropertyLong("Read Blocks", usage->blks_read, es);
+ 			ExplainPropertyLong("Written Blocks", usage->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) ||
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-02 02:23:41.000000000 +0900
--- work/src/backend/executor/instrument.c	2009-11-24 10:04:50.871436243 +0900
***************
*** 17,22 ****
--- 17,26 ----
  
  #include "executor/instrument.h"
  
+ BufferUsage			pgBufferUsage;
+ 
+ static void BufferUsageAccumDiff(BufferUsage *dst,
+ 		const BufferUsage *add, const BufferUsage *sub);
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,49 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* initialize buffer usage per plan node */
+ 	instr->bufusage_start = pgBufferUsage;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 66,79 ----
  
  	INSTR_TIME_SET_ZERO(instr->starttime);
  
+ 	/*
+ 	 * Adds delta of buffer usage to node's count and resets counter to start
+ 	 * so that the counters are not double counted by parent nodes.
+ 	 */
+ 	BufferUsageAccumDiff(&instr->bufusage,
+ 		&pgBufferUsage, &instr->bufusage_start);
+ 	pgBufferUsage = instr->bufusage_start;
+ 
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 110,128 ----
  	instr->firsttuple = 0;
  	instr->tuplecount = 0;
  }
+ 
+ static void
+ BufferUsageAccumDiff(BufferUsage *dst,
+ 					 const BufferUsage *add,
+ 					 const BufferUsage *sub)
+ {
+ 	/* dst += add - sub */
+ 	dst->blks_hit += add->blks_hit - sub->blks_hit;
+ 	dst->blks_read += add->blks_read - sub->blks_read;
+ 	dst->blks_written += add->blks_written - sub->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;
+ }
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	2009-01-02 02:23:47.000000000 +0900
--- work/src/backend/storage/buffer/buf_init.c	2009-11-24 10:04:50.871436243 +0900
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-11-24 10:04:50.872386293 +0900
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.blks_hit++;
! 		else
! 			pgBufferUsage.blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/localbuf.c	2009-11-24 10:04:50.873458462 +0900
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/file/buffile.c	2009-11-24 10:04:50.873458462 +0900
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-11-05 07:26:06.000000000 +0900
--- work/src/backend/tcop/postgres.c	2009-11-24 10:04:50.874015639 +0900
*************** ResetUsage(void)
*** 3901,3907 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3901,3906 ----
*************** ShowUsage(const char *title)
*** 3912,3918 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3911,3916 ----
*************** ShowUsage(const char *title)
*** 3986,3995 ****
  					 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';
--- 3984,3989 ----
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-08-10 14:46:50.000000000 +0900
--- work/src/include/commands/explain.h	2009-11-24 10:04:50.875067601 +0900
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-02 02:23:59.000000000 +0900
--- work/src/include/executor/instrument.h	2009-11-24 10:04:50.875067601 +0900
***************
*** 16,21 ****
--- 16,33 ----
  #include "portability/instr_time.h"
  
  
+ typedef struct BufferUsage
+ {
+ 	long	blks_hit;			/* # of buffer hits at start */
+ 	long	blks_read;			/* # of disk blocks read at start */
+ 	long	blks_written;		/* # of disk blocks written at start */
+ 	long	local_blks_hit;		/* # of buffer hits at start */
+ 	long	local_blks_read;	/* # of disk blocks read at start */
+ 	long	local_blks_written;	/* # of disk blocks written at start */
+ 	long	temp_blks_read;		/* # of temp blocks read at start */
+ 	long	temp_blks_written;	/* # of temp blocks written at start */
+ } BufferUsage;
+ 
  typedef struct Instrumentation
  {
  	/* Info about current plan cycle: */
*************** typedef struct Instrumentation
*** 24,36 ****
--- 36,52 ----
  	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 BufferUsage		pgBufferUsage;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/buf_internals.h	2009-11-24 10:04:50.875067601 +0900
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/bufmgr.h	2009-11-24 10:04:50.875067601 +0900
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-08-10 14:46:49.000000000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-12-08 11:28:09.398644461 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 218,225 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
--- 229,238 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument &&
! 				(auto_explain_log_analyze || auto_explain_log_buffers));
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-12-08 11:28:09.399563675 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-12-08 11:42:32.165582000 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,161 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. Specifically, include the number of
+       hits/reads/writes of shared blocks and local blocks, and number of reads
+       and writes of temp blocks. Shared blocks contain global tables and
+       indexes, local blocks contain temporary tables and indexes, and temp
+       blocks contain disk blocks used in sort and materialized plans.
+       The value of a parent node contains values of its children.
+       This parameter should be used with <literal>ANALYZE</literal> parameter.
+       This parameter defaults to <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-11-05 07:26:04.000000000 +0900
--- work/src/backend/commands/explain.c	2009-12-08 11:51:06.599538966 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 125,130 ****
--- 125,132 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 148,153 ****
--- 150,160 ----
  							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).
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1040,1045 ****
--- 1047,1083 ----
  			break;
  	}
  
+ 	/* Show buffer usage */
+ 	if (es->buffers)
+ 	{
+ 		const BufferUsage *usage = &planstate->instrument->bufusage;
+ 
+ 		if (es->format == EXPLAIN_FORMAT_TEXT)
+ 		{
+ 			appendStringInfoSpaces(es->str, es->indent * 2);
+ 			appendStringInfo(es->str,
+ 				"Shared Blocks: (hit=%ld read=%ld written=%ld) "
+ 				"Local Blocks: (hit=%ld read=%ld written=%ld) "
+ 				"Temp Blocks: (read=%ld written=%ld)\n",
+ 				usage->shared_blks_hit, usage->shared_blks_read,
+ 				usage->shared_blks_written,
+ 				usage->local_blks_hit, usage->local_blks_read,
+ 				usage->local_blks_written,
+ 				usage->temp_blks_read, usage->temp_blks_written);
+ 		}
+ 		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) ||
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-02 02:23:41.000000000 +0900
--- work/src/backend/executor/instrument.c	2009-12-08 11:53:00.714541295 +0900
***************
*** 17,22 ****
--- 17,26 ----
  
  #include "executor/instrument.h"
  
+ BufferUsage			pgBufferUsage;
+ 
+ static void BufferUsageAccumDiff(BufferUsage *dst,
+ 		const BufferUsage *add, const BufferUsage *sub);
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,49 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* initialize buffer usage per plan node */
+ 	instr->bufusage_start = pgBufferUsage;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 66,78 ----
  
  	INSTR_TIME_SET_ZERO(instr->starttime);
  
+ 	/*
+ 	 * Adds delta of buffer usage to node's count and resets counter to start
+ 	 * so that the counters are not double counted by parent nodes.
+ 	 */
+ 	BufferUsageAccumDiff(&instr->bufusage,
+ 		&pgBufferUsage, &instr->bufusage_start);
+ 
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 109,127 ----
  	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;
+ }
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	2009-01-02 02:23:47.000000000 +0900
--- work/src/backend/storage/buffer/buf_init.c	2009-12-08 11:28:09.400644825 +0900
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-12-08 11:53:00.757645179 +0900
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.shared_blks_hit++;
! 		else
! 			pgBufferUsage.shared_blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.shared_blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/localbuf.c	2009-12-08 11:28:09.402644626 +0900
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/file/buffile.c	2009-12-08 11:28:09.402644626 +0900
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-11-05 07:26:06.000000000 +0900
--- work/src/backend/tcop/postgres.c	2009-12-08 11:28:09.403644636 +0900
*************** ResetUsage(void)
*** 3901,3907 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3901,3906 ----
*************** ShowUsage(const char *title)
*** 3912,3918 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3911,3916 ----
*************** ShowUsage(const char *title)
*** 3986,3995 ****
  					 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';
--- 3984,3989 ----
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-08-10 14:46:50.000000000 +0900
--- work/src/include/commands/explain.h	2009-12-08 11:28:09.404674074 +0900
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-02 02:23:59.000000000 +0900
--- work/src/include/executor/instrument.h	2009-12-08 11:52:03.376544810 +0900
***************
*** 16,21 ****
--- 16,33 ----
  #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 struct Instrumentation
  {
  	/* Info about current plan cycle: */
*************** typedef struct Instrumentation
*** 24,36 ****
--- 36,52 ----
  	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 BufferUsage		pgBufferUsage;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/buf_internals.h	2009-12-08 11:28:09.404674074 +0900
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/bufmgr.h	2009-12-08 11:28:09.405636486 +0900
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-08-10 14:46:49.000000000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-12-09 13:54:40.292404947 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 92,97 ****
--- 93,108 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 218,225 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
--- 229,238 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument &&
! 				(auto_explain_log_analyze || auto_explain_log_buffers));
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-12-09 13:54:40.293421709 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-08-10 14:46:50.000000000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-12-09 13:59:44.985468000 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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 } } [, ...] ) ] <replaceable class="parameter">statement</replaceable>
  EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
*************** ROLLBACK;
*** 140,145 ****
--- 140,162 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. 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 of an upper-level
+       node includes the blocks of all its child nodes. This parameter should
+       be used with <literal>ANALYZE</literal> parameter. It defaults to
+       <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-11-05 07:26:04.000000000 +0900
--- work/src/backend/commands/explain.c	2009-12-09 14:19:50.048388685 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 125,130 ****
--- 125,132 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 148,153 ****
--- 150,160 ----
  							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).
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1040,1045 ****
--- 1047,1083 ----
  			break;
  	}
  
+ 	/* Show buffer usage */
+ 	if (es->buffers)
+ 	{
+ 		const BufferUsage *usage = &planstate->instrument->bufusage;
+ 
+ 		if (es->format == EXPLAIN_FORMAT_TEXT)
+ 		{
+ 			appendStringInfoSpaces(es->str, es->indent * 2);
+ 			appendStringInfo(es->str,
+ 				"Blocks: (shared hit=%ld read=%ld written=%ld) "
+ 				"(local hit=%ld read=%ld written=%ld) "
+ 				"(temp read=%ld written=%ld)\n",
+ 				usage->shared_blks_hit, usage->shared_blks_read,
+ 				usage->shared_blks_written,
+ 				usage->local_blks_hit, usage->local_blks_read,
+ 				usage->local_blks_written,
+ 				usage->temp_blks_read, usage->temp_blks_written);
+ 		}
+ 		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) ||
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-02 02:23:41.000000000 +0900
--- work/src/backend/executor/instrument.c	2009-12-09 13:54:40.294422165 +0900
***************
*** 17,22 ****
--- 17,26 ----
  
  #include "executor/instrument.h"
  
+ BufferUsage			pgBufferUsage;
+ 
+ static void BufferUsageAccumDiff(BufferUsage *dst,
+ 		const BufferUsage *add, const BufferUsage *sub);
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,49 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* initialize buffer usage per plan node */
+ 	instr->bufusage_start = pgBufferUsage;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 66,78 ----
  
  	INSTR_TIME_SET_ZERO(instr->starttime);
  
+ 	/*
+ 	 * Adds delta of buffer usage to node's count and resets counter to start
+ 	 * so that the counters are not double counted by parent nodes.
+ 	 */
+ 	BufferUsageAccumDiff(&instr->bufusage,
+ 		&pgBufferUsage, &instr->bufusage_start);
+ 
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 109,127 ----
  	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;
+ }
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	2009-01-02 02:23:47.000000000 +0900
--- work/src/backend/storage/buffer/buf_init.c	2009-12-09 13:54:40.295553562 +0900
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-12-09 13:54:40.296426875 +0900
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.shared_blks_hit++;
! 		else
! 			pgBufferUsage.shared_blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.shared_blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/buffer/localbuf.c	2009-12-09 13:54:40.296426875 +0900
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	2009-06-11 23:49:01.000000000 +0900
--- work/src/backend/storage/file/buffile.c	2009-12-09 13:54:40.296426875 +0900
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-11-05 07:26:06.000000000 +0900
--- work/src/backend/tcop/postgres.c	2009-12-09 13:54:40.297410363 +0900
*************** ResetUsage(void)
*** 3901,3907 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3901,3906 ----
*************** ShowUsage(const char *title)
*** 3912,3918 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3911,3916 ----
*************** ShowUsage(const char *title)
*** 3986,3995 ****
  					 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';
--- 3984,3989 ----
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-08-10 14:46:50.000000000 +0900
--- work/src/include/commands/explain.h	2009-12-09 13:54:40.298406797 +0900
*************** typedef struct ExplainState
*** 29,34 ****
--- 29,35 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-02 02:23:59.000000000 +0900
--- work/src/include/executor/instrument.h	2009-12-09 13:54:40.298406797 +0900
***************
*** 16,21 ****
--- 16,33 ----
  #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 struct Instrumentation
  {
  	/* Info about current plan cycle: */
*************** typedef struct Instrumentation
*** 24,36 ****
--- 36,52 ----
  	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 BufferUsage		pgBufferUsage;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/buf_internals.h	2009-12-09 13:54:40.298406797 +0900
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-11 23:49:12.000000000 +0900
--- work/src/include/storage/bufmgr.h	2009-12-09 13:54:40.299427251 +0900
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	Fri Dec 11 10:47:06 2009
--- work/contrib/auto_explain/auto_explain.c	Fri Dec 11 11:08:04 2009
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 93,98 ****
--- 94,109 ----
  							 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,
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 219,226 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
--- 230,239 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument &&
! 				(auto_explain_log_analyze || auto_explain_log_buffers));
  			es.verbose = auto_explain_log_verbose;
+ 			es.buffers = (es.analyze && auto_explain_log_buffers);
  			es.format = auto_explain_log_format;
  
  			ExplainPrintPlan(&es, queryDesc);
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	Fri Dec 11 10:47:06 2009
--- work/doc/src/sgml/auto-explain.sgml	Fri Dec 11 11:08:04 2009
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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. Also, this
+       parameter only has effect if <varname>auto_explain.log_analyze</>
+       parameter is set.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
+     <term>
       <varname>auto_explain.log_format</varname> (<type>enum</type>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	Fri Dec 11 10:47:06 2009
--- work/doc/src/sgml/ref/explain.sgml	Fri Dec 11 11:34:58 2009
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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>
*************** ROLLBACK;
*** 140,145 ****
--- 140,162 ----
     </varlistentry>
  
     <varlistentry>
+     <term><literal>BUFFERS</literal></term>
+     <listitem>
+      <para>
+       Include information on the buffers. 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 of an upper-level
+       node includes the blocks of all its child nodes. This parameter should
+       be used with <literal>ANALYZE</literal> parameter. It defaults to
+       <literal>FALSE</literal>.
+      </para>
+     </listitem>
+    </varlistentry>
+ 
+    <varlistentry>
      <term><literal>FORMAT</literal></term>
      <listitem>
       <para>
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	Fri Dec 11 10:47:06 2009
--- work/src/backend/commands/explain.c	Fri Dec 11 11:32:15 2009
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 127,132 ****
--- 127,134 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 152,157 ****
--- 154,164 ----
  							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).
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1044,1049 ****
--- 1051,1134 ----
  			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) ||
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	Mon Jan  5 00:22:25 2009
--- work/src/backend/executor/instrument.c	Fri Dec 11 11:08:04 2009
***************
*** 17,22 ****
--- 17,26 ----
  
  #include "executor/instrument.h"
  
+ BufferUsage			pgBufferUsage;
+ 
+ static void BufferUsageAccumDiff(BufferUsage *dst,
+ 		const BufferUsage *add, const BufferUsage *sub);
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 41,49 ----
  		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
+ 
+ 	/* initialize buffer usage per plan node */
+ 	instr->bufusage_start = pgBufferUsage;
  }
  
  /* Exit from a plan node */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 66,78 ----
  
  	INSTR_TIME_SET_ZERO(instr->starttime);
  
+ 	/*
+ 	 * Adds delta of buffer usage to node's count and resets counter to start
+ 	 * so that the counters are not double counted by parent nodes.
+ 	 */
+ 	BufferUsageAccumDiff(&instr->bufusage,
+ 		&pgBufferUsage, &instr->bufusage_start);
+ 
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 109,127 ----
  	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;
+ }
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	Mon Jan  5 00:22:25 2009
--- work/src/backend/storage/buffer/buf_init.c	Fri Dec 11 11:08:04 2009
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	Fri Jun 12 09:52:43 2009
--- work/src/backend/storage/buffer/bufmgr.c	Fri Dec 11 11:08:04 2009
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.shared_blks_hit++;
! 		else
! 			pgBufferUsage.shared_blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.shared_blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	Fri Jun 12 09:52:43 2009
--- work/src/backend/storage/buffer/localbuf.c	Fri Dec 11 11:08:04 2009
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	Fri Jun 12 09:52:43 2009
--- work/src/backend/storage/file/buffile.c	Fri Dec 11 11:08:04 2009
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	Fri Nov  6 09:53:35 2009
--- work/src/backend/tcop/postgres.c	Fri Dec 11 11:08:04 2009
*************** ResetUsage(void)
*** 3901,3907 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3901,3906 ----
*************** ShowUsage(const char *title)
*** 3912,3918 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3911,3916 ----
*************** ShowUsage(const char *title)
*** 3986,3995 ****
  					 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';
--- 3984,3989 ----
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	Fri Dec 11 10:47:06 2009
--- work/src/include/commands/explain.h	Fri Dec 11 11:08:04 2009
*************** typedef struct ExplainState
*** 30,35 ****
--- 30,36 ----
  	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 */
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	Mon Jan  5 00:22:25 2009
--- work/src/include/executor/instrument.h	Fri Dec 11 11:08:04 2009
***************
*** 16,21 ****
--- 16,33 ----
  #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 struct Instrumentation
  {
  	/* Info about current plan cycle: */
*************** typedef struct Instrumentation
*** 24,36 ****
--- 36,52 ----
  	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 BufferUsage		pgBufferUsage;
+ 
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	Fri Jun 12 09:52:43 2009
--- work/src/include/storage/buf_internals.h	Fri Dec 11 11:08:04 2009
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	Fri Jun 12 09:52:43 2009
--- work/src/include/storage/bufmgr.h	Fri Dec 11 11:08:04 2009
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----

diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index 75ac9ca..88c33c0 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -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,
@@ -219,8 +230,10 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
 			ExplainState	es;
 
 			ExplainInitState(&es);
-			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
+			es.analyze = (queryDesc->doInstrument &&
+				(auto_explain_log_analyze || auto_explain_log_buffers));
 			es.verbose = auto_explain_log_verbose;
+			es.buffers = (es.analyze && auto_explain_log_buffers);
 			es.format = auto_explain_log_format;
 
 			ExplainPrintPlan(&es, queryDesc);
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index dd3f3fd..1b9d4d9 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -104,6 +104,25 @@ LOAD 'auto_explain';
 
    <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>)
     </term>
     <indexterm>
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 0d03469..c90a028 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -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>
@@ -140,6 +140,23 @@ ROLLBACK;
    </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. 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>
      <para>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 0437ffa..0aba2a7 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -127,6 +127,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);
@@ -152,6 +154,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).
@@ -1044,6 +1051,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) ||
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index d8d7039..8690581 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -17,6 +17,10 @@
 
 #include "executor/instrument.h"
 
+BufferUsage			pgBufferUsage;
+
+static void BufferUsageAccumDiff(BufferUsage *dst,
+		const BufferUsage *add, const BufferUsage *sub);
 
 /* Allocate new instrumentation structure(s) */
 Instrumentation *
@@ -37,6 +41,9 @@ InstrStartNode(Instrumentation *instr)
 		INSTR_TIME_SET_CURRENT(instr->starttime);
 	else
 		elog(DEBUG2, "InstrStartNode called twice in a row");
+
+	/* initialize buffer usage per plan node */
+	instr->bufusage_start = pgBufferUsage;
 }
 
 /* Exit from a plan node */
@@ -59,6 +66,13 @@ InstrStopNode(Instrumentation *instr, double nTuples)
 
 	INSTR_TIME_SET_ZERO(instr->starttime);
 
+	/*
+	 * Adds delta of buffer usage to node's count and resets counter to start
+	 * so that the counters are not double counted by parent nodes.
+	 */
+	BufferUsageAccumDiff(&instr->bufusage,
+		&pgBufferUsage, &instr->bufusage_start);
+
 	/* Is this the first tuple of this cycle? */
 	if (!instr->running)
 	{
@@ -95,3 +109,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;
+}
diff --git a/src/backend/storage/buffer/buf_init.c b/src/backend/storage/buffer/buf_init.c
index e0211f5..cc434c3 100644
--- a/src/backend/storage/buffer/buf_init.c
+++ b/src/backend/storage/buffer/buf_init.c
@@ -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:
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index de28374..276723d 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -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. */
@@ -1611,54 +1613,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.
  *
  *		As of PostgreSQL 8.0, buffer pins should get released by the
@@ -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
diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c
index 641f8e9..c7d25b9 100644
--- a/src/backend/storage/buffer/localbuf.c
+++ b/src/backend/storage/buffer/localbuf.c
@@ -16,6 +16,7 @@
 #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++;
 	}
 
 	/*
diff --git a/src/backend/storage/file/buffile.c b/src/backend/storage/file/buffile.c
index 436a82b..ebe77ff 100644
--- a/src/backend/storage/file/buffile.c
+++ b/src/backend/storage/file/buffile.c
@@ -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;
 
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 0672652..c985478 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -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';
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index ab48825..f97c0ee 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -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 */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 9846f6f..4bb6f91 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -16,6 +16,18 @@
 #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 struct Instrumentation
 {
 	/* Info about current plan cycle: */
@@ -24,13 +36,17 @@ typedef struct Instrumentation
 	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 BufferUsage		pgBufferUsage;
+
 extern Instrumentation *InstrAlloc(int n);
 extern void InstrStartNode(Instrumentation *instr);
 extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff --git a/src/include/storage/buf_internals.h b/src/include/storage/buf_internals.h
index 841cf09..42ed94e 100644
--- a/src/include/storage/buf_internals.h
+++ b/src/include/storage/buf_internals.h
@@ -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
diff --git a/src/include/storage/bufmgr.h b/src/include/storage/bufmgr.h
index d06eb77..f8d685c 100644
--- a/src/include/storage/bufmgr.h
+++ b/src/include/storage/bufmgr.h
@@ -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);

diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index f0d907d..491f479 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -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,
@@ -221,6 +232,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
 			ExplainInitState(&es);
 			es.analyze = (queryDesc->doInstrument && 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);
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index dd3f3fd..1b9d4d9 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -104,6 +104,25 @@ LOAD 'auto_explain';
 
    <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>)
     </term>
     <indexterm>
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 0d03469..6c68afd 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -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>
@@ -140,6 +140,24 @@ ROLLBACK;
    </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>
      <para>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 2067636..03a39c1 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -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).
@@ -1042,6 +1049,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) ||
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index d8d7039..8690581 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -17,6 +17,10 @@
 
 #include "executor/instrument.h"
 
+BufferUsage			pgBufferUsage;
+
+static void BufferUsageAccumDiff(BufferUsage *dst,
+		const BufferUsage *add, const BufferUsage *sub);
 
 /* Allocate new instrumentation structure(s) */
 Instrumentation *
@@ -37,6 +41,9 @@ InstrStartNode(Instrumentation *instr)
 		INSTR_TIME_SET_CURRENT(instr->starttime);
 	else
 		elog(DEBUG2, "InstrStartNode called twice in a row");
+
+	/* initialize buffer usage per plan node */
+	instr->bufusage_start = pgBufferUsage;
 }
 
 /* Exit from a plan node */
@@ -59,6 +66,13 @@ InstrStopNode(Instrumentation *instr, double nTuples)
 
 	INSTR_TIME_SET_ZERO(instr->starttime);
 
+	/*
+	 * Adds delta of buffer usage to node's count and resets counter to start
+	 * so that the counters are not double counted by parent nodes.
+	 */
+	BufferUsageAccumDiff(&instr->bufusage,
+		&pgBufferUsage, &instr->bufusage_start);
+
 	/* Is this the first tuple of this cycle? */
 	if (!instr->running)
 	{
@@ -95,3 +109,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;
+}
diff --git a/src/backend/storage/buffer/buf_init.c b/src/backend/storage/buffer/buf_init.c
index e0211f5..cc434c3 100644
--- a/src/backend/storage/buffer/buf_init.c
+++ b/src/backend/storage/buffer/buf_init.c
@@ -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:
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index de28374..276723d 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -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. */
@@ -1611,54 +1613,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.
  *
  *		As of PostgreSQL 8.0, buffer pins should get released by the
@@ -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
diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c
index 641f8e9..c7d25b9 100644
--- a/src/backend/storage/buffer/localbuf.c
+++ b/src/backend/storage/buffer/localbuf.c
@@ -16,6 +16,7 @@
 #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++;
 	}
 
 	/*
diff --git a/src/backend/storage/file/buffile.c b/src/backend/storage/file/buffile.c
index 436a82b..ebe77ff 100644
--- a/src/backend/storage/file/buffile.c
+++ b/src/backend/storage/file/buffile.c
@@ -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;
 
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 0672652..c985478 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -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';
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index ba2ba08..648b2be 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -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 */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 9846f6f..4bb6f91 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -16,6 +16,18 @@
 #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 struct Instrumentation
 {
 	/* Info about current plan cycle: */
@@ -24,13 +36,17 @@ typedef struct Instrumentation
 	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 BufferUsage		pgBufferUsage;
+
 extern Instrumentation *InstrAlloc(int n);
 extern void InstrStartNode(Instrumentation *instr);
 extern void InstrStopNode(Instrumentation *instr, double nTuples);
diff --git a/src/include/storage/buf_internals.h b/src/include/storage/buf_internals.h
index 841cf09..42ed94e 100644
--- a/src/include/storage/buf_internals.h
+++ b/src/include/storage/buf_internals.h
@@ -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
diff --git a/src/include/storage/bufmgr.h b/src/include/storage/bufmgr.h
index d06eb77..f8d685c 100644
--- a/src/include/storage/bufmgr.h
+++ b/src/include/storage/bufmgr.h
@@ -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);

diff -cprN head/contrib/auto_explain/auto_explain.c work/contrib/auto_explain/auto_explain.c
*** head/contrib/auto_explain/auto_explain.c	2009-12-14 09:21:34.822978000 +0900
--- work/contrib/auto_explain/auto_explain.c	2009-12-14 13:28:35.935089826 +0900
*************** PG_MODULE_MAGIC;
*** 22,27 ****
--- 22,28 ----
  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;
  
*************** _PG_init(void)
*** 93,98 ****
--- 94,109 ----
  							 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,
*************** explain_ExecutorStart(QueryDesc *queryDe
*** 147,153 ****
  	{
  		/* Enable per-node instrumentation iff log_analyze is required. */
  		if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
! 			queryDesc->doInstrument = true;
  	}
  
  	if (prev_ExecutorStart)
--- 158,168 ----
  	{
  		/* Enable per-node instrumentation iff log_analyze is required. */
  		if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
! 		{
! 			queryDesc->instrument_options |= INSTRUMENT_TIMER;
! 			if (auto_explain_log_buffers)
! 				queryDesc->instrument_options |= INSTRUMENT_BUFFERS;
! 		}
  	}
  
  	if (prev_ExecutorStart)
*************** explain_ExecutorStart(QueryDesc *queryDe
*** 167,173 ****
  			MemoryContext oldcxt;
  
  			oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
! 			queryDesc->totaltime = InstrAlloc(1);
  			MemoryContextSwitchTo(oldcxt);
  		}
  	}
--- 182,188 ----
  			MemoryContext oldcxt;
  
  			oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
! 			queryDesc->totaltime = InstrAlloc(1, INSTRUMENT_ALL);
  			MemoryContextSwitchTo(oldcxt);
  		}
  	}
*************** explain_ExecutorEnd(QueryDesc *queryDesc
*** 219,226 ****
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			es.analyze = (queryDesc->doInstrument && auto_explain_log_analyze);
  			es.verbose = auto_explain_log_verbose;
  			es.format = auto_explain_log_format;
  
  			ExplainBeginOutput(&es);
--- 234,242 ----
  			ExplainState	es;
  
  			ExplainInitState(&es);
! 			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);
diff -cprN head/contrib/pg_stat_statements/pg_stat_statements.c work/contrib/pg_stat_statements/pg_stat_statements.c
*** head/contrib/pg_stat_statements/pg_stat_statements.c	2009-12-03 13:12:47.180551000 +0900
--- work/contrib/pg_stat_statements/pg_stat_statements.c	2009-12-14 13:16:42.859766691 +0900
*************** pgss_ExecutorStart(QueryDesc *queryDesc,
*** 495,501 ****
  			MemoryContext oldcxt;
  
  			oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
! 			queryDesc->totaltime = InstrAlloc(1);
  			MemoryContextSwitchTo(oldcxt);
  		}
  	}
--- 495,501 ----
  			MemoryContext oldcxt;
  
  			oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
! 			queryDesc->totaltime = InstrAlloc(1, INSTRUMENT_ALL);
  			MemoryContextSwitchTo(oldcxt);
  		}
  	}
diff -cprN head/doc/src/sgml/auto-explain.sgml work/doc/src/sgml/auto-explain.sgml
*** head/doc/src/sgml/auto-explain.sgml	2009-12-11 10:47:06.949855000 +0900
--- work/doc/src/sgml/auto-explain.sgml	2009-12-14 11:32:38.419722226 +0900
*************** LOAD 'auto_explain';
*** 104,109 ****
--- 104,128 ----
  
     <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>)
      </term>
      <indexterm>
diff -cprN head/doc/src/sgml/ref/explain.sgml work/doc/src/sgml/ref/explain.sgml
*** head/doc/src/sgml/ref/explain.sgml	2009-12-11 10:47:06.949855000 +0900
--- work/doc/src/sgml/ref/explain.sgml	2009-12-14 11:32:38.419722226 +0900
*************** PostgreSQL documentation
*** 31,37 ****
  
   <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 ] [ VERBOSE ] <replaceable class="parameter">statement</replaceable>
  </synopsis>
   </refsynopsisdiv>
--- 31,37 ----
  
   <refsynopsisdiv>
  <synopsis>
! 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>
*************** ROLLBACK;
*** 140,145 ****
--- 140,163 ----
     </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>
       <para>
diff -cprN head/src/backend/commands/copy.c work/src/backend/commands/copy.c
*** head/src/backend/commands/copy.c	2009-11-24 10:04:57.883822000 +0900
--- work/src/backend/commands/copy.c	2009-12-14 13:21:28.588811970 +0900
*************** DoCopy(const CopyStmt *stmt, const char 
*** 1094,1100 ****
  		cstate->queryDesc = CreateQueryDesc(plan, queryString,
  											GetActiveSnapshot(),
  											InvalidSnapshot,
! 											dest, NULL, false);
  
  		/*
  		 * Call ExecutorStart to prepare the plan for execution.
--- 1094,1100 ----
  		cstate->queryDesc = CreateQueryDesc(plan, queryString,
  											GetActiveSnapshot(),
  											InvalidSnapshot,
! 											dest, NULL, 0);
  
  		/*
  		 * Call ExecutorStart to prepare the plan for execution.
diff -cprN head/src/backend/commands/explain.c work/src/backend/commands/explain.c
*** head/src/backend/commands/explain.c	2009-12-14 09:21:34.822978000 +0900
--- work/src/backend/commands/explain.c	2009-12-14 13:20:19.415713632 +0900
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 125,130 ****
--- 125,132 ----
  			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);
*************** ExplainQuery(ExplainStmt *stmt, const ch
*** 150,155 ****
--- 152,162 ----
  							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).
*************** ExplainOnePlan(PlannedStmt *plannedstmt,
*** 339,344 ****
--- 346,357 ----
  	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
*************** ExplainOnePlan(PlannedStmt *plannedstmt,
*** 349,355 ****
  	/* Create a QueryDesc requesting no output */
  	queryDesc = CreateQueryDesc(plannedstmt, queryString,
  								GetActiveSnapshot(), InvalidSnapshot,
! 								None_Receiver, params, es->analyze);
  
  	INSTR_TIME_SET_CURRENT(starttime);
  
--- 362,368 ----
  	/* Create a QueryDesc requesting no output */
  	queryDesc = CreateQueryDesc(plannedstmt, queryString,
  								GetActiveSnapshot(), InvalidSnapshot,
! 								None_Receiver, params, instrument_option);
  
  	INSTR_TIME_SET_CURRENT(starttime);
  
*************** ExplainNode(Plan *plan, PlanState *plans
*** 1042,1047 ****
--- 1055,1138 ----
  			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) ||
diff -cprN head/src/backend/commands/tablecmds.c work/src/backend/commands/tablecmds.c
*** head/src/backend/commands/tablecmds.c	2009-12-11 12:39:49.829461000 +0900
--- work/src/backend/commands/tablecmds.c	2009-12-14 13:21:28.546723185 +0900
*************** ExecuteTruncate(TruncateStmt *stmt)
*** 936,942 ****
  						  rel,
  						  0,	/* dummy rangetable index */
  						  CMD_DELETE,	/* don't need any index info */
! 						  false);
  		resultRelInfo++;
  	}
  	estate->es_result_relations = resultRelInfos;
--- 936,942 ----
  						  rel,
  						  0,	/* dummy rangetable index */
  						  CMD_DELETE,	/* don't need any index info */
! 						  0);
  		resultRelInfo++;
  	}
  	estate->es_result_relations = resultRelInfos;
diff -cprN head/src/backend/executor/execMain.c work/src/backend/executor/execMain.c
*** head/src/backend/executor/execMain.c	2009-12-14 09:21:34.822978000 +0900
--- work/src/backend/executor/execMain.c	2009-12-14 13:10:49.340796341 +0900
*************** standard_ExecutorStart(QueryDesc *queryD
*** 180,186 ****
  	 */
  	estate->es_snapshot = RegisterSnapshot(queryDesc->snapshot);
  	estate->es_crosscheck_snapshot = RegisterSnapshot(queryDesc->crosscheck_snapshot);
! 	estate->es_instrument = queryDesc->doInstrument;
  
  	/*
  	 * Initialize the plan state tree
--- 180,186 ----
  	 */
  	estate->es_snapshot = RegisterSnapshot(queryDesc->snapshot);
  	estate->es_crosscheck_snapshot = RegisterSnapshot(queryDesc->crosscheck_snapshot);
! 	estate->es_instrument = queryDesc->instrument_options;
  
  	/*
  	 * Initialize the plan state tree
*************** InitResultRelInfo(ResultRelInfo *resultR
*** 859,865 ****
  				  Relation resultRelationDesc,
  				  Index resultRelationIndex,
  				  CmdType operation,
! 				  bool doInstrument)
  {
  	/*
  	 * Check valid relkind ... parser and/or planner should have noticed this
--- 859,865 ----
  				  Relation resultRelationDesc,
  				  Index resultRelationIndex,
  				  CmdType operation,
! 				  int instrument_options)
  {
  	/*
  	 * Check valid relkind ... parser and/or planner should have noticed this
*************** InitResultRelInfo(ResultRelInfo *resultR
*** 914,923 ****
  			palloc0(n * sizeof(FmgrInfo));
  		resultRelInfo->ri_TrigWhenExprs = (List **)
  			palloc0(n * sizeof(List *));
! 		if (doInstrument)
! 			resultRelInfo->ri_TrigInstrument = InstrAlloc(n);
! 		else
! 			resultRelInfo->ri_TrigInstrument = NULL;
  	}
  	else
  	{
--- 914,921 ----
  			palloc0(n * sizeof(FmgrInfo));
  		resultRelInfo->ri_TrigWhenExprs = (List **)
  			palloc0(n * sizeof(List *));
! 		if (instrument_options)
! 			resultRelInfo->ri_TrigInstrument = InstrAlloc(n, instrument_options);
  	}
  	else
  	{
diff -cprN head/src/backend/executor/execProcnode.c work/src/backend/executor/execProcnode.c
*** head/src/backend/executor/execProcnode.c	2009-10-13 09:24:03.097662000 +0900
--- work/src/backend/executor/execProcnode.c	2009-12-14 13:10:30.437752389 +0900
*************** ExecInitNode(Plan *node, EState *estate,
*** 321,327 ****
  
  	/* Set up instrumentation for this node if requested */
  	if (estate->es_instrument)
! 		result->instrument = InstrAlloc(1);
  
  	return result;
  }
--- 321,327 ----
  
  	/* Set up instrumentation for this node if requested */
  	if (estate->es_instrument)
! 		result->instrument = InstrAlloc(1, estate->es_instrument);
  
  	return result;
  }
diff -cprN head/src/backend/executor/functions.c work/src/backend/executor/functions.c
*** head/src/backend/executor/functions.c	2009-11-06 09:53:35.834256000 +0900
--- work/src/backend/executor/functions.c	2009-12-14 13:21:28.623763373 +0900
*************** postquel_start(execution_state *es, SQLF
*** 414,420 ****
  								 fcache->src,
  								 snapshot, InvalidSnapshot,
  								 dest,
! 								 fcache->paramLI, false);
  	else
  		es->qd = CreateUtilityQueryDesc(es->stmt,
  										fcache->src,
--- 414,420 ----
  								 fcache->src,
  								 snapshot, InvalidSnapshot,
  								 dest,
! 								 fcache->paramLI, 0);
  	else
  		es->qd = CreateUtilityQueryDesc(es->stmt,
  										fcache->src,
diff -cprN head/src/backend/executor/instrument.c work/src/backend/executor/instrument.c
*** head/src/backend/executor/instrument.c	2009-01-05 00:22:25.168790000 +0900
--- work/src/backend/executor/instrument.c	2009-12-14 13:17:59.739739775 +0900
***************
*** 17,30 ****
  
  #include "executor/instrument.h"
  
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
! InstrAlloc(int n)
  {
! 	Instrumentation *instr = palloc0(n * sizeof(Instrumentation));
  
! 	/* we don't need to do any initialization except zero 'em */
  
  	return instr;
  }
--- 17,44 ----
  
  #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, int instrument_options)
  {
! 	Instrumentation *instr;
! 
! 	/* timer is always required for now */
! 	Assert(instrument_options & INSTRUMENT_TIMER);
  
! 	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;
  }
*************** InstrStartNode(Instrumentation *instr)
*** 37,42 ****
--- 51,60 ----
  		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 */
*************** InstrStopNode(Instrumentation *instr, do
*** 59,64 ****
--- 77,87 ----
  
  	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)
  	{
*************** InstrEndLoop(Instrumentation *instr)
*** 95,97 ****
--- 118,136 ----
  	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;
+ }
diff -cprN head/src/backend/executor/spi.c work/src/backend/executor/spi.c
*** head/src/backend/executor/spi.c	2009-11-06 09:53:35.834256000 +0900
--- work/src/backend/executor/spi.c	2009-12-14 13:21:28.660753362 +0900
*************** _SPI_execute_plan(SPIPlanPtr plan, Param
*** 1908,1914 ****
  										plansource->query_string,
  										snap, crosscheck_snapshot,
  										dest,
! 										paramLI, false);
  				res = _SPI_pquery(qdesc, fire_triggers,
  								  canSetTag ? tcount : 0);
  				FreeQueryDesc(qdesc);
--- 1908,1914 ----
  										plansource->query_string,
  										snap, crosscheck_snapshot,
  										dest,
! 										paramLI, 0);
  				res = _SPI_pquery(qdesc, fire_triggers,
  								  canSetTag ? tcount : 0);
  				FreeQueryDesc(qdesc);
diff -cprN head/src/backend/storage/buffer/buf_init.c work/src/backend/storage/buffer/buf_init.c
*** head/src/backend/storage/buffer/buf_init.c	2009-01-05 00:22:25.168790000 +0900
--- work/src/backend/storage/buffer/buf_init.c	2009-12-14 11:32:38.421721964 +0900
*************** BufferDesc *BufferDescriptors;
*** 22,37 ****
  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:
--- 22,27 ----
diff -cprN head/src/backend/storage/buffer/bufmgr.c work/src/backend/storage/buffer/bufmgr.c
*** head/src/backend/storage/buffer/bufmgr.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/buffer/bufmgr.c	2009-12-14 11:32:38.422722048 +0900
***************
*** 34,39 ****
--- 34,40 ----
  #include <unistd.h>
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "pg_trace.h"
  #include "pgstat.h"
*************** ReadBuffer_common(SMgrRelation smgr, boo
*** 300,321 ****
  
  	if (isLocalBuf)
  	{
- 		ReadLocalBufferCount++;
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			LocalBufferHitCount++;
  	}
  	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++;
  	}
  
  	/* At this point we do NOT hold any locks. */
--- 301,323 ----
  
  	if (isLocalBuf)
  	{
  		bufHdr = LocalBufferAlloc(smgr, forkNum, blockNum, &found);
  		if (found)
! 			pgBufferUsage.local_blks_hit++;
! 		else
! 			pgBufferUsage.local_blks_read++;
  	}
  	else
  	{
  		/*
  		 * 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)
! 			pgBufferUsage.shared_blks_hit++;
! 		else
! 			pgBufferUsage.shared_blks_read++;
  	}
  
  	/* At this point we do NOT hold any locks. */
*************** SyncOneBuffer(int buf_id, bool skip_rece
*** 1611,1664 ****
  
  
  /*
-  * 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.
   *
   *		As of PostgreSQL 8.0, buffer pins should get released by the
--- 1613,1618 ----
*************** FlushBuffer(volatile BufferDesc *buf, SM
*** 1916,1922 ****
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	BufferFlushCount++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
--- 1870,1876 ----
  			  (char *) BufHdrGetBlock(buf),
  			  false);
  
! 	pgBufferUsage.shared_blks_written++;
  
  	/*
  	 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
diff -cprN head/src/backend/storage/buffer/localbuf.c work/src/backend/storage/buffer/localbuf.c
*** head/src/backend/storage/buffer/localbuf.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/buffer/localbuf.c	2009-12-14 11:32:38.422722048 +0900
***************
*** 16,21 ****
--- 16,22 ----
  #include "postgres.h"
  
  #include "catalog/catalog.h"
+ #include "executor/instrument.h"
  #include "storage/buf_internals.h"
  #include "storage/bufmgr.h"
  #include "storage/smgr.h"
*************** LocalBufferAlloc(SMgrRelation smgr, Fork
*** 209,215 ****
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		LocalBufferFlushCount++;
  	}
  
  	/*
--- 210,216 ----
  		/* Mark not-dirty now in case we error out below */
  		bufHdr->flags &= ~BM_DIRTY;
  
! 		pgBufferUsage.local_blks_written++;
  	}
  
  	/*
diff -cprN head/src/backend/storage/file/buffile.c work/src/backend/storage/file/buffile.c
*** head/src/backend/storage/file/buffile.c	2009-06-12 09:52:43.356212000 +0900
--- work/src/backend/storage/file/buffile.c	2009-12-14 11:32:38.422722048 +0900
***************
*** 34,39 ****
--- 34,40 ----
  
  #include "postgres.h"
  
+ #include "executor/instrument.h"
  #include "storage/fd.h"
  #include "storage/buffile.h"
  #include "storage/buf_internals.h"
*************** BufFileLoadBuffer(BufFile *file)
*** 240,246 ****
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	BufFileReadCount++;
  }
  
  /*
--- 241,247 ----
  	file->offsets[file->curFile] += file->nbytes;
  	/* we choose not to advance curOffset here */
  
! 	pgBufferUsage.temp_blks_read++;
  }
  
  /*
*************** BufFileDumpBuffer(BufFile *file)
*** 304,310 ****
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		BufFileWriteCount++;
  	}
  	file->dirty = false;
  
--- 305,311 ----
  		file->curOffset += bytestowrite;
  		wpos += bytestowrite;
  
! 		pgBufferUsage.temp_blks_written++;
  	}
  	file->dirty = false;
  
diff -cprN head/src/backend/tcop/postgres.c work/src/backend/tcop/postgres.c
*** head/src/backend/tcop/postgres.c	2009-11-06 09:53:35.834256000 +0900
--- work/src/backend/tcop/postgres.c	2009-12-14 11:32:38.423855423 +0900
*************** ResetUsage(void)
*** 3901,3907 ****
  {
  	getrusage(RUSAGE_SELF, &Save_r);
  	gettimeofday(&Save_t, NULL);
- 	ResetBufferUsage();
  }
  
  void
--- 3901,3906 ----
*************** ShowUsage(const char *title)
*** 3912,3918 ****
  				sys;
  	struct timeval elapse_t;
  	struct rusage r;
- 	char	   *bufusage;
  
  	getrusage(RUSAGE_SELF, &r);
  	gettimeofday(&elapse_t, NULL);
--- 3911,3916 ----
*************** ShowUsage(const char *title)
*** 3986,3995 ****
  					 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';
--- 3984,3989 ----
diff -cprN head/src/backend/tcop/pquery.c work/src/backend/tcop/pquery.c
*** head/src/backend/tcop/pquery.c	2009-10-13 09:24:03.097662000 +0900
--- work/src/backend/tcop/pquery.c	2009-12-14 13:21:28.483752760 +0900
*************** CreateQueryDesc(PlannedStmt *plannedstmt
*** 67,73 ****
  				Snapshot crosscheck_snapshot,
  				DestReceiver *dest,
  				ParamListInfo params,
! 				bool doInstrument)
  {
  	QueryDesc  *qd = (QueryDesc *) palloc(sizeof(QueryDesc));
  
--- 67,73 ----
  				Snapshot crosscheck_snapshot,
  				DestReceiver *dest,
  				ParamListInfo params,
! 				int instrument_options)
  {
  	QueryDesc  *qd = (QueryDesc *) palloc(sizeof(QueryDesc));
  
*************** CreateQueryDesc(PlannedStmt *plannedstmt
*** 80,86 ****
  	qd->crosscheck_snapshot = RegisterSnapshot(crosscheck_snapshot);
  	qd->dest = dest;			/* output dest */
  	qd->params = params;		/* parameter values passed into query */
! 	qd->doInstrument = doInstrument;	/* instrumentation wanted? */
  
  	/* null these fields until set by ExecutorStart */
  	qd->tupDesc = NULL;
--- 80,86 ----
  	qd->crosscheck_snapshot = RegisterSnapshot(crosscheck_snapshot);
  	qd->dest = dest;			/* output dest */
  	qd->params = params;		/* parameter values passed into query */
! 	qd->instrument_options = instrument_options;	/* instrumentation wanted? */
  
  	/* null these fields until set by ExecutorStart */
  	qd->tupDesc = NULL;
*************** CreateUtilityQueryDesc(Node *utilitystmt
*** 111,117 ****
  	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 */
  
  	/* null these fields until set by ExecutorStart */
  	qd->tupDesc = NULL;
--- 111,117 ----
  	qd->crosscheck_snapshot = InvalidSnapshot;	/* RI check snapshot */
  	qd->dest = dest;			/* output dest */
  	qd->params = params;		/* parameter values passed into query */
! 	qd->instrument_options = false;	/* uninteresting for utilities */
  
  	/* null these fields until set by ExecutorStart */
  	qd->tupDesc = NULL;
*************** ProcessQuery(PlannedStmt *plan,
*** 178,184 ****
  	 */
  	queryDesc = CreateQueryDesc(plan, sourceText,
  								GetActiveSnapshot(), InvalidSnapshot,
! 								dest, params, false);
  
  	/*
  	 * Set up to collect AFTER triggers
--- 178,184 ----
  	 */
  	queryDesc = CreateQueryDesc(plan, sourceText,
  								GetActiveSnapshot(), InvalidSnapshot,
! 								dest, params, 0);
  
  	/*
  	 * Set up to collect AFTER triggers
*************** PortalStart(Portal portal, ParamListInfo
*** 515,521 ****
  											InvalidSnapshot,
  											None_Receiver,
  											params,
! 											false);
  
  				/*
  				 * We do *not* call AfterTriggerBeginQuery() here.	We assume
--- 515,521 ----
  											InvalidSnapshot,
  											None_Receiver,
  											params,
! 											0);
  
  				/*
  				 * We do *not* call AfterTriggerBeginQuery() here.	We assume
diff -cprN head/src/include/commands/explain.h work/src/include/commands/explain.h
*** head/src/include/commands/explain.h	2009-12-14 09:21:34.822978000 +0900
--- work/src/include/commands/explain.h	2009-12-14 11:32:38.424717292 +0900
*************** typedef struct ExplainState
*** 30,35 ****
--- 30,36 ----
  	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 */
diff -cprN head/src/include/executor/execdesc.h work/src/include/executor/execdesc.h
*** head/src/include/executor/execdesc.h	2009-01-05 00:22:25.168790000 +0900
--- work/src/include/executor/execdesc.h	2009-12-14 13:16:23.718736978 +0900
*************** typedef struct QueryDesc
*** 42,48 ****
  	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 */
  
  	/* These fields are set by ExecutorStart */
  	TupleDesc	tupDesc;		/* descriptor for result tuples */
--- 42,48 ----
  	Snapshot	crosscheck_snapshot;	/* crosscheck for RI update/delete */
  	DestReceiver *dest;			/* the destination for tuple output */
  	ParamListInfo params;		/* param values being passed in */
! 	int			instrument_options;		/* OR of InstrumentOption flags */
  
  	/* These fields are set by ExecutorStart */
  	TupleDesc	tupDesc;		/* descriptor for result tuples */
*************** extern QueryDesc *CreateQueryDesc(Planne
*** 60,66 ****
  				Snapshot crosscheck_snapshot,
  				DestReceiver *dest,
  				ParamListInfo params,
! 				bool doInstrument);
  
  extern QueryDesc *CreateUtilityQueryDesc(Node *utilitystmt,
  					   const char *sourceText,
--- 60,66 ----
  				Snapshot crosscheck_snapshot,
  				DestReceiver *dest,
  				ParamListInfo params,
! 				int instrument_options);
  
  extern QueryDesc *CreateUtilityQueryDesc(Node *utilitystmt,
  					   const char *sourceText,
diff -cprN head/src/include/executor/executor.h work/src/include/executor/executor.h
*** head/src/include/executor/executor.h	2009-12-09 13:45:22.745455000 +0900
--- work/src/include/executor/executor.h	2009-12-14 13:09:03.597764161 +0900
*************** extern void InitResultRelInfo(ResultRelI
*** 161,167 ****
  				  Relation resultRelationDesc,
  				  Index resultRelationIndex,
  				  CmdType operation,
! 				  bool doInstrument);
  extern ResultRelInfo *ExecGetTriggerResultRel(EState *estate, Oid relid);
  extern bool ExecContextForcesOids(PlanState *planstate, bool *hasoids);
  extern void ExecConstraints(ResultRelInfo *resultRelInfo,
--- 161,167 ----
  				  Relation resultRelationDesc,
  				  Index resultRelationIndex,
  				  CmdType operation,
! 				  int instrument_options);
  extern ResultRelInfo *ExecGetTriggerResultRel(EState *estate, Oid relid);
  extern bool ExecContextForcesOids(PlanState *planstate, bool *hasoids);
  extern void ExecConstraints(ResultRelInfo *resultRelInfo,
diff -cprN head/src/include/executor/instrument.h work/src/include/executor/instrument.h
*** head/src/include/executor/instrument.h	2009-01-05 00:22:25.168790000 +0900
--- work/src/include/executor/instrument.h	2009-12-14 13:17:12.753756326 +0900
***************
*** 16,37 ****
  #include "portability/instr_time.h"
  
  
  typedef struct Instrumentation
  {
  	/* Info about current plan cycle: */
  	bool		running;		/* TRUE if we've completed first tuple */
  	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 */
  	/* 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 */
  } Instrumentation;
  
! extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, double nTuples);
  extern void InstrEndLoop(Instrumentation *instr);
--- 16,61 ----
  #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 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);
diff -cprN head/src/include/nodes/execnodes.h work/src/include/nodes/execnodes.h
*** head/src/include/nodes/execnodes.h	2009-12-09 13:45:22.745455000 +0900
--- work/src/include/nodes/execnodes.h	2009-12-14 13:09:42.846822263 +0900
*************** typedef struct EState
*** 370,376 ****
  	uint32		es_processed;	/* # of tuples processed */
  	Oid			es_lastoid;		/* last oid processed (by INSERT) */
  
! 	bool		es_instrument;	/* true requests runtime instrumentation */
  	bool		es_select_into; /* true if doing SELECT INTO */
  	bool		es_into_oids;	/* true to generate OIDs in SELECT INTO */
  
--- 370,376 ----
  	uint32		es_processed;	/* # of tuples processed */
  	Oid			es_lastoid;		/* last oid processed (by INSERT) */
  
! 	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 */
  
diff -cprN head/src/include/storage/buf_internals.h work/src/include/storage/buf_internals.h
*** head/src/include/storage/buf_internals.h	2009-06-12 09:52:43.356212000 +0900
--- work/src/include/storage/buf_internals.h	2009-12-14 11:32:38.424717292 +0900
*************** extern PGDLLIMPORT BufferDesc *BufferDes
*** 173,188 ****
  /* 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
--- 173,178 ----
diff -cprN head/src/include/storage/bufmgr.h work/src/include/storage/bufmgr.h
*** head/src/include/storage/bufmgr.h	2009-06-12 09:52:43.356212000 +0900
--- work/src/include/storage/bufmgr.h	2009-12-14 11:32:38.424717292 +0900
*************** extern Buffer ReleaseAndReadBuffer(Buffe
*** 173,180 ****
  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);
--- 173,178 ----