EXPLAIN & EXPLAIN ANALYZE — đọc query plan của PostgreSQL

Query chạy 2 giây. PM hỏi "sao chậm?" Bạn đoán: thiếu index? JOIN sai? Data nhiều quá? Đoán xong thêm index thử — vẫn 2 giây. Thêm cái nữa — 1.8 giây. Đoán tiếp.

Đây là cách optimize của đa số developer. Và đây cũng là lý do phần lớn optimization không hiệu quả: đoán mà không nhìn vào bằng chứng.

EXPLAIN là công cụ PostgreSQL dùng để cho bạn xem bên trong — query planner đang nghĩ gì, chọn chiến lược gì, ước tính bao nhiêu row, tốn bao nhiêu cost. Trước khi đụng vào bất kỳ index nào, đọc EXPLAIN trước. Bài này dạy bạn đọc plan output từ đầu đến cuối.

1. Analogy — Google Maps route preview vs lái thực tế

Google Maps cho bạn xem route trước khi lái: ước tính 45 phút, 32 km, qua cao tốc. Bạn có thể chọn route khác trước khi nổ máy. EXPLAIN hoạt động theo đúng cách đó — cho bạn xem "plan" của PostgreSQL trước khi query thực sự chạy.

2. EXPLAIN vs EXPLAIN ANALYZE — khi nào dùng cái nào

-- Chi xem plan, khong chay query
-- An toan voi SELECT, INSERT, UPDATE, DELETE
EXPLAIN SELECT * FROM tasks WHERE assignee_id = 5;

-- Chay query thuc + do thoi gian thuc te
-- CANH BAO: INSERT/UPDATE/DELETE se thuc su thay doi data!
EXPLAIN ANALYZE SELECT * FROM tasks WHERE assignee_id = 5;

-- Chay thuc + dem I/O page (shared hit/read)
EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM tasks WHERE assignee_id = 5;

-- Output JSON de paste vao dalibo visualizer
EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) SELECT * FROM tasks WHERE id = 1;

EXPLAIN thuần chỉ hiển thị plan — planner chạy nhưng query không thực thi. An toàn hoàn toàn dù với mutation query.

EXPLAIN ANALYZE chạy query thật để đo actual time và actual rows. Với SELECT: không vấn đề. Với INSERT, UPDATE, DELETE: mutation thật sự xảy ra. Để test plan của mutation query mà không thay đổi data:

-- Wrap EXPLAIN ANALYZE mutation trong transaction roi ROLLBACK
BEGIN;
EXPLAIN ANALYZE UPDATE tasks SET status = 'done' WHERE id = 1;
ROLLBACK;
-- Mutation da chay (EXPLAIN ANALYZE do duoc), nhung transaction rollback
-- Data khong bi thay doi

3. Đọc plan tree bottom-up

PostgreSQL in plan dưới dạng cây thụt đầu dòng. Mỗi cấp indent = 1 node con. Nguyên tắc đọc: từ trong ra ngoài, từ dưới lên trên — leaf node chạy trước, kết quả chuyển lên node cha.

Limit  (cost=8.45..8.46 rows=1 width=64)
  ->  Sort  (cost=8.45..8.46 rows=2 width=64)
        Sort Key: due_at
        ->  Index Scan using idx_tasks_assignee on tasks  (cost=0.42..8.44 rows=2 width=64)
              Index Cond: (assignee_id = 5)

Thứ tự thực thi:

1. Index Scan (leaf, trong cùng) — scan index idx_tasks_assignee, lọc assignee_id = 5, trả row về Sort.
2. Sort — nhận row từ Index Scan, sort theo due_at.
3. Limit (root, ngoài cùng) — nhận row từ Sort, trả đúng số row cần.

Mỗi -> là một node con. Node không có -> là leaf — đây là điểm tiếp xúc thực tế với data (Seq Scan, Index Scan, v.v.). Đọc plan bắt đầu từ leaf node trong cùng, đi ngược ra ngoài.

4. Cost format — startup, total, rows, width

Mỗi node in ra dòng cost:

Index Scan using idx_tasks_assignee on tasks  (cost=0.42..8.44 rows=2 width=64)

Bốn con số có nghĩa:

Cost là đơn vị abstract — không phải millisecond. PostgreSQL định nghĩa: 1.0 cost ≈ chi phí đọc 1 sequential page (8 KB). random_page_cost = 4.0 mặc định nghĩa là đọc 1 random page tốn 4x chi phí sequential. Cost chỉ có ý nghĩa so sánh tương đối giữa các node và các plan với nhau — không convert sang ms được.

Startup cost thấp quan trọng với query có LIMIT: planner ưu tiên plan có startup thấp khi có LIMIT 1 vì không cần trả full result. Index Scan thường có startup cost thấp hơn Seq Scan, giúp LIMIT query nhanh hơn đáng kể.

rows ước tính là nơi hay sai nhất. Planner dùng statistics để ước tính — nếu statistics stale hoặc có correlation phức tạp, ước tính có thể sai xa so với thực tế. Phần sau của bài 4 và bài 5 trong module này giải thích cách đọc và fix vấn đề này.

5. EXPLAIN ANALYZE — actual time và loops

Thêm ANALYZE bổ sung thêm dòng actual time và rows thực tế sau mỗi node:

Index Scan using idx_tasks_assignee on tasks
    (cost=0.42..8.44 rows=2 width=64)
    (actual time=0.012..0.045 rows=3 loops=1)

Ví dụ trên: estimated 2 row, actual 3 row — sai 1.5x, chấp nhận được. Nếu estimated 1,000,000 mà actual 3 — đó là dấu hiệu planner đang chọn plan sai do statistics stale.

loops > 1 xuất hiện ở Nested Loop — node inner chạy nhiều lần, 1 lần per row của outer:

Nested Loop  (cost=0.42..45.32 rows=50 width=72)
             (actual time=0.030..2.500 rows=50 loops=1)
  ->  Index Scan on users  (cost=0.28..8.30 rows=10 width=40)
                           (actual time=0.015..0.080 rows=10 loops=1)
  ->  Index Scan on tasks  (cost=0.42..3.50 rows=5 width=32)
                           (actual time=0.018..0.024 rows=5 loops=10)

Node tasks chạy 10 lần (loops=10) — 1 lần per row từ users. actual time=0.018..0.024 là time của 1 lần chạy. Tổng time thực tế của node này = 10 × 0.024 ≈ 0.24 ms. Khi đọc actual time của node có loops > 1, nhớ nhân với số loops để có total time thực tế.

6. BUFFERS — đếm I/O page

Option BUFFERS thêm vào report số lần đọc/ghi page vào/từ buffer cache và disk:

Buffers: shared hit=124 read=8 dirtied=0 written=0

shared hit cao, shared read thấp = query đang dùng data đã cache trong RAM. shared read cao = query phải đọc nhiều từ disk — nguyên nhân thường gặp của query chậm dù đã có index đúng. Fix: tăng shared_buffers, hoặc query đang access cold dataset lớn hơn RAM.

Ví dụ đọc BUFFERS kết hợp với plan:

Index Scan using idx_tasks_assignee on tasks
    (cost=0.42..15.44 rows=200 width=12)
    (actual time=0.025..0.180 rows=180 loops=1)
    Index Cond: (assignee_id = 5)
Buffers: shared hit=22 read=2

22 page từ cache, 2 page từ disk. Tỷ lệ hit 92% — khá tốt. Nếu thấy read=150 hit=2 với cùng query — dataset lạnh hoặc shared_buffers quá nhỏ để giữ index trong RAM.

BUFFERS chỉ có ý nghĩa kết hợp với ANALYZE — cần chạy query thật mới đo được I/O thực tế.

7. FORMAT JSON và visualizer

PostgreSQL hỗ trợ output plan dưới dạng JSON, YAML, hoặc XML — hữu ích để paste vào tool visualizer:

EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON)
SELECT count(*) FROM tasks;

Output JSON paste vào explain.dalibo.com — visualizer hiển thị plan dưới dạng cây có màu, đánh dấu node chậm nhất, và highlight row estimate mismatch. Đặc biệt hữu ích với plan nhiều node phức tạp — dễ đọc hơn TEXT format nhiều.

Format mặc định là TEXT — đủ cho hầu hết trường hợp debug và là format in trong bài này. JSON dùng khi muốn dùng visualizer hoặc parse programmatically.

Workflow nhanh với dalibo:

1. Chạy EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) <query>; trong psql.
2. Copy toàn bộ JSON output (bắt đầu từ [ đến ]).
3. Paste vào explain.dalibo.com — visualizer tô màu node chậm nhất, hiển thị actual vs estimated rows side-by-side, và đánh dấu row estimate mismatch bằng màu đỏ.

Dalibo đặc biệt hữu ích với query có 5+ node — TEXT format khó scan mắt; visualizer collapse/expand từng nhánh của plan tree.

8. Pitfall — cost không phải ms, và estimated rows mismatch

-- Vi du estimated vs actual mismatch nghiem trong:
Seq Scan on tasks  (cost=0.00..50000.00 rows=1000000 width=64)
                   (actual time=0.012..2.500 rows=3 loops=1)
-- Planner nghi co 1 trieu row -> chon Seq Scan
-- Thuc te chi co 3 row -> Index Scan se nhanh hon 1000x
-- Root cause: statistics cu (can ANALYZE) hoac cross-column correlation

9. Applied — EXPLAIN ANALYZE BUFFERS trên TaskFlow dashboard query

Query dashboard từ bài 7 Module 2 của khoá này (tasks active của user 5, group by status). Chạy EXPLAIN ANALYZE BUFFERS để đọc toàn bộ plan:

-- Dashboard query (bai 7 Module 2 cua khoa nay)
-- Truoc khi chay, dam bao index ton tai:
-- CREATE INDEX idx_tasks_assignee ON tasks(assignee_id);

EXPLAIN (ANALYZE, BUFFERS)
SELECT
  status,
  count(*) FILTER (WHERE due_at < now()) AS overdue_count,
  count(*) FILTER (WHERE due_at >= now() AND due_at < now() + interval '7 days') AS this_week,
  count(*) AS total
FROM tasks
WHERE assignee_id = 5
GROUP BY status;

Output mẫu (realistic với dataset nhỏ, index trên assignee_id):

HashAggregate  (cost=20.45..20.50 rows=4 width=24)
               (actual time=0.350..0.355 rows=3 loops=1)
  Group Key: status
  Batches: 1  Memory Usage: 24kB
  ->  Index Scan using idx_tasks_assignee on tasks
          (cost=0.42..15.44 rows=200 width=12)
          (actual time=0.025..0.180 rows=180 loops=1)
          Index Cond: (assignee_id = 5)
  Buffers: shared hit=24
Planning Time: 0.150 ms
Execution Time: 0.420 ms

Đọc plan từ trong ra ngoài:

1. Index Scan (leaf) — dùng idx_tasks_assignee, filter assignee_id = 5. Estimated 200 row, actual 180 row — sai ~10%, hoàn toàn chấp nhận được. Thực thi trong 0.025–0.180 ms.
2. HashAggregate (root) — nhận 180 row từ Index Scan, group by status, tính các count(*) FILTER. Trả về 3 group (status: todo, doing, done). 0.350–0.355 ms.
3. Buffers: shared hit=24 — toàn bộ 24 page đọc từ buffer cache (RAM), read=0. Dataset đã warm trong cache — không có disk I/O.
4. Execution Time: 0.420 ms — tổng thời gian thực tế. Hoàn toàn đạt sub-millisecond.

Plan này tốt: Index Scan đúng, estimated rows gần actual, không có disk I/O, thời gian dưới 1 ms. Nếu thấy Seq Scan thay vì Index Scan ở bước 1 — đó là signal cần điều tra (index chưa có? statistics stale? data volume quá nhỏ để index có lợi?).

Planning Time: 0.150 ms là thời gian planner dành để tạo ra plan — thường nhỏ, chỉ đáng chú ý nếu vượt quá vài chục ms (ví dụ query có nhiều JOIN phức tạp với hàng trăm plan alternative). Execution Time: 0.420 ms là tổng thời gian thực thi — con số này nên dùng để so sánh trước/sau khi thêm index hoặc thay đổi query.

10. Deep Dive

11. Tóm tắt

• EXPLAIN <query> hiển thị plan + estimated cost — không chạy query, an toàn với mọi loại query.
• EXPLAIN ANALYZE <query> chạy query thật, đo actual time và actual rows per node. Với mutation query: wrap trong BEGIN + ROLLBACK nếu chỉ muốn test plan.
• EXPLAIN (ANALYZE, BUFFERS) thêm I/O accounting: shared hit (từ RAM), shared read (từ disk). Tỷ lệ hit cao = cache healthy; read cao = disk I/O bottleneck.
• Plan tree đọc bottom-up: leaf node chạy trước (Seq Scan, Index Scan), kết quả chuyển lên parent (Sort, HashAggregate, Limit).
• cost=startup..total là đơn vị abstract (1.0 ≈ 1 sequential page read) — không phải millisecond. Thời gian thực đọc từ actual time của EXPLAIN ANALYZE.
• rows=X (estimated) vs actual rows=Y: sai lệch lớn là root cause của plan sai — planner chọn Seq Scan thay vì Index Scan vì ước tính rows quá cao. Fix qua ANALYZE hoặc statistics tuning (bài 4 và bài 5 trong module này).
• loops=N > 1 ở Nested Loop inner node: actual time là time per 1 lần chạy, nhân với loops để có total time thực tế.
• FORMAT JSON + explain.dalibo.com = visualizer nhanh nhất để đọc plan phức tạp nhiều node.

12. Tự kiểm tra

BEGIN;
EXPLAIN ANALYZE UPDATE tasks SET status = 'done' WHERE id = 1;
ROLLBACK;
-- EXPLAIN ANALYZE da chay va do duoc actual time/rows
-- Nhung ROLLBACK huy bo mutation: row id=1 khong bi thay doi

Bài tiếp theo: Scan strategies — Seq Scan, Index Scan, Index Only Scan, Bitmap Scan