Query Planner (P2/3): Plan cache và sự cố query bỗng chậm

Ở phần trước: planner chạy trial cho mỗi candidate plan và chấm điểm bằng productivity, tức advanced chia cho works. Plan thắng được ghi vào plan cache, nên các lần sau không phải chạy lại trial.

• Cần đọc trước: Candidate plans và trial period
• Dẫn tới: hint(), query settings và sửa tận gốc

Bước 3: plan cache

Ý chính

Chạy trial cho mỗi query thì tốn kém. Vì vậy plan thắng được lưu vào plan cache, một bộ nhớ đệm trong RAM, riêng cho từng collection. Khoá của cache là query shape của query.

Plan cache query shape: cấu trúc, không phải giá trị

[tài liệu] Plan cache query shape là tổ hợp của predicate, sort, projection và collation. Với predicate, chỉ cấu trúc và tên field được dùng. Giá trị thì bị bỏ qua: { type: 'food' } và { type: 'drink' } là cùng một query shape. Mỗi query shape có một mã hash là planCacheShapeHash.

Thử vài biến thể, đọc planCacheShapeHash / planCacheKey trong explain:

A                2DA7E177 / B1BCA75B
B                2DA7E177 / B1BCA75B
field order swap 2DA7E177 / B1BCA75B     { status, tenantId } thay vì { tenantId, status }
+ limit 20       2DA7E177 / B1BCA75B
+ sort createdAt B5EE3E4E / 3B7D2868
status $in       C1C71E4C / 066A2E7C

[quan sát] A, B, đảo thứ tự field, thêm limit đều cho cùng một hash, nên chúng dùng chung một entry trong cache. Thêm sort hay đổi $eq thành $in thì ra query shape khác.

Có hai mã hash, và chúng khác nhau ở một điểm:

[tài liệu] Từ 8.0, queryHash được nhân bản thành planCacheShapeHash và sẽ bị bỏ ở phiên bản sau; code giám sát nên đọc planCacheShapeHash. Cũng từ 8.0 có queryShapeHash (chuỗi hex dài ở cuối explain): hash của query shape mới, dùng cho query settings và $queryStats, không phải khoá plan cache. Phần query settings sẽ cho thấy hai loại "query shape" này khác nhau ở đâu.

Ba trạng thái của một entry

[tài liệu] Mỗi plan cache query shape ở một trong ba trạng thái:

Missing ──(query đầu tiên)──► Inactive ──(plan mới tốn ≤ works ghi nhận)──► Active
                                  ▲   │                                       │
                                  │   └─(plan mới tốn > works) giữ Inactive,  │
                                  │      tăng works ghi nhận                  │
                                  └────────(plan cache không còn đạt)─────────┘

• Missing: chưa có entry. Query chạy trial, cache tạo entry Inactive ghi số works của plan thắng.
• Inactive: chỗ giữ, chưa dùng để chạy; query vẫn chạy trial. Plan thắng tốn ≤ works đã ghi thì entry thành Active, tốn hơn thì vẫn Inactive và works ghi nhận được tăng lên.
• Active: plan được dùng thẳng, bỏ qua trial, nhưng vẫn bị đánh giá; không còn đạt tiêu chí thì về Inactive.

Bước Inactive là bộ lọc chống "nhớ nhầm": một plan chỉ được tin khi đã thắng ít nhất hai lần với chi phí không tệ hơn.

Budget của plan đã cache và replanning

Khi entry Active, plan được chạy với một budget. [quan sát] Lý do replan trong profiler ("expected trial execution to take 1056 works but it took at least 10560 works", gặp lại ở phần sự cố) cho thấy budget là 10 lần số works đã ghi. [chi tiết cài đặt] Hệ số này là tham số nội bộ internalQueryCacheEvictionRatio, giá trị 10 trong lab. Tài liệu chỉ nói "không còn đạt tiêu chí" mà không công bố con số.

Active entry: works = 1056
        │
        ▼
chạy plan đã cache, đếm works
        │
        ├── đạt 101 kết quả hoặc EOF trước 10.560 works ✓  → dùng tiếp, chạy hết query
        │
        └── tới 10.560 works mà chưa xong ✗               → bỏ, chạy trial lại (replan)

Đọc explain từ góc nhìn của planner

Phần này gom lại những gì explain nói về quyết định của planner. Từng stage chạy ra sao (works, needYield, seeks...) thuộc về bài Query Execution Engine, nơi có bảng tra mọi stage.

⚠ Hai mức sau thực sự chạy query. Trên collection lớn, một explain có thể nặng ngang chính query đó.

⚠ [tài liệu] Explain bỏ qua plan cache: nó luôn chọn lại từ đầu và không ghi plan thắng vào cache. [quan sát] Số entry trong $planCacheStats trước và sau một lần explain: 2 và 2. Explain cho biết planner sẽ chọn gì nếu chọn lại lúc này, không cho biết production đang chạy plan nào. Sự cố ở phần sau xoay quanh đúng khoảng cách đó.

Ba câu hỏi:

• Plan nào thắng, đọc index nào, quét khoảng nào? winningPlan: ở IXSCAN đọc indexName và indexBounds; ở FETCH đọc filter, tức điều kiện index không trả lời được. rejectedPlans rỗng nghĩa là planner không phải chọn.
• Vì sao plan kia thua? allPlansExecution: so advanced/works của từng candidate, như ở Bước 2.
• Plan thắng có thật sự tốt cho cả query không? Planner chỉ nhìn đoạn đầu; executionStats cho biết giá của cả query. Đặt ba con số cạnh nhau:

totalKeysExamined 1409 ──► totalDocsExamined 1409 ──► nReturned 128      (A, plan tenantId_1)
      (IXSCAN)                    (FETCH)               (sau filter status)
tỉ lệ docs/nReturned = 11 : cứ 11 document fetch thì 1 cái có ích

keys ≈ docs ≈ nReturned là lý tưởng; keys ≈ docs ≫ nReturned (như A ở trên, C ở phần sau) nghĩa là index chỉ trả lời một phần filter và FETCH vứt đi nhiều. Các hình mẫu còn lại nằm trong bảng tra của bài Query Execution Engine.

queryPlanner còn hai trường dùng ở phần sau: planCacheKey (tra $planCacheStats) và querySettings (8.0+, plan đang bị ghim từ phía server).

Sự cố: query đang nhanh bỗng chậm

Bối cảnh

[hình dung] Câu chuyện là kịch bản dựng lại; mọi con số trong đó là số đo thật.

Màn hình "Đơn hàng theo trạng thái" của một hệ thống SaaS gọi một query: find({ tenantId, status }), trên collection có tenantId_1 và status_1. Nhiều tháng liền, người dùng là các shop nhỏ xem đơn pending (kiểu A). Plan cache ổn định ở tenantId_1, query chạy vài mili giây.

Rồi hai thứ đổi, không thứ nào là code: phân bố dữ liệu (khách lớn t0000 chuyển sang, chiếm 30% số đơn) và tham số (đội chăm sóc khách hàng của t0000 xem disputed và refunded, kiểu B và C). Từ hôm đó dashboard có những gai latency không theo quy luật.

Diễn biến bên trong plan cache

Ta chạy lại chuỗi request đó. Explain bỏ qua cache nên ta chạy query thật, bật profiler (db.setProfilingLevel(2, { slowms: 0 }), chỉ trong database lab) để đọc planSummary, fromPlanCache, replanned, replanReason, rồi đọc $planCacheStats sau mỗi query. Kết quả thật (môi trường lab08; mỗi dòng là lệnh find, tức batch đầu 101 document):

#1 A | IXSCAN { tenantId: 1 } | keys 1056 | fromPlanCache -    replanned false | 12 ms
     cache: {isActive:false, works:1056, plan:tenantId_1, key:B1BCA75B, scores:[1.0958,1.0002]}
#2 A | IXSCAN { tenantId: 1 } | keys 1056 | fromPlanCache -    replanned false |  4 ms
     cache: {isActive:true,  works:1056, plan:tenantId_1}
#3 B | IXSCAN { status: 1 }   | keys 352  | fromPlanCache -    replanned TRUE  | 22 ms
     (cached plan was less efficient than expected: expected trial execution to take 1056 works
      but it took at least 10560 works)
     cache: {isActive:true,  works:352,  plan:status_1,   scores:[1.2871,1.0002]}
#4 B | IXSCAN { status: 1 }   | keys 352  | fromPlanCache TRUE replanned false |  1 ms
#5 A | IXSCAN { tenantId: 1 } | keys 1056 | fromPlanCache -    replanned TRUE  |  6 ms
     (cached plan was less efficient than expected: expected trial execution to take 352 works
      but it took at least 3520 works)
     cache: {isActive:false, works:704,  plan:tenantId_1}
#6 A | IXSCAN { tenantId: 1 } | keys 1056 | fromPlanCache -    replanned false |  2 ms
     cache: {isActive:false, works:1408, plan:tenantId_1}
#7 B | IXSCAN { status: 1 }   | keys 352  | fromPlanCache -    replanned false |  1 ms
     cache: {isActive:true,  works:352,  plan:status_1}

#1–#2  A, A : Missing → Inactive → Active (tenantId_1, 1056 works, budget 10.560)
#3     B    : tenantId_1 hết 10.560 works chưa đủ 101 kết quả → REPLAN → status_1
#5     A    : status_1 hết budget 3.520 → REPLAN → tenantId_1 thắng nhưng 1056 > 352 → INACTIVE
#7     B    : status_1 thắng với 352 ≤ 1408 → B lại chiếm entry

Replanning bắt được cả hai lần lật. [quan sát] Số works ghi nhận tăng gấp đôi mỗi lần (352 → 704 → 1.408); [chi tiết cài đặt] tham số nội bộ internalQueryCacheWorksGrowthCoefficient = 2, tài liệu chỉ nói "được tăng lên". Nhưng ai chạy trước sẽ chiếm entry: entry lật theo luồng request, và mỗi lần lật là một request chậm. Đó là những gai trên dashboard. Mỗi gai tốn bao nhiêu? Đo B, mỗi tình huống 11 lần, 2 lượt, thời gian phía client (môi trường lab08):

[quan sát] Bộ đếm metrics.query.planCache.classic.replanned tăng đúng 11 mỗi lượt. Trial với hai candidate gần như miễn phí; replan tốn khoảng 2,3 đến 3,9 lần, vì server trả cả budget cho plan sai rồi mới chạy trial lại.

Ca nặng nhất: plan sai mà không ai báo

Replanning chỉ bảo vệ ta khi plan sai vượt budget trong đoạn đầu. Query C của đội chăm sóc khách hàng (t0000 + refunded, 29.882 đơn) thì không vượt. Khi cache trống, planner chọn đúng:

explain C (không dùng cache): winner status_1, keys 99483
  candidate status_1    works 334  advanced 101  score 1.3026   ← thắng
  candidate tenantId_1  works 334  advanced 32   score 1.0960

Bây giờ cho A (shop nhỏ) chạy trước hai lần để entry thành Active với tenantId_1, rồi chạy C:

C sau A (round 1): keys 299814 docs 299814 n 29882 first-op {"op":"query","fromPlanCache":true,"plan":"IXSCAN { tenantId: 1 }"}
   cache now: tenantId_1 active true works 1056

Không có replan: theo tỉ lệ trong explain (32 kết quả sau 334 works), tenantId_1 cần khoảng 1.050 works để có 101 đơn, trong budget 10.560. Plan qua đoạn đầu rồi chạy hết query: 299.814 key và 299.814 document cho 29.882 đơn.

Thời gian phía server (tổng millis của find và các getMore trong profiler), 9 lần mỗi lượt, 2 lượt (môi trường lab08):

C chậm 1,5 đến 2 lần chỉ vì một query khác chạy trước nó, không lỗi, không replanned. Đó là cái bẫy cốt lõi: cache theo query shape, kiểm tra theo đoạn đầu, tin plan cho phần còn lại.

Phát hiện: dấu vết trong slow query log

Explain chạy lúc điều tra sẽ chọn lại từ đầu và cho status_1: trông hoàn toàn ổn. Dấu vết thật nằm ở lần chạy thật. Hai dòng slow query log thật (môi trường lab10, đã lọc trường), của C sau A và của B khi bị replan:

"Slow query" C  planSummary "IXSCAN { tenantId: 1 }"  keysExamined 967  nreturned 101  fromPlanCache true
                planCacheShapeHash "2DA7E177"  planCacheKey "B1BCA75B"
"Slow query" B  planSummary "IXSCAN { status: 1 }"  keysExamined 352  nreturned 101  replanned true
                replanReason "cached plan was less efficient than expected: expected trial execution
                              to take 1056 works but it took at least 10560 works"
                planCacheShapeHash "2DA7E177"  planCacheKey "B1BCA75B"

Cách đọc:

1. Gom theo planCacheShapeHash. [tài liệu] Trường này chỉ phụ thuộc vào query shape, nên mọi biến thể của màn hình rơi vào một nhóm. Cùng hash mà planSummary khi thế này khi thế khác nghĩa là entry đang lật.
2. replanned: true và replanReason đánh dấu từng lần lật bị bắt. Bộ đếm toàn server là metrics.query.planCache.classic.replanned.
3. Ca C không có replanned. Dấu hiệu duy nhất là fromPlanCache: true đi cùng tỉ lệ keysExamined / nreturned cao bất thường (967/101; cả query 299.814/29.882). Một cảnh báo trên tỉ lệ này bắt được cả những plan sai mà replanning bỏ sót.
4. Xác nhận bằng $planCacheStats: db.orders.aggregate([{ $planCacheStats: {} }, { $match: { planCacheShapeHash: "2DA7E177" } }]) cho biết entry đang Active hay Inactive, giữ plan nào, works bao nhiêu (lab10: isActive: true, works: 1056, plan tenantId_1).

[quan sát] Dòng find chỉ phản ánh batch đầu; mỗi getMore có dòng riêng. Dựng cả quy trình giám sát là việc của bài Observe → Diagnose → Tune.

Chữa cháy tạm, và ba cách chữa thật

Cách nhanh nhất là xoá entry: db.orders.getPlanCache().clearPlansByQuery({ tenantId: "x", status: "y" }) (chỉ query shape có nghĩa; [quan sát] sau lệnh còn 0 entry). Nhưng query kế tiếp chọn lại theo tham số của nó, và cache lật như cũ. [tài liệu] Cache cũng tự xoá khi restart, khi tạo/xoá/ẩn index, và theo LRU, nên sự cố kiểu này hay "tự hết" rồi quay lại.

Muốn hết hẳn, có ba tầng: ép plan trong code (hint()), ép plan từ phía server (query settings), và cho planner một lựa chọn tốt cho mọi tham số (index).

Cột mốc: Bạn đã biết plan cache khoá theo query shape, và đọc slow log để tìm một entry chọn sai plan. Tiếp theo: hint(), query settings và sửa tận gốc.

Hỏi & đáp