Có một khoảnh khắc mà mọi kỹ sư backend đều trải qua: 3 giờ sáng, một dịch vụ đang lỗi, và bạn grep qua hàng triệu dòng log để tìm chuyện gì đã xảy ra. Đúng lúc đó bạn nhận ra một sự thật phũ phàng: lúc sự cố, bạn không đọc log, bạn truy vấn nó — "cho tôi mọi lỗi của service thanh toán trong 5 phút qua, kèm mã đơn hàng". Và nếu log của bạn là những dòng chuỗi tự do kiểu log.Printf("thanh toan that bai user=%d..."), câu truy vấn đó biến thành một cuộc vật lộn với regex, vì mỗi lập trình viên trong đội đã viết mỗi dòng log theo một kiểu khác nhau.
Đó là lý do structured logging (log có cấu trúc) ra đời, và từ Go 1.21 nó có mặt ngay trong thư viện chuẩn qua gói log/slog. Ý tưởng cốt lõi đơn giản: thay vì nhét mọi thứ vào một chuỗi, mỗi thông tin là một field có tên (key-value), và log được xuất ra định dạng máy đọc được (JSON). Bài này (phần 1 loạt Observability) đo thật sự khác biệt — không chỉ về cú pháp, mà về thứ thực sự quan trọng: khả năng truy vấn. Đây là trụ cột đầu tiên trong ba trụ cột của observability (log, metric, trace).
Cơ chế: từ chuỗi sang field có tên
Hãy so sánh cùng một sự kiện — một giao dịch thanh toán thất bại — ghi theo hai cách:
Hình 1: Cùng một sự kiện — log.Printf cho ra một chuỗi tự do phải regex mới tách được field; slog với NewJSONHandler cho ra JSON, mỗi giá trị là một field có tên (user_id, order_id, reason) mà công cụ có thể lọc trực tiếp.
Nhìn kỹ hai output. Dòng chuỗi thanh toan that bai user=4021 order 88123 so tien 250000d loi timeout với con người thì đọc được, nhưng với máy thì là một khối liền — để trích user bạn cần regex user=(\d+), để trích order lại cần một mẫu khác (chú ý: nó viết order 88123 không có dấu =, đúng kiểu mỗi dòng một phách). Ngược lại, dòng JSON có "user_id":4021, "order_id":88123, "reason":"timeout" — mọi công cụ log (Elasticsearch, Loki, CloudWatch) index được ngay theo field, và bạn lọc bằng cú pháp thay vì regex. slog cung cấp các hàm typed như slog.Int, slog.String, slog.Group để gắn field, và bốn mức Debug/Info/Warn/Error.
Đo thật trong go-lab
Mình sinh 1000 dòng log JSON bằng slog trong go-lab (golang 1.23, log/slog có sẵn), mỗi dòng có các field service, level, status, latency_ms, rồi dùng jq để truy vấn — chính xác kiểu bạn làm khi điều tra sự cố.
Hình 2: Kết quả thật — jq lọc 1000 dòng log JSON: đếm theo level (ERROR 333), lọc hai field cùng lúc (level="ERROR" and service="payment" → 111 dòng), tính latency trung bình của một service (29.5ms); và bảng chi phí: log.Printf 332 ns/log so với slog JSON 577 ns/log.
Phần truy vấn cho thấy đúng sức mạnh của log có cấu trúc:
- Đếm theo field:
jq -r .level | sort | uniq -ccho ngay ERROR 333, INFO 334, WARN 333 — không regex. - Lọc nhiều field cùng lúc:
jq 'select(.level=="ERROR" and .service=="payment")'trả về 111 dòng khớp cả hai điều kiện. Với log chuỗi, truy vấn "ERROR và của payment" đòi hỏi một regex phức tạp và mong manh. - Tính toán trên field số:
jq 'select(.service=="auth")|.latency_ms'rồijq -s 'add/length'cho latency trung bình của riêng service auth = 29.5ms. Field số được giữ nguyên là số, tính toán trực tiếp.
Đây là điều không thể làm gọn với log chuỗi tự do: khi mỗi field có tên và kiểu rõ ràng, log biến từ "văn bản để đọc" thành "dữ liệu để truy vấn".
Cái giá của cấu trúc: đo thẳng thắn
Nhưng structured logging không miễn phí, và mình đo thật để nói thẳng thay vì tô hồng. Ghi 200.000 dòng log vào /dev/null bằng mỗi cách:
| Cách | ns/log |
|---|---|
log.Printf (chuỗi) |
332 |
| slog TEXT (LogAttrs) | 643 |
| slog JSON (LogAttrs) | 577 |
| slog JSON (Info, any) | 596 |
Sự thật ngược đời với nhiều người: log.Printf chuỗi tự do là nhanh nhất — nhanh hơn slog JSON khoảng 1.7 lần. Và về kích thước, một dòng text ~54 byte trong khi dòng JSON tương đương ~117 byte (hơn gấp đôi, vì tên field lặp lại và có thêm time/level). Nói cách khác, log có cấu trúc đắt hơn cả về CPU lẫn dung lượng. Giá trị của nó không nằm ở tốc độ — mà ở chỗ máy truy vấn được. Khi bạn có hàng triệu dòng log và cần trả lời một câu hỏi trong lúc sự cố, khả năng lọc bằng máy đáng giá hơn nhiều so với vài trăm nanô giây mỗi dòng. Chọn structured logging là một đánh đổi có ý thức, không phải "nhanh hơn về mọi mặt".
Một chi tiết tối ưu đáng biết trong bảng: slog.LogAttrs (dùng các slog.Attr typed) nhanh hơn một chút và cấp phát ít hơn so với slog.Info(msg, "key", val, ...) — vì dạng variadic ...any phải đóng hộp (box) mỗi giá trị vào interface, sinh cấp phát. Trong demo này chênh lệch nhỏ (577 vs 596 ns), nhưng trên đường nóng (hot path) log nhiều, LogAttrs là lựa chọn đáng dùng.
Đánh đổi cần cân nhắc
JSON cho máy, text cho người — chọn handler theo môi trường. Không phải lúc nào cũng JSON. Khi dev ở máy local, đọc log bằng mắt, TextHandler (hay một handler màu mè như tint) dễ chịu hơn nhiều. Khi chạy production và log chảy vào hệ thống tập trung, JSONHandler là bắt buộc để index được. Mẫu quen thuộc: chọn handler theo biến môi trường — JSONHandler khi ENV=production, TextHandler khi dev. Cùng một mã slog, chỉ đổi handler.
Log đồng bộ chặn đường xử lý — cân nhắc khi ghi nhiều. Mặc định, mỗi lời gọi log ghi đồng bộ xuống đích (file, stdout). Nếu đích chậm (đĩa bận, stdout bị pipe qua thứ gì đó nghẽn), lời gọi log chặn chính request đang xử lý. Trên đường nóng ghi log dày đặc, cân nhắc handler có đệm (buffered writer) hoặc ghi bất đồng bộ — nhưng nhớ đánh đổi: đệm có thể mất các dòng log cuối nếu tiến trình chết đột ngột, đúng lúc bạn cần chúng nhất. Đừng thêm async khi chưa đo thấy log là nút thắt.
Đừng bao giờ log dữ liệu nhạy cảm. Cấu trúc hoá làm log dễ tìm kiếm hơn — và điều đó đúng cả với kẻ xấu lẫn với các quy định bảo mật. Một slog.String("password", pw) hay log nguyên một token/số thẻ sẽ nằm vĩnh viễn trong hệ thống log tập trung, nơi thường có nhiều người truy cập và được giữ rất lâu. Thiết lập quy tắc: không log mật khẩu, token, khoá, PII; nếu cần, che bớt (user_id thay vì email, 4 số cuối thẻ). Log có cấu trúc khiến việc rà soát field nhạy cảm dễ hơn — hãy tận dụng điều đó theo hướng phòng thủ.
Ba ý mang về
- Lúc sự cố bạn truy vấn log, không đọc log — và chuỗi tự do không truy vấn được: đo thật, với 1000 dòng log JSON,
jqlọc hai field cùng lúc (ERRORvàservice=payment→ 111 dòng) và tính latency trung bình của một service (29.5ms) chỉ bằng cú pháp; log chuỗi tự do buộc bạn viết regex mong manh cho từng câu hỏi. slogcủa Go biến mỗi thông tin thành field có tên: dùngslog.Int/slog.String/slog.Groupvà bốn mứcDebug/Info/Warn/Error, xuất JSON cho máy hoặc text cho người bằng cách đổi handler — cùng một mã.- Cấu trúc là đánh đổi có ý thức, không phải bữa trưa miễn phí: đo thật,
log.Printfnhanh hơn (332 vs 577 ns/log) và nhỏ hơn (54 vs 117 byte/dòng) slog JSON — giá trị của structured logging nằm ở khả năng truy vấn, không ở tốc độ; dùngLogAttrsđể bớt cấp phát, và tuyệt đối không log dữ liệu nhạy cảm.
Nguồn
- Go — Package log/slog: https://pkg.go.dev/log/slog
- Go Blog — Structured Logging with slog: https://go.dev/blog/slog
- jq — Manual (select, add, length): https://jqlang.github.io/jq/manual/
Phần sau ta giải một vấn đề nảy sinh ngay khi có log có cấu trúc: giữa hàng nghìn dòng log của nhiều request đan xen, làm sao gom đúng những dòng của một request? Câu trả lời là gắn một request ID / trace ID xuyên suốt qua context.Context.
