Dev & EngARTICLE

Como usar o pg_stat_statements para achar as queries mais caras em produção

No sétimo e último episódio da série Postgres in Production, Ryan Booz mostra por onde começar quando o chamado de lentidão chega e você não tem histórico de métricas guardado.

Como usar o pg_stat_statements para achar as queries mais caras em produção
Image: Roberto Diniz

pg_stat_statements is probably the most cited extension when the topic is PostgreSQL performance, but a good portion of those who enable it have never actually queried it in a structured way during a real incident. That's exactly the gap Ryan Booz, from the pganalyze team, closes in the seventh and final episode of the Postgres in Production series (source). After six episodes explaining what the extension is, how it normalizes query text, and where it stores that text, it's time to run real queries against the view.

Booz's starting point is uncomfortable, but correct: pg_stat_statements has no timeline at all. The numbers are cumulative since the last reset. If you want to see a trend, you need snapshots, delta calculations between them, and a place to store that history outside the view itself, handling resets, queries evicted from the cache, and new queries showing up along the way. That is, in essence, the work any monitoring tool does for you.

Why query pg_stat_activity first

The first instinct of anyone learning about pg_stat_statements during an incident is usually wrong: go straight to the extension. It only records a query's metrics after execution finishes. If the problem right now is an ad hoc query that's stuck, still running, it simply won't show up there (or it will show up with data from previous executions, which doesn't reflect what's happening this very second). That's why the correct playbook starts with pg_stat_activity:

sql
SELECT
 pid,
 query_id,
 usename,
 application_name,
 state,
 now() - xact_start AS transaction_duration,
 now() - query_start AS query_duration,
 wait_event_type,
 wait_event,
 query
FROM pg_stat_activity
WHERE state = 'active'
 AND pid <> pg_backend_pid()
ORDER BY query_duration DESC;

This query is a sanity check: is there something abnormal running right now, outside the pattern of replication and normal routines? If so, the problem may not even be about pg_stat_statements, but a stuck transaction, a lock, or a badly written ad hoc query that nobody has normalized yet.

Two ways to get a window out of cumulative data

Once the hypothesis of something happening in real time is ruled out, it's time to look for patterns: a query running repeatedly, a process hammering the same statement. Booz describes two approaches.

The safe approach is to take two snapshots with a time interval between them (10 seconds, 30 seconds, a minute, whatever makes sense for your workload) and calculate the difference:

sql
CREATE TEMP TABLE pgss_before AS
SELECT * FROM pg_stat_statements;

-- wait long enough for the workload to repeat

CREATE TEMP TABLE pgss_after AS
SELECT * FROM pg_stat_statements;

SELECT
 a.queryid,
 a.calls - b.calls AS calls_delta,
 round((a.total_exec_time - b.total_exec_time)::numeric, 2) AS exec_time_delta_ms,
 a.rows - b.rows AS rows_delta,
 a.shared_blks_read - b.shared_blks_read AS shared_reads_delta,
 a.temp_blks_written - b.temp_blks_written AS temp_written_delta,
 left(a.query, 100) AS query
FROM pgss_after a
JOIN pgss_before b
 ON a.userid = b.userid AND a.dbid = b.dbid AND a.queryid = b.queryid
WHERE a.calls > b.calls
ORDER BY exec_time_delta_ms DESC
LIMIT 10;

This is the option I would recommend for a sensitive production environment, because it doesn't discard anything: you're just looking at a time slice without erasing the accumulated history that already existed.

The aggressive approach, on the other hand, is to reset everything with SELECT pg_stat_statements_reset(); and start querying again from a clean table. It creates an observation window free of accumulated noise, which helps a lot when the incident is active and repeatable. But it has a cost: if the problem is rare, or if the previous history matters (to compare before/after a change, for example), resetting throws that away. To find out when the last reset happened, it's worth checking pg_stat_statements_info:

sql
SELECT dealloc, stats_reset FROM pg_stat_statements_info;

The right ORDER BY depends on the question, not the table

The most practical part of the episode is the reminder that the same query, just by changing the ORDER BY, answers different questions:

sql
-- what runs the most?
ORDER BY calls DESC

-- what's slow every time it runs?
WHERE calls >= 10
ORDER BY mean_exec_time DESC

-- what reads the most data from disk?
ORDER BY shared_blks_read DESC

-- what spills to disk (temp files)?
ORDER BY temp_blks_written DESC

Booz's warning here is the one most worth keeping: the query that's slowest on average isn't always your real problem. A 4ms query called 2 million times consumes 8,000 seconds of total time; a 4-second query called 20 times consumes 80 seconds. The first one looks harmless if you only look at mean_exec_time, but it's the one draining the server's CPU and I/O. total_exec_time captures this effect of

Translated from the Brazilian Portuguese original · Read the original