Commit 93f94e35 authored by Tom Lane's avatar Tom Lane

Adjust timing units in pg_stat_statements.

Display total time and I/O timings in milliseconds, for consistency with
the units used for timings in the core statistics views.  The columns
remain of float8 type, so that sub-msec precision is available.  (At some
point we will probably want to convert the core views to use float8 type
for the same reason, but this patch does not touch that issue.)

This is a release-note-requiring change in the meaning of the total_time
column.  The I/O timing columns are new as of 9.2, so there is no
compatibility impact from redefining them.

Do some minor copy-editing in the documentation, too.
parent cdbad241
...@@ -101,7 +101,7 @@ typedef struct pgssHashKey ...@@ -101,7 +101,7 @@ typedef struct pgssHashKey
typedef struct Counters typedef struct Counters
{ {
int64 calls; /* # of times executed */ int64 calls; /* # of times executed */
double total_time; /* total execution time in seconds */ double total_time; /* total execution time, in msec */
int64 rows; /* total # of retrieved or affected rows */ int64 rows; /* total # of retrieved or affected rows */
int64 shared_blks_hit; /* # of shared buffer hits */ int64 shared_blks_hit; /* # of shared buffer hits */
int64 shared_blks_read; /* # of shared disk blocks read */ int64 shared_blks_read; /* # of shared disk blocks read */
...@@ -113,8 +113,8 @@ typedef struct Counters ...@@ -113,8 +113,8 @@ typedef struct Counters
int64 local_blks_written; /* # of local disk blocks written */ int64 local_blks_written; /* # of local disk blocks written */
int64 temp_blks_read; /* # of temp blocks read */ int64 temp_blks_read; /* # of temp blocks read */
int64 temp_blks_written; /* # of temp blocks written */ int64 temp_blks_written; /* # of temp blocks written */
double time_read; /* time spent reading in seconds */ double time_read; /* time spent reading, in msec */
double time_write; /* time spent writing in seconds */ double time_write; /* time spent writing, in msec */
double usage; /* usage factor */ double usage; /* usage factor */
} Counters; } Counters;
...@@ -752,7 +752,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) ...@@ -752,7 +752,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
pgss_store(queryDesc->sourceText, pgss_store(queryDesc->sourceText,
queryId, queryId,
queryDesc->totaltime->total, queryDesc->totaltime->total * 1000.0, /* convert to msec */
queryDesc->estate->es_processed, queryDesc->estate->es_processed,
&queryDesc->totaltime->bufusage, &queryDesc->totaltime->bufusage,
NULL); NULL);
...@@ -856,7 +856,7 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString, ...@@ -856,7 +856,7 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
pgss_store(queryString, pgss_store(queryString,
queryId, queryId,
INSTR_TIME_GET_DOUBLE(duration), INSTR_TIME_GET_MILLISEC(duration),
rows, rows,
&bufusage, &bufusage,
NULL); NULL);
...@@ -1021,9 +1021,9 @@ pgss_store(const char *query, uint32 queryId, ...@@ -1021,9 +1021,9 @@ pgss_store(const char *query, uint32 queryId,
e->counters.local_blks_written += bufusage->local_blks_written; e->counters.local_blks_written += bufusage->local_blks_written;
e->counters.temp_blks_read += bufusage->temp_blks_read; e->counters.temp_blks_read += bufusage->temp_blks_read;
e->counters.temp_blks_written += bufusage->temp_blks_written; e->counters.temp_blks_written += bufusage->temp_blks_written;
e->counters.time_read += INSTR_TIME_GET_DOUBLE(bufusage->time_read); e->counters.time_read += INSTR_TIME_GET_MILLISEC(bufusage->time_read);
e->counters.time_write += INSTR_TIME_GET_DOUBLE(bufusage->time_write); e->counters.time_write += INSTR_TIME_GET_MILLISEC(bufusage->time_write);
e->counters.usage += USAGE_EXEC(duration); e->counters.usage += USAGE_EXEC(total_time);
SpinLockRelease(&e->mutex); SpinLockRelease(&e->mutex);
} }
......
...@@ -75,7 +75,7 @@ ...@@ -75,7 +75,7 @@
<entry><structfield>total_time</structfield></entry> <entry><structfield>total_time</structfield></entry>
<entry><type>double precision</type></entry> <entry><type>double precision</type></entry>
<entry></entry> <entry></entry>
<entry>Total time spent in the statement, in seconds</entry> <entry>Total time spent in the statement, in milliseconds</entry>
</row> </row>
<row> <row>
...@@ -89,14 +89,14 @@ ...@@ -89,14 +89,14 @@
<entry><structfield>shared_blks_hit</structfield></entry> <entry><structfield>shared_blks_hit</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of shared blocks hits by the statement</entry> <entry>Total number of shared block cache hits by the statement</entry>
</row> </row>
<row> <row>
<entry><structfield>shared_blks_read</structfield></entry> <entry><structfield>shared_blks_read</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of shared blocks reads by the statement</entry> <entry>Total number of shared blocks read by the statement</entry>
</row> </row>
<row> <row>
...@@ -110,21 +110,21 @@ ...@@ -110,21 +110,21 @@
<entry><structfield>shared_blks_written</structfield></entry> <entry><structfield>shared_blks_written</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of shared blocks writes by the statement</entry> <entry>Total number of shared blocks written by the statement</entry>
</row> </row>
<row> <row>
<entry><structfield>local_blks_hit</structfield></entry> <entry><structfield>local_blks_hit</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of local blocks hits by the statement</entry> <entry>Total number of local block cache hits by the statement</entry>
</row> </row>
<row> <row>
<entry><structfield>local_blks_read</structfield></entry> <entry><structfield>local_blks_read</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of local blocks reads by the statement</entry> <entry>Total number of local blocks read by the statement</entry>
</row> </row>
<row> <row>
...@@ -138,21 +138,21 @@ ...@@ -138,21 +138,21 @@
<entry><structfield>local_blks_written</structfield></entry> <entry><structfield>local_blks_written</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of local blocks writes by the statement</entry> <entry>Total number of local blocks written by the statement</entry>
</row> </row>
<row> <row>
<entry><structfield>temp_blks_read</structfield></entry> <entry><structfield>temp_blks_read</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of temp blocks reads by the statement</entry> <entry>Total number of temp blocks read by the statement</entry>
</row> </row>
<row> <row>
<entry><structfield>temp_blks_written</structfield></entry> <entry><structfield>temp_blks_written</structfield></entry>
<entry><type>bigint</type></entry> <entry><type>bigint</type></entry>
<entry></entry> <entry></entry>
<entry>Total number of temp blocks writes by the statement</entry> <entry>Total number of temp blocks written by the statement</entry>
</row> </row>
<row> <row>
...@@ -160,7 +160,7 @@ ...@@ -160,7 +160,7 @@
<entry><type>double precision</type></entry> <entry><type>double precision</type></entry>
<entry></entry> <entry></entry>
<entry> <entry>
Total time the statement spent reading blocks, in seconds Total time the statement spent reading blocks, in milliseconds
(if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero) (if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
</entry> </entry>
</row> </row>
...@@ -170,7 +170,7 @@ ...@@ -170,7 +170,7 @@
<entry><type>double precision</type></entry> <entry><type>double precision</type></entry>
<entry></entry> <entry></entry>
<entry> <entry>
Total time the statement spent writing blocks, in seconds Total time the statement spent writing blocks, in milliseconds
(if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero) (if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
</entry> </entry>
</row> </row>
...@@ -285,7 +285,7 @@ ...@@ -285,7 +285,7 @@
Specify <literal>top</> to track top-level statements (those issued Specify <literal>top</> to track top-level statements (those issued
directly by clients), <literal>all</> to also track nested statements directly by clients), <literal>all</> to also track nested statements
(such as statements invoked within functions), or <literal>none</> to (such as statements invoked within functions), or <literal>none</> to
disable. disable statement statistics collection.
The default value is <literal>top</>. The default value is <literal>top</>.
Only superusers can change this setting. Only superusers can change this setting.
</para> </para>
...@@ -366,31 +366,31 @@ bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit / ...@@ -366,31 +366,31 @@ bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
-[ RECORD 1 ]--------------------------------------------------------------------- -[ RECORD 1 ]---------------------------------------------------------------------
query | UPDATE pgbench_branches SET bbalance = bbalance + ? WHERE bid = ?; query | UPDATE pgbench_branches SET bbalance = bbalance + ? WHERE bid = ?;
calls | 3000 calls | 3000
total_time | 9.60900100000002 total_time | 9609.00100000002
rows | 2836 rows | 2836
hit_percent | 99.9778970000200936 hit_percent | 99.9778970000200936
-[ RECORD 2 ]--------------------------------------------------------------------- -[ RECORD 2 ]---------------------------------------------------------------------
query | UPDATE pgbench_tellers SET tbalance = tbalance + ? WHERE tid = ?; query | UPDATE pgbench_tellers SET tbalance = tbalance + ? WHERE tid = ?;
calls | 3000 calls | 3000
total_time | 8.015156 total_time | 8015.156
rows | 2990 rows | 2990
hit_percent | 99.9731126579631345 hit_percent | 99.9731126579631345
-[ RECORD 3 ]--------------------------------------------------------------------- -[ RECORD 3 ]---------------------------------------------------------------------
query | copy pgbench_accounts from stdin query | copy pgbench_accounts from stdin
calls | 1 calls | 1
total_time | 0.310624 total_time | 310.624
rows | 100000 rows | 100000
hit_percent | 0.30395136778115501520 hit_percent | 0.30395136778115501520
-[ RECORD 4 ]--------------------------------------------------------------------- -[ RECORD 4 ]---------------------------------------------------------------------
query | UPDATE pgbench_accounts SET abalance = abalance + ? WHERE aid = ?; query | UPDATE pgbench_accounts SET abalance = abalance + ? WHERE aid = ?;
calls | 3000 calls | 3000
total_time | 0.271741999999997 total_time | 271.741999999997
rows | 3000 rows | 3000
hit_percent | 93.7968855088209426 hit_percent | 93.7968855088209426
-[ RECORD 5 ]--------------------------------------------------------------------- -[ RECORD 5 ]---------------------------------------------------------------------
query | alter table pgbench_accounts add primary key (aid) query | alter table pgbench_accounts add primary key (aid)
calls | 1 calls | 1
total_time | 0.08142 total_time | 81.42
rows | 0 rows | 0
hit_percent | 34.4947735191637631 hit_percent | 34.4947735191637631
</screen> </screen>
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment