Định dạng và cấp độ log: thực tiễn tốt nhất

1. Cấu trúc thông điệp log

Hãy tưởng tượng log không chỉ là “dòng ý thức” của chương trình bạn, mà là một nhật ký giá trị, nơi sau một tháng hay một năm bạn hoặc đồng nghiệp có thể tìm thấy câu trả lời cho câu hỏi: “Rốt cuộc ở đây đã xảy ra chuyện quái quỷ gì vậy?”. Để làm được như vậy, mỗi thông điệp log phải có cấu trúc. Thông thường (và đây là chuẩn trong hầu hết thư viện) mỗi thông điệp gồm:

• Thời điểm sự kiện — khi nó xảy ra.
• Cấp độ — mức độ quan trọng (INFO, ERROR v.v.).
• Tên logger — thường là tên class hoặc component.
• Nội dung thông điệp — điều gì đã xảy ra.
• Stack trace (nếu có lỗi) — để hiểu xảy ra ở đâu và vì sao.

Đây là ví dụ về một dòng log được định dạng tốt (Log4j/SLF4J):

2024-06-16 18:42:07,123 INFO  com.example.MainApp - Người dùng đã đăng nhập vào hệ thống: username=vasya

Còn nếu xảy ra lỗi:

2024-06-16 18:42:10,456 ERROR com.example.LoginService - Lỗi xác thực người dùng: vasya
java.lang.IllegalArgumentException: Mật khẩu không hợp lệ
    at com.example.LoginService.checkPassword(LoginService.java:42)
    ...

Vì sao điều này quan trọng?
Khi ứng dụng chạy lâu, log có thể chiếm hàng gigabyte. Nếu thông điệp không có cấu trúc, việc tìm lỗi sẽ giống như “đoán giai điệu chỉ từ tiếng ồn của quạt máy”.

2. Định dạng thông điệp

Vì sao không nên làm như sau:

logger.info("Người dùng " + username + " đã đăng nhập vào hệ thống");

Có vẻ đơn giản, nhưng có một điểm cần lưu ý: ngay cả khi cấp độ logging hiện tại là ERROR, chuỗi bên trong dấu ngoặc vẫn sẽ được tạo (phép nối chuỗi vẫn chạy), và đó là tiêu tốn tài nguyên không cần thiết. Trong các hệ thống lớn, nơi log có hàng nghìn dòng mỗi giây, điều này có thể dẫn tới độ trễ thực sự.

Cách đúng: template và tham số

Các thư viện hiện đại (ví dụ SLF4J và Log4j 2) hỗ trợ template có tham số:

logger.info("Người dùng {} đã đăng nhập vào hệ thống", username);

Ở đây, chuỗi chỉ được dựng khi cấp độ logging cho phép in thông điệp này. Nếu hiện đặt, chẳng hạn, WARN, thì thậm chí chuỗi cũng không được tính toán — tiết kiệm tài nguyên và công sức.

Bonus: nếu truyền nhiều tham số, chúng sẽ được thay thế theo thứ tự:

logger.info("Người dùng {} đã thực hiện hành động {} trên đối tượng {}", username, action, objectId);

Ghi log exception (stack trace)

Khi bắt exception, đừng tự thêm stack trace vào thông điệp:

// KHÔNG NÊN:
logger.error("Lỗi: " + ex.getMessage() + "\n" + Arrays.toString(ex.getStackTrace()));

Đúng:

logger.error("Lỗi khi xử lý yêu cầu", ex);

SLF4J và Log4j sẽ tự thêm stack trace đầy đủ vào log.

Ví dụ: so sánh hai cách

// Tệ (phép nối chuỗi luôn được thực hiện)
logger.debug("Đối tượng: " + expensiveToString(obj));

// Tốt (tạo chuỗi một cách lười biếng)
logger.debug("Đối tượng: {}", obj);

3. Chọn cấp độ logging

Nếu mọi thứ trong log đều ở cấp ERROR, đó không còn là log nữa mà là “đèn đỏ”. Nếu tất cả — ở DEBUG, bạn sẽ chìm trong chi tiết. Hãy xem khi nào nên dùng mỗi cấp độ.

ERROR

WARN

INFO

DEBUG

TRACE

Ví dụ điển hình

• ERROR — ghi file thất bại, bắt được exception chưa được xử lý, dịch vụ không khả dụng.
• WARN — API lỗi thời, hành vi người dùng đáng ngờ, vượt quá giới hạn số lần thử.
• INFO — người dùng đăng nhập/đăng xuất, xử lý đơn hàng hoàn tất, ứng dụng khởi động.
• DEBUG — tham số request, giá trị biến, kết quả tính toán trung gian.
• TRACE — vào/ra phương thức, vòng lặp nội bộ, chi tiết hoạt động của thuật toán.

Gợi ý:
Trong môi trường production thường chỉ bật INFO trở lên, đôi khi WARN và ERROR. DEBUG và TRACE — chỉ khi săn lỗi phức tạp.

4. Best practices (thực tiễn tốt nhất cho ghi log)

Không ghi log dữ liệu nhạy cảm

Mật khẩu, token, số thẻ tín dụng — tất cả không nên xuất hiện trong log. Dù bạn nghĩ rằng “file log chỉ mình tôi xem”, hãy nhớ đến GDPR và đồng nghiệp có thể vô tình gửi log vào kênh chung.

// Tệ:
logger.info("Người dùng {} đăng nhập với mật khẩu {}", username, password);

// Tốt:
logger.info("Người dùng {} đã đăng nhập vào hệ thống", username);

Đừng lạm dụng cấp ERROR

Nếu bạn ghi mọi thứ bằng logger.error, khi thảm họa thực sự xảy ra sẽ chẳng ai nhận ra — mọi người đã quen với “đèn đỏ”. Chỉ dùng ERROR cho các tình huống ứng dụng thực sự không thể tiếp tục chạy hoặc logic nghiệp vụ bị vi phạm.

Ghi log exception kèm đầy đủ stack

Đừng chỉ ghi ex.getMessage(), nếu không bạn sẽ không biết lỗi xảy ra ở đâu. Hãy truyền exception làm tham số thứ hai cho logger.

logger.error("Lỗi khi xử lý yêu cầu", ex);

Sử dụng định danh duy nhất (tương quan sự kiện)

Trong hệ thống lớn, hữu ích khi gán cho mỗi request, người dùng hoặc thao tác một định danh duy nhất. Điều này giúp “khâu” các sự kiện từ những phần khác nhau của hệ thống.

logger.info("Bắt đầu xử lý đơn hàng: orderId={}", orderId);
logger.info("Đơn hàng được xử lý thành công: orderId={}", orderId);

Đừng ghi mọi thứ vào log

Nếu có quá nhiều log — chúng sẽ trở nên vô dụng. Đừng ghi log mọi dòng code, nếu không sẽ không thể tìm ra thông tin cần thiết.

Định dạng thông điệp dễ hiểu

Hãy viết thông điệp để không chỉ tác giả code mà cả người đọc log sau nửa năm cũng hiểu. Tránh viết tắt khó hiểu và “trò đùa nội bộ”.

5. Thực hành: cấu hình định dạng log và cấp độ

Ví dụ cấu hình định dạng trong Log4j2 (log4j2.xml)

<Configuration>
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %logger{36} - %msg%n"/>
    </Console>
  </Appenders>
  <Loggers>
    <Root level="info">
      <AppenderRef ref="Console"/>
    </Root>
  </Loggers>
</Configuration>

Điều này nghĩa là gì?

• %d{...} — thời gian sự kiện.
• %-5level — cấp độ (ERROR, INFO v.v.).
• %logger{36} — tên logger (thường là class).
• %msg — chính thông điệp.

Ví dụ mã với các cấp độ logging khác nhau (SLF4J)

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LogDemo {
    private static final Logger logger = LoggerFactory.getLogger(LogDemo.class);

    public static void main(String[] args) {
        logger.info("Ứng dụng đã khởi động");
        logger.debug("Giá trị biến x: {}", 42);

        try {
            throw new IllegalArgumentException("Ôi ôi ôi!");
            // ...
        } catch (Exception ex) {
            logger.error("Đã xảy ra lỗi khi khởi động", ex);
        }
    }
}

Minh họa sự khác biệt giữa các cấp độ

Nếu cấu hình logger đặt cấp độ INFO, các thông điệp ở cấp DEBUG và thấp hơn sẽ không được in. Hãy thử đổi cấp độ thành debug trong cấu hình — bạn sẽ thấy chi tiết.

6. Lỗi thường gặp

Lỗi №1: Nối chuỗi trong log. Người mới thường viết như sau:

logger.debug("Người dùng: " + user.getName() + ", vai trò: " + user.getRole());

Kết quả là ngay cả khi tắt DEBUG, các chuỗi này vẫn được dựng, gây tải không cần thiết. Hãy dùng tham số!

Lỗi №2: Ghi log mà không kèm stack của exception. Chỉ ghi mỗi thông điệp:

logger.error("Lỗi: " + ex.getMessage());

Kết quả là log không có thông tin vị trí lỗi. Hãy truyền exception làm tham số thứ hai!

Lỗi №3: Ghi mọi thứ ở cấp ERROR. Nếu cái gì cũng đỏ thì chẳng có gì đỏ nữa. Hãy dùng đúng cấp độ, nếu không lỗi quan trọng sẽ bị chìm trong “chuyện vặt”.

Lỗi №4: Ghi log dữ liệu nhạy cảm. Không bao giờ ghi vào log mật khẩu, token, số thẻ. Dù nghĩ rằng chẳng ai thấy, cuộc đời luôn đầy bất ngờ.

Lỗi №5: Thông điệp khó hiểu. Nếu thông điệp trong log trông như “ERR42: fail”, sau một tháng chính bạn cũng không nhớ nó nghĩa là gì. Hãy viết rõ ràng và đầy đủ.

Lỗi №6: Thiếu định danh duy nhất. Trong hệ thống phức tạp, nếu không có orderId, userId và các định danh khác, bạn sẽ không thể “khâu” các sự kiện để hiểu chuyện gì đã xảy ra với người dùng hay đơn hàng cụ thể.