PG-435: Adding new counters that are available in PG15 (#329)

In line with pg_stat_statments for PG15, This commit adds eight new cumulative
counters for jit operations, making it easier to diagnose how JIT is used in an
installation. And two new columns, temp_blk_read_time, and temp_blk_write_time,
respectively, show the time spent reading and writing temporary file blocks
on disk.
Moreover, The commit also contains a few indentations and API adjustments.
pull/330/head
Muhammad Usama 2022-12-07 15:40:13 +05:00 committed by GitHub
parent 4a254a538b
commit 913064b68d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 303 additions and 33 deletions

View File

@ -62,15 +62,28 @@ CREATE FUNCTION pg_stat_monitor_internal(
OUT temp_blks_written int8,
OUT blk_read_time float8,
OUT blk_write_time float8,
OUT temp_blk_read_time float8,
OUT temp_blk_write_time float8,
OUT resp_calls text, -- 41
OUT cpu_user_time float8,
OUT cpu_sys_time float8,
OUT wal_records int8,
OUT wal_fpi int8,
OUT wal_bytes numeric,
OUT comments TEXT,
OUT toplevel BOOLEAN,
OUT bucket_done BOOLEAN
OUT wal_records int8,
OUT wal_fpi int8,
OUT wal_bytes numeric,
OUT comments TEXT,
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,
OUT toplevel BOOLEAN,
OUT bucket_done BOOLEAN
)
RETURNS SETOF record
AS 'MODULE_PATHNAME', 'pg_stat_monitor_2_0'
@ -258,18 +271,97 @@ RETURN 0;
END;
$$ LANGUAGE plpgsql;
CREATE FUNCTION pgsm_create_15_view() RETURNS INT AS
$$
BEGIN
CREATE VIEW pg_stat_monitor AS SELECT
bucket,
bucket_start_time AS bucket_start_time,
userid::regrole,
datname,
'0.0.0.0'::inet + client_ip AS client_ip,
queryid,
toplevel,
top_queryid,
query,
comments,
planid,
query_plan,
top_query,
application_name,
string_to_array(relations, ',') AS relations,
cmd_type,
get_cmd_type(cmd_type) AS cmd_type_text,
elevel,
sqlcode,
message,
calls,
total_exec_time,
min_exec_time,
max_exec_time,
mean_exec_time,
stddev_exec_time,
rows_retrieved,
shared_blks_hit,
shared_blks_read,
shared_blks_dirtied,
shared_blks_written,
local_blks_hit,
local_blks_read,
local_blks_dirtied,
local_blks_written,
temp_blks_read,
temp_blks_written,
blk_read_time,
blk_write_time,
temp_blk_read_time,
temp_blk_write_time,
(string_to_array(resp_calls, ',')) resp_calls,
cpu_user_time,
cpu_sys_time,
wal_records,
wal_fpi,
wal_bytes,
bucket_done,
plans_calls,
total_plan_time,
min_plan_time,
max_plan_time,
mean_plan_time,
stddev_plan_time,
jit_functions,
jit_generation_time,
jit_inlining_count,
jit_inlining_time,
jit_optimization_count,
jit_optimization_time,
jit_emission_count,
jit_emission_time
FROM pg_stat_monitor_internal(TRUE) p, pg_database d WHERE dbid = oid
ORDER BY bucket_start_time;
RETURN 0;
END;
$$ LANGUAGE plpgsql;
CREATE FUNCTION pgsm_create_view() RETURNS INT AS
$$
DECLARE ver integer;
BEGIN
SELECT current_setting('server_version_num') INTO ver;
IF (ver >= 14000) THEN
IF (ver >= 150000) THEN
return pgsm_create_15_view();
END IF;
IF (ver >= 140000) THEN
return pgsm_create_14_view();
END IF;
IF (ver >= 13000) THEN
IF (ver >= 130000) THEN
return pgsm_create_13_view();
END IF;
IF (ver >= 11000) THEN
IF (ver >= 110000) THEN
return pgsm_create_11_view();
END IF;
RETURN 0;

View File

@ -116,7 +116,6 @@ CREATE FUNCTION pg_stat_monitor_internal(
OUT planid text,
OUT query text,
OUT query_plan text,
OUT state_code int8,
OUT top_queryid text,
OUT top_query text,
OUT application_name text,
@ -158,15 +157,29 @@ CREATE FUNCTION pg_stat_monitor_internal(
OUT temp_blks_written int8,
OUT blk_read_time float8,
OUT blk_write_time float8,
OUT temp_blk_read_time float8,
OUT temp_blk_write_time float8,
OUT resp_calls text, -- 41
OUT cpu_user_time float8,
OUT cpu_sys_time float8,
OUT wal_records int8,
OUT wal_fpi int8,
OUT wal_bytes numeric,
OUT comments TEXT,
OUT wal_records int8,
OUT wal_fpi int8,
OUT wal_bytes numeric,
OUT comments TEXT,
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,
OUT toplevel BOOLEAN,
OUT bucket_done BOOLEAN
OUT bucket_done BOOLEAN
)
RETURNS SETOF record
AS 'MODULE_PATHNAME', 'pg_stat_monitor_2_0'
@ -355,11 +368,90 @@ RETURN 0;
END;
$$ LANGUAGE plpgsql;
CREATE FUNCTION pgsm_create_15_view() RETURNS INT AS
$$
BEGIN
CREATE VIEW pg_stat_monitor AS SELECT
bucket,
bucket_start_time AS bucket_start_time,
userid::regrole,
datname,
'0.0.0.0'::inet + client_ip AS client_ip,
queryid,
toplevel,
top_queryid,
query,
comments,
planid,
query_plan,
top_query,
application_name,
string_to_array(relations, ',') AS relations,
cmd_type,
get_cmd_type(cmd_type) AS cmd_type_text,
elevel,
sqlcode,
message,
calls,
total_exec_time,
min_exec_time,
max_exec_time,
mean_exec_time,
stddev_exec_time,
rows_retrieved,
shared_blks_hit,
shared_blks_read,
shared_blks_dirtied,
shared_blks_written,
local_blks_hit,
local_blks_read,
local_blks_dirtied,
local_blks_written,
temp_blks_read,
temp_blks_written,
blk_read_time,
blk_write_time,
temp_blk_read_time,
temp_blk_write_time,
(string_to_array(resp_calls, ',')) resp_calls,
cpu_user_time,
cpu_sys_time,
wal_records,
wal_fpi,
wal_bytes,
bucket_done,
plans_calls,
total_plan_time,
min_plan_time,
max_plan_time,
mean_plan_time,
stddev_plan_time,
jit_functions,
jit_generation_time,
jit_inlining_count,
jit_inlining_time,
jit_optimization_count,
jit_optimization_time,
jit_emission_count,
jit_emission_time
FROM pg_stat_monitor_internal(TRUE) p, pg_database d WHERE dbid = oid
ORDER BY bucket_start_time;
RETURN 0;
END;
$$ LANGUAGE plpgsql;
CREATE FUNCTION pgsm_create_view() RETURNS INT AS
$$
DECLARE ver integer;
BEGIN
SELECT current_setting('server_version_num') INTO ver;
IF (ver >= 150000) THEN
return pgsm_create_15_view();
END IF;
IF (ver >= 140000) THEN
return pgsm_create_14_view();
END IF;

View File

@ -36,7 +36,12 @@
PG_MODULE_MAGIC;
#define BUILD_VERSION "2.0.0-dev"
#define PG_STAT_STATEMENTS_COLS 53 /* maximum of above */
/* Number of output arguments (columns) for various API versions */
#define PG_STAT_MONITOR_COLS_V1_0 52
#define PG_STAT_MONITOR_COLS_V2_0 61
#define PG_STAT_MONITOR_COLS 61 /* maximum of above */
#define PGSM_TEXT_FILE PGSTAT_STAT_PERMANENT_DIRECTORY "pg_stat_monitor_query"
#define roundf(x,d) ((floor(((x)*pow(10,d))+.5))/pow(10,d))
@ -186,6 +191,7 @@ static void pgss_store(uint64 queryid,
uint64 rows,
BufferUsage *bufusage,
WalUsage *walusage,
const struct JitInstrumentation *jitusage,
JumbleState *jstate,
pgssStoreKind kind);
@ -241,7 +247,7 @@ _PG_init(void)
* In order to create our shared memory area, we have to be loaded via
* shared_preload_libraries. If not, fall out without hooking into any of
* the main system. (We don't throw error here because it seems useful to
* allow the pg_stat_statements functions to be created even when the
* allow the pg_stat_monitor functions to be created even when the
* module isn't active. The functions must protect themselves against
* being called then, however.)
*/
@ -432,6 +438,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate)
0, /* rows */
NULL, /* bufusage */
NULL, /* walusage */
NULL, /* jitusage */
jstate, /* JumbleState */
PGSS_PARSE); /* pgssStoreKind */
}
@ -490,6 +497,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
0, /* rows */
NULL, /* bufusage */
NULL, /* walusage */
NULL, /* jitusage */
&jstate, /* JumbleState */
PGSS_PARSE); /* pgssStoreKind */
}
@ -661,6 +669,11 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
&queryDesc->totaltime->walusage, /* walusage */
#else
NULL,
#endif
#if PG_VERSION_NUM >= 150000
queryDesc->estate->es_jit ? &queryDesc->estate->es_jit->instr : NULL,
#else
NULL,
#endif
NULL,
PGSS_FINISHED); /* pgssStoreKind */
@ -804,6 +817,7 @@ pgss_planner_hook(Query *parse, const char *query_string, int cursorOptions, Par
&bufusage, /* bufusage */
&walusage, /* walusage */
NULL, /* JumbleState */
NULL,
PGSS_PLAN); /* pgssStoreKind */
}
else
@ -993,6 +1007,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
#else
NULL, /* walusage, NULL for PG <= 12 */
#endif
NULL,
NULL, /* JumbleState */
PGSS_FINISHED); /* pgssStoreKind */
}
@ -1139,7 +1154,7 @@ pg_get_client_addr(bool *ok)
static void
pgss_update_entry(pgssEntry *entry,
int bucketid,
uint64 bucketid,
uint64 queryid,
const char *query,
const char *comments,
@ -1151,6 +1166,7 @@ pgss_update_entry(pgssEntry *entry,
uint64 rows,
BufferUsage *bufusage,
WalUsage *walusage,
const struct JitInstrumentation *jitusage,
bool reset,
pgssStoreKind kind,
const char *app_name,
@ -1272,6 +1288,10 @@ pgss_update_entry(pgssEntry *entry,
e->counters.blocks.temp_blks_written += bufusage->temp_blks_written;
e->counters.blocks.blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_read_time);
e->counters.blocks.blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_write_time);
#if PG_VERSION_NUM >= 150000
e->counters.blocks.temp_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_read_time);
e->counters.blocks.temp_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_write_time);
#endif
}
e->counters.calls.usage += USAGE_EXEC(total_time);
if (sys_info)
@ -1285,6 +1305,23 @@ pgss_update_entry(pgssEntry *entry,
e->counters.walusage.wal_fpi += walusage->wal_fpi;
e->counters.walusage.wal_bytes += walusage->wal_bytes;
}
if (jitusage)
{
e->counters.jitinfo.jit_functions += jitusage->created_functions;
e->counters.jitinfo.jit_generation_time += INSTR_TIME_GET_MILLISEC(jitusage->generation_counter);
if (INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter))
e->counters.jitinfo.jit_inlining_count++;
e->counters.jitinfo.jit_inlining_time += INSTR_TIME_GET_MILLISEC(jitusage->inlining_counter);
if (INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter))
e->counters.jitinfo.jit_optimization_count++;
e->counters.jitinfo.jit_optimization_time += INSTR_TIME_GET_MILLISEC(jitusage->optimization_counter);
if (INSTR_TIME_GET_MILLISEC(jitusage->emission_counter))
e->counters.jitinfo.jit_emission_count++;
e->counters.jitinfo.jit_emission_time += INSTR_TIME_GET_MILLISEC(jitusage->emission_counter);
}
SpinLockRelease(&e->mutex);
}
}
@ -1313,6 +1350,7 @@ pgss_store_error(uint64 queryid,
NULL, /* bufusage */
NULL, /* walusage */
NULL, /* JumbleState */
NULL,
PGSS_ERROR); /* pgssStoreKind */
}
@ -1339,6 +1377,7 @@ pgss_store(uint64 queryid,
uint64 rows,
BufferUsage *bufusage,
WalUsage *walusage,
const struct JitInstrumentation *jitusage,
JumbleState *jstate,
pgssStoreKind kind)
{
@ -1553,6 +1592,7 @@ pgss_store(uint64 queryid,
rows, /* rows */
bufusage, /* bufusage */
walusage, /* walusage */
jitusage,
reset, /* reset */
kind, /* kind */
app_name_ptr,
@ -1627,7 +1667,7 @@ IsBucketValid(uint64 bucketid)
return true;
}
/* Common code for all versions of pg_stat_statements() */
/* Common code for all versions of pg_stat_monitor() */
static void
pg_stat_monitor_internal(FunctionCallInfo fcinfo,
pgsmVersion api_version,
@ -1645,6 +1685,7 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
HTAB *pgss_hash = pgsm_get_hash();
char *query_txt = (char *) palloc0(PGSM_QUERY_MAX_LEN + 1);
char *parent_query_txt = (char *) palloc0(PGSM_QUERY_MAX_LEN + 1);
int expected_columns = (api_version >= PGSM_V2_0)?PG_STAT_MONITOR_COLS_V2_0:PG_STAT_MONITOR_COLS_V1_0;
/* Safety check... */
if (!IsSystemInitialized())
@ -1671,7 +1712,7 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
elog(ERROR, "pg_stat_monitor: return type must be a row type");
if (tupdesc->natts != 52)
if (tupdesc->natts != expected_columns)
elog(ERROR, "pg_stat_monitor: incorrect number of output arguments, required %d", tupdesc->natts);
tupstore = tuplestore_begin_heap(true, false, work_mem);
@ -1686,18 +1727,18 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
hash_seq_init(&hash_seq, pgss_hash);
while ((entry = hash_seq_search(&hash_seq)) != NULL)
{
Datum values[PG_STAT_STATEMENTS_COLS] = {0};
bool nulls[PG_STAT_STATEMENTS_COLS] = {0};
Datum values[PG_STAT_MONITOR_COLS] = {0};
bool nulls[PG_STAT_MONITOR_COLS] = {0};
int i = 0;
Counters tmp;
double stddev;
char queryid_text[32] = {0};
char planid_text[32] = {0};
uint64 queryid = entry->key.queryid;
uint64 bucketid = entry->key.bucket_id;
int64 bucketid = entry->key.bucket_id;
uint64 dbid = entry->key.dbid;
uint64 userid = entry->key.userid;
uint64 ip = entry->key.ip;
int64 ip = entry->key.ip;
uint64 planid = entry->key.planid;
#if PG_VERSION_NUM < 140000
bool toplevel = 1;
@ -1816,8 +1857,9 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
values[i++] = CStringGetTextDatum("<insufficient privilege>");
}
/* state at column number 8 */
values[i++] = Int64GetDatumFast(tmp.state);
/* state at column number 8 for V1.0 API*/
if (api_version <= PGSM_V1_0)
values[i++] = Int64GetDatumFast(tmp.state);
/* parentid at column number 9 */
if (tmp.info.parentid != UINT64CONST(0))
@ -1871,7 +1913,7 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
if (tmp.info.cmd_type == CMD_NOTHING)
nulls[i++] = true;
else
values[i++] = Int64GetDatumFast(tmp.info.cmd_type);
values[i++] = Int64GetDatumFast((int64)tmp.info.cmd_type);
/* elevel at column number 12 */
values[i++] = Int64GetDatumFast(tmp.error.elevel);
@ -1969,6 +2011,12 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
values[i++] = Float8GetDatumFast(tmp.blocks.blk_read_time);
values[i++] = Float8GetDatumFast(tmp.blocks.blk_write_time);
if (api_version >= PGSM_V2_0)
{
values[i++] = Float8GetDatumFast(tmp.blocks.temp_blk_read_time);
values[i++] = Float8GetDatumFast(tmp.blocks.temp_blk_write_time);
}
/* resp_calls at column number 41 */
values[i++] = IntArrayGetTextDatum(tmp.resp_calls, PGSM_HISTOGRAM_BUCKETS);
@ -2002,6 +2050,19 @@ pg_stat_monitor_internal(FunctionCallInfo fcinfo,
values[i++] = CStringGetTextDatum(tmp.info.comments);
else
nulls[i++] = true;
if (api_version >= PGSM_V2_0)
{
values[i++] = Int64GetDatumFast(tmp.jitinfo.jit_functions);
values[i++] = Float8GetDatumFast(tmp.jitinfo.jit_generation_time);
values[i++] = Int64GetDatumFast(tmp.jitinfo.jit_inlining_count);
values[i++] = Float8GetDatumFast(tmp.jitinfo.jit_inlining_time);
values[i++] = Int64GetDatumFast(tmp.jitinfo.jit_optimization_count);
values[i++] = Float8GetDatumFast(tmp.jitinfo.jit_optimization_time);
values[i++] = Int64GetDatumFast(tmp.jitinfo.jit_emission_count);
values[i++] = Float8GetDatumFast(tmp.jitinfo.jit_emission_time);
}
}
values[i++] = BoolGetDatum(toplevel);
values[i++] = BoolGetDatum(pg_atomic_read_u64(&pgss->current_wbucket) != bucketid);
@ -3343,8 +3404,8 @@ pg_stat_monitor_settings(PG_FUNCTION_ARGS)
}
else
{
values[j++] = Int64GetDatumFast(get_conf(i)->guc_min);
values[j++] = Int64GetDatumFast(get_conf(i)->guc_max);
values[j++] = Int32GetDatum(get_conf(i)->guc_min);
values[j++] = Int32GetDatum(get_conf(i)->guc_max);
}
if (conf->type == PGC_ENUM)

View File

@ -31,6 +31,7 @@
#include "catalog/pg_authid.h"
#include "executor/instrument.h"
#include "common/ip.h"
#include "jit/jit.h"
#include "funcapi.h"
#include "access/twophase.h"
#include "mb/pg_wchar.h"
@ -255,8 +256,27 @@ typedef struct Blocks
int64 temp_blks_written; /* # of temp blocks written */
double blk_read_time; /* time spent reading, in msec */
double blk_write_time; /* time spent writing, in msec */
double temp_blk_read_time; /* time spent reading temp blocks, in msec */
double temp_blk_write_time; /* time spent writing temp blocks, in
* msec */
} Blocks;
typedef struct JitInfo
{
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 */
} JitInfo;
typedef struct SysInfo
{
float utime; /* user cpu time */
@ -283,11 +303,12 @@ typedef struct Counters
Blocks blocks;
SysInfo sysinfo;
JitInfo jitinfo;
ErrorInfo error;
Wal_Usage walusage;
int resp_calls[MAX_RESPONSE_BUCKET]; /* execution time's in
* msec */
uint64 state; /* query state */
int64 state; /* query state */
} Counters;
/* Some global structure to get the cpu usage, really don't like the idea of global variable */

View File

@ -26,14 +26,18 @@ close $conf;
my %pg_versions_pgsm_columns = ( 15 => "application_name,blk_read_time," .
"blk_write_time,bucket,bucket_done,bucket_start_time,calls," .
"client_ip,cmd_type,cmd_type_text,comments,cpu_sys_time,cpu_user_time," .
"datname,elevel,local_blks_dirtied,local_blks_hit,local_blks_read," .
"datname,elevel,jit_emission_count,jit_emission_time,jit_functions," .
"jit_generation_time,jit_inlining_count,jit_inlining_time," .
"jit_optimization_count,jit_optimization_time," .
"local_blks_dirtied,local_blks_hit,local_blks_read," .
"local_blks_written,max_exec_time,max_plan_time,mean_exec_time," .
"mean_plan_time,message,min_exec_time,min_plan_time,planid," .
"plans_calls,query,query_plan,queryid,relations,resp_calls," .
"rows_retrieved,shared_blks_dirtied,shared_blks_hit,shared_blks_read," .
"shared_blks_written,sqlcode,stddev_exec_time,stddev_plan_time," .
"temp_blks_read,temp_blks_written,top_query,top_queryid,toplevel," .
"total_exec_time,total_plan_time,userid,wal_bytes,wal_fpi,wal_records",
"temp_blk_read_time,temp_blk_write_time,temp_blks_read,temp_blks_written," .
"top_query,top_queryid,toplevel,total_exec_time,total_plan_time," .
"userid,wal_bytes,wal_fpi,wal_records",
14 => "application_name,blk_read_time," .
"blk_write_time,bucket,bucket_done,bucket_start_time,calls," .
"client_ip,cmd_type,cmd_type_text,comments,cpu_sys_time,cpu_user_time," .