Skip to content

Commit 93f94e3

Browse files
tglsfdctglsfdc
committed
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.
1 parent cdbad24 commit 93f94e3

File tree

2 files changed

+25
-25
lines changed

2 files changed

+25
-25
lines changed

‎contrib/pg_stat_statements/pg_stat_statements.c

+8-8
Original file line numberDiff line numberDiff line change
@@ -101,7 +101,7 @@ typedef struct pgssHashKey
101101
typedef struct Counters
102102
{
103103
int64 calls; /* # of times executed */
104-
double total_time; /* total execution time in seconds */
104+
double total_time; /* total execution time, in msec */
105105
int64 rows; /* total # of retrieved or affected rows */
106106
int64 shared_blks_hit; /* # of shared buffer hits */
107107
int64 shared_blks_read; /* # of shared disk blocks read */
@@ -113,8 +113,8 @@ typedef struct Counters
113113
int64 local_blks_written; /* # of local disk blocks written */
114114
int64 temp_blks_read; /* # of temp blocks read */
115115
int64 temp_blks_written; /* # of temp blocks written */
116-
double time_read; /* time spent reading in seconds */
117-
double time_write; /* time spent writing in seconds */
116+
double time_read; /* time spent reading, in msec */
117+
double time_write; /* time spent writing, in msec */
118118
double usage; /* usage factor */
119119
} Counters;
120120

@@ -752,7 +752,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
752752

753753
pgss_store(queryDesc->sourceText,
754754
queryId,
755-
queryDesc->totaltime->total,
755+
queryDesc->totaltime->total * 1000.0, /* convert to msec */
756756
queryDesc->estate->es_processed,
757757
&queryDesc->totaltime->bufusage,
758758
NULL);
@@ -856,7 +856,7 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString,
856856

857857
pgss_store(queryString,
858858
queryId,
859-
INSTR_TIME_GET_DOUBLE(duration),
859+
INSTR_TIME_GET_MILLISEC(duration),
860860
rows,
861861
&bufusage,
862862
NULL);
@@ -1021,9 +1021,9 @@ pgss_store(const char *query, uint32 queryId,
10211021
e->counters.local_blks_written += bufusage->local_blks_written;
10221022
e->counters.temp_blks_read += bufusage->temp_blks_read;
10231023
e->counters.temp_blks_written += bufusage->temp_blks_written;
1024-
e->counters.time_read += INSTR_TIME_GET_DOUBLE(bufusage->time_read);
1025-
e->counters.time_write += INSTR_TIME_GET_DOUBLE(bufusage->time_write);
1026-
e->counters.usage += USAGE_EXEC(duration);
1024+
e->counters.time_read += INSTR_TIME_GET_MILLISEC(bufusage->time_read);
1025+
e->counters.time_write += INSTR_TIME_GET_MILLISEC(bufusage->time_write);
1026+
e->counters.usage += USAGE_EXEC(total_time);
10271027

10281028
SpinLockRelease(&e->mutex);
10291029
}

‎doc/src/sgml/pgstatstatements.sgml

+17-17
Original file line numberDiff line numberDiff line change
@@ -75,7 +75,7 @@
7575
<entry><structfield>total_time</structfield></entry>
7676
<entry><type>double precision</type></entry>
7777
<entry></entry>
78-
<entry>Total time spent in the statement, in seconds</entry>
78+
<entry>Total time spent in the statement, in milliseconds</entry>
7979
</row>
8080

8181
<row>
@@ -89,14 +89,14 @@
8989
<entry><structfield>shared_blks_hit</structfield></entry>
9090
<entry><type>bigint</type></entry>
9191
<entry></entry>
92-
<entry>Total number of shared blocks hits by the statement</entry>
92+
<entry>Total number of shared block cache hits by the statement</entry>
9393
</row>
9494

9595
<row>
9696
<entry><structfield>shared_blks_read</structfield></entry>
9797
<entry><type>bigint</type></entry>
9898
<entry></entry>
99-
<entry>Total number of shared blocks reads by the statement</entry>
99+
<entry>Total number of shared blocks read by the statement</entry>
100100
</row>
101101

102102
<row>
@@ -110,21 +110,21 @@
110110
<entry><structfield>shared_blks_written</structfield></entry>
111111
<entry><type>bigint</type></entry>
112112
<entry></entry>
113-
<entry>Total number of shared blocks writes by the statement</entry>
113+
<entry>Total number of shared blocks written by the statement</entry>
114114
</row>
115115

116116
<row>
117117
<entry><structfield>local_blks_hit</structfield></entry>
118118
<entry><type>bigint</type></entry>
119119
<entry></entry>
120-
<entry>Total number of local blocks hits by the statement</entry>
120+
<entry>Total number of local block cache hits by the statement</entry>
121121
</row>
122122

123123
<row>
124124
<entry><structfield>local_blks_read</structfield></entry>
125125
<entry><type>bigint</type></entry>
126126
<entry></entry>
127-
<entry>Total number of local blocks reads by the statement</entry>
127+
<entry>Total number of local blocks read by the statement</entry>
128128
</row>
129129

130130
<row>
@@ -138,29 +138,29 @@
138138
<entry><structfield>local_blks_written</structfield></entry>
139139
<entry><type>bigint</type></entry>
140140
<entry></entry>
141-
<entry>Total number of local blocks writes by the statement</entry>
141+
<entry>Total number of local blocks written by the statement</entry>
142142
</row>
143143

144144
<row>
145145
<entry><structfield>temp_blks_read</structfield></entry>
146146
<entry><type>bigint</type></entry>
147147
<entry></entry>
148-
<entry>Total number of temp blocks reads by the statement</entry>
148+
<entry>Total number of temp blocks read by the statement</entry>
149149
</row>
150150

151151
<row>
152152
<entry><structfield>temp_blks_written</structfield></entry>
153153
<entry><type>bigint</type></entry>
154154
<entry></entry>
155-
<entry>Total number of temp blocks writes by the statement</entry>
155+
<entry>Total number of temp blocks written by the statement</entry>
156156
</row>
157157

158158
<row>
159159
<entry><structfield>time_read</structfield></entry>
160160
<entry><type>double precision</type></entry>
161161
<entry></entry>
162162
<entry>
163-
Total time the statement spent reading blocks, in seconds
163+
Total time the statement spent reading blocks, in milliseconds
164164
(if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
165165
</entry>
166166
</row>
@@ -170,7 +170,7 @@
170170
<entry><type>double precision</type></entry>
171171
<entry></entry>
172172
<entry>
173-
Total time the statement spent writing blocks, in seconds
173+
Total time the statement spent writing blocks, in milliseconds
174174
(if <xref linkend="guc-track-iotiming"> is enabled, otherwise zero)
175175
</entry>
176176
</row>
@@ -285,7 +285,7 @@
285285
Specify <literal>top</> to track top-level statements (those issued
286286
directly by clients), <literal>all</> to also track nested statements
287287
(such as statements invoked within functions), or <literal>none</> to
288-
disable.
288+
disable statement statistics collection.
289289
The default value is <literal>top</>.
290290
Only superusers can change this setting.
291291
</para>
@@ -366,31 +366,31 @@ bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
366366
-[ RECORD 1 ]---------------------------------------------------------------------
367367
query | UPDATE pgbench_branches SET bbalance = bbalance + ? WHERE bid = ?;
368368
calls | 3000
369-
total_time | 9.60900100000002
369+
total_time | 9609.00100000002
370370
rows | 2836
371371
hit_percent | 99.9778970000200936
372372
-[ RECORD 2 ]---------------------------------------------------------------------
373373
query | UPDATE pgbench_tellers SET tbalance = tbalance + ? WHERE tid = ?;
374374
calls | 3000
375-
total_time | 8.015156
375+
total_time | 8015.156
376376
rows | 2990
377377
hit_percent | 99.9731126579631345
378378
-[ RECORD 3 ]---------------------------------------------------------------------
379379
query | copy pgbench_accounts from stdin
380380
calls | 1
381-
total_time | 0.310624
381+
total_time | 310.624
382382
rows | 100000
383383
hit_percent | 0.30395136778115501520
384384
-[ RECORD 4 ]---------------------------------------------------------------------
385385
query | UPDATE pgbench_accounts SET abalance = abalance + ? WHERE aid = ?;
386386
calls | 3000
387-
total_time | 0.271741999999997
387+
total_time | 271.741999999997
388388
rows | 3000
389389
hit_percent | 93.7968855088209426
390390
-[ RECORD 5 ]---------------------------------------------------------------------
391391
query | alter table pgbench_accounts add primary key (aid)
392392
calls | 1
393-
total_time | 0.08142
393+
total_time | 81.42
394394
rows | 0
395395
hit_percent | 34.4947735191637631
396396
</screen>

0 commit comments

Comments
 (0)