Expose track_iotiming information via pg_stat_statements.
authorRobert Haas <rhaas@postgresql.org>
Tue, 27 Mar 2012 19:17:22 +0000 (15:17 -0400)
committerRobert Haas <rhaas@postgresql.org>
Tue, 27 Mar 2012 19:18:49 +0000 (15:18 -0400)
Ants Aasma, reviewed by Greg Smith, with very minor tweaks by me.

contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql
contrib/pg_stat_statements/pg_stat_statements--1.1.sql
contrib/pg_stat_statements/pg_stat_statements.c
doc/src/sgml/pgstatstatements.sgml

index 223271d0ce59108ecc82215e1dee61a251a53ec5..f976419d989c216f944aa0410958b6eaa2c3da6d 100644 (file)
@@ -28,7 +28,9 @@ CREATE FUNCTION pg_stat_statements(
     OUT local_blks_dirtied int8,
     OUT local_blks_written int8,
     OUT temp_blks_read int8,
-    OUT temp_blks_written int8
+    OUT temp_blks_written int8,
+    OUT time_read float8,
+    OUT time_write float8
 )
 RETURNS SETOF record
 AS 'MODULE_PATHNAME'
index 1233736c9c439bb21e387208a41518391c3e5825..f4bdf125da6d4c5030f9fb391d3ae4656daeea1d 100644 (file)
@@ -25,7 +25,9 @@ CREATE FUNCTION pg_stat_statements(
     OUT local_blks_dirtied int8,
     OUT local_blks_written int8,
     OUT temp_blks_read int8,
-    OUT temp_blks_written int8
+    OUT temp_blks_written int8,
+    OUT time_read float8,
+    OUT time_write float8
 )
 RETURNS SETOF record
 AS 'MODULE_PATHNAME'
index 914fbf270d7db4e13cad18e7fba1901c2df27618..5d3bea09b1b63df0dcfd1b1e0dc1817025190176 100644 (file)
@@ -85,6 +85,8 @@ typedef struct Counters
        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          time_read;              /* time spent reading in seconds */
+       double          time_write;             /* time spent writing in seconds */
        double          usage;                  /* usage factor */
 } Counters;
 
@@ -618,9 +620,9 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
                instr_time      start;
                instr_time      duration;
                uint64          rows = 0;
-               BufferUsage bufusage;
+               BufferUsage bufusage_start, bufusage;
 
-               bufusage = pgBufferUsage;
+               bufusage_start = pgBufferUsage;
                INSTR_TIME_SET_CURRENT(start);
 
                nested_level++;
@@ -651,25 +653,29 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
 
                /* calc differences of buffer counters. */
                bufusage.shared_blks_hit =
-                       pgBufferUsage.shared_blks_hit - bufusage.shared_blks_hit;
+                       pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit;
                bufusage.shared_blks_read =
-                       pgBufferUsage.shared_blks_read - bufusage.shared_blks_read;
+                       pgBufferUsage.shared_blks_read - bufusage_start.shared_blks_read;
                bufusage.shared_blks_dirtied =
-                       pgBufferUsage.shared_blks_dirtied - bufusage.shared_blks_dirtied;
+                       pgBufferUsage.shared_blks_dirtied - bufusage_start.shared_blks_dirtied;
                bufusage.shared_blks_written =
-                       pgBufferUsage.shared_blks_written - bufusage.shared_blks_written;
+                       pgBufferUsage.shared_blks_written - bufusage_start.shared_blks_written;
                bufusage.local_blks_hit =
-                       pgBufferUsage.local_blks_hit - bufusage.local_blks_hit;
+                       pgBufferUsage.local_blks_hit - bufusage_start.local_blks_hit;
                bufusage.local_blks_read =
-                       pgBufferUsage.local_blks_read - bufusage.local_blks_read;
+                       pgBufferUsage.local_blks_read - bufusage_start.local_blks_read;
                bufusage.local_blks_dirtied =
-                       pgBufferUsage.local_blks_dirtied - bufusage.local_blks_dirtied;
+                       pgBufferUsage.local_blks_dirtied - bufusage_start.local_blks_dirtied;
                bufusage.local_blks_written =
-                       pgBufferUsage.local_blks_written - bufusage.local_blks_written;
+                       pgBufferUsage.local_blks_written - bufusage_start.local_blks_written;
                bufusage.temp_blks_read =
-                       pgBufferUsage.temp_blks_read - bufusage.temp_blks_read;
+                       pgBufferUsage.temp_blks_read - bufusage_start.temp_blks_read;
                bufusage.temp_blks_written =
-                       pgBufferUsage.temp_blks_written - bufusage.temp_blks_written;
+                       pgBufferUsage.temp_blks_written - bufusage_start.temp_blks_written;
+               bufusage.time_read = pgBufferUsage.time_read;
+               INSTR_TIME_SUBTRACT(bufusage.time_read, bufusage_start.time_read);
+               bufusage.time_write = pgBufferUsage.time_write;
+               INSTR_TIME_SUBTRACT(bufusage.time_write, bufusage_start.time_write);
 
                pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows,
                                   &bufusage);
@@ -780,6 +786,8 @@ pgss_store(const char *query, double total_time, uint64 rows,
                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.time_read +=  INSTR_TIME_GET_DOUBLE(bufusage->time_read);
+               e->counters.time_write += INSTR_TIME_GET_DOUBLE(bufusage->time_write);
                e->counters.usage += usage;
                SpinLockRelease(&e->mutex);
        }
@@ -802,7 +810,7 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
 }
 
 #define PG_STAT_STATEMENTS_COLS_V1_0   14
-#define PG_STAT_STATEMENTS_COLS                        16
+#define PG_STAT_STATEMENTS_COLS                        18
 
 /*
  * Retrieve statement statistics.
@@ -819,7 +827,7 @@ pg_stat_statements(PG_FUNCTION_ARGS)
        bool            is_superuser = superuser();
        HASH_SEQ_STATUS hash_seq;
        pgssEntry  *entry;
-       bool            sql_supports_dirty_counters = true;
+       bool            sql_supports_v1_1_counters = true;
 
        if (!pgss || !pgss_hash)
                ereport(ERROR,
@@ -841,7 +849,7 @@ pg_stat_statements(PG_FUNCTION_ARGS)
        if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
                elog(ERROR, "return type must be a row type");
        if (tupdesc->natts == PG_STAT_STATEMENTS_COLS_V1_0)
-               sql_supports_dirty_counters = false;
+               sql_supports_v1_1_counters = false;
 
        per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
        oldcontext = MemoryContextSwitchTo(per_query_ctx);
@@ -899,18 +907,23 @@ pg_stat_statements(PG_FUNCTION_ARGS)
                values[i++] = Int64GetDatumFast(tmp.rows);
                values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
                values[i++] = Int64GetDatumFast(tmp.shared_blks_read);
-               if (sql_supports_dirty_counters)
+               if (sql_supports_v1_1_counters)
                        values[i++] = Int64GetDatumFast(tmp.shared_blks_dirtied);
                values[i++] = Int64GetDatumFast(tmp.shared_blks_written);
                values[i++] = Int64GetDatumFast(tmp.local_blks_hit);
                values[i++] = Int64GetDatumFast(tmp.local_blks_read);
-               if (sql_supports_dirty_counters)
+               if (sql_supports_v1_1_counters)
                        values[i++] = Int64GetDatumFast(tmp.local_blks_dirtied);
                values[i++] = Int64GetDatumFast(tmp.local_blks_written);
                values[i++] = Int64GetDatumFast(tmp.temp_blks_read);
                values[i++] = Int64GetDatumFast(tmp.temp_blks_written);
+               if (sql_supports_v1_1_counters)
+               {
+                       values[i++] = Float8GetDatumFast(tmp.time_read);
+                       values[i++] = Float8GetDatumFast(tmp.time_write);
+               }
 
-               Assert(i == sql_supports_dirty_counters ? \
+               Assert(i == sql_supports_v1_1_counters ? \
                        PG_STAT_STATEMENTS_COLS : PG_STAT_STATEMENTS_COLS_V1_0);
 
                tuplestore_putvalues(tupstore, tupdesc, values, nulls);
index ab34ca193a4edb28c2e9ff15690fed587c0b34ff..ca7bd4427411d35fb5aad1d53189a3dccc9bda28 100644 (file)
       <entry>Total number of temp blocks writes by the statement</entry>
      </row>
 
+     <row>
+      <entry><structfield>time_read</structfield></entry>
+      <entry><type>double precision</type></entry>
+      <entry></entry>
+      <entry>
+        Total time the statement spent reading blocks, in seconds
+        (if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
+      </entry>
+     </row>
+
+     <row>
+      <entry><structfield>time_write</structfield></entry>
+      <entry><type>double precision</type></entry>
+      <entry></entry>
+      <entry>
+        Total time the statement spent writing blocks, in seconds
+        (if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
+      </entry>
+     </row>
+
     </tbody>
    </tgroup>
   </table>