Journal (P1/3): Đường đi một lần ghi và journal

Bài này trả lời một câu hỏi: một thay đổi chỉ mới nằm trong RAM thì sống sót thế nào khi mất điện?

Phần sau có group commit.

Bài có 3 Part:

• P1 (Part này): Đường đi một lần ghi và journal.
• P2: j: true, checkpoint và hai lab.
• P3: Crash recovery; chỉnh gì, đừng chỉnh gì.

Mấy bài trước đã hứa bốn lần mà chưa giải thích. Bài Durability & Consistency nói j: true hứa lệnh ghi "đã nằm trong journal trên đĩa" và cái giá của nó tuỳ đĩa. Bài Mental Model nói WiredTiger ghi checkpoint mỗi 60 giây và phát lại journal sau crash. Bài Schema Patterns & Evolution thấy một $inc 4 byte làm checkpoint ghi 10.920.698 byte. Bài WiredTiger & Compression hỏi: thay đổi chỉ nằm trong RAM sống sót qua mất điện bằng cách nào?

Bài này trả lời bằng thí nghiệm: nhìn thư mục journal, đo j:true với 1 đến 64 client, kill -9 một mongod đang chịu tải rồi đếm lệnh ghi còn sống, đọc log recovery thật, và xem một checkpoint ghi bao nhiêu byte sau một $inc.

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

• Cần biết trước: WiredTiger & Compression (page trong RAM khác page trên đĩa, reconciliation, file .wt), Durability & Consistency (j: true, w: 1, acknowledged)
• Giới thiệu: journal (write-ahead log) ghi gì, nằm ở đâu, được ghi xuống đĩa khi nào, nén ra sao; group commit; checkpoint ghi gì và mỗi bao lâu; recovery sau khi mongod chết đột ngột; các chỉ số wiredTiger.log và wiredTiger.checkpoint trong serverStatus
• Không dạy ở đây: w, j, wtimeout nghĩa là gì với ứng dụng (bài Durability & Consistency); dirty page bị evict khi nào (bài Cache, Eviction & Working Set); update chain và timestamp (bài WiredTiger MVCC); oplog và majority commit point lúc failover (bài Replica Set & Oplog, bài Elections, Failover & Majority). Bài này chỉ chạm vào chúng ở chỗ ranh giới
• Dẫn tới: WiredTiger MVCC

Môi trường lab: MongoDB 8.3.11 trong Docker (image mongo:8, WiredTiger 12.0.0 theo WiredTiger.turtle), mongosh 2.12.0. Mọi mongod là standalone, mỗi cái 2 CPU, 2 GB RAM, WiredTiger cache 1 GB, một volume riêng; client chạy trong container khác. Host Apple M4 với Docker Desktop; volume nằm trên ổ ảo /dev/vda1 (ext4) của máy ảo Docker. Tôi không biết fsync trong máy ảo có chạm tới SSD của Mac hay dừng ở lớp ảo hoá, nên các con số j: true là của lab này, không phải của đĩa production. Host còn chạy nhiều container không liên quan và một lab khác (load average khoảng 11 ở một lần đọc uptime), nên thời gian dao động. Script và output thô nằm trong lab22/ kèm INDEX.md.

Cần nói thẳng: (1) thử $inc trên document lớn, đôi khi một lệnh trong 100 lệnh ghi vào journal cỡ 1 MB thay vì vài chục byte; tôi không điều tra nguyên nhân (xem mục "Journal: ghi gì, ở đâu, khi nào xuống đĩa"). (2) Thử nghiệm kill dùng docker kill (SIGKILL tới mongod), không phải mất điện; Lab 4 nói rõ nó chứng minh và không chứng minh gì.

Nhãn: [tài liệu] theo tài liệu chính thức (manual "current" lúc viết ghi 9.0, trong khi lab là 8.3.11); [quan sát] đo trong lab này; [suy luận] rút ra từ quan sát, không kiểm tra riêng; [chi tiết cài đặt] cách server đang làm, không phải cam kết API; [hình dung] mô hình để dễ nhớ.

Ý chính

Khi bạn ghi một document, MongoDB không sửa file dữ liệu ngay. Nó sửa page trong RAM (cache), và đồng thời ghi một dòng mô tả thao tác vào cuối một file tuần tự gọi là journal (về mặt kỹ thuật là một write-ahead log: log được ghi trước, file dữ liệu được sửa sau). Ghi nối vào cuối một file thì rẻ; sửa rải rác nhiều page trong nhiều file .wt thì đắt. Vì vậy dòng journal được ghi ngay, còn page thì để đó.

Cứ khoảng 60 giây, WiredTiger làm một checkpoint: ghi mọi page đã sửa xuống file dữ liệu, thành một bản nhất quán, rồi mới cho phép bỏ những đoạn journal cũ. Nếu mongod chết giữa hai checkpoint, lúc khởi động lại nó tìm checkpoint cuối cùng trong file dữ liệu rồi phát lại (replay) phần journal sau đó. Chỗ còn lại để mất dữ liệu là khoảng từ lúc lệnh ghi được xác nhận tới lúc dòng journal của nó xuống đĩa; j: true đóng khoảng đó bằng cách chờ.

Hình dung trước: cuốn sổ ghi chép của cửa hàng

Một cửa hàng tạp hoá có sổ cái: gọn gàng, chia theo từng mặt hàng, mỗi mặt hàng một trang. Sửa sổ cái mỗi lần bán hàng thì rất chậm: phải lật tới đúng trang, tẩy, viết lại. Vì vậy chủ tiệm làm hai việc. Mỗi lần bán, ông ghi một dòng ngắn vào cuốn sổ ghi chép hằng ngày ("10:02 bán 2 chai nước, mặt hàng 17") rồi quên chuyện sổ cái đi. Cứ mỗi giờ, ông ngồi lại chỉnh sổ cái theo các giao dịch trong giờ qua, đóng dấu "sổ cái đúng tới đây", rồi xé những trang sổ ghi chép đã chỉnh xong.

Một đêm mất điện, hàng hoá trên quầy (bộ nhớ làm việc) chẳng còn dấu vết nào. Sáng hôm sau ông mở sổ cái, đọc dấu "đúng tới đây", rồi làm lại từng dòng của sổ ghi chép kể từ dấu đó. Không giao dịch nào đã vào sổ ghi chép bị mất.

Cửa hàng                                    MongoDB / WiredTiger
─────────────────────────────────────       ──────────────────────────────────────────────
quầy hàng, bàn làm việc                     cache: page trong RAM, một số đã bị sửa
một lần bán hàng                            một lệnh ghi của client
một dòng ngắn trong sổ ghi chép             một record trong journal (thao tác, không phải page)
sổ cái                                      các file .wt
chỉnh sổ cái mỗi giờ, đóng dấu              checkpoint (mặc định mỗi 60 giây)
xé các trang sổ ghi chép đã chỉnh xong      journal file cũ bị xoá sau khi checkpoint xong
sáng hôm sau đọc lại sổ ghi chép            recovery: replay journal sau checkpoint cuối

[hình dung] Hình ảnh này khác thực tế ở bốn chỗ. Một: dòng viết vào sổ ghi chép trước hết nằm trong bộ đệm RAM của mongod, rồi tới bộ đệm của hệ điều hành, rồi mới tới đĩa; chữ "đã ghi" có ba nghĩa, và đó là toàn bộ chuyện của j: true. Hai: checkpoint không viết lại cả sổ cái, chỉ các page đã sửa, nhưng viết lại cả page. Ba: sổ ghi chép chỉ của một cửa hàng; chuyện sao chép sang cửa hàng khác (oplog) là cơ chế riêng. Bốn: mất điện thật còn làm mất cả những gì hệ điều hành chưa kịp đẩy xuống đĩa, điều lab không mô phỏng được.

Đường đi của một lần ghi

Client: insertOne({ ... }, { writeConcern: { w: 1, j: true } })
   │
   ▼
mongod (query layer)
   │
   ▼
WiredTiger
   ├─① sửa page trong cache ─────────────▶ page bị đánh dấu "dirty" (đã sửa, chưa ghi xuống file)
   │
   ├─② viết một record vào bộ đệm của journal (trong RAM của mongod)
   │         │
   │         ▼   (gộp với record của các thread khác, rồi write() xuống OS)
   │      page cache của hệ điều hành
   │         │
   │         ▼   fsync(): chờ thiết bị lưu trữ xác nhận
   │      file journal/WiredTigerLog.NNNNNNNNNN trên đĩa
   │         │
   │         └──▶ nếu j: true, client chỉ nhận acknowledged SAU bước này
   │
   └─③ khoảng mỗi 60 giây: checkpoint
             reconciliation các page dirty ─▶ ghi vào file .wt (khối mới, không đè khối cũ)
             ─▶ cập nhật metadata ─▶ journal file cũ không còn cần nữa

Tuỳ mongod hay cả máy chết ở mũi tên nào, phần sống sót khác nhau:

Hai dòng đầu là lý do w: 1 không có j có một cửa sổ mất dữ liệu nhỏ (Lab 4 đo nó); dòng thứ hai cũng là lý do lab kill không chứng minh được mọi thứ về mất điện.

Journal: ghi gì, ở đâu, khi nào xuống đĩa

Ghi gì: thao tác, không phải page

[tài liệu] WiredTiger tạo một record journal cho mỗi lệnh ghi do client khởi tạo, gồm cả thay đổi nội bộ do nó gây ra: cập nhật một document làm đổi index vẫn chỉ có một record. Mỗi record có header 16 byte và kích thước là bội của 128 byte.

[quan sát] Đo (e0b-ops-not-pages.out): chèn 5.000 document (273 byte BSON, hex ngẫu nhiên 200 ký tự để không nén được) và đọc bộ đếm wiredTiger.log trước và sau.

Payload lớn hơn document một chút (khoá, header), và ba index phụ chỉ làm payload tăng khoảng 48 byte: thay đổi của index nằm trong cùng record. Byte thực ghi khoảng 384 = 3 × 128 mỗi insert: record được làm tròn lên bội của 128.

Quan trọng hơn là $inc trên document lớn. Tôi chạy $inc lên một field số của một document 10.897.823 byte (mảng 70.000 phần tử, cùng dạng với document 10,9 MB của bài Schema Patterns) 100 lần, đo journal sau từng lệnh: cả 100 lệnh ghi 62 byte payload và 128 byte thực ghi (e3b-inc-checkpoint.out, document 10.068.933 byte: 63 byte). Journal ghi thao tác ("cộng 1 vào field này của document kia"), không ghi page chứa document.

Một điều tôi không giải thích được: ở document 7,3 MB, một trong 100 lệnh $inc ghi khoảng 1,26 MB vào journal còn 99 lệnh kia 62 byte (e0b-odd-runs.out); ở e3b, 100 lệnh $inc trên document 8 KB tổng cộng 64.158 byte thay vì khoảng 6.400. [suy luận] Có vẻ thỉnh thoảng WiredTiger ghi cả giá trị thay vì chỉ thao tác; tôi không kiểm chứng. Cái đã chắc: phần lớn lệnh chỉ ghi vài chục byte, rất ít so với checkpoint (Lab 3).

Vì journal chứa thao tác, nó cũng nén được như dữ liệu. [tài liệu] Mặc định mongod nén journal bằng snappy (storage.wiredTiger.engineConfig.journalCompressor, các giá trị none, snappy, zlib, zstd); record từ 128 byte trở xuống không được nén. Log khởi động của lab xác nhận (e0a-anatomy.out):

"Opening WiredTiger" ... log=(enabled=true,remove=true,path=journal,compressor=snappy) ...

[quan sát] e0d-journal-compression.out: cùng 5.000 insert, cùng 229 byte BSON mỗi document, chỉ khác nội dung.

Chuỗi lặp: payload 98,5 byte mỗi insert, 5.004 trên 5.009 record được nén (1.347.483 → 491.389 byte, còn 36%). Hex ngẫu nhiên: 269,5 byte mỗi insert, chỉ 4 record được nén.

Dữ liệu không nén được thì WiredTiger thử rồi bỏ.

Nằm ở đâu: thư mục journal/

[tài liệu] Journal nằm ở thư mục con journal của dbPath, các file tên WiredTigerLog.<số thứ tự>, mỗi file tối đa khoảng 100 MB; khi vượt giới hạn, WiredTiger tạo file mới. Journal file được cấp phát sẵn (pre-allocate) để lúc chuyển file thread của client không phải chờ tạo file. File cũ chỉ được giữ khi còn cần để recovery từ checkpoint cuối.

[quan sát] Thư mục của container mongo-jrn22-main ngay sau khi khởi động (e0a-anatomy.out):

-rw------- 1 mongodb mongodb 104857600 Oct  9 09:50 WiredTigerLog.0000000001
-rw------- 1 mongodb mongodb 104857600 Oct  9 09:46 WiredTigerPreplog.0000000001

Hai file đều dài đúng 100 MiB (104.857.600 byte) dù mới có vài KB dữ liệu: ls cho kích thước cấp phát, không phải lượng journal đã dùng. WiredTigerPreplog.* là file chuẩn bị sẵn cho lần chuyển file kế tiếp.

Khi nào xuống đĩa

[tài liệu] Trang Journaling của manual nói WiredTiger gom record vào bộ đệm trong RAM (record tới 128 kB đều được đệm) và đẩy xuống đĩa (sync) khi một trong các điều kiện sau xảy ra:

1. Một lệnh ghi có hoặc ngầm có j: true (w: "majority" ngầm có j: true khi writeConcernMajorityJournalDefault là true, mặc định);
2. Với secondary, sau mỗi batch áp dụng oplog;
3. Mỗi 100 ms (storage.journal.commitIntervalMs, mặc định 100, khoảng 1 đến 500);
4. Khi tạo file journal mới (khoảng mỗi 100 MB).

Điều (3) là cửa sổ của w: 1: nếu không ai đòi j: true, record của một lệnh ghi có thể đợi tới khoảng một chu kỳ này mới được sync xuống đĩa. [quan sát] Server tự khai báo đúng giá trị đó: getParameter trả journalCommitInterval: 100 và syncdelay: 60 (e0a-anatomy.out). Tần suất cũng hiện ra trong bộ đếm: khi mongod rảnh, log flush operations tăng 99 lần trong 10 giây; khi 1 đến 64 client ghi w: 1 liên tục, log sync operations chỉ khoảng 37 đến 40 lần trong 4 giây (e1b-concurrency.out), tức khoảng 10 lần mỗi giây, bất kể có bao nhiêu lệnh ghi.

Phiên bản. [tài liệu] Từ MongoDB 6.1 journaling luôn bật: tuỳ chọn storage.journal.enabled và cờ --journal, --nojournal đã bị gỡ. "Tắt journal để chạy nhanh" không còn là lựa chọn. [tài liệu] Ngày nay j: true đòi mọi node được đếm trong w ghi journal xong; chi tiết nằm ở bài Durability & Consistency, bài này không nhắc lại.

Cột mốc: Bạn đã có thể chỉ ra journal nằm ở đâu, mô tả đường đi của một lần ghi từ cache tới đĩa, và nói vì sao journal ghi tuần tự. Tiếp theo: Checkpoint và j: true.

Hỏi & đáp