Performance tuning does not only mean adjusting postgresql.conf properly, or making sure that your kernel parameters are properly tuned. Performance tuning also implies that we have to find performance bottlenecks first, isolate slow queries and understand what the system is doing.
I believe the best and most efficient way to detect performance problems is to make use of pg_stat_statement, which is an excellent extension shipped with PostgreSQL and is used to inspect query statistics in general. It helps you to instantly figure out which queries cause bad performance and how often they are executed.
Over the years, I have begun to get the impression that for most people “tuning” is limited to adjusting some magical PostgreSQL parameters. Sure, parameter tuning does help, but I can assure you, there is no such thing as “speed = on”. It does not exist and it most likely never will. Instead, we have to fall back on some pretty “boring techniques” such as inspecting queries to figure out what is going on in your database.
There is one law of nature that has been true for the past 20 years and will most likely still hold true 20 years from now:
Queries cause database load
And slow queries are the main reason for such load.
Armed with this important, yet highly under-appreciated wisdom, we can use pg_stat_statements to figure out which queries have caused the most load, and tackle those – instead of wasting time on irrelevant guess work.
Installing pg_stat_statements in PostgreSQL
As mentioned above, pg_stat_statements comes as part of PostgreSQL. All you have to do to enjoy the full benefit of this exceptionally useful extension, is enable it.
The first thing you have to do is to change shared_preload_libraries in postgresql.conf:
shared_preload_libraries = ‘pg_stat_statements’
Then restart PostgreSQL.
Finally, the module can be enabled in your desired database:
test=# CREATE EXTENSION pg_stat_statements; CREATE EXTENSION
The last step will deploy a view – we will need to inspect the data collected by the pg_stat_statements machinery.
Taking a look at pg_stat_statements
pg_stat_statements provides a ton of useful information. Here is the definition of the view, as of PostgreSQL 13. Note that the view has been growing over the years and more and more vital information is added as PostgreSQL is steadily extended:
test=# \d pg_stat_statements View "public.pg_stat_statements" Column | Type | Collation | Nullable | Default ---------------------+------------------+-----------+----------+--------- userid | oid | | | dbid | oid | | | 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 | | | wal_records | bigint | | | wal_fpi | bigint | | | wal_bytes | numeric | | | ...
The danger here is that people get lost in the sheer volume of information. Therefore it makes sense to process this data a bit to extract useful information.
Making use of the data
To make it easier for our readers to extract as much information as possible from pg_stat_statements, we have compiled a couple of queries that we have found useful over the years.
The most important one is used to find out which operations are the most time-consuming. Here is the query:
test=# SELECT substring(query, 1, 30) AS query,
calls,
round(total_exec_time::numeric, 2) AS total_time,
round(mean_exec_time::numeric, 2) AS mean_time,
round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 2) AS percentage
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;
query | calls | total_time | mean_time | percentage
--------------------------------+-------+------------+-----------+------------
UPDATE pgbench_tellers SET tba | 97609 | 102212.40 | 1.05 | 51.94
UPDATE pgbench_branches SET bb | 97609 | 88689.63 | 0.91 | 45.07
UPDATE pgbench_accounts SET ab | 97609 | 3183.96 | 0.03 | 1.62
SELECT abalance FROM pgbench_a | 97609 | 1126.53 | 0.01 | 0.57
INSERT INTO pgbench_history (t | 97609 | 703.98 | 0.01 | 0.36
copy pgbench_accounts from std | 1 | 240.15 | 240.15 | 0.12
alter table pgbench_accounts a | 1 | 61.18 | 61.18 | 0.03
CREATE EXTENSION pg_stat_state | 2 | 52.61 | 26.30 | 0.03
SELECT pg_catalog.quote_ident( | 3 | 51.81 | 17.27 | 0.03
vacuum analyze pgbench_account | 1 | 49.31 | 49.31 | 0.03
(10 rows)
What you see here is how often a certain type of query has been executed, and how many milliseconds of total execution time we have measured. Finally, I have put the numbers into context and calculated the percentage of total runtime for each type of query. Also, note that I have used substring to make the query shorter. The reason for that is to make it easier to display the data on the website. In real life, you usually want to see the full query.
The main observations in my example are that the first two queries already need 97% of the total runtime. In other words: The rest is totally irrelevant. One can also see that the slowest query by far (= the loading process) has absolutely no significance in the bigger picture. The real power of this query is that we instantly spot the most time-consuming operations.
However, sometimes it is not only about runtime – often I/O is the real issue. pg_stat_statements can help you with that one as well. But let’s first reset the content of the view:
test=# SELECT pg_stat_statements_reset(); pg_stat_statements_reset -------------------------- (1 row)
Measuring I/O time is simple. The track_io_timing parameter can be adjusted to measure this vital KPI. You can turn it on in postgresql.conf for the entire server, or simply adjust things on the database level if you want more fine-grained data:
test=# ALTER DATABASE test SET track_io_timing = on; ALTER DATABASE
In this example, the parameter has been set for this one specific database. To create more data, we can again run a couple of tests:
iMac:~ hs$ pgbench -c 10 -j 10 -T 30 test starting vacuum...end. transaction type: <builtin: TPC-B (sort of)> scaling factor: 1 query mode: simple number of clients: 10 number of threads: 10 duration: 30 s number of transactions actually processed: 125744 latency average = 2.387 ms tps = 4189.758792 (including connections establishing) tps = 4191.299887 (excluding connections establishing) iMac:~ hs$ pgbench -c 10 -j 10 -T 30 -S test starting vacuum...end. transaction type: <builtin: select only> scaling factor: 1 query mode: simple number of clients: 10 number of threads: 10 duration: 30 s number of transactions actually processed: 1239972 latency average = 0.242 ms tps = 41323.638554 (including connections establishing) tps = 41337.620153 (excluding connections establishing)
If you want to know more about pgbench utility, please, read the post from Kaarel Moppel.
These two tests can then be checked using one more query:
test=# SELECT substring(query, 1, 30) AS query,
calls,
round(total_exec_time::numeric, 2) AS total_time,
round(blk_read_time::numeric, 2) AS io_read_time,
round(blk_write_time::numeric, 2) AS io_write_time,
round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 2) AS percentage
FROM pg_stat_statements
ORDER BY blk_read_time + blk_write_time DESC
LIMIT 10;
query | calls | total_time | io_read_time | io_write_time | percentage
--------------------------------+---------+------------+--------------+---------------+------------
INSERT INTO pgbench_history (t | 125744 | 847.02 | 0.04 | 0.00 | 0.44
END | 125744 | 50.11 | 0.00 | 0.00 | 0.03
truncate pgbench_history | 2 | 1.29 | 0.00 | 0.00 | 0.00
select count(*) from pgbench_b | 2 | 0.37 | 0.00 | 0.00 | 0.00
ALTER DATABASE test SET track_ | 1 | 0.24 | 0.00 | 0.00 | 0.00
SELECT abalance FROM pgbench_a | 1365716 | 16740.08 | 0.00 | 0.00 | 8.69
UPDATE pgbench_tellers SET tba | 125744 | 103813.51 | 0.00 | 0.00 | 53.92
UPDATE pgbench_accounts SET ab | 125744 | 5795.74 | 0.00 | 0.00 | 3.01
SELECT substring(query, $1, $ | 1 | 0.16 | 0.00 | 0.00 | 0.00
SELECT substring(query, $1, $ | 1 | 0.37 | 0.00 | 0.00 | 0.00
(10 rows)
blk_read_time is the amount of time spent on reading data from the operating system. blk_write_time tells us about the time needed to send data to the OS. The important observation here is that I/O is not really an issue. A fraction of a second is needed, which is basically nothing compared to the overall execution time. In other words: Spending a ton of money on additional I/O capacity (disks, cloud services) does not really pay off in this case. However, many people pay for hardware or services BEFORE they figure out that it is pointless.
If you are looking for good performance, it makes sense to consider temporary I/O as a potential factor. temp_blks_read and temp_blks_written are the important parameters here. But keep in mind that simply throwing work_mem at temporary I/O is not usually the solution. In the case of normal everyday operations, the real problem is often a missing index.
Finally…
pg_stat_statements is an important topic, but it is often overlooked. However, if you want to find out more about performance, we have tons of useful content for you. Maybe you want to check out our post about checkpoints and checkpoint performance in PostgreSQL.
Also, try watching some of the exciting new videos on our YouTube channel. We post fresh content there on a regular basis. If you enjoy the videos, like us and subscribe!