Add buffer access counters to pg_stat_statements.

This uses the same infrastructure with EXPLAIN BUFFERS to support
{shared|local}_blks_{hit|read|written} andtemp_blks_{read|written}
columns in the pg_stat_statements view. The dumped file format
also updated.

Thanks to Robert Haas for the review.

contrib/pg_stat_statements/pg_stat_statements.c

@@ -14,7 +14,7 @@
  * Copyright (c) 2008-2010, PostgreSQL Global Development Group
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.11 2010/01/02 16:57:32 momjian Exp $
+ *	  $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.12 2010/01/08 00:38:19 itagaki Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -26,6 +26,7 @@
 #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"
@@ -44,7 +45,7 @@ PG_MODULE_MAGIC;
 #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;
+static const uint32 PGSS_FILE_HEADER = 0x20100108;
 
 /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */
 #define USAGE_EXEC(duration)	(1.0)
@@ -75,10 +76,18 @@ typedef struct pgssHashKey
  */
 typedef struct Counters
 {
-	int64		calls;			/* # of times executed */
-	double		total_time;		/* total execution time in seconds */
-	int64		rows;			/* total # of retrieved or affected rows */
-	double		usage;			/* usage factor */
+	int64		calls;				/* # of times executed */
+	double		total_time;			/* total execution time in seconds */
+	int64		rows;				/* total # of retrieved or affected rows */
+	int64		shared_blks_hit;	/* # of shared buffer hits */
+	int64		shared_blks_read;	/* # of shared disk blocks read */
+	int64		shared_blks_written;/* # of shared disk blocks written */
+	int64		local_blks_hit;		/* # of local buffer hits */
+	int64		local_blks_read;	/* # of local disk blocks read */
+	int64		local_blks_written;	/* # of local disk blocks written */
+	int64		temp_blks_read;		/* # of temp blocks read */
+	int64		temp_blks_written;	/* # of temp blocks written */
+	double		usage;				/* usage factor */
 } Counters;
 
 /*
@@ -129,7 +138,8 @@ typedef enum
 	PGSS_TRACK_ALL				/* all statements, including nested ones */
 } PGSSTrackLevel;
 
-static const struct config_enum_entry track_options[] = {
+static const struct config_enum_entry track_options[] =
+{
 	{"none", PGSS_TRACK_NONE, false},
 	{"top", PGSS_TRACK_TOP, false},
 	{"all", PGSS_TRACK_ALL, false},
@@ -169,7 +179,8 @@ static void pgss_ProcessUtility(Node *parsetree,
 			   DestReceiver *dest, char *completionTag);
 static uint32 pgss_hash_fn(const void *key, Size keysize);
 static int	pgss_match_fn(const void *key1, const void *key2, Size keysize);
-static void pgss_store(const char *query, double total_time, uint64 rows);
+static void pgss_store(const char *query, double total_time, uint64 rows,
+					   const BufferUsage *bufusage);
 static Size pgss_memsize(void);
 static pgssEntry *entry_alloc(pgssHashKey *key);
 static void entry_dealloc(void);
@@ -558,7 +569,8 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
 
 		pgss_store(queryDesc->sourceText,
 				   queryDesc->totaltime->total,
-				   queryDesc->estate->es_processed);
+				   queryDesc->estate->es_processed,
+				   &queryDesc->totaltime->bufusage);
 	}
 
 	if (prev_ExecutorEnd)
@@ -580,7 +592,9 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
 		instr_time	start;
 		instr_time	duration;
 		uint64		rows = 0;
+		BufferUsage	bufusage;
 
+		bufusage = pgBufferUsage;
 		INSTR_TIME_SET_CURRENT(start);
 
 		nested_level++;
@@ -609,7 +623,26 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
 			sscanf(completionTag, "COPY " UINT64_FORMAT, &rows) != 1)
 			rows = 0;
 
-		pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows);
+		/* calc differences of buffer counters. */
+		bufusage.shared_blks_hit =
+			pgBufferUsage.shared_blks_hit - bufusage.shared_blks_hit;
+		bufusage.shared_blks_read =
+			pgBufferUsage.shared_blks_read - bufusage.shared_blks_read;
+		bufusage.shared_blks_written =
+			pgBufferUsage.shared_blks_written - bufusage.shared_blks_written;
+		bufusage.local_blks_hit =
+			pgBufferUsage.local_blks_hit - bufusage.local_blks_hit;
+		bufusage.local_blks_read =
+			pgBufferUsage.local_blks_read - bufusage.local_blks_read;
+		bufusage.local_blks_written =
+			pgBufferUsage.local_blks_written - bufusage.local_blks_written;
+		bufusage.temp_blks_read =
+			pgBufferUsage.temp_blks_read - bufusage.temp_blks_read;
+		bufusage.temp_blks_written =
+			pgBufferUsage.temp_blks_written - bufusage.temp_blks_written;
+
+		pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows,
+				   &bufusage);
 	}
 	else
 	{
@@ -660,7 +693,8 @@ pgss_match_fn(const void *key1, const void *key2, Size keysize)
  * Store some statistics for a statement.
  */
 static void
-pgss_store(const char *query, double total_time, uint64 rows)
+pgss_store(const char *query, double total_time, uint64 rows,
+		   const BufferUsage *bufusage)
 {
 	pgssHashKey key;
 	double		usage;
@@ -706,6 +740,14 @@ pgss_store(const char *query, double total_time, uint64 rows)
 		e->counters.calls += 1;
 		e->counters.total_time += total_time;
 		e->counters.rows += rows;
+		e->counters.shared_blks_hit += bufusage->shared_blks_hit;
+		e->counters.shared_blks_read += bufusage->shared_blks_read;
+		e->counters.shared_blks_written += bufusage->shared_blks_written;
+		e->counters.local_blks_hit += bufusage->local_blks_hit;
+		e->counters.local_blks_read += bufusage->local_blks_read;
+		e->counters.local_blks_written += bufusage->local_blks_written;
+		e->counters.temp_blks_read += bufusage->temp_blks_read;
+		e->counters.temp_blks_written += bufusage->temp_blks_written;
 		e->counters.usage += usage;
 		SpinLockRelease(&e->mutex);
 	}
@@ -727,7 +769,7 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
 	PG_RETURN_VOID();
 }
 
-#define PG_STAT_STATEMENTS_COLS		6
+#define PG_STAT_STATEMENTS_COLS		14
 
 /*
  * Retrieve statement statistics.
@@ -761,23 +803,13 @@ pg_stat_statements(PG_FUNCTION_ARGS)
 				 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 = 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;
 	rsinfo->setResult = tupstore;
@@ -829,6 +861,14 @@ pg_stat_statements(PG_FUNCTION_ARGS)
 		values[i++] = Int64GetDatumFast(tmp.calls);
 		values[i++] = Float8GetDatumFast(tmp.total_time);
 		values[i++] = Int64GetDatumFast(tmp.rows);
+		values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
+		values[i++] = Int64GetDatumFast(tmp.shared_blks_read);
+		values[i++] = Int64GetDatumFast(tmp.shared_blks_written);
+		values[i++] = Int64GetDatumFast(tmp.local_blks_hit);
+		values[i++] = Int64GetDatumFast(tmp.local_blks_read);
+		values[i++] = Int64GetDatumFast(tmp.local_blks_written);
+		values[i++] = Int64GetDatumFast(tmp.temp_blks_read);
+		values[i++] = Int64GetDatumFast(tmp.temp_blks_written);
 
 		Assert(i == PG_STAT_STATEMENTS_COLS);
 

contrib/pg_stat_statements/pg_stat_statements.sql.in

-/* $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.sql.in,v 1.1 2009/01/04 22:19:59 tgl Exp $ */
+/* $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.sql.in,v 1.2 2010/01/08 00:38:19 itagaki Exp $ */
 
 -- Adjust this setting to control where the objects get created.
 SET search_path = public;
@@ -15,7 +15,15 @@ CREATE FUNCTION pg_stat_statements(
     OUT query text,
     OUT calls int8,
     OUT total_time float8,
-    OUT rows int8
+    OUT rows int8,
+    OUT shared_blks_hit int8,
+    OUT shared_blks_read int8,
+    OUT shared_blks_written int8,
+    OUT local_blks_hit int8,
+    OUT local_blks_read int8,
+    OUT local_blks_written int8,
+    OUT temp_blks_read int8,
+    OUT temp_blks_written int8
 )
 RETURNS SETOF record
 AS 'MODULE_PATHNAME'

doc/src/sgml/pgstatstatements.sgml

-<!-- $PostgreSQL: pgsql/doc/src/sgml/pgstatstatements.sgml,v 1.5 2009/12/15 20:04:49 tgl Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/pgstatstatements.sgml,v 1.6 2010/01/08 00:38:20 itagaki Exp $ -->
 
 <sect1 id="pgstatstatements">
  <title>pg_stat_statements</title>
@@ -85,6 +85,62 @@
       <entry>Total number of rows retrieved or affected by the statement</entry>
      </row>
 
+     <row>
+      <entry><structfield>shared_blks_hit</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of shared blocks hits by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>shared_blks_read</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of shared blocks reads by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>shared_blks_written</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of shared blocks writes by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>local_blks_hit</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of local blocks hits by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>local_blks_read</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of local blocks reads by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>local_blks_written</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of local blocks writes 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 reads by the statement</entry>
+     </row>
+
+     <row>
+      <entry><structfield>temp_blks_written</structfield></entry>
+      <entry><type>bigint</type></entry>
+      <entry></entry>
+      <entry>Total number of temp blocks writes by the statement</entry>
+     </row>
+
     </tbody>
    </tgroup>
   </table>
@@ -239,35 +295,45 @@ pg_stat_statements.track = all
   <title>Sample output</title>
 
   <programlisting>
-$ pgbench -i bench
-
-postgres=# SELECT pg_stat_statements_reset();
+bench=# SELECT pg_stat_statements_reset();
 
+$ pgbench -i bench
 $ pgbench -c10 -t300 -M prepared bench
 
-postgres=# \x
-postgres=# SELECT * FROM pg_stat_statements ORDER BY total_time DESC LIMIT 3;
--[ RECORD 1 ]------------------------------------------------------------
-userid     | 10
-dbid       | 63781
-query      | UPDATE branches SET bbalance = bbalance + $1 WHERE bid = $2;
-calls      | 3000
-total_time | 20.716706
-rows       | 3000
--[ RECORD 2 ]------------------------------------------------------------
-userid     | 10
-dbid       | 63781
-query      | UPDATE tellers SET tbalance = tbalance + $1 WHERE tid = $2;
-calls      | 3000
-total_time | 17.1107649999999
-rows       | 3000
--[ RECORD 3 ]------------------------------------------------------------
-userid     | 10
-dbid       | 63781
-query      | UPDATE accounts SET abalance = abalance + $1 WHERE aid = $2;
-calls      | 3000
-total_time | 0.645601
-rows       | 3000
+bench=# \x
+bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
+               nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
+          FROM pg_stat_statements ORDER BY total_time DESC LIMIT 5;
+-[ RECORD 1 ]---------------------------------------------------------------------
+query       | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2;
+calls       | 3000
+total_time  | 9.60900100000002
+rows        | 2836
+hit_percent | 99.9778970000200936
+-[ RECORD 2 ]---------------------------------------------------------------------
+query       | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2;
+calls       | 3000
+total_time  | 8.015156
+rows        | 2990
+hit_percent | 99.9731126579631345
+-[ RECORD 3 ]---------------------------------------------------------------------
+query       | copy pgbench_accounts from stdin
+calls       | 1
+total_time  | 0.310624
+rows        | 100000
+hit_percent | 0.30395136778115501520
+-[ RECORD 4 ]---------------------------------------------------------------------
+query       | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2;
+calls       | 3000
+total_time  | 0.271741999999997
+rows        | 3000
+hit_percent | 93.7968855088209426
+-[ RECORD 5 ]---------------------------------------------------------------------
+query       | alter table pgbench_accounts add primary key (aid)
+calls       | 1
+total_time  | 0.08142
+rows        | 0
+hit_percent | 34.4947735191637631
   </programlisting>
  </sect2>