One of the greatest features of Postgres is extensibility. In particular, extensions can help to dramatically improve performance troubleshooting capabilities. You can leverage built-in extensions or install from some third-party repositories managed by companies like Percona or EDB or simply install them from git sources.
One of the typical performance issues is when some process takes much longer than it used to take in the past. This post describes Top 5 extensions which can help with such retrospective analysis.
pg_stat_statements extension
This is arguably the most popular extension in the performance tuning area. It is shipped by default with PostgreSQL and you can see it in pg_available_extensions. This extension provides great cumulative statistics per statement however it might be a little tricky to investigate performance issues for specific retrospective period.
In order to address that the most straightforward way is to take snapshot of pg_stat_statements every X seconds and store it in a separate table. This article gives really good explanation how that can be done with TimescaleDB but you can implement similar solution in vanilla PostgreSQL as well.
auto_explain module
auto_explain module is also shipped by default with PostgreSQL. In order to use this one it is not necessary to modify shared_preload_libraries in postgresql.conf. We can simply enable it in a particular session with load command.
Quick demo
We enable auto_explain for a given session and it will log query plan along with execution stats if excution takes more than 3 seconds.
postgres=# load 'auto_explain';
LOAD
postgres=# set auto_explain.log_min_duration = '3s';
SET
postgres=# set auto_explain.log_analyze = on;
SET
postgres=# select sum(i*sin(i)) result from generate_series(1, 25*1000*1000) i;
result
-------------------
14400086.14370021
(1 row)
Here is what we can see in the log
postgres@postgres LOG: duration: 7871.471 ms plan:
Query Text: select sum(i*sin(i)) result from generate_series(1, 25*1000*1000) i;
Aggregate (cost=562500.00..562500.01 rows=1 width=8) (actual time=7871.459..7871.460 rows=1 loops=1)
-> Function Scan on generate_series i (cost=0.00..250000.00 rows=25000000 width=4) (actual time=2594.601..4840.086 rows=25000000 loops=1)
pg_sentinel extension
This one should be download installed and installed separately. This extension samples pg_stat_statements every X seconds so the idea is exactly the same as the one explained in the first section but you do not need to maintain your own solution.
One more important detail about pg_stat_statements is that is groups statements by normalized query text. For example, query from above demo turns into
select sum(i*sin(i)) result from generate_series($1, $2*$3*$4) i
pg_sentinel allows to view original text which may be very handy when you want to see exact query predicates with literals, for example.
pg_stat_monitor extension
Another extension which can be installed from git sources like pg_sentinel. Percona provides a number of alternative options to download and install this extension.
pg_stat_monitor also uses pg_stats_statements under the hood. Similar to pg_sentinel it allows to see original query text but pg_stat_monitor aggregates stats per bucket and bucket lifetime is 60 seconds by default.
Also this extension provides some extra information comparing to pg_sentinel – for example, error awareness per query. Features are explained in detail here.
Quick demo
To demonstrate some capabilities let’s clear statistics and run a few statements with 10 seconds delay before each.
select pg_stat_monitor_reset();
select sum(i*sin(i)) result from generate_series(1, 1*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 2*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 3*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 4*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 5*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 6*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 7*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 8*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 9*1000*1000) i;
select pg_sleep(10);
select sum(i*sin(i)) result from generate_series(1, 1/0) i;
The statistics is following
postgres=# select query, calls, sqlcode, message from pg_stat_monitor where query ~ 'sin' and query !~ 'stat';
query | calls | sqlcode | message
--------------------------------------------------------------------+-------+---------+------------------
select sum(i*sin(i)) result from generate_series(1, 1*1000*1000) i | 5 | |
select sum(i*sin(i)) result from generate_series(1, 6*1000*1000) i | 4 | |
select sum(i*sin(i)) result from generate_series(1, 1/0) i; | 1 | 22012 | division by zero
(3 rows)
pg_stat_monitor aggregated stats for each bucket and it may be a little confusing that it takes query text for the first execution for each bucket. So 9 executions went into two buckets: 5 + 4.
Also, as mentioned earlier, you can see error status for each query which might be extremely helpful in some scenarios.
sql_profiler extension
In order to install this extension you need to have EDB account and set-up EDB repositories. EDB provides instructions how to install this extension depending on the PostgreSQL edition you have. Whether it is EDB Postgres Advanced Server and EDB Postgres Extended or regular PostgreSQL.
SQL Profiler stores raw trace files under traces directory which is located in data directory for a given cluster. Function sp_load_trace can load trace files into temporary table _sp_tmp_tbl_sql_profiler – see usage here.
In a nutshell trace contains an output similar to explain analyze with some additional stats. Below is a description of _sp_tmp_tbl_sql_profiler from psql to give a hint what potentially can be reported with SQL Profiler.
Column | Type | Collation | Nullable | Default
--------------------+--------------------------+-----------+----------+---------
trace_id | bigint | | |
start_time | timestamp with time zone | | |
end_time | timestamp with time zone | | |
appl_name | text | | |
user_id | oid | | |
db_id | oid | | |
query_type | smallint | | |
query_id | bigint | | |
explain | text | | |
duration | double precision | | |
rows_updated | bigint | | |
fs_in | bigint | | |
fs_out | bigint | | |
page_faults | bigint | | |
page_reclaims | bigint | | |
swaps | bigint | | |
sign_recv | bigint | | |
msg_recv | bigint | | |
msg_snd | bigint | | |
vol_contx_switch | bigint | | |
invol_contx_switch | bigint | | |
shared_blk_read | bigint | | |
shared_blk_written | bigint | | |
shared_blk_hit | bigint | | |
local_blk_read | bigint | | |
local_blk_written | bigint | | |
local_blk_hit | bigint | | |
tmp_blk_read | bigint | | |
tmp_blk_written | bigint | | |
pid | integer | | |
This extension was designed to be used in PEM and following video shows typical usage scenario.
SQLMDX 