Skip to content

Commit 57d6aea

Browse files
mhagandermhagander
committed
Add JIT counters to pg_stat_statements
This adds cumulative counters for jit operations to pg_stat_statements, making it easier to diagnose how JIT is used in an installation. These changes merge into the 1.10 changes applied in 76cbf7e without creating a new version. Reviewed-By: Julien Rouhaud Discussion: https://www.postgresql.org/message-id/flat/CABUevEySt4NTYqvWzwyAW_0-jG1bjN-y+tykapAnA0FALOs+Lw@mail.gmail.com
1 parent dad9ba1 commit 57d6aea

File tree

4 files changed

+175
-41
lines changed

4 files changed

+175
-41
lines changed

‎contrib/pg_stat_statements/expected/oldextversions.out

Lines changed: 46 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -197,44 +197,52 @@ SELECT count(*) > 0 AS has_data FROM pg_stat_statements;
197197
-- New functions and views for pg_stat_statements in 1.10
198198
AlTER EXTENSION pg_stat_statements UPDATE TO '1.10';
199199
\d pg_stat_statements
200-
View "public.pg_stat_statements"
201-
Column | Type | Collation | Nullable | Default
202-
---------------------+------------------+-----------+----------+---------
203-
userid | oid | | |
204-
dbid | oid | | |
205-
toplevel | boolean | | |
206-
queryid | bigint | | |
207-
query | text | | |
208-
plans | bigint | | |
209-
total_plan_time | double precision | | |
210-
min_plan_time | double precision | | |
211-
max_plan_time | double precision | | |
212-
mean_plan_time | double precision | | |
213-
stddev_plan_time | double precision | | |
214-
calls | bigint | | |
215-
total_exec_time | double precision | | |
216-
min_exec_time | double precision | | |
217-
max_exec_time | double precision | | |
218-
mean_exec_time | double precision | | |
219-
stddev_exec_time | double precision | | |
220-
rows | bigint | | |
221-
shared_blks_hit | bigint | | |
222-
shared_blks_read | bigint | | |
223-
shared_blks_dirtied | bigint | | |
224-
shared_blks_written | bigint | | |
225-
local_blks_hit | bigint | | |
226-
local_blks_read | bigint | | |
227-
local_blks_dirtied | bigint | | |
228-
local_blks_written | bigint | | |
229-
temp_blks_read | bigint | | |
230-
temp_blks_written | bigint | | |
231-
blk_read_time | double precision | | |
232-
blk_write_time | double precision | | |
233-
temp_blk_read_time | double precision | | |
234-
temp_blk_write_time | double precision | | |
235-
wal_records | bigint | | |
236-
wal_fpi | bigint | | |
237-
wal_bytes | numeric | | |
200+
View "public.pg_stat_statements"
201+
Column | Type | Collation | Nullable | Default
202+
------------------------+------------------+-----------+----------+---------
203+
userid | oid | | |
204+
dbid | oid | | |
205+
toplevel | boolean | | |
206+
queryid | bigint | | |
207+
query | text | | |
208+
plans | bigint | | |
209+
total_plan_time | double precision | | |
210+
min_plan_time | double precision | | |
211+
max_plan_time | double precision | | |
212+
mean_plan_time | double precision | | |
213+
stddev_plan_time | double precision | | |
214+
calls | bigint | | |
215+
total_exec_time | double precision | | |
216+
min_exec_time | double precision | | |
217+
max_exec_time | double precision | | |
218+
mean_exec_time | double precision | | |
219+
stddev_exec_time | double precision | | |
220+
rows | bigint | | |
221+
shared_blks_hit | bigint | | |
222+
shared_blks_read | bigint | | |
223+
shared_blks_dirtied | bigint | | |
224+
shared_blks_written | bigint | | |
225+
local_blks_hit | bigint | | |
226+
local_blks_read | bigint | | |
227+
local_blks_dirtied | bigint | | |
228+
local_blks_written | bigint | | |
229+
temp_blks_read | bigint | | |
230+
temp_blks_written | bigint | | |
231+
blk_read_time | double precision | | |
232+
blk_write_time | double precision | | |
233+
temp_blk_read_time | double precision | | |
234+
temp_blk_write_time | double precision | | |
235+
wal_records | bigint | | |
236+
wal_fpi | bigint | | |
237+
wal_bytes | numeric | | |
238+
jit_functions | bigint | | |
239+
jit_generation_time | double precision | | |
240+
jit_inlining_count | bigint | | |
241+
jit_inlining_time | double precision | | |
242+
jit_optimization_count | bigint | | |
243+
jit_optimization_time | double precision | | |
244+
jit_emission_count | bigint | | |
245+
jit_emission_time | double precision | | |
238246

239247
SELECT count(*) > 0 AS has_data FROM pg_stat_statements;
240248
has_data

‎contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,15 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
4747
OUT temp_blk_write_time float8,
4848
OUT wal_records int8,
4949
OUT wal_fpi int8,
50-
OUT wal_bytes numeric
50+
OUT wal_bytes numeric,
51+
OUT jit_functions int8,
52+
OUT jit_generation_time float8,
53+
OUT jit_inlining_count int8,
54+
OUT jit_inlining_time float8,
55+
OUT jit_optimization_count int8,
56+
OUT jit_optimization_time float8,
57+
OUT jit_emission_count int8,
58+
OUT jit_emission_time float8
5159
)
5260
RETURNS SETOF record
5361
AS 'MODULE_PATHNAME', 'pg_stat_statements_1_10'

‎contrib/pg_stat_statements/pg_stat_statements.c

Lines changed: 48 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,7 @@
5252
#include "common/hashfn.h"
5353
#include "executor/instrument.h"
5454
#include "funcapi.h"
55+
#include "jit/jit.h"
5556
#include "mb/pg_wchar.h"
5657
#include "miscadmin.h"
5758
#include "optimizer/planner.h"
@@ -188,6 +189,17 @@ typedef struct Counters
188189
int64 wal_records; /* # of WAL records generated */
189190
int64 wal_fpi; /* # of WAL full page images generated */
190191
uint64 wal_bytes; /* total amount of WAL generated in bytes */
192+
int64 jit_functions; /* total number of JIT functions emitted */
193+
double jit_generation_time; /* total time to generate jit code */
194+
int64 jit_inlining_count; /* number of times inlining time has been
195+
* > 0 */
196+
double jit_inlining_time; /* total time to inline jit code */
197+
int64 jit_optimization_count; /* number of times optimization time
198+
* has been > 0 */
199+
double jit_optimization_time; /* total time to optimize jit code */
200+
int64 jit_emission_count; /* number of times emission time has been
201+
* > 0 */
202+
double jit_emission_time; /* total time to emit jit code */
191203
} Counters;
192204

193205
/*
@@ -330,6 +342,7 @@ static void pgss_store(const char *query, uint64 queryId,
330342
double total_time, uint64 rows,
331343
const BufferUsage *bufusage,
332344
const WalUsage *walusage,
345+
const struct JitInstrumentation *jitusage,
333346
JumbleState *jstate);
334347
static void pg_stat_statements_internal(FunctionCallInfo fcinfo,
335348
pgssVersion api_version,
@@ -854,6 +867,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate)
854867
0,
855868
NULL,
856869
NULL,
870+
NULL,
857871
jstate);
858872
}
859873

@@ -938,6 +952,7 @@ pgss_planner(Query *parse,
938952
0,
939953
&bufusage,
940954
&walusage,
955+
NULL,
941956
NULL);
942957
}
943958
else
@@ -1056,6 +1071,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
10561071
queryDesc->estate->es_processed,
10571072
&queryDesc->totaltime->bufusage,
10581073
&queryDesc->totaltime->walusage,
1074+
queryDesc->estate->es_jit ? &queryDesc->estate->es_jit->instr : NULL,
10591075
NULL);
10601076
}
10611077

@@ -1173,6 +1189,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
11731189
rows,
11741190
&bufusage,
11751191
&walusage,
1192+
NULL,
11761193
NULL);
11771194
}
11781195
else
@@ -1206,6 +1223,7 @@ pgss_store(const char *query, uint64 queryId,
12061223
double total_time, uint64 rows,
12071224
const BufferUsage *bufusage,
12081225
const WalUsage *walusage,
1226+
const struct JitInstrumentation *jitusage,
12091227
JumbleState *jstate)
12101228
{
12111229
pgssHashKey key;
@@ -1375,6 +1393,23 @@ pgss_store(const char *query, uint64 queryId,
13751393
e->counters.wal_records += walusage->wal_records;
13761394
e->counters.wal_fpi += walusage->wal_fpi;
13771395
e->counters.wal_bytes += walusage->wal_bytes;
1396+
if (jitusage)
1397+
{
1398+
e->counters.jit_functions += jitusage->created_functions;
1399+
e->counters.jit_generation_time += INSTR_TIME_GET_MILLISEC(jitusage->generation_counter);
1400+
1401+
if (INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter))
1402+
e->counters.jit_inlining_count++;
1403+
e->counters.jit_inlining_time += INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter);
1404+
1405+
if (INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter))
1406+
e->counters.jit_optimization_count++;
1407+
e->counters.jit_optimization_time += INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter);
1408+
1409+
if (INSTR_TIME_GET_MILLISEC(jitusage->emission_counter))
1410+
e->counters.jit_emission_count++;
1411+
e->counters.jit_emission_time += INSTR_TIME_GET_MILLISEC(jitusage->emission_counter);
1412+
}
13781413

13791414
SpinLockRelease(&e->mutex);
13801415
}
@@ -1424,8 +1459,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
14241459
#define PG_STAT_STATEMENTS_COLS_V1_3 23
14251460
#define PG_STAT_STATEMENTS_COLS_V1_8 32
14261461
#define PG_STAT_STATEMENTS_COLS_V1_9 33
1427-
#define PG_STAT_STATEMENTS_COLS_V1_10 35
1428-
#define PG_STAT_STATEMENTS_COLS 35 /* maximum of above */
1462+
#define PG_STAT_STATEMENTS_COLS_V1_10 43
1463+
#define PG_STAT_STATEMENTS_COLS 43 /* maximum of above */
14291464

14301465
/*
14311466
* Retrieve statement statistics.
@@ -1786,6 +1821,17 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
17861821
Int32GetDatum(-1));
17871822
values[i++] = wal_bytes;
17881823
}
1824+
if (api_version >= PGSS_V1_10)
1825+
{
1826+
values[i++] = Int64GetDatumFast(tmp.jit_functions);
1827+
values[i++] = Float8GetDatumFast(tmp.jit_generation_time);
1828+
values[i++] = Int64GetDatumFast(tmp.jit_inlining_count);
1829+
values[i++] = Float8GetDatumFast(tmp.jit_inlining_time);
1830+
values[i++] = Int64GetDatumFast(tmp.jit_optimization_count);
1831+
values[i++] = Float8GetDatumFast(tmp.jit_optimization_time);
1832+
values[i++] = Int64GetDatumFast(tmp.jit_emission_count);
1833+
values[i++] = Float8GetDatumFast(tmp.jit_emission_time);
1834+
}
17891835

17901836
Assert(i == (api_version == PGSS_V1_0 ? PG_STAT_STATEMENTS_COLS_V1_0 :
17911837
api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 :

‎doc/src/sgml/pgstatstatements.sgml

Lines changed: 72 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -401,6 +401,78 @@
401401
Total amount of WAL generated by the statement in bytes
402402
</para></entry>
403403
</row>
404+
405+
<row>
406+
<entry role="catalog_table_entry"><para role="column_definition">
407+
<structfield>jit_functions</structfield> <type>bigint</type>
408+
</para>
409+
<para>
410+
Total number of functions JIT-compiled by the statement
411+
</para></entry>
412+
</row>
413+
414+
<row>
415+
<entry role="catalog_table_entry"><para role="column_definition">
416+
<structfield>jit_generation_time</structfield> <type>bigint</type>
417+
</para>
418+
<para>
419+
Total time spent by the statement on generating JIT code, in milliseconds
420+
</para></entry>
421+
</row>
422+
423+
<row>
424+
<entry role="catalog_table_entry"><para role="column_definition">
425+
<structfield>jit_inlining_count</structfield> <type>bigint</type>
426+
</para>
427+
<para>
428+
Number of times functions have been inlined
429+
</para></entry>
430+
</row>
431+
432+
<row>
433+
<entry role="catalog_table_entry"><para role="column_definition">
434+
<structfield>jit_inlining_time</structfield> <type>bigint</type>
435+
</para>
436+
<para>
437+
Total time spent by the statement on inlining functions, in milliseconds
438+
</para></entry>
439+
</row>
440+
441+
<row>
442+
<entry role="catalog_table_entry"><para role="column_definition">
443+
<structfield>jit_optimization_count</structfield> <type>bigint</type>
444+
</para>
445+
<para>
446+
Number of times the statement has been optimized
447+
</para></entry>
448+
</row>
449+
450+
<row>
451+
<entry role="catalog_table_entry"><para role="column_definition">
452+
<structfield>jit_optimization_time</structfield> <type>bigint</type>
453+
</para>
454+
<para>
455+
Total time spent by the statement on optimizing, in milliseconds
456+
</para></entry>
457+
</row>
458+
459+
<row>
460+
<entry role="catalog_table_entry"><para role="column_definition">
461+
<structfield>jit_emission_count</structfield> <type>bigint</type>
462+
</para>
463+
<para>
464+
Number of times code has been emitted
465+
</para></entry>
466+
</row>
467+
468+
<row>
469+
<entry role="catalog_table_entry"><para role="column_definition">
470+
<structfield>jit_emission_time</structfield> <type>bigint</type>
471+
</para>
472+
<para>
473+
Total time spent by the statement on emitting code, in milliseconds
474+
</para></entry>
475+
</row>
404476
</tbody>
405477
</tgroup>
406478
</table>

0 commit comments

Comments
 (0)