後端仔的效能優化實戰(4) Slow Query找出效能瓶頸

前言

在效能優化的路上，除了APP本身的效能問題，資料庫也是避不開的議題，現代許多服務都可以隨著K8S做水平擴展來提升效能，但往往資料庫都還是維持單體狀態，在這種情況下，資料庫的壓力就比過去還要來得大，如何優化資料庫也是一大議題。以下我就要介紹常見的資料庫的效能排查工具： Slow Query Log 與 EXPLAIN 語法。

Slow Query Log

Slow Query 是什麼？簡單來說就是SQL的一項工具，他可以記錄查詢時間超過某些門檻的語句，並記錄下來，方便工程師們盤查。當我們今天想要看某些查詢是否緩慢時，第一個就是要查詢Slow Query。你可以用以下指令去查詢當前的slow query設定

SHOW log_min_duration_statement;

預設值是-1，代表不啟動slow query功能，正式環境建議開啟。設定方法如下，假設我們想要找出查詢耗時超過100毫秒的查詢。

ALTER SYSTEM SET log_min_duration_statement = 100;
SELECT pg_reload_conf();

注意，我們在設定完紀錄查詢之後，我們需要另外呼叫pg_reload_conf()，才能夠立即套用設定。另外，這個操作不需要重啟DB也可以當下生效。設定好之後，我們就可以嘗試查詢了，舉例來說，我發動以下查詢，這是一個ticket表，我預先放入了超過1.5G的假資料來模擬慢查詢。

SELECT count(*) FROM ticket WHERE user_id = 200;

查詢後便可以在postgresql container log找到紀錄

...
2026-07-13 02:49:11.796 UTC [302]: LOG:  duration: 245.075 ms  statement: SELECT count(*) FROM ticket WHERE user_id = 200;
2026-07-13 02:49:13.350 UTC [302]: LOG:  duration: 272.983 ms  statement: SELECT count(*) FROM ticket WHERE user_id = 200;
...

由此可見，這個查詢特定使用者的票券功能，查詢就要花上 200 多毫秒，這超過了我們設定的 100 毫秒基準，因此我們可以找到相關紀錄。

那麼，我們知道慢了，但是慢在哪裡？這邊我們就可以介紹我們的下一個工具，就是EXPLAIN語法。

EXPLAIN 是 SQL 的特殊語法，他會分析這筆查詢，並提供詳細資料，他不會先跑查詢，只是會預先分析這個查詢。

EXPLAIN SELECT count(*) FROM ticket WHERE user_id = 200;

結果如下：

Finalize Aggregate  (cost=179475.17..179475.18 rows=1 width=8)
  ->  Gather  (cost=179474.96..179475.17 rows=2 width=8)
        Workers Planned: 2
        ->  Partial Aggregate  (cost=178474.96..178474.97 rows=1 width=8)
              ->  Parallel Seq Scan on ticket  (cost=0.00..178455.61 rows=7737 width=0)
                    Filter: (user_id = 200)
JIT:
  Functions: 6
  Options: Inlining false, Optimization false, Expressions true, Deforming true

第一次看到這張表可能會有點頭暈，我們先抓幾個關鍵欄位來看：

由內而外、由下往上讀：最內層縮排最深的節點（這裡是 Parallel Seq Scan）是最先執行的，資料一層一層往上傳給 Aggregate 做加總。
cost=0.00..178455.61：這是規劃器估算的成本，前面是「開始回傳第一列的成本」、後面是「跑完整個節點的成本」。注意它是一個抽象的估算單位，不是毫秒，數字越大代表規劃器覺得越貴。
rows=7737：規劃器估算這個節點會吐出幾列，注意是估算值，不一定準。
width=0：每一列預估的資料寬度（bytes），因為我們只做 count(*) 不需要真正欄位，所以是 0。

看到最關鍵的 Parallel Seq Scan on ticket，Seq Scan 就是 Full Table Scan（整表掃描），代表資料庫是一列一列翻完整張 ticket 表來找 user_id = 200，這通常就是效能低落的元兇——這裡是因為 user_id 這個 ForeignKey 並沒有加上 Index。不過純 EXPLAIN 只是「估算」，我們可以再用 ANALYZE 實際跑一次來驗證這一點

EXPLAIN (ANALYZE, BUFFERS) SELECT count(*) FROM ticket WHERE user_id = 200;

結果：

Finalize Aggregate  (cost=179475.17..179475.18 rows=1 width=8) (actual time=290.771..295.209 rows=1.00 loops=1)
  Buffers: shared hit=9916 read=120975
  ->  Gather  (cost=179474.96..179475.17 rows=2 width=8) (actual time=290.640..295.199 rows=3.00 loops=1)
        Workers Planned: 2
        Workers Launched: 2
        Buffers: shared hit=9916 read=120975
        ->  Partial Aggregate  (cost=178474.96..178474.97 rows=1 width=8) (actual time=271.163..271.164 rows=1.00 loops=3)
              Buffers: shared hit=9916 read=120975
              ->  Parallel Seq Scan on ticket  (cost=0.00..178455.61 rows=7737 width=0) (actual time=11.709..270.432 rows=5624.00 loops=3)
                    Filter: (user_id = 200)
                    Rows Removed by Filter: 3038511
                    Buffers: shared hit=9916 read=120975
Planning Time: 0.080 ms
JIT:
  Functions: 14
  Options: Inlining false, Optimization false, Expressions true, Deforming true
  Timing: Generation 2.172 ms (Deform 0.667 ms), Inlining 0.000 ms, Optimization 1.948 ms, Emission 28.265 ms, Total 32.385 ms
Execution Time: 295.586 ms

加上 ANALYZE 之後，PostgreSQL 會真的把這筆查詢跑一次，所以多了 actual time（實際耗時）；再加上 BUFFERS 則會告訴我們資料是從記憶體還是磁碟拿的。這張表裡有兩個數字最能說明「慢在哪」：

Rows Removed by Filter: 3038511：這是整篇最有殺傷力的數字。它代表資料庫掃過去、然後丟掉了 300 萬列，只為了留下我們要的那幾千列。這就是 Full Table Scan 的痛——大部分工都做白工。
Buffers: shared hit=9916 read=120975：hit 是命中記憶體（快），read 是實際去磁碟讀的區塊（慢）。這裡 read 高達 12 萬個 block，代表大量資料得從磁碟撈上來，記住這個數字，等一下加了 Index 會有很戲劇性的對比。
actual time=290.771..295.209 / Execution Time: 295.586 ms：最後總結，這筆查詢實際跑了約 300 毫秒。

大約是300毫秒的延遲，延遲非常高，這時我們可以透過加入Index來優化查詢速度。

CREATE INDEX CONCURRENTLY idx_ticket_user_id ON ticket(user_id);

重新再Analyze的結果便是

Aggregate  (cost=435.81..435.82 rows=1 width=8) (actual time=1.882..1.883 rows=1.00 loops=1)
  Buffers: shared hit=22
  ->  Index Only Scan using idx_ticket_user_id on ticket  (cost=0.43..389.39 rows=18569 width=0) (actual time=0.019..1.036 rows=16872.00 loops=1)
        Index Cond: (user_id = 200)
        Heap Fetches: 0
        Index Searches: 1
        Buffers: shared hit=22
Planning:
  Buffers: shared hit=12 read=1
Planning Time: 0.374 ms
Execution Time: 1.935 ms

把前後兩張表的關鍵數字擺在一起，衝擊就很清楚了：

指標	加 Index 前	加 Index 後
掃描方式	Parallel Seq Scan（整表掃描）	Index Only Scan（走索引）
Buffers read（磁碟讀取）	120975	0（`shared hit=22`）
Rows Removed by Filter	3038511	0
Execution Time	295.586 ms	1.935 ms

執行時間從約 300 毫秒降到 1.9 毫秒，快了大約 150 倍；更關鍵的是它不再掃整張表、也不用再去磁碟撈 12 萬個 block，直接走索引就找到答案。這就是為什麼看懂 EXPLAIN 這麼重要——它會直接告訴你「慢在哪」，你才知道該對症下什麼藥。

這樣就是一個簡單的Slow Query + Explain的應用，那麼本篇文章就到這裡。