One way to get the workload profile and wait history in PostgreSQL

Continuation of the article " Attempting to create an analogue of ASH for PostgreSQL ".

The article will be considered and shown on specific queries and examples - what useful information can be obtained using the history of the pg_stat_activity view.

Warning.
Due to the novelty of the topic and the incomplete testing period, the article may contain errors. Criticism and comments are strongly encouraged and expected.

Input data

Submission History pg_stat_statements

pg_stat_history

CREATE TABLE pg_stat_history ( id SERIAL, snapshot_timestamp timestamp without time zone, database_id integer, dbid oid, userid oid, queryid bigint, query text, calls bigint, total_time double precision, min_time double precision, max_time double precision, mean_time double precision, stddev_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, baseline_id integer );

The table is populated every hour using dblink to the target database. The most interesting and useful column in the table, of course, is queryid .

Pg_stat_activity view history

archive_pg_stat_activity

 CREATE TABLE archive_pg_stat_activity ( timepoint timestamp without time zone, datid oid, datname name, pid integer, usesysid oid, usename name, application_name text, client_addr inet, client_hostname text, client_port integer, backend_start timestamp without time zone, xact_start timestamp without time zone, query_start timestamp without time zone, state_change timestamp without time zone, wait_event_type text, wait_event text, state text, backend_xid xid, backend_xmin xid, query text, backend_type text, queryid bigint );

The table is a clock-partitioned history_pg_stat_activity table (For details, see pg_stat_statements + pg_stat_activity + loq_query = pg_ash? And here is an attempt to create an analogue of ASH for PostgreSQL.)

Output

CLUSTER CPU TIME (SYSTEM + CLIENTS)

Inquiry

 WITH t AS ( SELECT date_trunc('second', timepoint) FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND ( aa.wait_event_type IS NULL ) AND aa.state = 'active' ) SELECT count(*) INTO cpu_total FROM t ;

Example

 CLUSTER CPU TIME (SYSTEM + CLIENTS ) : 28:37:46

CLUSTER WAITINGS TIME

Inquiry

 WITH t AS ( SELECT date_trunc('second', timepoint) FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND ( aa.wait_event_type IS NOT NULL ) AND aa.state = 'active' ) SELECT count(*) INTO cpu_total FROM t ;

Example

 CLUSTER WAITINGS TIME : 30:12:49

Total pg_stat_statements values

Inquiry

  --TOTAL pg_stat SELECT SUM(calls) AS calls, SUM(total_time) AS total_time, SUM(rows) AS rows , SUM(shared_blks_hit) AS shared_blks_hit,SUM(shared_blks_read) AS shared_blks_read , SUM(shared_blks_dirtied) AS shared_blks_dirtied,SUM(shared_blks_written) AS shared_blks_written , SUM(local_blks_hit) AS local_blks_hit , SUM(local_blks_read) AS local_blks_read , SUM(local_blks_dirtied) AS local_blks_dirtied , SUM(local_blks_written) AS local_blks_written, SUM(temp_blks_read) AS temp_blks_read, SUM(temp_blks_written) temp_blks_written , SUM(blk_read_time) AS blk_read_time , SUM(blk_write_time) AS blk_write_time INTO pg_total_stat_history_rec FROM pg_stat_history WHERE snapshot_timestamp BETWEEN pg_stat_history_begin AND pg_stat_history_end AND queryid IS NULL;

SQL DBTIME - Total Query Runtime

Inquiry

 dbtime_total = interval '1 millisecond' * pg_total_stat_history_rec.total_time ;

Example

 SQL DBTIME : 136:49:36

SQL CPU TIME time of the CPU spent executing queries

Inquiry

 WITH t AS ( SELECT date_trunc('second', timepoint) FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND ( aa.wait_event_type IS NULL ) AND backend_type = 'client backend' AND aa.state = 'active' ) SELECT count(*) INTO cpu_total FROM t ;

Example

 SQL CPU TIME : 27:40:15

SQL WAITINGS TIME - Total Wait Time for Queries

Inquiry

 WITH t AS ( SELECT date_trunc('second', timepoint) FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND ( aa.wait_event_type IS NOT NULL ) AND aa.state = 'active' AND backend_type = 'client backend' ) SELECT count(*) INTO waiting_total FROM t ;

Example

 SQL WAITINGS TIME : 30:04:09

The following queries are trivial and to save space, implementation details are omitted:

Example

 | SQL IOTIME : 19:44:50 | SQL READ TIME : 19:44:32 | SQL WRITE TIME : 00:00:17 | | SQL CALLS : 12188248 ------------------------------------------------------------- | SQL SHARED BLOCKS READS : 7997039120 | SQL SHARED BLOCKS HITS : 8868286092 | SQL SHARED BLOCKS HITS/READS % : 110.89 | SQL SHARED BLOCKS DIRTED : 419945 | SQL SHARED BLOCKS WRITTEN : 19857 | | SQL TEMPORARY BLOCKS READS : 7836169 | SQL TEMPORARY BLOCKS WRITTEN : 10683938

We pass to the most interesting section

WAITINGS STATICTICS

TOP 10 WAITINGS BY TOTAL WAIT TIME FOR CLIENTS PROCESSES

Inquiry

 SELECT wait_event_type , wait_event , get_system_waiting_duration( wait_event_type , wait_event ,pg_stat_history_begin+(current_hour_diff * interval '1 hour') ,pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type != 'client backend' AND wait_event_type IS NOT NULL GROUP BY wait_event_type, wait_event ORDER BY 3 DESC LIMIT 10

Example

  + ------------------------------------------------- -----------------------------------
 |  TOP 10 WAITINGS BY TOTAL WAIT TIME FOR SYSTEM PROCESSES
 + ----- + ------------------------------ + ------------ -------- + --------------------
 |  # |  wait_event_type |  wait_event |  duration
 + ----- + ------------------------------ + ------------ -------- + --------------------
 |  1 |  Activity |  LogicalLauncherMain |  10:43:28
 |  2 |  Activity |  AutoVacuumMain |  10:42:49
 |  3 |  Activity |  WalWriterMain |  10:28:53
 |  4 |  Activity |  CheckpointerMain |  10:23:50
 |  5 |  Activity |  BgWriterMain |  09:11:59
 |  6 |  Activity |  BgWriterHibernate |  01:37:46
 |  7 |  IO |  BufFileWrite |  00:02:35
 |  8 |  LWLock |  buffer_mapping |  00:01:54
 |  9 |  IO |  DataFileRead |  00:01:23
 |  10 |  IO |  WALWrite |  00:00:59
 + ----- + ------------------------------ + ------------ -------- + --------------------

TOP 10 WAITINGS BY TOTAL WAIT TIME FOR CLIENTS PROCESSES

Inquiry

 SELECT wait_event_type , wait_event , get_clients_waiting_duration( wait_event_type , wait_event , pg_stat_history_begin+(current_hour_diff * interval '1 hour') , pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type = 'client backend' AND wait_event_type IS NOT NULL GROUP BY wait_event_type, wait_event ORDER BY 3 DESC LIMIT 10

Example

  + ----- + ------------------------------ + ------------ -------- + -------------------- + ----------
 |  # |  wait_event_type |  wait_event |  duration |  % dbtime
 + ----- + ------------------------------ + ------------ -------- + -------------------- + ----------
 |  1 |  Lock |  transactionid |  08: 16: 47 |  6.05
 |  2 |  IO |  DataFileRead |  06: 13: 41 |  4.55
 |  3 |  Timeout |  PgSleep |  02: 53: 21 |  2.11
 |  4 |  LWLock |  buffer_mapping |  00: 40: 42 |  0.5
 |  5 |  LWLock |  buffer_io |  00: 17: 17 |  0.21
 |  6 |  IO |  BufFileWrite |  00: 01: 34 |  0.02
 |  7 |  Lock |  tuple |  00: 01: 32 |  0.02
 |  8 |  Client |  ClientRead |  00: 01: 19 |  0.02
 |  9 |  IO |  BufFileRead |  00: 00: 37 |  0.01
 |  10 |  LWLock |  buffer_content |  00: 00: 08 |  0
 + ----- + ------------------------------ + ------------ -------- + -------------------- + ----------

WAITINGS TYPES BY TOTAL WAIT TIME, FOR SYSTEM PROCESSES

Inquiry

 SELECT wait_event_type , get_system_waiting_type_duration( wait_event_type , pg_stat_history_begin+(current_hour_diff * interval '1 hour') , pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type != 'client backend' AND wait_event_type IS NOT NULL GROUP BY wait_event_type ORDER BY 2 DESC

Example

  + ----- + ------------------------------ + ------------ --------
 |  # |  wait_event_type |  duration
 + ----- + ------------------------------ + ------------ --------
 |  1 |  Activity |  53:08:45
 |  2 |  IO |  00:06:24
 |  3 |  LWLock |  00:03:02
 + ----- + ------------------------------ + ------------ --------

WAITINGS TYPES BY TOTAL WAIT TIME, FOR CLIENTS PROCESSES

Inquiry

 SELECT wait_event_type , get_clients_waiting_type_duration( wait_event_type , pg_stat_history_begin+(current_hour_diff * interval '1 hour') , pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type = 'client backend' AND wait_event_type IS NOT NULL GROUP BY wait_event_type ORDER BY 2 DESC

Example

  + ----- + ------------------------------ + ------------ -------- + --------------------
 |  # |  wait_event_type |  duration |  % dbtime
 + ----- + ------------------------------ + ------------ -------- + --------------------
 |  1 |  Lock |  08: 18: 19 |  6.07
 |  2 |  IO |  06: 16: 01 |  4.58
 |  3 |  Timeout |  02: 53: 21 |  2.11
 |  4 |  LWLock |  00: 58: 12 |  0.71
 |  5 |  Client |  00: 01: 19 |  0.02
 |  6 |  IPC |  00: 00: 04 |  0
 + ----- + ------------------------------ + ------------ -------- + --------------------

Duration of expectations, for system processes and individual requests.

WAITINGS FOR SYSTEM PROCESSES

Inquiry

 SELECT backend_type , datname , wait_event_type , wait_event , get_backend_type_waiting_duration( backend_type , wait_event_type , wait_event , pg_stat_history_begin+(current_hour_diff * interval '1 hour') , pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type != 'client backend' AND wait_event_type IS NOT NULL GROUP BY backend_type , datname , wait_event_type , wait_event ORDER BY 5 DESC

Example

  + ----- + ----------------------------- + ---------- + - ------------------ + ---------------------- + -------- ------------
 |  # |  backend_type |  dbname |  wait_event_type |  wait_event |  duration
 + ----- + ----------------------------- + ---------- + - ------------------ + ---------------------- + -------- ------------
 |  1 |  logical replication launcher |  |  Activity |  LogicalLauncherMain |  10:43:28
 |  2 |  autovacuum launcher |  |  Activity |  AutoVacuumMain |  10:42:49
 |  3 |  walwriter |  |  Activity |  WalWriterMain |  10:28:53
 |  4 |  checkpointer |  |  Activity |  CheckpointerMain |  10:23:50
 |  5 |  background writer |  |  Activity |  BgWriterMain |  09:11:59
 |  6 |  background writer |  |  Activity |  BgWriterHibernate |  01:37:46
 |  7 |  parallel worker |  tdb1 |  IO |  BufFileWrite |  00:02:35
 |  8 |  parallel worker |  tdb1 |  LWLock |  buffer_mapping |  00:01:41
 |  9 |  parallel worker |  tdb1 |  IO |  DataFileRead |  00:01:22
 |  10 |  parallel worker |  tdb1 |  IO |  BufFileRead |  00:00:59
 |  11 |  walwriter |  |  IO |  WALWrite |  00:00:57
 |  12 |  parallel worker |  tdb1 |  LWLock |  buffer_io |  00:00:47
 |  13 |  autovacuum worker |  tdb1 |  LWLock |  buffer_mapping |  00:00:13
 |  14 |  background writer |  |  IO |  DataFileWrite |  00:00:12
 |  15 |  checkpointer |  |  IO |  DataFileWrite |  00:00:11
 |  16 |  walwriter |  |  LWLock |  WALWriteLock |  00:00:09
 |  17 |  checkpointer |  |  LWLock |  WALWriteLock |  00:00:06
 |  18 |  background writer |  |  LWLock |  WALWriteLock |  00:00:06
 |  19 |  walwriter |  |  IO |  WALInitWrite |  00:00:02
 |  20 |  autovacuum worker |  tdb1 |  LWLock |  WALWriteLock |  00:00:02
 |  21 |  walwriter |  |  IO |  WALInitSync |  00:00:02
 |  22 |  autovacuum worker |  tdb1 |  IO |  DataFileRead |  00:00:01
 |  23 |  checkpointer |  |  IO |  ControlFileSyncUpdate |  00:00:01
 |  24 |  background writer |  |  IO |  WALWrite |  00:00:01
 |  25 |  background writer |  |  IO |  DataFileFlush |  00:00:01
 |  26 |  checkpointer |  |  IO |  SLRUFlushSync |  00:00:01
 |  27 |  autovacuum worker |  tdb1 |  IO |  WALWrite |  00:00:01
 |  28 |  checkpointer |  |  IO |  DataFileSync |  00:00:01
 + ----- + ----------------------------- + ---------- + - ------------------ + ---------------------- + -------- ------------

WAITINGS FOR SQL - expectations for individual queries by queryid

Inquiry

 SELECT queryid , datname , wait_event_type , wait_event , get_query_waiting_duration( queryid , wait_event_type , wait_event , pg_stat_history_begin+(current_hour_diff * interval '1 hour') , pg_stat_history_end+(current_hour_diff * interval '1 hour') ) as duration FROM activity_hist.archive_pg_stat_activity aa WHERE timepoint BETWEEN pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND backend_type = 'client backend' AND wait_event_type IS NOT NULL AND queryid IS NOT NULL GROUP BY queryid , datname , wait_event_type , wait_event ORDER BY 1 , 5 DESC

Example

  + ----- + ------------------------- + ---------- + ------ -------------- + -------------------- + -------------- ------ + --------------------
 |  # |  queryid |  dbname |  wait_event_type |  wait_event |  waitings |  total
 |  |  |  |  |  |  duration |  duration
 + ----- + ------------------------- + ---------- + ------ -------------- + -------------------- + -------------- ------ + --------------------
 |  1 |  -8247416849404883188 |  tdb1 |  Client |  ClientRead |  00: 00: 02 |
 |  2 |  -6572922443698419129 |  tdb1 |  Client |  ClientRead |  00: 00: 05 |
 |  3 |  -6572922443698419129 |  tdb1 |  IO |  DataFileRead |  00: 00: 01 |
 |  4 |  -5917408132400665328 |  tdb1 |  Client |  ClientRead |  00: 00: 04 |
 |  5 |  -4091009262735781873 |  tdb1 |  Client |  ClientRead |  00: 00: 03 |
 |  6 |  -1473395109729441239 |  tdb1 |  Client |  ClientRead |  00: 00: 01 |
 |  7 |  28942442626229688 |  tdb1 |  IO |  BufFileWrite |  00: 01: 34 |  00:46:06
 |  8 |  28942442626229688 |  tdb1 |  LWLock |  buffer_mapping |  00: 01: 05 |  00:46:06
 |  9 |  28942442626229688 |  tdb1 |  IO |  DataFileRead |  00: 00: 44 |  00:46:06
 |  10 |  28942442626229688 |  tdb1 |  IO |  BufFileRead |  00: 00: 37 |  00:46:06
 |  11 |  28942442626229688 |  tdb1 |  LWLock |  buffer_io |  00: 00: 35 |  00:46:06
 |  12 |  28942442626229688 |  tdb1 |  Client |  ClientRead |  00: 00: 05 |  00:46:06
 |  13 |  28942442626229688 |  tdb1 |  IPC |  MessageQueueReceive |  00: 00: 03 |  00:46:06
 |  14 |  28942442626229688 |  tdb1 |  IPC |  BgWorkerShutdown |  00: 00: 01 |  00:46:06
 |  15 |  389015618226997618 |  tdb1 |  Lock |  transactionid |  03: 55: 09 |  04:14:15
 |  16 |  389015618226997618 |  tdb1 |  IO |  DataFileRead |  03: 23: 09 |  04:14:15
 |  17 |  389015618226997618 |  tdb1 |  LWLock |  buffer_mapping |  00: 12: 09 |  04:14:15
 |  18 |  389015618226997618 |  tdb1 |  LWLock |  buffer_io |  00: 10: 18 |  04:14:15
 |  19 |  389015618226997618 |  tdb1 |  Lock |  tuple |  00: 00: 35 |  04:14:15
 |  20 |  389015618226997618 |  tdb1 |  LWLock |  WALWriteLock |  00: 00: 02 |  04:14:15
 |  21 |  389015618226997618 |  tdb1 |  IO |  DataFileWrite |  00: 00: 01 |  04:14:15
 |  22 |  389015618226997618 |  tdb1 |  LWLock |  SyncScanLock |  00: 00: 01 |  04:14:15
 |  23 |  389015618226997618 |  tdb1 |  Client |  ClientRead |  00: 00: 01 |  04:14:15
 |  24 |  734234407411547467 |  tdb1 |  Client |  ClientRead |  00: 00: 11 |
 |  25 |  734234407411547467 |  tdb1 |  LWLock |  buffer_mapping |  00: 00: 05 |
 |  26 |  734234407411547467 |  tdb1 |  IO |  DataFileRead |  00: 00: 02 |
 |  27 |  1237430309438971376 |  tdb1 |  LWLock |  buffer_mapping |  00: 02: 18 |  02:45:40
 |  28 |  1237430309438971376 |  tdb1 |  IO |  DataFileRead |  00: 00: 27 |  02:45:40
 |  29 |  1237430309438971376 |  tdb1 |  Client |  ClientRead |  00: 00: 02 |  02:45:40
 |  30 |  2404820632950544954 |  tdb1 |  Client |  ClientRead |  00: 00: 01 |
 |  31 |  2515308626622579467 |  tdb1 |  Client |  ClientRead |  00: 00: 02 |
 |  32 |  4710212362688288619 |  tdb1 |  LWLock |  buffer_mapping |  00: 03: 08 |  02:18:21
 |  33 |  4710212362688288619 |  tdb1 |  IO |  DataFileRead |  00: 00: 22 |  02:18:21
 |  34 |  4710212362688288619 |  tdb1 |  Client |  ClientRead |  00: 00: 06 |  02:18:21
 |  35 |  4710212362688288619 |  tdb1 |  LWLock |  buffer_io |  00: 00: 02 |  02:18:21
 |  36 |  9150846928388977274 |  tdb1 |  IO |  DataFileRead |  00: 01: 19 |
 |  37 |  9150846928388977274 |  tdb1 |  LWLock |  buffer_mapping |  00: 00: 34 |
 |  38 |  9150846928388977274 |  tdb1 |  Client |  ClientRead |  00: 00: 10 |
 |  39 |  9150846928388977274 |  tdb1 |  LWLock |  buffer_io |  00: 00: 01 |
 + ----- + ------------------------- + ---------- + ------ -------------- + -------------------- + -------------- ------ + --------------------

CLIENT SQL STATICTICS - TOP queries

Requests for receiving again, however, are trivial and to save space, are not given.

Examples

  + ------------------------------------------------- -----------------------------------
 |  CLIENT SQL ordered by Elapsed Time
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + --------------------
 |  elapsed time |  calls |  % dbtime |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + --------------------
 |  04: 14: 15 |  19 |  3.1 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 |  02: 45: 40 |  746 |  2.02 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 |  02: 18: 21 |  749 |  1.69 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 |  00: 46: 06 |  375 |  0.56 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + --------------------
 |  CLIENT SQL ordered by CPU Time
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  cpu time |  calls |  % dbtime | total_time |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  02: 59: 49 |  19 |  3.1 |  04: 14: 15 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 |  01: 10: 12 |  746 |  2.02 |  02: 45: 40 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 |  00: 56: 15 |  749 |  1.69 |  02: 18: 21 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 |  00: 15: 35 |  375 |  0.56 |  00: 46: 06 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  CLIENT SQL ordered by User I / O Wait Time
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  io_wait time |  calls |  % dbtime | total_time |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  03: 23: 10 |  19 |  3.1 |  04: 14: 15 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 |  00: 02: 54 |  375 |  0.56 |  00: 46: 06 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 |  00: 00: 27 |  746 |  2.02 |  02: 45: 40 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 |  00: 00: 22 |  749 |  1.69 |  02: 18: 21 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  CLIENT SQL ordered by Shared Buffers Reads
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  buffers reads |  calls |  % dbtime | total_time |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  1056388566 |  19 |  3.1 |  04: 14: 15 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 |  11709251 |  375 |  0.56 |  00: 46: 06 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 |  3439004 |  746 |  2.02 |  02: 45: 40 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 |  3373330 |  749 |  1.69 |  02: 18: 21 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  CLIENT SQL ordered by Disk Reads Time
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  read time |  calls |  % dbtime | total_time |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  02: 16: 30 |  19 |  3.1 |  04: 14: 15 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 |  00: 04: 50 |  375 |  0.56 |  00: 46: 06 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 |  00: 01: 10 |  749 |  1.69 |  02: 18: 21 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 |  00: 00: 57 |  746 |  2.02 |  02: 45: 40 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  CLIENT SQL ordered by Executions
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  calls |  rows |  % dbtime | total_time |  % CPU |  % IO |  dbname |  queryid
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------
 |  749 |  749 |  1.69 |  02: 18: 21 |  3.39 |  0.1 |  tdb1 |  4710212362688288619
 |  746 |  746 |  2.02 |  02: 45: 40 |  4.23 |  0.08 |  tdb1 |  1237430309438971376
 |  375 |  0 |  0.56 |  00: 46: 06 |  0.94 |  0.41 |  tdb1 |  28942442626229688
 |  19 |  19 |  3.1 |  04: 14: 15 |  10.83 |  11.52 |  tdb1 |  389015618226997618
 + -------------------- + ---------- + ---------- + ------ ---- + ---------- + ---------- + ---------- + ------------ --------

Total

Using the submitted requests and the resulting reporting, you can get a more complete picture for analyzing and solving the problems of degradation of performance for individual requests and the entire cluster as a whole.

Development

So far, development plans are as follows:

Supplement reporting with a lock history. Requests are being tested and will be submitted shortly.
Use the TimescaleDB extension to store the history of pg_stat_activity and pg_locks.
Prepare a batch solution on github for mass deployment on production bases.

To be continued…

Source: https://habr.com/ru/post/467575/

All Articles

One way to get the workload profile and wait history in PostgreSQL

Input data

Submission History pg_stat_statements

Pg_stat_activity view history

Output

CLUSTER CPU TIME (SYSTEM + CLIENTS)

CLUSTER WAITINGS TIME

Total pg_stat_statements values

SQL DBTIME - Total Query Runtime

SQL CPU TIME time of the CPU spent executing queries

SQL WAITINGS TIME - Total Wait Time for Queries

WAITINGS STATICTICS

TOP 10 WAITINGS BY TOTAL WAIT TIME FOR CLIENTS PROCESSES

TOP 10 WAITINGS BY TOTAL WAIT TIME FOR CLIENTS PROCESSES

WAITINGS TYPES BY TOTAL WAIT TIME, FOR SYSTEM PROCESSES

WAITINGS TYPES BY TOTAL WAIT TIME, FOR CLIENTS PROCESSES

WAITINGS FOR SYSTEM PROCESSES

WAITINGS FOR SQL - expectations for individual queries by queryid

CLIENT SQL STATICTICS - TOP queries

Total

Development

More articles: