Lang thang vào viblo xem mấy thông báo 'bài viết XYZ của bạn đã được upvote' hay 'Trần X, Phạm Y... đã theo dõi bạn' mình tình cờ thấy được thông báo này của Viblo.
Mình cũng quyết định nhanh tay dinh ngay quà Tết với một bài viết khai bút đầu xuân (thực ra là khai phím đầu xuân) ^^.
Và chắc chắn rồi, đầu năm người Việt ta thường dành cho nhau những lời chúc tốt đẹp nhất. Nhân dịp đầu xuân, mình mong rằng năm mới sẽ mang đến hạnh phúc mới, mục tiêu mới, thành công mới và nguồn động lực mới đến với mọi người. Mình xin kính chúc mọi người và gia đình năm mới thật nhiều sức khỏe và tràn ngập niềm vui. 
Thoạt đầu mình định viết tiếp về technical skills của các series trước đó. Nhưng ngồi nghĩ một lúc, mình nghĩ lại nên chọn một chủ đề nào đó mang tính phổ quát, tính áp dụng rộng rãi thay vì một chủ đề, một ngôn ngữ hay một Framework cụ thể. Hai nữa bài viết này phải ngắn gọn, dễ hiểu, không hàn lâm vì đầu năm chắc mọi người cũng chưa muốn ngồi để ngấu nghiến một bài viết dài về technical. Cuối cùng thì cũng nghĩ ra một chủ đề đó là Log Messages trong hệ thống, ứng dụng phần mềm. Cụ thể là ghi logs sao cho khi tiếp cận lỗi hệ thống, hay các thông báo trong hệ thống thì người phát triển hệ thống và người dùng hệ thống đều có thể dễ dàng đọc hiểu thông tin đó. Mình xin phép được bắt đầu bài viết luôn và ngay.
Đã bao giờ có một tình huống mà bạn nhìn chằm chằm vào thông báo lỗi và tự hỏi "Thông báo lỗi này nghĩa là gì? Thông tin nào trong thông báo lỗi này có thể giúp mình fixbug?...". Và rất có thể tình huống đó bạn đã chửi thề ai đó đã code đoạn code này. Dưới đây là một số rule viết thông báo, nhật ký (gọi chung là log messages) trong một số trường hợp.
Câu chuyện thúc đẩy việc phải viết logs rõ ràng, mạch lạc, dễ hiểu
Mình đã từng triển khai một ứng dụng Java và nhận được thông báo nguyên nhân từ nhật ký ghi logs như sau:
Caused by: java.net.SocketTimeoutException: connect timed out at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_171] at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_171]
Một thông báo rất chung chung. Những dòng logs này cung cấp thông tin không thật sự rõ ràng rõ ràng, nó không trả lời bất kỳ câu hỏi nào của mình mong đợi:
- Kết nối đến URL nào đang bị timeout (host, port là gì)?
- Thời gian chờ timeout đã định cấu hình là bao lâu?
- Thành phần nào chịu trách nhiệm thiết lập thời gian chờ?
- Thông số cấu hình nào có thể được điều chỉnh để sửa đổi thời gian chờ?
Nếu để ý, trong những dòng logs thêm các thông tin ở trên sẽ giúp chúng ta rất nhiều trong việc tìm hiểu cách khắc phục sự cố.
Chúng ta hãy cùng xem xét một số trường hợp điển hình hơn, nếu ghi logs rõ ràng mạch lạc có thể sẽ giúp ích cho chúng ta rất nhiều.
“Not Found” Errors
Đây là một lỗi rất phổ biến. Khi ghi logs các lỗi "Not Found", nhật ký logs nên chứa thông tin:
- Các tham số trong truy vấn tìm kiếm (thông thường, đây là ID của một thực thể hoặc có thể là một số thông tin khác)
- Loại đối tượng không tìm thấy.
Bad Example:
User not found.
Good Examples:
User with ID '42' was not found.
No Contract found for client '42'.
Exceptions
Ngoại lệ là một lỗi phổ biến khác, một số loại ngoại lệ do chúng ta định nghĩa hoặc một số loại ngoại lệ do chương trình throws ra. Nhật ký logs nên chứa các thông tin:
- Nguyên nhân dẫn đến ngoại lệ.
- Nguyên nhân gốc của ngoại lệ (nếu có) dẫn đến ngoại lệ.
Bad Example:
Registration failed.
Good Examples:
Registration failed because the user name 'superman42' is already taken.
Registration failed due to database error: (stacktrace of root exception)
Validation Errors
Dữ liệu đầu vào từ người dùng hoặc hệ thống bên ngoài thường phải được xác thực để ứng dụng có thể hoạt động an toàn với nó.
Nếu việc xác thực như vậy không thành công, việc thêm thông tin ngữ cảnh sau vào nhật ký logs sẽ giúp ích rất nhiều:
- Trường hợp sử dụng trong đó xác nhận không thành công.
- Tên của trường (field) có xác nhận không thành công, lý do xác thực không thành công.
- Giá trị của trường (field) xác thực không thành công.
Ngoài ra, chúng ta nên đảm bảo bao gồm tất cả các lỗi xác thực trong nhật ký và không chỉ lỗi đầu tiên.
Thông thường, trong phản hồi về lại cho Client (người dùng hệ thống) thông tin cũng cần rõ ràng để khách hàng có thể trực tiếp xem những gì đã xảy ra.
Bad Example:
Validation failed.
Validation failed for field "name".
Validation failed: field must not be null.
Good Examples:
Registration failed: field "name" must not be null.
Registration failed due to the following reasons: "age" must be a number; "name" must not be null.
Status Changes
Khi một thực thể chuyển từ trạng thái này sang trạng thái khác, nhật ký logs nên bao gồm các thông tin:
- ID của thực thể thay đổi trạng thái
- Loại thực thể thay đổi trạng thái
- Trạng thái trước đây của thực thể
- Trạng thái mới của thực thể
Bad Examples:
Status changed.
Status changed to "PROCESSED".
Good Examples:
Status of Job "42" changed from "IN_PROGRESS" to "PROCESSED".
Cấu hình tham số khi chạy ứng dụng
Khi khởi động ứng dụng, nó có thể giúp ích rất nhiều để in ra cấu hình hiện tại của ứng dụng, bao gồm:
- Tên của từng tham số cấu hình
- Giá trị của từng tham số cấu hình
- Giá trị dự phòng mặc định nếu tham số không được giải thích.
Khi tham số cấu hình thay đổi trong suốt thời gian sống của ứng dụng, nó phải được ghi lại giống như thay đổi trạng thái. Bad Examples:
Parameter "waitTime" has not been set.
Parameter "timeout" has been set.
Good Examples:
Parameter "waitTime" falls back to default value "5".
Parameter "timeout" set to "10". Theo dõi hoạt động của một phương thức
Khi chúng ta đang theo dõi hoạt động của phương thức, nó sẽ là hiển nhiên để cung cấp một số thông tin theo ngữ cảnh:
- Tên của phương thức
- Khoảng thời gian thực hiện, tốt nhất là ở dạng con người có thể đọc được (tức là "3m 5s 354ms" thay vì "185354ms")
- Giá trị của các tham số trong phương thức (chỉ khi chúng có ảnh hưởng đến thời gian thực hiện).
Lưu ý rằng nếu nhật ký ghi logs theo dõi được xử lý tự động để thu thập số liệu thống kê về thời gian thực hiện, thì nên tính bằng mili giây thay vì hình thức có thể đọc được của con người.
Bad Example:
Took 543ms to finish.
Good Examples:
Method "FooBar.myMethod()" took "1s 345ms" to finish.
FooBar.myMethod() processed "432" records in "1s 345ms".
Batch Jobs
Batch Jobs - Công việc xử lý tác vụ hàng loạt thường xử lý một số bản ghi theo cách này hay cách khác. Thêm thông tin sau vào nhật ký ghi logs có thể giúp ích khi phân tích chúng:
- Thời gian bắt đầu công việc
- Thời gian kết thúc công việc
- Thời gian thực hiện công việc
- Số lượng bản ghi đã được xử lý
- Số lượng bản ghi KHÔNG được xử lý và lý do tại sao (tức là vì chúng không khớp với bộ lọc được xác định bởi batch jobs)
- Loại bản ghi đang được xử lý.
- Trạng thái xử lý của công việc (đang chờ/đang tiến hành/đã xử lý - waiting/in progress/progressed)
- Trạng thái thành công của công việc (thành công/thất bại - success/failure) Bad Example:
Batch Job finished.
Batch Job "SendNewsletter" finished in 5123ms.
Good Examples:
Batch Job "SendNewsLetter" sent "3456" mails in "5s 123ms". 324 mails were not sent due to an invalid mail address. Tổng kết
Có một lưu ý rằng cung cấp thông tin dưới dạng dữ liệu có cấu trúc thay vì chỉ cung cấp dưới dạng văn bản sẽ giúp chúng ta dễ dàng hơn để tìm thông tin chúng ta muốn. Thêm một số thông tin theo ngữ cảnh trong các thông báo hay các lỗi hệ thống vào logs message thường không mất nhiều công sức nhưng những lợi ích nó mang lại rất rõ ràng về mặt thống kê, về mặt theo dõi hệ thống hay khắc phục sự cố.
Mình hi vọng bài viết này sẽ hữu ích cho mọi người trong quá trình phát triển hệ thống, ứng dụng phần mềm.
Một lần nữa xin được chúc mọi người ra gia đình một năm mới an khang thịnh vượng, vạn sự như ý!