Add JIT counters to pg_stat_statements
authorMagnus Hagander <[email protected]>
Fri, 8 Apr 2022 11:51:01 +0000 (13:51 +0200)
committerMagnus Hagander <[email protected]>
Fri, 8 Apr 2022 11:52:16 +0000 (13:52 +0200)
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 76cbf7edb6 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

contrib/pg_stat_statements/expected/oldextversions.out
contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql
contrib/pg_stat_statements/pg_stat_statements.c
doc/src/sgml/pgstatstatements.sgml

index 2813eb16cbe929cf12e76d9c3d20940700d953aa..efb2049ecff44d83a1a495ae2930f2d0247dc340 100644 (file)
@@ -197,44 +197,52 @@ SELECT count(*) > 0 AS has_data FROM pg_stat_statements;
 -- New functions and views for pg_stat_statements in 1.10
 AlTER EXTENSION pg_stat_statements UPDATE TO '1.10';
 \d pg_stat_statements
-                    View "public.pg_stat_statements"
-       Column        |       Type       | Collation | Nullable | Default 
----------------------+------------------+-----------+----------+---------
- userid              | oid              |           |          | 
- dbid                | oid              |           |          | 
- toplevel            | boolean          |           |          | 
- queryid             | bigint           |           |          | 
- query               | text             |           |          | 
- plans               | bigint           |           |          | 
- total_plan_time     | double precision |           |          | 
- min_plan_time       | double precision |           |          | 
- max_plan_time       | double precision |           |          | 
- mean_plan_time      | double precision |           |          | 
- stddev_plan_time    | double precision |           |          | 
- calls               | bigint           |           |          | 
- total_exec_time     | double precision |           |          | 
- min_exec_time       | double precision |           |          | 
- max_exec_time       | double precision |           |          | 
- mean_exec_time      | double precision |           |          | 
- stddev_exec_time    | double precision |           |          | 
- rows                | bigint           |           |          | 
- shared_blks_hit     | bigint           |           |          | 
- shared_blks_read    | bigint           |           |          | 
- shared_blks_dirtied | bigint           |           |          | 
- shared_blks_written | bigint           |           |          | 
- local_blks_hit      | bigint           |           |          | 
- local_blks_read     | bigint           |           |          | 
- local_blks_dirtied  | bigint           |           |          | 
- local_blks_written  | bigint           |           |          | 
- temp_blks_read      | bigint           |           |          | 
- temp_blks_written   | bigint           |           |          | 
- blk_read_time       | double precision |           |          | 
- blk_write_time      | double precision |           |          | 
- temp_blk_read_time  | double precision |           |          | 
- temp_blk_write_time | double precision |           |          | 
- wal_records         | bigint           |           |          | 
- wal_fpi             | bigint           |           |          | 
- wal_bytes           | numeric          |           |          | 
+                      View "public.pg_stat_statements"
+         Column         |       Type       | Collation | Nullable | Default 
+------------------------+------------------+-----------+----------+---------
+ userid                 | oid              |           |          | 
+ dbid                   | oid              |           |          | 
+ toplevel               | boolean          |           |          | 
+ queryid                | bigint           |           |          | 
+ query                  | text             |           |          | 
+ plans                  | bigint           |           |          | 
+ total_plan_time        | double precision |           |          | 
+ min_plan_time          | double precision |           |          | 
+ max_plan_time          | double precision |           |          | 
+ mean_plan_time         | double precision |           |          | 
+ stddev_plan_time       | double precision |           |          | 
+ calls                  | bigint           |           |          | 
+ total_exec_time        | double precision |           |          | 
+ min_exec_time          | double precision |           |          | 
+ max_exec_time          | double precision |           |          | 
+ mean_exec_time         | double precision |           |          | 
+ stddev_exec_time       | double precision |           |          | 
+ rows                   | bigint           |           |          | 
+ shared_blks_hit        | bigint           |           |          | 
+ shared_blks_read       | bigint           |           |          | 
+ shared_blks_dirtied    | bigint           |           |          | 
+ shared_blks_written    | bigint           |           |          | 
+ local_blks_hit         | bigint           |           |          | 
+ local_blks_read        | bigint           |           |          | 
+ local_blks_dirtied     | bigint           |           |          | 
+ local_blks_written     | bigint           |           |          | 
+ temp_blks_read         | bigint           |           |          | 
+ temp_blks_written      | bigint           |           |          | 
+ blk_read_time          | double precision |           |          | 
+ blk_write_time         | double precision |           |          | 
+ temp_blk_read_time     | double precision |           |          | 
+ temp_blk_write_time    | double precision |           |          | 
+ wal_records            | bigint           |           |          | 
+ wal_fpi                | bigint           |           |          | 
+ wal_bytes              | numeric          |           |          | 
+ jit_functions          | bigint           |           |          | 
+ jit_generation_time    | double precision |           |          | 
+ jit_inlining_count     | bigint           |           |          | 
+ jit_inlining_time      | double precision |           |          | 
+ jit_optimization_count | bigint           |           |          | 
+ jit_optimization_time  | double precision |           |          | 
+ jit_emission_count     | bigint           |           |          | 
+ jit_emission_time      | double precision |           |          | 
 
 SELECT count(*) > 0 AS has_data FROM pg_stat_statements;
  has_data 
index ca777f14e8d7a5fda6addaa3ba16dbb69009b890..811813c49159f72add84af8ca2414c7190575d75 100644 (file)
@@ -47,7 +47,15 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
     OUT temp_blk_write_time float8,
     OUT wal_records int8,
     OUT wal_fpi int8,
-    OUT wal_bytes numeric
+    OUT wal_bytes numeric,
+    OUT jit_functions int8,
+    OUT jit_generation_time float8,
+    OUT jit_inlining_count int8,
+    OUT jit_inlining_time float8,
+    OUT jit_optimization_count int8,
+    OUT jit_optimization_time float8,
+    OUT jit_emission_count int8,
+    OUT jit_emission_time float8
 )
 RETURNS SETOF record
 AS 'MODULE_PATHNAME', 'pg_stat_statements_1_10'
index 42ac001053d6f1c3e9fde09c88e2229a86a9d922..1ca67ef623452e21e550e89dab67d16e09abda4d 100644 (file)
@@ -52,6 +52,7 @@
 #include "common/hashfn.h"
 #include "executor/instrument.h"
 #include "funcapi.h"
+#include "jit/jit.h"
 #include "mb/pg_wchar.h"
 #include "miscadmin.h"
 #include "optimizer/planner.h"
@@ -188,6 +189,17 @@ typedef struct Counters
        int64           wal_records;    /* # of WAL records generated */
        int64           wal_fpi;                /* # of WAL full page images generated */
        uint64          wal_bytes;              /* total amount of WAL generated in bytes */
+       int64           jit_functions;  /* total number of JIT functions emitted */
+       double          jit_generation_time;    /* total time to generate jit code */
+       int64           jit_inlining_count; /* number of times inlining time has been
+                                                                        * > 0 */
+       double          jit_inlining_time;      /* total time to inline jit code */
+       int64           jit_optimization_count; /* number of times optimization time
+                                                                                * has been > 0 */
+       double          jit_optimization_time;  /* total time to optimize jit code */
+       int64           jit_emission_count; /* number of times emission time has been
+                                                                        * > 0 */
+       double          jit_emission_time;      /* total time to emit jit code */
 } Counters;
 
 /*
@@ -330,6 +342,7 @@ static void pgss_store(const char *query, uint64 queryId,
                                           double total_time, uint64 rows,
                                           const BufferUsage *bufusage,
                                           const WalUsage *walusage,
+                                          const struct JitInstrumentation *jitusage,
                                           JumbleState *jstate);
 static void pg_stat_statements_internal(FunctionCallInfo fcinfo,
                                                                                pgssVersion api_version,
@@ -854,6 +867,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate)
                                   0,
                                   NULL,
                                   NULL,
+                                  NULL,
                                   jstate);
 }
 
@@ -938,6 +952,7 @@ pgss_planner(Query *parse,
                                   0,
                                   &bufusage,
                                   &walusage,
+                                  NULL,
                                   NULL);
        }
        else
@@ -1056,6 +1071,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
                                   queryDesc->estate->es_processed,
                                   &queryDesc->totaltime->bufusage,
                                   &queryDesc->totaltime->walusage,
+                                  queryDesc->estate->es_jit ? &queryDesc->estate->es_jit->instr : NULL,
                                   NULL);
        }
 
@@ -1173,6 +1189,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
                                   rows,
                                   &bufusage,
                                   &walusage,
+                                  NULL,
                                   NULL);
        }
        else
@@ -1206,6 +1223,7 @@ pgss_store(const char *query, uint64 queryId,
                   double total_time, uint64 rows,
                   const BufferUsage *bufusage,
                   const WalUsage *walusage,
+                  const struct JitInstrumentation *jitusage,
                   JumbleState *jstate)
 {
        pgssHashKey key;
@@ -1375,6 +1393,23 @@ pgss_store(const char *query, uint64 queryId,
                e->counters.wal_records += walusage->wal_records;
                e->counters.wal_fpi += walusage->wal_fpi;
                e->counters.wal_bytes += walusage->wal_bytes;
+               if (jitusage)
+               {
+                       e->counters.jit_functions += jitusage->created_functions;
+                       e->counters.jit_generation_time += INSTR_TIME_GET_MILLISEC(jitusage->generation_counter);
+
+                       if (INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter))
+                               e->counters.jit_inlining_count++;
+                       e->counters.jit_inlining_time += INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter);
+
+                       if (INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter))
+                               e->counters.jit_optimization_count++;
+                       e->counters.jit_optimization_time += INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter);
+
+                       if (INSTR_TIME_GET_MILLISEC(jitusage->emission_counter))
+                               e->counters.jit_emission_count++;
+                       e->counters.jit_emission_time += INSTR_TIME_GET_MILLISEC(jitusage->emission_counter);
+               }
 
                SpinLockRelease(&e->mutex);
        }
@@ -1424,8 +1459,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
 #define PG_STAT_STATEMENTS_COLS_V1_3   23
 #define PG_STAT_STATEMENTS_COLS_V1_8   32
 #define PG_STAT_STATEMENTS_COLS_V1_9   33
-#define PG_STAT_STATEMENTS_COLS_V1_10  35
-#define PG_STAT_STATEMENTS_COLS                        35      /* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_10  43
+#define PG_STAT_STATEMENTS_COLS                        43      /* maximum of above */
 
 /*
  * Retrieve statement statistics.
@@ -1786,6 +1821,17 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
                                                                                        Int32GetDatum(-1));
                        values[i++] = wal_bytes;
                }
+               if (api_version >= PGSS_V1_10)
+               {
+                       values[i++] = Int64GetDatumFast(tmp.jit_functions);
+                       values[i++] = Float8GetDatumFast(tmp.jit_generation_time);
+                       values[i++] = Int64GetDatumFast(tmp.jit_inlining_count);
+                       values[i++] = Float8GetDatumFast(tmp.jit_inlining_time);
+                       values[i++] = Int64GetDatumFast(tmp.jit_optimization_count);
+                       values[i++] = Float8GetDatumFast(tmp.jit_optimization_time);
+                       values[i++] = Int64GetDatumFast(tmp.jit_emission_count);
+                       values[i++] = Float8GetDatumFast(tmp.jit_emission_time);
+               }
 
                Assert(i == (api_version == PGSS_V1_0 ? PG_STAT_STATEMENTS_COLS_V1_0 :
                                         api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 :
index 0ead2464d874f54a4acc7d04d40146fb667e775b..45e720e995deaf387cab569df921bf3f2a63201b 100644 (file)
        Total amount of WAL generated by the statement in bytes
       </para></entry>
      </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_functions</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Total number of functions JIT-compiled by the statement
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_generation_time</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Total time spent by the statement on generating JIT code, in milliseconds
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_inlining_count</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of times functions have been inlined
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_inlining_time</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Total time spent by the statement on inlining functions, in milliseconds
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_optimization_count</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of times the statement has been optimized
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_optimization_time</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Total time spent by the statement on optimizing, in milliseconds
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_emission_count</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of times code has been emitted
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>jit_emission_time</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Total time spent by the statement on emitting code, in milliseconds
+      </para></entry>
+     </row>
     </tbody>
    </tgroup>
   </table>