Journal (P2/3): `j: true`, checkpoint và hai lab

10 phút đọcSeries: MongoDB: từ gốc đến internals

Ở phần trước: mỗi lệnh ghi thêm một record vào journal, còn page trong RAM được sửa và để đó. Sau crash, mongod replay journal kể từ checkpoint cuối. Với j: true, lệnh ghi chỉ được xác nhận khi record đã xuống đĩa.

Lab 1: cái giá của j: true, và group commit

Câu hỏi mà bài Durability để ngỏ: j: true đắt bao nhiêu, và "journal có thể gộp nhiều lệnh vào một lần flush" nghĩa là sao khi nhiều client cùng ghi.

Một client, tuần tự, chạy ngay trong container của mongod (e1a-latency.out, 5 lượt xen kẽ, mỗi lượt 1.000 insertOne sau 200 lệnh khởi động, median của 5 lượt): w: 1 có p50 0,251 ms, p95 0,358 ms; w: 1, j: true có p50 0,463 ms, p95 0,984 ms. Với j: true, log sync operations tăng đúng 1 mỗi insert ở cả 5 lượt, mỗi lần sync trung bình 173 đến 431 µs; với w: 1 chỉ 0,002 đến 0,004 (sync nền). Để có điểm tham chiếu, dd ghi 2.000 lần 4 KiB với oflag=dsync trong container mất 1,07 và 1,81 giây ở hai lần chạy (0,53 và 0,90 ms mỗi lần, e1c-fsync-ref.out), cùng bậc độ lớn. Các lượt dao động: một lượt j: true có p50 tới 1,016 ms (host đang bận).

Nhiều client cùng ghi (e1b-concurrency.js/.out): từ container client riêng, N luồng bất đồng bộ trong một tiến trình mongosh, mỗi luồng insertOne tuần tự; cửa sổ đo 4 giây, 3 lượt xen kẽ giữa w: 1 và j: true, N = 1, 4, 16, 64. "Ops mỗi sync" = số lệnh ghi hoàn tất chia cho số lần tăng của log sync operations trong cửa sổ.

N clientw: 1: ops/giây (median 3 lượt)j: true: ops/giây (median 3 lượt)j: true / w: 1j: true: p50 / p95Ops mỗi lần sync (3 lượt)Một lần sync (µs, 3 lượt)
14.5222.6710,590,323 / 0,734 ms1,0 / 1,0 / 1,0129 / 149 / 137
411.4345.5310,480,584 / 1,335 ms1,4 đến 1,5185 đến 208
1614.02310.1610,721,442 / 2,560 ms3,6 đến 3,8297 đến 306
6413.15212.1560,925,169 / 7,348 ms6,7 / 6,7 / 6,9383 đến 532

(p50 của w: 1 ở N = 1, 4, 16, 64 lần lượt là 0,193, 0,321, 1,054, 4,156 ms.)

Group commit (gộp nhiều lần ghi vào một lần fsync) hiện ra trong hai cột cuối. Với một client, mỗi lệnh ghi tự trả một lần sync. Càng nhiều client, càng nhiều lệnh dùng chung một lần sync: ở 64 client, một lần sync phục vụ khoảng 6,7 lệnh, và throughput của j: true chỉ còn thấp hơn w: 1 khoảng 8% (12.156 so với 13.152), trong khi ở 1 client nó thấp hơn 41%. Cái giá còn lại chuyển sang latency: p50 của j: true ở 64 client là 5,2 ms so với 4,2 ms của w: 1.

[tài liệu] Cơ chế gộp nằm ở bộ đệm journal: một nhóm "slot" trong RAM, mỗi thread giành chỗ trong slot đang mở bằng thao tác nguyên tử rồi chép record vào; khi slot đầy hoặc tới giờ flush, cả slot được ghi xuống một lần. [suy luận] Khi một fsync đang chạy (129 đến 532 µs ở lab này), các lệnh tới sau xếp vào slot kế tiếp và cùng chờ fsync tiếp theo, nên nhóm lớn dần theo số client đang chờ, nhưng nhỏ hơn N vì client còn tốn thời gian ở CPU (6,7 ở 64 client).

Hai giới hạn. Một: throughput của w: 1 dừng ở khoảng 13.000 đến 14.000 ops/giây từ 16 client; [suy luận] đó là trần của mongod 2 CPU cộng một mongosh đơn luồng sinh tải, không phải trần của journal. Hai: một lần sync hết 130 đến 530 µs là của volume Docker này; trên đĩa mà fsync tốn 2 ms hay 10 ms, cả chi phí lẫn lợi ích của group commit đều khác. Cái hình dạng mang đi được: một lệnh j: true đơn độc trả nguyên một lần chờ đĩa; trăm lệnh đồng thời chia nhau một lần chờ.

Checkpoint: chỉnh "sổ cái"

Nó là gì, nó làm gì

[tài liệu] Checkpoint là một bản chụp nhất quán của mọi file dữ liệu tại một thời điểm, ghi xuống đĩa; sau khi nó hoàn tất, các file dữ liệu nhất quán tới thời điểm đó và có thể dùng làm điểm khôi phục. MongoDB cấu hình WiredTiger làm checkpoint mỗi 60 giây (storage.syncPeriodSecs, tham số syncdelay, mặc định 60; manual dặn "không đặt giá trị này ở production", và đặt bằng 0 thì journal "cuối cùng ăn hết đĩa").

Theo tài liệu kiến trúc của WiredTiger (cảnh báo của chính họ: tài liệu này không được cập nhật cùng nhịp với mã nguồn), một checkpoint đi qua các bước:

1. Eviction trước, để giảm lượng page dirty; chỉ một checkpoint chạy một lúc
2. Với mỗi file có thay đổi: duyệt cây, reconciliation mọi page dirty (clean page, tức page chưa bị sửa, bị bỏ qua)
3. History store được checkpoint sau các file dữ liệu; flush mọi file xuống đĩa
4. Ghi metadata cuối cùng; vị trí checkpoint mới nhất nằm trong WiredTiger.turtle

[tài liệu] Manual MongoDB nói thêm hai điều quan trọng cho an toàn: trong lúc checkpoint mới đang được ghi, checkpoint trước vẫn hợp lệ (mongod chết giữa chừng thì recovery dùng lại checkpoint trước), và checkpoint mới chỉ có hiệu lực khi bảng metadata của WiredTiger được cập nhật nguyên tử để trỏ tới nó; sau đó các page của checkpoint cũ mới được giải phóng. Đó chính là "ghi vào chỗ trống mới, không đè lên chỗ cũ" của bài WiredTiger & Compression: nhờ vậy checkpoint dở dang không làm hỏng file.

Đo nó: field nào, ở đâu

Các chỉ số tôi dùng, từ serverStatus().wiredTiger sau một workload ngắn (10.000 insert w: 1 rồi 2.000 insert j: true tuần tự, rồi một checkpoint ép bằng fsync; e0c-fields.out):

Section . fieldGiá trị trong labCho biết gì
log . log bytes of payload data3.171.146Tổng payload của các record (sau nén)
log . log bytes written4.619.392Byte thực ghi vào journal (mỗi record làm tròn lên bội 128)
log . log sync operations2.041Số lần fsync journal; ≈ 2.000 từ các lệnh j: true, phần còn lại là sync nền
checkpoint . most recent time (msecs)30Thời gian checkpoint gần nhất
cache . tracked dirty bytes in the cache0Lượng dirty đang chờ checkpoint hoặc eviction

Một cạm bẫy phiên bản. [tài liệu] Trang serverStatus của manual (bản "current", 9.0) liệt kê các chỉ số checkpoint dưới wiredTiger.transaction, tên dạng transaction checkpoint most recent time (msecs), transaction checkpoint currently running, transaction checkpoints. [quan sát] Trên 8.3.11 những khoá đó không còn ở wiredTiger.transaction: ở đó chỉ còn năm khoá nhắc tới checkpoint (ví dụ transaction global checkpoint timestamp); các chỉ số thời gian và số lượng nằm ở một section riêng, wiredTiger.checkpoint, với tên ngắn hơn (most recent time (msecs), total succeed number of checkpoints, progress state). Tôi không biết thay đổi từ bản nào và không thử trên 9.0; dashboard đọc transaction checkpoint most recent time thì kiểm tra lại trên phiên bản bạn chạy. Manual có nói chỉ số này, khi tăng lên trong lúc tải ghi đều, "có thể báo hiệu I/O bị nghẽn".

Lab 2: một checkpoint trong lúc tải ghi đều

e3a.sh: 190 giây tải đều trên container mongo-jrn22-main (4 client, mỗi client chèn một document khoảng 1,1 KB rồi nghỉ 2 ms; tổng 169.533 document, khoảng 890 document/giây), một script khác đọc serverStatus mỗi giây, và từ host liệt kê thư mục journal/ mỗi 5 giây.

 mốc (s từ poll đầu) | checkpoint hoàn tất | cách lần trước | thời gian | reconcile | ghi vào file | journal ghi trong khoảng đó
 +40  | ckN 25 → 26 |  (đầu cửa sổ) |   101 ms |         — |        — | —
 +101 | ckN 26 → 27 |   61 s        | 1.521 ms |  10,1 MiB |  7,5 MiB |  57,8 MiB
 +162 | ckN 27 → 28 |   61 s        |   724 ms |  15,5 MiB | 13,3 MiB |  64,6 MiB

(derive-e3a.out; "reconcile" là number of bytes caused to be reconciled, "ghi vào file" là bytes written for checkpoint, cả hai là hiệu của hai lần checkpoint liên tiếp. Poll bị thưa ở cuối cửa sổ vì host bận, nên chỉ có hai khoảng đầy đủ.)

[quan sát]

  • Checkpoint hoàn tất cách nhau 61 giây ở cả hai khoảng (poll mỗi giây), khớp mặc định 60 giây cộng thời gian chạy. Từ lần khởi động đầu tiên của lab, checkpoint đầu tiên cũng tới đúng 60 giây sau (log: 09:46:20 → 09:47:21, e0a-first-checkpoint.out).
  • Thời gian checkpoint: 101 ms lần đầu (tải mới chạy khoảng 40 giây), rồi 1.521 và 724 ms cho hai phút ghi gần như nhau; số của volume Docker trên host bận.
  • Mỗi phút journal ghi 58 đến 65 MiB, nhưng checkpoint chỉ phải ghi 7,5 đến 13,3 MiB vào file dữ liệu (đã nén). [suy luận] Phần lớn page dirty đã được eviction ghi xuống từ trước (bài Cache, Eviction & Working Set). Dirty trong cache đạt đỉnh 26,4 MiB (trung bình 17,2 MiB trong cả lần quan sát).

Dọn journal sau checkpoint (e3a-journal-dir.out, liệt kê từ host mỗi 5 giây, WiredTigerLog.* và Preplog.*):

t=25s  10:09:08   Log.0000000003 (104.610.816)  Log.0000000004 (mới)  Preplog.0000000004
t=35s  10:09:18   Log.0000000003                Log.0000000004        Preplog.0000000004
t=40s  10:09:23                                 Log.0000000004        Preplog.0000000004   ← file 3 biến mất
t=125s 10:11:14   Log.0000000004                Log.0000000005        Preplog.0000000005
t=130s 10:11:20                                 Log.0000000005        Preplog.0000000005   ← file 4 biến mất

File 3 đầy tới 104.610.816 byte và journal chuyển sang file 4; file 3 chỉ biến mất vào lần checkpoint tiếp theo hoàn tất (giữa 10:09:18 và 10:09:23, trùng mốc +40 s của poll; file 4 giữa 10:11:14 và 10:11:20, trùng mốc +162 s; nhãn t= là thứ tự lần liệt kê × 5, không phải giây thật, và hai đồng hồ lệch vài giây). Đúng như manual: giữ journal tới khi checkpoint làm nó thừa. [suy luận] Nếu checkpoint bị chặn lại (đĩa quá chậm) thì journal cứ lớn dần; manual dặn chừa đủ chỗ cho journal, nếu không server sẽ crash.

Lab 3: một $inc nhỏ, một checkpoint lớn

Đây là lời hứa của bài Schema Patterns: "một $inc 4 byte làm checkpoint ghi lại cả document". Tạo document sz10m 10.068.933 byte (mảng 70.000 phần tử, mỗi phần tử có một chuỗi hex ngẫu nhiên 110 ký tự để nén được ít), và 2.000 document khoảng 8 KB (e3b-inc-checkpoint.out, e3c-inc-cold.out). Mỗi bước: ép một checkpoint bằng fsync trước để bắt đầu từ trạng thái đã ghi hết, ghi bộ đếm, chạy $inc, ghi bộ đếm, ép checkpoint, ghi bộ đếm.

BướcJournal payloadDirty trong cache sau $incCheckpoint reconcileLeaf byte ghi (trước nén → sau nén)
Document 10 MB, 1 lệnh $inc63 byte10.875.11110.420.95010.135.736 → 8.473.082
Document 10 MB, 100 lệnh $inc rồi một checkpoint6.300 byte (cả 100 lệnh)10.889.07410.294.83610.135.725 → 8.473.071
Document 8 KB, nạp bằng insertMany (chưa restart), 1 $inc64 byte9.056.7348.598.6118.347.076 → 8.342.590
Document 8 KB, sau khi restart mongod, 1 $inc60 đến 61 byte26.844 đến 26.847100.282 đến 108.53275.812 đến 75.820 (cả năm document)

[quan sát] Hai điều.

Một. Với document 10 MB, journal ghi 63 byte còn checkpoint ghi 10,1 triệu byte trước nén (10.135.736; sau nén 8,47 triệu vì hex ngẫu nhiên nén kém), khớp kích thước document (10.068.933): so byte trước nén với payload journal (10.135.736 / 63), checkpoint ghi nhiều hơn khoảng 160.000 lần. Đó là hiện tượng của bài Schema Patterns (10.920.698 byte cho document 10,9 MB, số trước nén): journal nhẹ vì ghi thao tác, checkpoint nặng vì ghi page, và document 10 MB gần như tự là một page. Dòng "1 lệnh" và dòng "100 lệnh rồi một checkpoint" cho cùng lượng byte: checkpoint trả giá theo số page dirty, không theo số lần sửa; trăm lần $inc vào cùng document giữa hai checkpoint chỉ làm nó ghi một lần.

Hai, và là điều tôi không ngờ: với document 8 KB, kết quả phụ thuộc kích thước page đang nằm trong cache. Ngay sau insertMany, một $inc lên document 8 KB tạo 9 MB dirty và checkpoint ghi khoảng 8,3 MB; sau khi restart mongod (page đọc lại từ đĩa) cùng lệnh chỉ tạo khoảng 26,8 KB dirty và checkpoint ghi khoảng 76 KB lá (chừng chín document cùng page). [suy luận] Page trong RAM của collection có thể lớn hơn nhiều page 32 KB trên đĩa (bài WiredTiger & Compression ghi memory_page_max=10M), và dữ liệu vừa nạp chưa bị eviction chia nhỏ; tôi không kiểm chứng trực tiếp kích thước page trong RAM. Ý nghĩa: "checkpoint ghi lại cả page" có thể là rất nhiều document, và con số "page 108 KB" ở bài Schema Patterns là một điểm trên một dải rộng.

Cột mốc: Bạn đã có thể đọc cái giá của j: true khi một client và khi nhiều client, giải thích group commit, và nói checkpoint ghi những gì xuống đĩa. Tiếp theo: Crash recovery.

Hỏi & đáp

Lab đo j: true với 1, 4, 16 và 64 client. Ở 64 client, throughput chỉ thấp hơn w: 1 khoảng 8% (12.156 so với 13.152 ops/s), còn ở 1 client thì thấp hơn 41%. Vì sao?

  1. Nhiều lệnh ghi dùng chung một lần fsync

    Đó là group commit: ở 64 client, trung bình 6,7 lệnh dùng chung một lần sync, ở 1 client chỉ 1,0. Cái giá chuyển sang latency (p50 5,2 so với 4,2 ms). Xem "Lab 1".

  2. Mỗi lần fsync trở nên nhanh hơn khi có nhiều client

    Ngược lại: thời gian trung bình một lần sync tăng từ khoảng 130 µs (1 client) lên 380 đến 530 µs (64 client). Lợi ích đến từ việc chia sẻ lần sync, không phải từ sync nhanh hơn. Xem bảng ở "Lab 1".

  3. Khi có nhiều client, mongod bỏ qua j: true để giữ throughput

    Không có cơ chế đó: j: true vẫn chờ một lần sync (lab: số lần sync còn khoảng 1.800 mỗi giây ở 64 client). Chỉ là một lần sync phục vụ nhiều lệnh. Xem "Lab 1".

  4. Journal chuyển sang ghi checkpoint thay cho từng lệnh khi tải cao

    Checkpoint vẫn chạy mỗi 60 giây (61 giây giữa hai lần ở Lab 2) bất kể tải; nó không thay journal. Xem mục "Checkpoint".

Một document 10 MB, bạn chạy một $inc 4 byte lên một field số, rồi checkpoint kế tiếp chạy. Theo lab, chuyện gì xảy ra?

  1. Journal ghi cả document 10 MB; checkpoint chỉ ghi vài byte của field đổi

    Ngược hẳn: journal ghi thao tác, không ghi page. Page được ghi cả khối ở checkpoint, không ghi từng field. Xem "Lab 3"; về việc journal ghi thao tác, xem Journal.

  2. Journal ghi vài chục byte; checkpoint ghi lại gần như cả document 10 MB đó

    Lab: journal 63 byte, checkpoint reconcile khoảng 10,4 triệu byte và ghi 10,1 triệu byte lá trước nén. Xem "Lab 3".

  3. Journal và checkpoint đều chỉ ghi vài chục byte, vì MongoDB chỉ lưu phần thay đổi

    Journal đúng, checkpoint sai: WiredTiger ghi xuống file theo page, và document 10 MB gần như là cả page. Xem "Lab 3".

  4. Cả hai đều ghi cả 10 MB, vì mỗi lệnh ghi phải ghi lại toàn bộ document ở mọi nơi

    Journal chỉ 63 byte cho một lệnh $inc ở lab này. Xem "Lab 3".