Module 8: Tooling and Testing
Debugging Queries
A method for finding wrong results and slow queries: shrink the problem, check row counts at every step, decode common error messages, and find blocked or runaway sessions.
SQL fails in two ways. Loudly, with an error message, which is the easy case. And quietly, by returning a result that looks reasonable and is wrong, which is the dangerous one. A report with the wrong revenue figure does not crash. It gets pasted into a slide.
Debugging a query is a method, not inspiration. The same few moves resolve nearly every case.
The method#
- Define what "right" looks like before you debug. Know one correct number from somewhere else: a count you can verify by hand, last month's figure, a total from the source system.
- Reproduce on the smallest input. Cut the query to one customer, one day, one order.
- Build the query up from the bottom. Run the first table alone. Add one join. Check. Add the next.
- Check the row count after each step. Surprises show up as a count that jumped or dropped.
- Compare against your known-good number at each stage, not only at the end.
Skip step 1 and you will spend an hour staring at a query with no idea whether it is wrong.
Wrong results: the usual suspects#
Walk this list in order. Each of these has produced a "the data must be corrupt" report that turned out to be the query.
Join fan-out. A join to a table with several rows per key repeats the parent row, and every SUM and COUNT over it inflates. The tell: the total is a clean multiple of the right one, or a count exceeds the number of entities.
SELECT COUNT(*) AS joined_rows,
COUNT(DISTINCT o.order_id) AS orders
FROM orders o
JOIN order_items oi ON oi.order_id = o.order_id;
-- joined_rows | orders
-- 26 | 14
If joined rows far exceed distinct parents, ask what one row now represents. The course data's correct non-cancelled revenue is 3139.50. Suppose someone adds a join to an order_events table that logs two status changes per order. Every order line now appears twice and the sum reports exactly 6279.00. A clean 2x multiple is a fan-out fingerprint.
NULL in a comparison. NOT IN against a nullable column returns nothing. <> 'x' drops the NULL rows. COUNT(column) skips them. Check WHERE column IS NULL to see how many rows you are quietly excluding.
A LEFT JOIN filtered in WHERE. The filter turns it into an inner join, and the unmatched rows disappear. Move the condition to ON.
Integer division. SUM(a) / COUNT(*) on integers truncates. Cast one side to NUMERIC.
Time zones and date boundaries. A "daily" total that is off by a few rows is usually a timestamp that fell on the other side of midnight in a different zone. Check the type and the zone.
BETWEEN on timestamps. The last day is cut off at midnight.
Implicit filtering by INNER JOIN. A customer with no matching row in a lookup table silently vanishes. Try a LEFT JOIN and look at the NULLs.
DISTINCT hiding duplicates. If removing DISTINCT changes the answer, your join is multiplying rows.
Unstable sort or LIMIT without ORDER BY. Different runs return different rows.
A stale view. A materialized view not refreshed, a cached report.
Check each CTE on its own#
CTEs make isolation easy. Stop at any step:
WITH monthly AS (...),
with_prev AS (...)
SELECT * FROM monthly; -- instead of the final SELECT
Compare each stage's counts and totals to what you expect. The first stage where they diverge contains the bug.
Reading error messages#
PostgreSQL's errors are specific. Read the whole message, including DETAIL and HINT.
| Message | Usual cause | First move |
|---|---|---|
syntax error at or near "FROM" | the real mistake is before that spot: a trailing comma, a missing keyword | look at the token just before it |
column "x" does not exist | typo, wrong table alias, or a quoted mixed-case name | check spelling; check \d table; remember aliases are not visible in WHERE |
relation "orders" does not exist | wrong database, wrong schema, or the table was created as "Orders" | \dt, SHOW search_path |
column reference "status" is ambiguous | the name exists in two joined tables | qualify it: o.status |
column "x" must appear in the GROUP BY clause or be used in an aggregate function | selected a column that is not grouped | group by it or aggregate it |
operator does not exist: integer = text | comparing different types | cast one side, or fix the column type |
more than one row returned by a subquery used as an expression | a scalar subquery matched several rows | aggregate, LIMIT 1, or use IN / a join |
division by zero | a zero denominator | NULLIF(denominator, 0) |
value too long for type character varying(20) | input exceeds the column limit | trim or widen the column |
null value in column "x" violates not-null constraint | an insert missed a required column | supply it or set a default |
duplicate key value violates unique constraint | key already exists | upsert, or find the existing row |
current transaction is aborted, commands ignored until end of transaction block | an earlier statement failed inside the transaction | ROLLBACK, then fix the first error |
deadlock detected | two transactions locked in opposite order | lock in a consistent order; retry |
canceling statement due to statement timeout | the query ran longer than the limit | read the plan; add an index or rewrite |
permission denied for table x | role lacks a privilege | \dp x, check GRANTs |
One name trap deserves a mention. Unquoted identifiers fold to lowercase. CREATE TABLE Orders makes orders. CREATE TABLE "Orders" makes a different, case-sensitive table that you must always quote. Avoid quoted identifiers in your own schemas.
Slow queries#
Do not guess. Measure.
EXPLAIN (ANALYZE, BUFFERS) SELECT ...;
Look for the node with the largest actual time, then ask three questions about it. Is it reading far more rows than it returns (Rows Removed by Filter is huge)? Is the estimate wildly different from the actual row count? Is it running inside a loop with a large loops=?
To find the worst offenders across the whole system, use the pg_stat_statements extension:
SELECT calls,
ROUND(total_exec_time::numeric, 0) AS total_ms,
ROUND(mean_exec_time::numeric, 2) AS mean_ms,
LEFT(query, 80) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;
A query that runs 2 million times at 5 ms each costs far more than one that runs once at 4 seconds. Sort by total time first.
To catch slow statements as they happen, set log_min_duration_statement = '500ms' and read the logs.
What is running right now, and who is blocking whom#
-- Active sessions and what they are waiting for
SELECT pid, usename, state, wait_event_type, wait_event,
now() - query_start AS running_for, LEFT(query, 70) AS query
FROM pg_stat_activity
WHERE state <> 'idle'
ORDER BY query_start;
-- Who is blocked, and by whom
SELECT pid, pg_blocking_pids(pid) AS blocked_by, LEFT(query, 70) AS query
FROM pg_stat_activity
WHERE cardinality(pg_blocking_pids(pid)) > 0;
A session in idle in transaction that appears in someone's blocked_by list is the usual culprit: a client that opened a transaction and wandered off.
Stop a runaway query gently first:
SELECT pg_cancel_backend(12345); -- cancel the current query, keep the connection
SELECT pg_terminate_backend(12345); -- drop the whole connection (last resort)
Find out why it happened afterward, or it will recur.
When you are stuck#
- Explain it out loud, to a colleague or a rubber duck. Describing "this join should produce one row per order" often exposes the line where it does not.
- Shrink until it works, then grow until it breaks. The step that breaks it is the bug.
- Test the assumption you are most sure of. "Order IDs are unique" is the claim that is wrong.
- Look at actual rows, not only aggregates. Ten raw rows beat an hour of theory.
Common mistakes#
Debugging the final query instead of its stages. Check each step.
Having no known-good number. You cannot tell whether a result is wrong.
Trusting a result because it looks plausible. Reconcile with another source.
Reading only the first line of an error. DETAIL and HINT usually name the exact row or column.
Guessing at indexes. Read the plan first.
Killing a session without finding out why it hung. The next one will do the same.
Practice#
- Write a query that joins
customers,ordersandorder_itemsand sums revenue per customer. Compare each customer's figure with theorder_totalsview. Introduce a deliberate extra join that fans out, and spot the inflation. - Cause each of these errors on purpose and read the message: a missing
GROUP BYcolumn, an ambiguous column,integer = text, and a scalar subquery returning two rows. - Reproduce the
NOT INtrap: list employees who manage nobody withNOT IN (SELECT manager_id FROM employees), see the empty result, and explain why. Fix it two ways. - In two sessions, create a blocked update and use
pg_blocking_pidsto identify the blocker. Cancel it withpg_cancel_backend. - Install
pg_stat_statements, run a few queries, and list the top three by total time.