Add buffer access counters to pg_stat_statements.
authorItagaki Takahiro <itagaki.takahiro@gmail.com>
Fri, 8 Jan 2010 00:38:20 +0000 (00:38 +0000)
committerItagaki Takahiro <itagaki.takahiro@gmail.com>
Fri, 8 Jan 2010 00:38:20 +0000 (00:38 +0000)
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
contrib/pg_stat_statements/pg_stat_statements.sql.in
doc/src/sgml/pgstatstatements.sgml

index 75fda12452a09f85adbc90bad98b4f85d25df8b8..11dfb6280ad25f98d52a6a3586863a312b8cbf86 100644 (file)
@@ -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);
 
index 7655136ed987f6c016fb1c18cc46540ff64e5294..cf82a0e3dc8e518f70c619ae933e6b9f4b637242 100644 (file)
@@ -1,4 +1,4 @@
-/* $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'
index 470902152fff437296726c76c29b702799ae212c..3bd3d60d765d9c0e3123ee65b2da30352311b6a3 100644 (file)
@@ -1,4 +1,4 @@
-<!-- $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>
       <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>