Finding the load, not the knobs

Tuning a PostgreSQL instance is usually understood as editing postgresql.conf and checking kernel parameters. Those things matter, but they come second: before anything can be optimized, the bottlenecks have to be located, the slow queries isolated, and the system's actual behavior understood. There is no "speed = on" setting, and there most likely never will be. That leaves the unglamorous work of inspecting queries.

The underlying rule has held for two decades and will probably hold for two more: queries cause database load, and slow queries are the main source of it. The practical consequence is to identify which statements generate the most load and work on those, rather than guessing.

Enabling pg_stat_statements

pg_stat_statements ships with PostgreSQL and is the most efficient way to inspect general query statistics — which queries hurt performance and how often they run. It only needs to be turned on. First add it to shared_preload_libraries in postgresql.conf:

1

shared_preload_libraries = 'pg_stat_statements'

Then restart PostgreSQL, and enable the module in the target database:

1

2

test=# CREATE EXTENSION pg_stat_statements;

CREATE EXTENSION

That last step deploys the view holding the collected data.

Reading the view

As of PostgreSQL 15 the view definition looks like this; it has grown steadily across releases as more information was added:

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

test=# d pg_stat_statements

                      View 'public.pg_stat_statements'

         Column         |       Type       | Collation | Nullable | Default

------------------------+------------------+-----------+----------+---------

userid                 | oid              |           |          |

dbid                   | oid              |           |          |

toplevel               | boolean          |           |          |

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 |           |          |

temp_blk_read_time     | double precision |           |          |

temp_blk_write_time    | double precision |           |          |

wal_records            | bigint           |           |          |

wal_fpi                | bigint           |           |          |

wal_bytes              | numeric          |           |          |

jit_functions          | bigint           |           |          |

jit_generation_time    | double precision |           |          |

jit_inlining_count     | bigint           |           |          |

jit_inlining_time      | double precision |           |          |

jit_optimization_count | bigint           |           |          |

jit_optimization_time  | double precision |           |          |

jit_emission_count     | bigint           |           |          |

jit_emission_time      | double precision |           |          |

The volume of columns is itself a hazard. Some processing is needed to turn it into something usable.

Queries worth running

The single most important one ranks operations by time consumed:

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

test=# SELECT substring(query, 1, 40) 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

------------------------------------------+---------+------------+-----------+------------

SELECT  * FROM t_group AS a, t_product A | 1378242 |  128913.80 |      0.09 |      41.81

SELECT  * FROM t_group AS a, t_product A |  900898 |  122081.85 |      0.14 |      39.59

SELECT relid AS stat_rel, (y).*, n_tup_i |      67 |   14526.71 |    216.82 |       4.71

SELECT $1                                | 6146457 |    5259.13 |      0.00 |       1.71

SELECT  * FROM t_group AS a, t_product A | 1135914 |    4960.74 |      0.00 |       1.61

/*pga4dash*/                            +|    5289 |    4369.62 |      0.83 |       1.42

SELECT $1 AS chart_name, pg              |         |            |           |

SELECT attrelid::regclass::text, count(* |      59 |    3834.34 |     64.99 |       1.24

SELECT  *                               +|  245118 |    2040.52 |      0.01 |       0.66

FROM    t_group AS a, t_product          |         |            |           |

SELECT count(*) FROM pg_available_extens |     430 |    1383.77 |      3.22 |       0.45

SELECT   query_id::jsonb->$1 AS qual_que |      59 |    1112.68 |     18.86 |       0.36

(10 rows)

Each row shows how often a type of query ran, the total milliseconds of execution time measured for it, and — with the numbers put into context — its share of total runtime. The substring here only shortens the output for display; in real use the full query is what you want to see.

In the example above, the first two queries already account for 80% of total runtime, making the remainder irrelevant, while the slowest query by far — the loading process — turns out to have no significance in the bigger picture. That is the point: the most time-consuming operations become visible immediately.

Runtime is not always the issue; I/O often is. Start by resetting the view contents:

1

2

3

4

5

test=# SELECT pg_stat_statements_reset();

pg_stat_statements_reset

--------------------------

(1 row)

I/O timing is measured through track_io_timing, which can be set in postgresql.conf for the whole server or scoped to a database for finer granularity:

1

2

1 test=# ALTER DATABASE test SET track_io_timing = on;

2 ALTER DATABASE

With that in place, setting total_exec_time against the time actually spent on I/O shows whether the workload is bound by the I/O system or by the CPU — and therefore whether more disks (IOPS) would help at all:

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

test=# SELECT substring(query, 1, 30),

total_exec_time,

blk_read_time,

blk_write_time

FROM pg_stat_statements

ORDER BY blk_read_time + blk_write_time DESC

LIMIT 10;

           substring            |  total_exec_time   |   blk_read_time    | blk_write_time

--------------------------------+--------------------+--------------------+----------------

SELECT relid AS stat_rel, (y). | 14526.714420000004 |        9628.731881 |              0

SELECT attrelid::regclass::tex | 3834.3388820000005 | 1800.8131490000003 |       3.351335

FETCH 100 FROM c1              |   593.835973999964 | 143.45405699999006 |              0

SELECT   query_id::jsonb->$1 A |        1112.681625 |  72.39612800000002 |              0

SELECT   oid::regclass, relkin |         536.750372 | 57.409583000000005 |              0

INSERT INTO deep_thinker.t_adv |  90.34870800000012 | 46.811619999999984 |              0

INSERT INTO deep_thinker.t_thi |  72.65854599999999 |          43.621994 |              0

create database xyz            |          97.532209 |          32.450164 |              0

WITH x AS (SELECT c.conrelid:: | 46.389295000000004 | 25.007044999999994 |              0

SELECT * FROM (SELECT relid::r | 511.72187599999995 | 23.482600000000005 |              0

(10 rows)

Temporary I/O deserves the same attention through temp_blks_read and temp_blks_written. Throwing work_mem at that problem is usually the wrong move; in everyday operations the real cause is often a missing index.

Closing note

pg_stat_statements remains an underused extension, and it is worth spreading the word about it. Parameter tuning helps, but it starts with knowing which queries are actually responsible for the load.