Hello hackers, Andrey and Nik, thank you for selecting this patch for review in Postgres Hacking 101: I've modified the patch based both on your email and the video.
1. Session statistics is now collected only for client backends. PG internal processes like wal sender seem to stop sending statistics after they have entered their respective main loops. 2. Fastpath state now counts towards the running state. I think this special case does not justify tracking two extra numbers for every client backend. 3. I've added a small test for pg_stat_session similar to other tests in src/test/regress/sql/sysviews.sql 4. Here are the pb_bench results requested in the video review: Conditions: no assertions, number of transactions = 1000 The query: SELECT generate_series(1, 10000000) OFFSET 10000000; With pg_stat_session: latency average = 324.480 ms tps = 3.081857 (without initial connection time) Without pg_stat_session: latency average = 327.370 ms tps = 3.054651 (without initial connection time) Regards, Sergey
From 329db9a594b96499135bcbfdfad674f6af7ae1dc Mon Sep 17 00:00:00 2001 From: Sergey Dudoladov <sergey.dudola...@gmail.com> Date: Tue, 22 Nov 2022 09:23:32 +0100 Subject: [PATCH] Add pg_stat_session Author: Sergey Dudoladov Adds pg_stat_session view to track statistics accumulated during lifetime of a session (client backend). catversion bump is necessary due to a new view / function Reviewed-by: Aleksander Alekseev, Bertrand Drouvot, and Atsushi Torikoshi Discussion: https://www.postgresql.org/message-id/flat/CA%2BFpmFcJF0vwi-SWW0wYO-c-FbhyawLq4tCpRDCJJ8Bq%3Dja-gA%40mail.gmail.com --- doc/src/sgml/monitoring.sgml | 134 ++++++++++++++++++++ src/backend/catalog/system_views.sql | 13 ++ src/backend/utils/activity/backend_status.c | 57 +++++++-- src/backend/utils/adt/pgstatfuncs.c | 70 ++++++++++ src/include/catalog/pg_proc.dat | 9 ++ src/include/utils/backend_status.h | 32 +++++ src/test/regress/expected/rules.out | 10 ++ src/test/regress/expected/sysviews.out | 7 + src/test/regress/sql/sysviews.sql | 3 + 9 files changed, 325 insertions(+), 10 deletions(-) diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 5cfdc70c03..aa759e36c5 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -414,6 +414,20 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser See <xref linkend="copy-progress-reporting"/>. </entry> </row> + + <row> + <entry> + <structname>pg_stat_session</structname> + <indexterm><primary>pg_stat_session</primary></indexterm> + </entry> + <entry> + One row per client backend, showing information related to + the currently accumulated activity of that process, such as time spent in + a certain state. + See <link linkend="monitoring-pg-stat-session-view"> + <structname>pg_stat_session</structname></link> for details. + </entry> + </row> </tbody> </tgroup> </table> @@ -5755,6 +5769,110 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i </tgroup> </table> + <table id="monitoring-pg-stat-session-view" xreflabel="pg_stat_session"> + <title><structname>pg_stat_session</structname> View</title> + <tgroup cols="1"> + <thead> + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + Column Type + </para> + <para> + Description + </para></entry> + </row> + </thead> + + <tbody> + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>pid</structfield> <type>integer</type> + </para> + <para> + Process ID of this client backend. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_running_time</structfield> <type>double precision</type> + </para> + <para> + Time in milliseconds this backend spent in the <literal>running</literal> or <literal>fastpath</literal> state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_running_count</structfield> <type>bigint</type> + </para> + <para> + Number of times this backend switched to the <literal>running</literal> or <literal>fastpath</literal> state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_idle_time</structfield> <type>double precision</type> + </para> + <para> + Time in milliseconds this backend spent in the <literal>idle</literal> state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_idle_count</structfield> <type>bigint</type> + </para> + <para> + Number of times this backend switched to the <literal>idle</literal> state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_transaction_idle_time</structfield> <type>double precision</type> + </para> + <para> + Time in milliseconds this backend spent in the <literal>idle in transaction</literal> + state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_transaction_idle_count</structfield> <type>bigint</type> + </para> + <para> + Number of times this backend switched to the <literal>idle in transaction</literal> + state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_transaction_idle_aborted_time</structfield> <type>double precision</type> + </para> + <para> + Time in milliseconds this backend spent in the <literal>idle in transaction (aborted)</literal> + state. + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>total_transaction_idle_aborted_count</structfield> <type>bigint</type> + </para> + <para> + Number of times this backend switched to the <literal>idle in transaction (aborted)</literal> + state. + </para></entry> + </row> + + </tbody> + </tgroup> + </table> + </sect2> <sect2 id="monitoring-stats-functions"> @@ -5822,6 +5940,22 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i </para></entry> </row> + <row> + <entry role="func_table_entry"><para role="func_signature"> + <indexterm> + <primary>pg_stat_get_session</primary> + </indexterm> + <function>pg_stat_get_session</function> ( <type>integer</type> ) + <returnvalue>setof record</returnvalue> + </para> + <para> + Returns a record of information about the client backend with the specified + process ID, or one record for each active backend in the system + if <literal>NULL</literal> is specified. The fields returned are a + subset of those in the <structname>pg_stat_session</structname> view. + </para></entry> + </row> + <row> <entry role="func_table_entry"><para role="func_signature"> <indexterm> diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql index c18fea8362..8f073b442c 100644 --- a/src/backend/catalog/system_views.sql +++ b/src/backend/catalog/system_views.sql @@ -872,6 +872,19 @@ CREATE VIEW pg_stat_activity AS LEFT JOIN pg_database AS D ON (S.datid = D.oid) LEFT JOIN pg_authid AS U ON (S.usesysid = U.oid); +CREATE VIEW pg_stat_session AS + SELECT + s.pid, + s.total_running_time, + s.total_running_count, + s.total_idle_time, + s.total_idle_count, + s.total_transaction_idle_time, + s.total_transaction_idle_count, + s.total_transaction_idle_aborted_time, + s.total_transaction_idle_aborted_count + FROM pg_stat_get_session(NULL) as s; + CREATE VIEW pg_stat_replication AS SELECT S.pid, diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c index 38f91a495b..b20ef8c51e 100644 --- a/src/backend/utils/activity/backend_status.c +++ b/src/backend/utils/activity/backend_status.c @@ -338,6 +338,8 @@ pgstat_bestart(void) lbeentry.st_xact_start_timestamp = 0; lbeentry.st_databaseid = MyDatabaseId; + MemSet(&lbeentry.st_session, 0, sizeof(lbeentry.st_session)); + /* We have userid for client-backends, wal-sender and bgworker processes */ if (lbeentry.st_backendType == B_BACKEND || lbeentry.st_backendType == B_WAL_SENDER @@ -526,6 +528,9 @@ pgstat_report_activity(BackendState state, const char *cmd_str) TimestampTz current_timestamp; int len = 0; + PgBackendSessionStatus st_session_diff; + MemSet(&st_session_diff, 0, sizeof(st_session_diff)); + TRACE_POSTGRESQL_STATEMENT_STATUS(cmd_str); if (!beentry) @@ -551,6 +556,7 @@ pgstat_report_activity(BackendState state, const char *cmd_str) beentry->st_xact_start_timestamp = 0; beentry->st_query_id = UINT64CONST(0); proc->wait_event_info = 0; + MemSet(&beentry->st_session, 0, sizeof(beentry->st_session)); PGSTAT_END_WRITE_ACTIVITY(beentry); } return; @@ -573,27 +579,44 @@ pgstat_report_activity(BackendState state, const char *cmd_str) current_timestamp = GetCurrentTimestamp(); /* - * If the state has changed from "active" or "idle in transaction", - * calculate the duration. + * If a client backend has changed state, update per-database and per-session counters. */ - if ((beentry->st_state == STATE_RUNNING || - beentry->st_state == STATE_FASTPATH || - beentry->st_state == STATE_IDLEINTRANSACTION || - beentry->st_state == STATE_IDLEINTRANSACTION_ABORTED) && - state != beentry->st_state) + if ((PGSTAT_IS_ACTIVE(beentry) || + PGSTAT_IS_IDLEINTRANSACTION(beentry) || + PGSTAT_IS_IDLEINTRANSACTION_ABORTED(beentry) || + PGSTAT_IS_IDLE(beentry)) && + state != beentry->st_state && + beentry->st_backendType == B_BACKEND) { long secs; int usecs; + int64 usecs_diff; TimestampDifference(beentry->st_state_start_timestamp, current_timestamp, &secs, &usecs); + usecs_diff = secs * 1000000 + usecs; - if (beentry->st_state == STATE_RUNNING || - beentry->st_state == STATE_FASTPATH) + /* Keep statistics for pg_stat_database intact */ + if (PGSTAT_IS_ACTIVE(beentry)) pgstat_count_conn_active_time((PgStat_Counter) secs * 1000000 + usecs); - else + else if (PGSTAT_IS_IDLEINTRANSACTION(beentry) || + PGSTAT_IS_IDLEINTRANSACTION_ABORTED(beentry)) pgstat_count_conn_txn_idle_time((PgStat_Counter) secs * 1000000 + usecs); + + if (PGSTAT_IS_ACTIVE(beentry)) { + st_session_diff.total_running_time = usecs_diff; + st_session_diff.total_running_count += 1; + } else if (PGSTAT_IS_IDLE(beentry)){ + st_session_diff.total_idle_time = usecs_diff; + st_session_diff.total_idle_count += 1; + } else if (PGSTAT_IS_IDLEINTRANSACTION(beentry)){ + st_session_diff.total_transaction_idle_time = usecs_diff; + st_session_diff.total_transaction_idle_count += 1; + } else if (PGSTAT_IS_IDLEINTRANSACTION_ABORTED(beentry)){ + st_session_diff.total_transaction_idle_aborted_time = usecs_diff; + st_session_diff.total_transaction_idle_aborted_count += 1; + } } /* @@ -619,6 +642,20 @@ pgstat_report_activity(BackendState state, const char *cmd_str) beentry->st_activity_start_timestamp = start_timestamp; } + if (beentry->st_backendType == B_BACKEND) { + beentry->st_session.total_running_time += st_session_diff.total_running_time; + beentry->st_session.total_running_count += st_session_diff.total_running_count; + + beentry->st_session.total_idle_time += st_session_diff.total_idle_time; + beentry->st_session.total_idle_count += st_session_diff.total_idle_count; + + beentry->st_session.total_transaction_idle_time += st_session_diff.total_transaction_idle_time; + beentry->st_session.total_transaction_idle_count += st_session_diff.total_transaction_idle_count; + + beentry->st_session.total_transaction_idle_aborted_time += st_session_diff.total_transaction_idle_aborted_time; + beentry->st_session.total_transaction_idle_aborted_count += st_session_diff.total_transaction_idle_aborted_count; + } + PGSTAT_END_WRITE_ACTIVITY(beentry); } diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c index 49adc319fc..6eb2384618 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -297,6 +297,76 @@ pg_stat_get_progress_info(PG_FUNCTION_ARGS) return (Datum) 0; } +/* + * Returns accumulated statistics of current PG backends. + */ +Datum +pg_stat_get_session(PG_FUNCTION_ARGS) +{ +#define PG_STAT_GET_SESSION_COLS 9 + int num_backends = pgstat_fetch_stat_numbackends(); + int curr_backend; + int pid = PG_ARGISNULL(0) ? -1 : PG_GETARG_INT32(0); + ReturnSetInfo *rsinfo = (ReturnSetInfo *) fcinfo->resultinfo; + + InitMaterializedSRF(fcinfo, 0); + + /* 1-based index */ + for (curr_backend = 1; curr_backend <= num_backends; curr_backend++) + { + /* for each row */ + Datum values[PG_STAT_GET_SESSION_COLS] = {0}; + bool nulls[PG_STAT_GET_SESSION_COLS] = {0}; + LocalPgBackendStatus *local_beentry; + PgBackendStatus *beentry; + + /* Get the next one in the list */ + local_beentry = pgstat_fetch_stat_local_beentry(curr_backend); + beentry = &local_beentry->backendStatus; + + /* Report statistics only for client backends */ + if (beentry->st_backendType != B_BACKEND) + continue; + + /* If looking for specific PID, ignore all the others */ + if (pid != -1 && beentry->st_procpid != pid) + continue; + + /* Values available to all callers */ + values[0] = Int32GetDatum(beentry->st_procpid); + + /* Values only available to role member or pg_read_all_stats */ + if (HAS_PGSTAT_PERMISSIONS(beentry->st_userid)){ + /* convert to msec */ + values[1] = Float8GetDatum(beentry->st_session.total_running_time / 1000.0); + values[2] = Int64GetDatum(beentry->st_session.total_running_count); + values[3] = Float8GetDatum(beentry->st_session.total_idle_time / 1000.0); + values[4] = Int64GetDatum(beentry->st_session.total_idle_count); + values[5] = Float8GetDatum(beentry->st_session.total_transaction_idle_time / 1000.0); + values[6] = Int64GetDatum(beentry->st_session.total_transaction_idle_count); + values[7] = Float8GetDatum(beentry->st_session.total_transaction_idle_aborted_time / 1000.0); + values[8] = Int64GetDatum(beentry->st_session.total_transaction_idle_aborted_count); + } else { + nulls[1] = true; + nulls[2] = true; + nulls[3] = true; + nulls[4] = true; + nulls[5] = true; + nulls[6] = true; + nulls[7] = true; + nulls[8] = true; + } + + tuplestore_putvalues(rsinfo->setResult, rsinfo->setDesc, values, nulls); + + /* If only a single backend was requested, and we found it, break. */ + if (pid != -1) + break; + } + + return (Datum) 0; +} + /* * Returns activity of PG backends. */ diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 6996073989..60ac6ea3de 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -5417,6 +5417,15 @@ proargmodes => '{i,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o}', proargnames => '{pid,datid,pid,usesysid,application_name,state,query,wait_event_type,wait_event,xact_start,query_start,backend_start,state_change,client_addr,client_hostname,client_port,backend_xid,backend_xmin,backend_type,ssl,sslversion,sslcipher,sslbits,ssl_client_dn,ssl_client_serial,ssl_issuer_dn,gss_auth,gss_princ,gss_enc,gss_delegation,leader_pid,query_id}', prosrc => 'pg_stat_get_activity' }, +{ oid => '2173', + descr => 'statistics: cumulative information about currently active client backends', + proname => 'pg_stat_get_session', prorows => '100', proisstrict => 'f', + proretset => 't', provolatile => 's', proparallel => 'r', + prorettype => 'record', proargtypes => 'int4', + proallargtypes => '{int4,int4,float8,int8,float8,int8,float8,int8,float8,int8}', + proargmodes => '{i,o,o,o,o,o,o,o,o,o}', + proargnames => '{pid,pid,total_running_time,total_running_count,total_idle_time,total_idle_count,total_transaction_idle_time,total_transaction_idle_count,total_transaction_idle_aborted_time,total_transaction_idle_aborted_count}', + prosrc => 'pg_stat_get_session' }, { oid => '3318', descr => 'statistics: information about progress of backends running maintenance command', proname => 'pg_stat_get_progress_info', prorows => '100', proretset => 't', diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h index 16500d53b2..b0099d307e 100644 --- a/src/include/utils/backend_status.h +++ b/src/include/utils/backend_status.h @@ -81,6 +81,24 @@ typedef struct PgBackendGSSStatus } PgBackendGSSStatus; +/* + * PgBackendSessionStatus + * + * For each session, we keep counters accumulated since the start of the session + * in a separate struct. The struct is always filled. + * + */ +typedef struct PgBackendSessionStatus +{ + int64 total_running_time; + int64 total_running_count; + int64 total_idle_time; + int64 total_idle_count; + int64 total_transaction_idle_time; + int64 total_transaction_idle_count; + int64 total_transaction_idle_aborted_time; + int64 total_transaction_idle_aborted_count; +} PgBackendSessionStatus; /* ---------- * PgBackendStatus @@ -170,6 +188,9 @@ typedef struct PgBackendStatus /* query identifier, optionally computed using post_parse_analyze_hook */ uint64 st_query_id; + + /* Counters accumulated since the start of the session */ + PgBackendSessionStatus st_session; } PgBackendStatus; @@ -234,6 +255,17 @@ typedef struct PgBackendStatus ((before_changecount) & 1) == 0) +/* Macros to identify the states for time accounting */ +#define PGSTAT_IS_ACTIVE(s) \ + ((s)->st_state == STATE_RUNNING || (s)->st_state == STATE_FASTPATH) +#define PGSTAT_IS_IDLE(s) \ + ((s)->st_state == STATE_IDLE) +#define PGSTAT_IS_IDLEINTRANSACTION(s) \ + ((s)->st_state == STATE_IDLEINTRANSACTION) +#define PGSTAT_IS_IDLEINTRANSACTION_ABORTED(s) \ + ((s)->st_state == STATE_IDLEINTRANSACTION_ABORTED) + + /* ---------- * LocalPgBackendStatus * diff --git a/src/test/regress/expected/rules.out b/src/test/regress/expected/rules.out index 7fd81e6a7d..9eb67d4763 100644 --- a/src/test/regress/expected/rules.out +++ b/src/test/regress/expected/rules.out @@ -2094,6 +2094,16 @@ pg_stat_replication_slots| SELECT s.slot_name, FROM pg_replication_slots r, LATERAL pg_stat_get_replication_slot((r.slot_name)::text) s(slot_name, spill_txns, spill_count, spill_bytes, stream_txns, stream_count, stream_bytes, total_txns, total_bytes, stats_reset) WHERE (r.datoid IS NOT NULL); +pg_stat_session| SELECT pid, + total_running_time, + total_running_count, + total_idle_time, + total_idle_count, + total_transaction_idle_time, + total_transaction_idle_count, + total_transaction_idle_aborted_time, + total_transaction_idle_aborted_count + FROM pg_stat_get_session(NULL::integer) s(pid, total_running_time, total_running_count, total_idle_time, total_idle_count, total_transaction_idle_time, total_transaction_idle_count, total_transaction_idle_aborted_time, total_transaction_idle_aborted_count); pg_stat_slru| SELECT name, blks_zeroed, blks_hit, diff --git a/src/test/regress/expected/sysviews.out b/src/test/regress/expected/sysviews.out index 001c6e7eb9..e66c08cd40 100644 --- a/src/test/regress/expected/sysviews.out +++ b/src/test/regress/expected/sysviews.out @@ -167,3 +167,10 @@ select count(distinct utc_offset) >= 24 as ok from pg_timezone_abbrevs; t (1 row) +select total_idle_count as prev_idle_count from pg_stat_session where pid = pg_backend_pid() \gset +select (select total_idle_count from pg_stat_session where pid = pg_backend_pid()) - :prev_idle_count = 1 as ok; + ok +---- + t +(1 row) + diff --git a/src/test/regress/sql/sysviews.sql b/src/test/regress/sql/sysviews.sql index 351e469c77..6545e65d21 100644 --- a/src/test/regress/sql/sysviews.sql +++ b/src/test/regress/sql/sysviews.sql @@ -68,3 +68,6 @@ set timezone_abbreviations = 'Australia'; select count(distinct utc_offset) >= 24 as ok from pg_timezone_abbrevs; set timezone_abbreviations = 'India'; select count(distinct utc_offset) >= 24 as ok from pg_timezone_abbrevs; + +select total_idle_count as prev_idle_count from pg_stat_session where pid = pg_backend_pid() \gset +select (select total_idle_count from pg_stat_session where pid = pg_backend_pid()) - :prev_idle_count = 1 as ok; \ No newline at end of file -- 2.34.1