Query Performance & Pagination: phân trang, multi-tenant và truy vết query chậm

Các bài trước của Phần 2 dạy bạn đọc một query từ bên trong: index là gì (07), ghép nhiều field thành compound index ra sao (08), planner chọn plan thế nào và đọc explain() ra sao (10), aggregation pipeline tốn gì (11). Bài này đưa tất cả ra môi trường production, nơi câu hỏi không còn là "query này dùng index nào" mà là:

• Trang 10.000 của danh sách đơn hàng có chậm hơn trang 1 không, và chậm bao nhiêu?
• Vì sao cùng một index, tenant này nhanh còn tenant kia mất 1,4 giây?
• Lúc 3 giờ sáng API chậm, bạn bắt đầu tìm thủ phạm từ đâu?
• Một query mất 50 ms thì "ổn". Tám request cùng lúc thì còn ổn không?

Bài này nằm ở đâu

Cần biết trước : bài 06 (sort/skip/limit, cursor), bài 07 (IXSCAN + FETCH, selectivity),
                 bài 08 (compound index, sort bằng index), bài 10 (đọc explain, hint)
Giới thiệu     : skip + limit vs range/cursor (keyset) pagination, tie-breaker _id,
                 thiết kế index cho multi-tenant, slow query log (slowms), database profiler,
                 $currentOp / killOp, quy trình chẩn đoán query chậm,
                 query performance vs system performance (latency vs throughput)
Dẫn tới        : bài 14, Cost-Based Ranker & Cardinality Estimation

Môi trường lab: MongoDB 8.3.11 trong Docker (image mongo:8, standalone), container mongo-lab-10 giới hạn 2 CPU, 3 GB RAM, WiredTiger cache 1 GB, máy host Apple M4. Database riêng lab10. Trên cùng máy host có vài container lab khác chạy song song, nên các phép đo thời gian đều lặp lại nhiều lần và báo median. Mọi con số là đo thật, trừ khi ghi là minh hoạ.

Cách gắn nhãn trong bài, giống các bài trước: [tài liệu] là hành vi được tài liệu MongoDB mô tả, [quan sát] là thứ đo được trong lab (có thể khác ở version hoặc dữ liệu khác), [hình dung] là mô hình đơn giản hoá để dễ nghĩ.

Vì sao bài này quan trọng

Ở bài 07–10, mỗi thí nghiệm là một query, một lần chạy, một người dùng. Production thì khác ba điểm:

Phòng lab                         Production
─────────                         ──────────
một query                         hàng trăm "hình dạng" query, cái nào cũng có thể chậm
dữ liệu đều                       tenant lệch nhau 100 lần, có tenant đã ngừng dùng
một client                        nhiều request cùng lúc, tranh nhau CPU, cache, đĩa

Ba điểm đó sinh ra ba loại vấn đề mà bài này giải quyết theo thứ tự: phân trang (query chạy đi chạy lại với tham số lớn dần), thiết kế index theo tenant (dữ liệu lệch), và truy vết query chậm khi hệ thống đang chịu tải.

Dataset của bài

Setup

MongoDB version : 8.3.11 (Docker image mongo:8, standalone)
Hardware        : Apple M4 host; container giới hạn 2 CPU, 3 GB RAM
Configuration   : WiredTiger cache 1 GB (--wiredTigerCacheSizeGB 1)
Dataset         : lab10.orders, 1.000.000 document
Kích thước      : 215 MB chưa nén (avgObjSize 215 byte), 74 MB trên đĩa

Dataset

Cùng hình dạng đơn hàng với bài 06, nhưng cố ý làm lệch như một SaaS thật:

createdAt được làm tròn đến giây, nên nhiều đơn trùng createdAt như ngoài đời. Dữ liệu sinh bằng PRNG có seed cố định.

// trích gen.js
docs.push({
  tenantId: "t0000",
  userId:   "u" + String(Math.floor(rnd() * 2000)).padStart(4, "0"),
  status:   pickStatus(rnd()),            // 70% completed, 10% mỗi loại còn lại
  createdAt: new Date(Math.floor((END - rnd() * 365 * DAY) / 1000) * 1000),
  total, items
});
db.orders.insertMany(docs, { ordered: false });   // 10.000 document mỗi lần

inserted 1000000 docs in 30347 ms

Hình dung trước: đọc tiếp một cuốn sách dày

Bạn đang đọc một cuốn sách 12.500 trang. Tối qua bạn dừng ở trang 9.999. Có hai cách để đọc tiếp:

Cách 1: nhớ "tôi đã đọc 9.999 trang"     Cách 2: kẹp bookmark ở chỗ đã dừng
      ↓                                        ↓
mở trang đầu, đếm qua 9.999 trang         mở thẳng chỗ bookmark
      ↓                                        ↓
đọc tiếp                                  đọc tiếp

Cách 1 tốn công tỉ lệ với số trang đã đọc. Cách 2 tốn công như nhau dù bạn ở trang 2 hay trang 9.999. Và nếu trong đêm có người chèn thêm một trang vào đầu sách, cách 1 sẽ làm bạn đọc lại một đoạn, còn cách 2 vẫn đúng chỗ.

skip + limit           = đếm từ đầu sách
range/cursor (keyset)  = kẹp bookmark

Đây chỉ là cách hình dung. MongoDB không "lật trang". Nhưng skip thật sự phải đi qua mọi entry bị bỏ, còn cursor pagination thật sự nhảy thẳng vào index tại vị trí bookmark. Phần dưới đo cả hai.

Phân trang bằng skip + limit

30 giây

skip(n).limit(20) nghĩa là "bỏ n kết quả đầu, lấy 20 cái tiếp". Rất dễ viết, và API trả về ?page=N gần như ai cũng bắt đầu từ đây. Vấn đề: server không thể nhảy tới kết quả thứ n. Nó phải sinh ra n kết quả đầu rồi vứt đi. [tài liệu] Trang cursor.skip() nói thẳng: skip phải quét từ đầu tập kết quả, và offset càng lớn thì càng chậm.

Đo trên index đúng

Màn hình "đơn hàng mới nhất của tenant" cần index phục vụ cả filter lẫn sort (bài 08):

db.orders.createIndex({ tenantId: 1, createdAt: -1, _id: -1 })   // build 833 ms, 27,9 MB

db.orders.find({ tenantId: "t0000" })
  .sort({ createdAt: -1, _id: -1 })
  .skip((page - 1) * 20).limit(20)

Mỗi trang đo explain("executionStats"), rồi gọi toArray() thật 201 lần (31 lần cho trang 10.000) và lấy median. Cả bộ chạy 2 lượt:

Plan của trang 10.000 [quan sát]:

LIMIT <- FETCH <- SKIP <- IXSCAN { tenantId: ["t0000","t0000"], createdAt: [MaxKey, MinKey], _id: [MaxKey, MinKey] }

Đọc con số

Có một chi tiết thú vị: totalDocsExamined luôn là 20, nhưng totalKeysExamined tăng tuyến tính với số trang. Lý do nằm ở vị trí của stage SKIP trong plan: nó nằm dưới FETCH. Planner bỏ qua 199.980 entry ngay trên index mà không cần đọc document, chỉ FETCH 20 document cuối. Đây là trường hợp tốt nhất của skip.

Trang 10.000 với skip

IXSCAN  ──► đi qua 200.000 key trong index
   ↓
SKIP    ──► vứt 199.980 key
   ↓
FETCH   ──► đọc 20 document
   ↓
20 kết quả, khoảng 31–33 ms

Vẫn 31–33 ms cho 20 document, gấp khoảng 100 lần trang 1. Và trường hợp tốt nhất này rất dễ mất. Chỉ cần thêm một điều kiện không nằm trong index, ví dụ lọc thêm status: "pending":

pending skip page 1000: LIMIT <- SKIP <- FETCH <- IXSCAN  keys 199924  docs 199924  median 139.3 ms

Giờ server phải FETCH từng document để kiểm tra status trước khi biết nó có được tính vào số bị skip hay không. SKIP bị đẩy lên trên FETCH, và trang 1.000 đã đọc gần 200.000 document, median 139 ms. Đây là kịch bản bạn sẽ gặp thật: filter của màn hình danh sách thường có thêm vài điều kiện tuỳ chọn mà index không phủ hết.

Skip còn sai, không chỉ chậm

Chậm là một nửa vấn đề. Nửa còn lại là đúng. Thử đọc trang 1, rồi có một đơn mới được tạo, rồi đọc trang 2:

const p1 = db.orders.find({ tenantId: "t0000" }, { _id: 1 }).sort(SORT).limit(20).toArray();
db.orders.insertOne({ tenantId: "t0000", createdAt: new Date("2026-09-30T23:59:59.500Z"), /* ... */ });
const p2 = db.orders.find({ tenantId: "t0000" }, { _id: 1 }).sort(SORT).skip(20).limit(20).toArray();

D skip: last of page1 ObjectId('6ac742fe541f7b91fc816a60')  first of page2 ObjectId('6ac742fe541f7b91fc816a60')  duplicate: true

Đơn mới chen vào đầu danh sách, đẩy mọi thứ lùi một vị trí. Đơn cuối trang 1 trở thành đơn đầu trang 2: người dùng thấy trùng. Nếu là xoá thay vì thêm, họ sẽ sót một đơn. Với danh sách "mới nhất trước" của một tenant đang hoạt động, chuyện này xảy ra liên tục.

Phân trang bằng cursor (keyset)

30 giây

Thay vì nói "bỏ 199.980 cái đầu", ta nói "cho tôi 20 cái đứng sau cái cuối cùng tôi đã thấy". Cái cuối cùng đó được mô tả bằng chính các field của sort: (createdAt, _id). Vì index đã xếp theo đúng thứ tự đó, server nhảy thẳng tới vị trí ấy trong B-tree (bài 07) rồi đọc tiếp 20 entry.

Query

MongoDB không có phép so sánh cả bộ (createdAt, _id) < (c, id) như SQL, nên ta viết nó ra bằng $or:

// last = document cuối của trang trước
db.orders.find({
  tenantId: "t0000",
  $or: [
    { createdAt: { $lt: last.createdAt } },                       // cũ hơn hẳn
    { createdAt: last.createdAt, _id: { $lt: last._id } }         // cùng giây, _id nhỏ hơn
  ]
}).sort({ createdAt: -1, _id: -1 }).limit(20)

Trước khi đo tốc độ, kiểm tra tính đúng: ở trang 100 và trang 10.000, kết quả keyset giống hệt kết quả skip (same result as skip: true) khi dữ liệu không đổi.

Đo

Keyset tốn đúng 20 key và 20 document ở mọi trang. Ở trang 10.000, skip chậm hơn khoảng 100 lần. Với filter có thêm status: "pending" ở trang 1.000: skip đọc 199.924 document (139 ms), keyset đọc 268 key, 268 document, median 0,77 ms. Vẫn có lãng phí (248 đơn không phải pending bị đọc rồi vứt) nhưng nó tỉ lệ với một trang, không tỉ lệ với số trang đã đi qua.

Planner biến $or thành gì

[quan sát] Ở bản 8.3.11, mỗi nhánh của $or thành một IXSCAN với bounds riêng, rồi SORT_MERGE trộn hai luồng đã sẵn thứ tự:

LIMIT <- FETCH <- SORT_MERGE
                     ├── IXSCAN tenantId ["t0000"], createdAt (2025-12-14T06:08:11, MinKey], _id [MaxKey, MinKey]
                     │       keys 20, advanced 20
                     └── IXSCAN tenantId ["t0000"], createdAt [2025-12-14T06:08:11], _id (6ac742ff…, MinKey]
                             keys 0, advanced 0

Không có stage SORT nào: thứ tự đến thẳng từ index, nên limit(20) dừng được sau 20 entry. Đây là điều kiện bắt buộc. Nếu index không cung cấp được thứ tự sort, server phải đọc hết mọi document khớp rồi mới sort (blocking sort, bài 06), và keyset mất gần hết lợi thế. Cách đọc bounds chi tiết ở bài 10, SORT_MERGE ở bài 15.

Vì sao phải có _id làm tie-breaker

Đây là chỗ nhiều implementation "cursor pagination" bị sai. Hãy thử phân trang hết 250.000 đơn của t0000 theo ba cách:

// A: chỉ dùng createdAt, so sánh $lt
{ tenantId: T, createdAt: { $lt: last.createdAt } }
// B: createdAt + _id như trên
// C: chỉ dùng createdAt, so sánh $lte (để "không sót")
{ tenantId: T, createdAt: { $lte: last.createdAt } }

orders at 2026-09-15T08:00:00Z: 3000
A createdAt only ($lt): 12349 pages, 246974 orders seen
B createdAt + _id: 12500 pages, 250000 orders seen, 250000 distinct
C createdAt only ($lte): same page returned again at request # 554 createdAt 2026-09-15T08:00:00.000Z

• A sót 3.026 đơn. Khi trang kết thúc giữa một nhóm đơn trùng createdAt, $lt nhảy qua cả nhóm. Đợt import 3.000 đơn cùng một giây mất gần trọn, cộng thêm vài chục chỗ trùng giây rải rác.
• C kẹt vòng lặp vô hạn ở request 554: cả trang nằm trong nhóm 3.000 đơn cùng giây, $lte trả lại đúng trang đó mãi mãi.
• B đi đủ 250.000 đơn, không trùng, không sót.

sort chỉ theo createdAt                 sort theo (createdAt, _id)

08:00:00                                08:00:00, id 9
08:00:00  ← trang dừng ở đây            08:00:00, id 7  ← trang dừng ở đây
08:00:00    "sau" là cái nào?           08:00:00, id 4    "sau" = id < 7, rõ ràng
            không xác định

Nguyên tắc: các field trong sort phải tạo thành một khoá duy nhất. createdAt không duy nhất, _id thì luôn duy nhất, nên thêm _id vào cuối sort, vào cuối index, và vào cursor. [tài liệu] Trang cursor.skip() cũng khuyên đưa ít nhất một field có giá trị duy nhất vào sort, đơn giản nhất là _id, vì sort trên field trùng có thể cho thứ tự khác nhau giữa các lần chạy, nhất là khi collection đang được ghi. Điều này đúng cho cả skip lẫn keyset.

Vì sao không phân trang chỉ bằng _id? Trang tài liệu có ví dụ đó, và nó dùng được khi bạn thật sự muốn thứ tự "theo lúc tạo, đại khái". Nhưng [tài liệu] ObjectId chỉ chính xác đến giây và do client sinh ra theo đồng hồ của client (bài 03), nên nó không thay được createdAt khi app cho phép sửa ngày, import dữ liệu cũ, hay sort theo field khác.

Cursor trong API trông thế nào

API không nên lộ skip, cũng không nên bắt client tự ghép $or. Server trả về một cursor mờ (opaque token), client chỉ việc gửi lại:

{
  "items": [ "... 20 đơn ..." ],
  "nextCursor": "eyJjIjoiMjAyNS0xMi0xNFQwNjowODoxMVoiLCJpZCI6IjZhYzc0MmZmNTQxZjdiOTFmYzgxZmQwNSJ9"
}

Bên trong chỉ là { c: "2025-12-14T06:08:11Z", id: "6ac742ff541f7b91fc81fd05" } mã hoá base64. Nếu cursor đi kèm filter (status, khoảng ngày), hãy đưa cả filter vào token hoặc ký nó, để client không thể ghép cursor của tenant này với filter của tenant khác.

Cái giá của keyset

Keyset pagination
   │
   ├── ✓ chi phí mỗi trang không đổi theo độ sâu
   ├── ✓ không trùng, không sót khi có ghi xen giữa
   ├── ✗ không nhảy thẳng tới "trang 437" được
   ├── ✗ cần index khớp đúng thứ tự sort (thêm _id ở cuối)
   ├── ✗ đổi sort = đổi cursor = có thể cần index khác
   └── ⚠ "tổng số trang" vẫn cần countDocuments, mà count trên tenant lớn không rẻ

Khi nào skip vẫn ổn? Khi tập kết quả nhỏ và bị chặn trên (ví dụ tối đa 50 trang kết quả tìm kiếm), hoặc màn hình admin nội bộ ít người dùng. Một mẫu hay gặp: cho phép nhảy trang bằng skip trong vài chục trang đầu, sâu hơn thì chỉ có "tải thêm" bằng cursor. Đó là lý do nhiều sản phẩm lớn chỉ có nút "Xem thêm" thay vì danh sách số trang.

Thiết kế index cho multi-tenant: vì sao tenantId đứng đầu

Hình dung: kho có nhiều khách thuê

Một kho hàng cho 500 công ty thuê. Cách 1: xếp mọi thùng theo ngày nhập, khách nào cũng lẫn vào nhau. Cách 2: mỗi công ty một dãy kệ riêng, trong dãy thì xếp theo ngày nhập.

Công ty A hỏi "20 thùng mới nhất của tôi". Với cách 1, thủ kho đi từ đầu dãy ngày mới nhất, nhặt thùng nào của A, bỏ qua thùng của 499 công ty khác. Nếu A là khách lớn thì sớm gom đủ 20. Nếu A là khách nhỏ, hoặc A đã ngừng gửi hàng từ năm ngoái, thủ kho đi gần hết kho. Với cách 2, thủ kho đi thẳng tới dãy của A, lấy 20 thùng đầu.

{ createdAt: -1 }                         { tenantId: 1, createdAt: -1 }
mới ─────────────────────────► cũ        t0000: mới ──► cũ
t0000 t0371 t0000 t0042 t0000 ...         t0042: mới ──► cũ     ← nhảy thẳng vào đây
                                          t0499: mới ──► cũ
khách nhỏ / khách cũ = đi rất xa           khách nào cũng = 20 bước

Đo: ba tenant, ba index

Query của màn hình danh sách, dùng hint() để ép từng index (bài 10):

db.orders.find({ tenantId: t }).sort({ createdAt: -1 }).limit(20).hint(idx)

Đọc bảng

• Với index bắt đầu bằng createdAt, chi phí phụ thuộc vào tenant là ai: khách lớn thì 78 key, khách nhỏ 8.590 key, khách đã nghỉ 823.117 key. Đó là chi phí của thủ kho đi dọc dãy "theo ngày" cho đến khi gom đủ 20 thùng của đúng khách. Khách t0499 có đơn mới nhất từ hơn 300 ngày trước, nên phải đi qua 82% collection mới gặp đơn đầu tiên.
• Với tenantId đứng đầu, mọi tenant đều tốn 20 key. Chi phí không phụ thuộc vào kích thước hay hành vi của tenant khác.
• Đặt tenantId ở sau createdAt không cứu được. [quan sát] Ở bản này, khi hint index { createdAt: -1, tenantId: 1 }, bounds của tenantId là [MinKey, MaxKey] và điều kiện tenant được kiểm tra ở FETCH, nên số document đọc bằng số key. Nhưng kể cả khi điều kiện được áp lên key, server vẫn phải đi qua 823.117 key, vì các key của t0499 nằm rải rác khắp chiều thời gian.

Đây là ESR của bài 08 (Equality trước, Sort sau) nhìn từ góc multi-tenant: tenantId là điều kiện bằng có mặt trong mọi query, nên nó đứng đầu. Điều nguy hiểm của index sai không phải là chậm đều, mà là chậm theo tenant: dashboard trung bình trông ổn, còn một nhóm khách nhỏ hoặc khách cũ nhận latency 1,4 giây và không ai thấy trên biểu đồ p50.

Lưu ý: khi cả ba index tồn tại, planner tự chọn { tenantId: 1, createdAt: -1, _id: -1 } cho t0499 (trial run ở bài 10 loại các plan đi xa). Bảng trên dùng hint để thấy cái giá của từng index, không phải để mô tả lựa chọn mặc định.

Hệ quả cho thiết kế

Mọi index phục vụ query của tenant
   │
   ├── bắt đầu bằng tenantId          (equality, có trong mọi query)
   ├── tiếp theo là field sort         (createdAt)
   ├── cuối là _id nếu dùng cursor     (tie-breaker)
   └── ⚠ index không có tenantId ở đầu = ổn với khách lớn, thảm hoạ với khách nhỏ/cũ

Còn một lý do không liên quan đến tốc độ: tenantId có trong mọi filter cũng là một hàng rào bảo mật. Một query quên tenantId vừa có thể trả dữ liệu của tenant khác, vừa không dùng được index nào ở trên. Nhiều team ép điều này ở tầng repository của app (không có hàm nào nhận filter mà thiếu tenantId). Bài 32 (Security) sẽ quay lại chuyện cô lập tenant.

Chi phí: mỗi index phục vụ một "màn hình" có thứ tự sort riêng. Index { tenantId, createdAt, _id } ở đây tốn 27,9 MB, lớn hơn cả _id_ (11 MB). Mỗi index như vậy là thêm một lần ghi cho mỗi insert (bài 07). Đừng tạo index cho mọi cách sort mà UI có thể cho phép; hãy tạo cho những cách sort người dùng thật sự dùng, và giới hạn UI theo đó.

Truy vết query chậm

30 giây

Khi hệ thống chậm, câu hỏi đầu tiên không phải "thêm index gì" mà là "query nào đang chậm, chậm vì làm nhiều việc hay vì phải chờ". MongoDB cho bạn ba công cụ, mỗi cái nhìn một khoảng thời gian khác nhau:

            đã xong                         đang chạy
   ◄──────────────────────────────┤├────────────────►
   slow query log    profiler           $currentOp
   (luôn bật,        (bật theo DB,      (ảnh chụp
    ghi ra log)       ghi vào            ngay lúc này)
                      system.profile)

Tầng 1: slow query log

[tài liệu] Mọi operation có thời gian làm việc vượt slowms (mặc định 100 ms) được ghi vào diagnostic log của mongod, kể cả khi profiler đang tắt. Tài liệu lệnh profile ghi rõ việc so ngưỡng dựa trên workingMillis, tức thời gian MongoDB thật sự làm việc; thời gian chờ lock và flow control không được tính vào để quyết định "chậm hay không".

Màn hình "Đơn của tôi" lấy đơn của một user trong tenant lớn. Index hiện có là { tenantId: 1, createdAt: -1, _id: -1 }. Một user mới tên u9999 vừa tạo 2 đơn và mở màn hình:

db.orders.find({ tenantId: "t0000", userId: "u9999" })
  .sort({ createdAt: -1 }).limit(20)
  .comment("api:GET /orders/me")

Đọc log ngay trong shell bằng getLog (đã cắt bớt):

msg: 'Slow query'
attr: {
  ns: 'lab10.orders',
  queryShapeHash: '6CA356B6B92BD8E0965E0134DDBCEF61D88B68DC860AAE8E0BEA7EF9D86CA2A9',
  command: { find: 'orders', filter: { tenantId: 't0000', userId: 'u9999' },
             sort: { createdAt: -1 }, limit: 20, comment: 'api:GET /orders/me' },
  planSummary: 'IXSCAN { tenantId: 1, createdAt: -1, _id: -1 }',
  keysExamined: 250002,
  docsExamined: 250002,
  nreturned: 2,
  numYields: 25,
  planCacheShapeHash: '6294005E',
  queryFramework: 'classic',
  cpuNanos: 414484284,
  workingMillis: 484,
  durationMillis: 484
}

Từng dòng trả lời một câu hỏi:

[tài liệu] queryShapeHash có từ 8.0. Cũng từ 8.0, planCacheShapeHash thay cho queryHash (vẫn còn, nhưng deprecated), và cpuNanos chỉ có trên Linux. [quan sát] Trên 8.3.11, getProfilingStatus() còn trả về slowinprogms: 5000: [tài liệu] từ 8.3 có thêm ngưỡng cho operation đang chạy lâu (mặc định 5.000 ms), đặt qua db.setProfilingLevel() hoặc --defaultSlowInProgMS.

Tầng 2: database profiler

Log cho bạn từng dòng. Profiler cho bạn một collection để query, gom nhóm, sắp xếp. Bật cho database lab10 với ngưỡng thấp hơn để bắt cả những query "hơi chậm":

db.setProfilingLevel(1, { slowms: 50 })

{ was: 0, slowms: 100, slowinprogms: Long('5000'), sampleRate: 1, ok: 1 }

Mô phỏng một tải nhỏ: 30 user khác nhau của t0000 mở trang "Đơn của tôi", trong đó có u9999. Rồi gom system.profile theo hình dạng query:

db.system.profile.aggregate([
  { $match: { ns: "lab10.orders", op: "query" } },
  { $group: {
      _id: { shape: "$queryShapeHash", plan: "$planSummary" },
      n: { $sum: 1 },
      p50ms: { $median: { input: "$millis", method: "approximate" } },
      maxms: { $max: "$millis" },
      keys: { $sum: "$keysExamined" }, docs: { $sum: "$docsExamined" }, ret: { $sum: "$nreturned" } } },
  { $sort: { n: -1 } }
])

[ { _id: { shape: '6CA356B6...', plan: 'IXSCAN { tenantId: 1, createdAt: -1, _id: -1 }' },
    n: 25, p50ms: 97, maxms: 607,
    keys: 1243341, docs: 1243341, ret: 482 } ]

25 trên 30 lần gọi vượt 50 ms. Tổng cộng 1.243.341 key và document được đọc để trả 482 document, khoảng 2.580 cho mỗi kết quả. Đó là con số đáng chú ý nhất, không phải p50ms: nó nói query này lãng phí có hệ thống, không phải xui một lần.

Cái giá của profiler [tài liệu]:

Profiler level 1
   │
   ├── ✓ query được, gom nhóm được, có cả command đầy đủ
   ├── ✗ mỗi operation bị ghi = một lần ghi thêm vào system.profile
   ├── ✗ slowms thấp hoặc level 2 = overhead lớn, tài liệu cảnh báo có thể làm giảm hiệu năng
   ├── ⚠ system.profile là capped collection, mặc định chỉ 1 MB: dữ liệu cũ bị đè rất nhanh
   ├── ⚠ level và filter đặt theo từng database; slowms và sampleRate là toàn cục cho cả mongod
   └── ⚠ không bật được trên mongos; mỗi mongod trong cluster bật riêng

Xong việc thì tắt, và nhớ trả slowms về giá trị cũ (vì nó toàn cục, ảnh hưởng cả log):

db.setProfilingLevel(0, { slowms: 100 })

Có thể dùng sampleRate hoặc filter (ví dụ chỉ ghi op: "query" với millis > 2000) để giảm overhead khi phải bật lâu trên production. Trên Atlas còn có Query Profiler, Performance Advisor và stage $queryStats; [tài liệu] $queryStats chỉ có trên Atlas (cluster M10 trở lên), không có trong bản self-managed của lab này.

Tầng 3: $currentOp, ảnh chụp lúc đang cháy

Log và profiler chỉ thấy operation đã xong. Khi server đang nghẹt ngay lúc này, bạn cần nhìn những gì đang chạy. Ảnh chụp dưới đây lấy trong lúc 8 client cùng chạy query "Đơn của tôi" (thí nghiệm ở phần sau):

db.getSiblingDB("admin").aggregate([
  { $currentOp: { allUsers: true } },
  { $match: { active: true, ns: "lab10.orders" } },
  { $project: { opid: 1, op: 1, secs_running: 1, microsecs_running: 1,
                planSummary: 1, "command.filter": 1, "command.comment": 1, numYields: 1 } }
])

{ opid: 522265, op: 'query', ns: 'lab10.orders',
  secs_running: Long('0'), microsecs_running: Long('311037'),
  command: { filter: { tenantId: 't0000', userId: 'u0042' }, comment: 'bench' },
  planSummary: 'IXSCAN { tenantId: 1, createdAt: -1, _id: -1 }', numYields: 7 }
...
active ops on lab10.orders: 6

Sáu operation cùng hình dạng đang chạy song song trên một server 2 CPU, cái lâu nhất đã chạy 311 ms. Đó là hình ảnh của hàng đợi: không phải một query hỏng, mà nhiều bản sao của cùng một query tốn kém đang tranh nhau CPU.

[tài liệu] $currentOp là stage aggregation chạy trên database admin, và là cách được khuyên dùng; lệnh currentOp đã deprecated từ 6.2. Nếu một operation chạy hàng phút và đang làm hại cả hệ thống, bạn có thể dừng nó bằng db.killOp(opid). Tài liệu nhắc chỉ kill operation do client gửi tới, kiểm tra opid, ns, command trước khi kill, và đừng đụng vào operation nội bộ của database. killOp là băng cá nhân; nếu query đó sẽ chạy lại sau 5 giây theo lịch của app, bạn chưa sửa được gì.

Chẩn đoán từng bước trên một query thật

Ghép ba tầng lại thành một quy trình. Đây là quy trình chạy trên chính query "Đơn của tôi":

1. Triệu chứng     API /orders/me chậm, p95 tăng
        ↓
2. Tìm hình dạng   slow log / profiler: gom theo queryShapeHash, xếp theo tổng thời gian
        ↓
3. Đọc tỉ lệ       keysExamined : docsExamined : nreturned
        ↓
4. Tái hiện        explain("executionStats") với tham số xấu nhất
        ↓
5. Giả thuyết      index đang thiếu field nào? sort có từ index không?
        ↓
6. Sửa và đo lại   explain + profiler, kiểm tra cả cái giá (RAM, đĩa, ghi)

Bước 2–3. Profiler cho thấy một hình dạng duy nhất, planSummary là IXSCAN, tỉ lệ khoảng 2.580 key cho mỗi kết quả. Bài 07 đã cảnh báo: IXSCAN không có nghĩa là nhanh.

Bình thường                Ở đây
keys ≈ docs ≈ nreturned    keys = docs = 250.002  >>  nreturned = 2

keysExamined bằng docsExamined nói rằng mọi key được quét đều phải FETCH document. Lý do: điều kiện userId không nằm trong index, nên server phải mở từng document để kiểm tra.

Bước 4. Tái hiện với hai user, một bình thường và một user mới:

u0042 keys 38974  docs 38974  n 20 median 60.9 ms
u9999 keys 250002 docs 250002 n 2  median 351.4 ms

Cùng một hình dạng query, chi phí khác nhau 6 lần tuỳ giá trị tham số. u0042 có 117 đơn, nên đi qua khoảng 39.000 đơn của tenant (theo thứ tự thời gian) là gom đủ 20. u9999 chỉ có 2 đơn, không bao giờ gom đủ 20, nên đi hết cả 250.000 đơn của tenant. Đây là kiểu query "nhanh khi test, chậm với khách thật": dev test với user có nhiều đơn, còn user mới mới là người chịu thiệt.

Bước 5. Index đang có trả lời "đơn của tenant, mới nhất trước". Câu hỏi thật là "đơn của user trong tenant, mới nhất trước". Theo ESR, tenantId và userId đều là equality, createdAt là sort:

db.orders.createIndex({ tenantId: 1, userId: 1, createdAt: -1 })

Bước 6. Đo lại:

build ms 1558
u0042 plan LIMIT <- FETCH <- IXSCAN {"tenantId":1,"userId":1,"createdAt":-1} rejected 1  keys 20 docs 20 n 20  median 0.89 ms
u9999 plan LIMIT <- FETCH <- IXSCAN {"tenantId":1,"userId":1,"createdAt":-1} rejected 1  keys 2  docs 2  n 2   median 0.57 ms

BEFORE (u9999)                     AFTER (u9999)
IXSCAN {tenantId, createdAt}       IXSCAN {tenantId, userId, createdAt}
   ↓                                  ↓
250.002 key                        2 key
   ↓                                  ↓
FETCH 250.002 doc, vứt 250.000     FETCH 2 doc
   ↓                                  ↓
2 kết quả, 351 ms                  2 kết quả, 0,57 ms

Và cái giá, vì không có index nào miễn phí:

Index { tenantId, userId, createdAt }
   │
   ├── ✓ "Đơn của tôi": 351 ms → 0,57 ms với user xấu nhất
   ├── ✗ +19,9 MB index (cả collection 74 MB trên đĩa)
   ├── ✗ thêm một index phải cập nhật cho mỗi insert, và mỗi update đổi userId/createdAt
   ├── ✗ build 1,6 s trên 1 triệu document; trên collection thật có thể là hàng giờ
   └── ⚠ chưa bỏ được index cũ: màn hình danh sách của tenant vẫn cần { tenantId, createdAt, _id }

Khi nghi ngờ một index cũ không còn ai dùng, [tài liệu] bạn có thể hideIndex() nó trước: planner không thấy index đó nữa, nhưng nó vẫn được cập nhật khi ghi, nên unhideIndex() là dùng lại được ngay, không phải build lại. _id index thì không ẩn được.

Query performance và system performance

Hình dung: quán phở có hai đầu bếp

Quán có 2 đầu bếp (2 CPU). Một tô phở bình thường mất 50 giây để nấu. Có 1 khách: khách chờ 50 giây. Có 2 khách: mỗi đầu bếp nấu một tô, cả hai vẫn chờ 50 giây, quán ra gấp đôi số tô mỗi phút. Có 8 khách cùng lúc: vẫn chỉ 2 đầu bếp. Quán không ra nhiều tô hơn mỗi phút, nhưng mỗi khách chờ lâu gấp nhiều lần vì phải xếp hàng.

2 đầu bếp           = 2 CPU
thời gian nấu 1 tô  = chi phí của một query (query performance)
số tô mỗi phút      = throughput (system performance)
thời gian khách chờ = latency = nấu + xếp hàng

Bây giờ đổi công thức để mỗi tô chỉ mất 1 giây. Cùng 8 khách, hàng đợi gần như biến mất.

Đây chỉ là cách hình dung. mongod không có "một đầu bếp một query"; nhiều thread chia nhau CPU và có thể nhường nhau (yield). Nhưng khi query bị giới hạn bởi CPU như ở đây, quy luật "hết đầu bếp thì xếp hàng" khớp với số đo.

Đo: 8 client, có và không có index đúng

Query "Đơn của tôi" với u0042 (kết quả 20 đơn). Mỗi client là một tiến trình mongosh chạy liên tục trong 10 giây, mọi client chờ một mốc giờ chung rồi bắt đầu cùng lúc. Mỗi mức chạy 3 lần (không index đúng) hoặc 5 lần (có index), bảng ghi median, trong ngoặc là khoảng min–max của throughput:

Không có index đúng (chỉ { tenantId, createdAt, _id }):

Có index { tenantId, userId, createdAt }:

Trong lúc 8 client chạy, chụp top bên trong container:

Không index đúng (index ẩn bằng hideIndex):
  mongod   190.9 %CPU      8 × mongosh   0.0 %CPU     → server làm hết việc
Có index:
  mongod    50.0 %CPU      mỗi mongosh  20–60 %CPU    → client làm phần lớn việc

Đọc con số

Không có index đúng. Từ 1 lên 2 client, throughput gần gấp đôi (18 → 34 query/s) mà latency gần như giữ nguyên: đầu bếp thứ hai vào việc. Từ 2 lên 8 client, throughput không tăng (thậm chí giảm), nhưng p50 latency nhảy từ 53 ms lên 294 ms. mongod ăn 191% CPU, tức cả 2 CPU. Server đã bão hoà. Thêm client chỉ thêm người xếp hàng.

Có một phép kiểm tra nhanh, [hình dung] gọi là Little's law: số request đang ở trong hệ thống = throughput × thời gian mỗi request. 8 client, 24,8 query/s, suy ra mỗi request trung bình mất khoảng 8 / 24,8 ≈ 323 ms, khớp với p50 đo được là 294 ms. Nghĩa là: khi throughput đã đụng trần, latency không do query quyết định nữa, mà do có bao nhiêu người đang chờ.

Query performance                     System performance
1 client: 52 ms, "chấp nhận được"     8 client: ~25 query/s cho CẢ server
                                      p50 294 ms, p95 546 ms
                                      CPU 191%: bận đọc 39.000 đơn để trả 20

Có index đúng. Mỗi query giờ tốn khoảng 20 key và 20 document. Throughput lên hàng nghìn query/s và latency dưới 1 ms ở p50. Con số 8 client (1.987 query/s) thấp hơn 2 client, nhưng đọc top sẽ thấy lý do: mongod chỉ dùng 50% CPU, phần còn lại là 8 tiến trình mongosh tranh nhau 2 CPU trong cùng container. Bottleneck đã dời từ database sang chính công cụ đo. Lab này đo được cái chính (từ ~25 lên hàng nghìn query/s, từ 294 ms xuống dưới 1 ms) nhưng không đo được trần thật của server khi có index; muốn đo phải để client chạy trên máy khác.

Lưu ý phương pháp: máy host còn chạy các container lab khác, nên số có index dao động khá rộng giữa các lượt (1.471–2.800 query/s với 8 client). Số không có index thì ổn định hơn vì bị chặn bởi CPU của chính mongod.

Bài học

• Một query 50 ms nghe có vẻ ổn khi chạy một mình. Nhưng nó giữ một CPU bận 50 ms, và server chỉ có 2 CPU. Chi phí của query quyết định trần throughput của cả hệ thống.
• Khi hệ thống bão hoà, latency tăng theo số request đồng thời, không theo query. Tăng connection pool hay thêm instance app lúc này chỉ làm hàng đợi dài hơn (bài 34 đo chuyện pool lớn hơn không làm nhanh hơn).
• Sửa query (giảm việc từ 39.000 xuống 20 document) tăng throughput khoảng 80 lần với 8 client trong lab này (24,8 lên 1.987 query/s), và con số thật còn cao hơn vì lúc đó client mới là bottleneck. Không nâng cấp phần cứng nào cho được con số đó.
• Ngược lại, một query nhanh vẫn có thể là vấn đề hệ thống nếu nó chạy với tần suất cực lớn. Gom theo queryShapeHash rồi xếp theo tổng thời gian (n × thời gian), không chỉ theo query chậm nhất.

So với PostgreSQL

Bài toán và lời giải giống nhau ở cả hai bên: offset tỉ lệ với độ sâu, keyset cần index khớp thứ tự sort và một tie-breaker duy nhất, và multi-tenant cần tenant_id đứng đầu index. Khác biệt chính là cú pháp: PostgreSQL diễn đạt "đứng sau bộ (c, id)" trong một biểu thức, MongoDB cần hai nhánh $or và planner ghép lại bằng SORT_MERGE.

Những lỗi thường gặp

• Phân trang bằng skip trên danh sách dài, đang được ghi. Chậm dần theo độ sâu (31 ms ở trang 10.000, 139 ms ở trang 1.000 khi có filter ngoài index), và trùng hoặc sót khi có insert/delete xen giữa.
• Cursor chỉ có createdAt. $lt sót đơn (3.026 đơn trong lab), $lte lặp vô hạn. Luôn thêm _id vào sort, index và cursor.
• Index không có tenantId ở đầu. Trông ổn với khách lớn, rồi 1,4 giây cho khách nhỏ hoặc khách đã nghỉ.
• Thấy IXSCAN là yên tâm. Phải nhìn tỉ lệ keysExamined : docsExamined : nreturned. 250.002 : 250.002 : 2 là IXSCAN tệ.
• Test với dữ liệu "đẹp". Query nhanh với user có nhiều đơn, chậm với user mới. Luôn tái hiện với tham số xấu nhất.
• Không gắn comment vào query. Đến lúc đọc slow log thì không biết query từ endpoint nào.
• Bật profiler level 2 hoặc slowms rất thấp trên production rồi quên tắt. Thêm việc ghi cho mọi operation, và slowms là toàn cục.
• Kill query thay vì sửa query. killOp cứu được năm phút, không cứu được ngày mai.
• Đánh giá query bằng một lần chạy, một client. 52 ms một mình thành 294 ms khi có 8 người cùng chờ.

Tóm tắt

• skip + limit tốn công tỉ lệ với offset: trang 10.000 đi qua 200.000 key (31–33 ms) dù chỉ trả 20 document; nếu filter có field ngoài index, skip còn phải FETCH mọi document bị bỏ (199.924 document, 139 ms ở trang 1.000).
• Keyset pagination trên { tenantId, createdAt, _id } tốn 20 key, 20 document ở mọi trang (0,22–0,32 ms ở trang 10.000), không trùng hay sót khi có ghi xen giữa, nhưng không nhảy thẳng tới trang N được.
• _id làm tie-breaker là bắt buộc khi field sort không duy nhất. Không có nó, lab sót 3.026 đơn hoặc lặp vô hạn.
• tenantId đứng đầu index làm chi phí mỗi tenant bằng nhau (20 key). Index bắt đầu bằng createdAt tốn từ 78 đến 823.117 key tuỳ tenant.
• Truy vết: slow log (luôn bật, slowms 100 ms, tính theo workingMillis) → profiler (gom theo queryShapeHash) → $currentOp (đang chạy gì) → explain với tham số xấu nhất → sửa → đo lại và tính cái giá.
• Query vs system performance: không có index đúng, 2 CPU bão hoà ở khoảng 25–35 query/s, 8 client đẩy p50 lên 294 ms. Có index đúng, server chạy hàng nghìn query/s và bottleneck dời sang client.

Tự kiểm tra

1. Vì sao ở trang 10.000, totalDocsExamined của skip chỉ là 20 mà query vẫn mất 31 ms? Điều gì làm nó tăng lên 199.924? (SKIP nằm dưới FETCH nên bỏ qua trên key; nhưng vẫn đi qua 200.000 key. Khi filter có field không nằm trong index, phải FETCH để kiểm tra trước khi skip.)
2. Cursor { createdAt: { $lt: last.createdAt } } hoạt động hoàn hảo trên staging. Vì sao nó sót dữ liệu trên production? (Production có nhiều đơn cùng giây, ví dụ do import hàng loạt; trang kết thúc giữa nhóm trùng thì $lt nhảy qua phần còn lại.)
3. Một index { createdAt: -1 } phục vụ màn hình "đơn mới nhất của tenant" rất tốt trong load test. Khách nào sẽ phàn nàn đầu tiên? (Khách nhỏ và khách đã ngừng dùng: index phải đi qua đơn của mọi tenant khác cho tới khi gom đủ đơn của họ.)
4. Slow log cho thấy cpuNanos gần bằng workingMillis. Điều đó gợi ý gì về hướng sửa? (Query bận tính, không chờ I/O hay lock: giảm lượng việc, thường là sửa index, chứ không phải tăng cache hay đổi đĩa.)
5. Throughput không đổi khi tăng từ 2 lên 8 client, nhưng latency tăng gấp 5. Tăng connection pool của app lên gấp đôi có giúp không? (Không. Server đã hết CPU; thêm request chỉ dài hàng đợi.)

Nếu phải giải thích bài này mà không dùng thuật ngữ MongoDB nào: muốn đọc tiếp thì kẹp bookmark, đừng đếm lại từ đầu sách, và bookmark phải chỉ đúng một chỗ. Kho cho nhiều khách thuê thì chia kệ theo khách trước, theo ngày sau. Khi kho chậm, xem sổ ghi những yêu cầu lâu, tìm loại yêu cầu bắt thủ kho đi nhiều nhất mà mang về ít nhất. Và một yêu cầu mất một phút thì không sao, nhưng tám người cùng gửi cho hai thủ kho thì người cuối hàng chờ rất lâu.

Bài tiếp theo

Các bài thực hành của Phần 2 dừng ở đây. Từ bài 07 đến bài này, mọi thứ xoay quanh một câu hỏi: làm sao để đọc ít nhất có thể. Index, planner, pipeline, cursor pagination đều là cách để server đi thẳng tới đúng document và không đụng vào những thứ còn lại.

Còn một câu hỏi bài 10 mới trả lời một nửa: planner dựa vào đâu để biết một plan sẽ đọc bao nhiêu document? Bài 14, Cost-Based Ranker & Cardinality Estimation, mở phần bên trong đó: khi nào planner ước lượng chi phí thay vì chạy thử các plan, con số ước lượng đến từ đâu, và ước lượng sai thì plan sai ra sao. Bài 15, Query Execution Engine, khép lại Phần 2 bằng cách các stage thực sự chạy.

Sau 14–15 là Phần 3. Hầu hết thí nghiệm của Phần 2 chỉ đọc, và các lệnh ghi đều chạm vào một document. Khi một nghiệp vụ phải chạm nhiều document cùng lúc (tạo đơn hàng và trừ tồn kho và ghi sổ cái), Phần 3 mở đầu bằng bài 16, Transactions.

Tài liệu tham khảo

• cursor.skip()
• Database Profiler (Manage the Database Profiler)
• profile command
• Database Profiler Output
• $currentOp (aggregation)
• $queryStats
• Hidden Indexes