vi
new
+5
Avatar
Bách Nguyễn Ngọc @ngocbach99
8.4K 181 42
Đã đăng vào khoảng 16 giờ trước 78 phút đọc
41

Bạn đã thực sự hiểu về Log trong Spring Boot chưa?

Nếu ai đó hỏi bạn: 'Hệ thống Spring Boot của bạn đang dùng thư viện nào để ghi log?', bạn sẽ trả lời ra sao? SLF4J? Logback? Hay Log4j2? Nếu bạn đang cảm thấy bối rối giữa những cái tên này, thì tin tôi đi, bạn không cô đơn đâu!

Hầu hết chúng ta khi code Spring Boot đều mặc định coi Logging là một 'tính năng tự chạy'. Chúng ta hài lòng với những dòng chữ trắng đen trôi tuột trên màn hình Console của IntelliJ. Cho đến khi đẩy app lên Production và nhận ra: Ổ cứng server đang gào thét vì ghi log quá tải, còn ứng dụng thì chậm đi trông thấy ở mỗi nhịp xử lý đồng bộ.

Cấu hình Log không chỉ là đổi màu cho đẹp, nó là nghệ thuật quản lý tài nguyên và hiệu năng hệ thống. Bài viết hôm nay sẽ thay đổi hoàn toàn cách bạn nhìn nhận về System.out.println hay những dòng log.info() tưởng chừng vô hại. Chúng ta sẽ cùng đi từ số 0 đến cấu hình chuẩn chỉ cho môi trường thực tế.

I. Bức tranh tổng quan: Hệ sinh thái Logging trong Java

Trong Java, Logging không chỉ đơn thuần là ghi nhật ký, mà là "hộp đen" giúp bạn truy vết mọi sự cố trên Production. Tuy nhiên, hệ sinh thái này lại được xây dựng trên một kiến trúc phân lớp khá đặc thù để xử lý sự hỗn loạn của lịch sử phát triển.

A. Tại sao Java lại cần chia Logging thành hai lớp?

Không giống như một số ngôn ngữ khác chỉ có một thư viện log chuẩn, Java có một lịch sử phát triển dài với rất nhiều thư viện logging ra đời ở các thời điểm khác nhau (Log4j 1.x, JUL - java.util.logging, JCL - Jakarta Commons Logging, v.v.).

Để tránh việc code ứng dụng bị phụ thuộc cứng (tight-coupling) vào một thư viện cụ thể, cộng đồng Java áp dụng Facade Design Pattern.

Bạn có thể hình dung kiến trúc này qua nguyên lý hoạt động của một ổ cắm điện đa năng:

  • SLF4J (Facade) đóng vai trò là phần mặt của ổ cắm. Khi bạn viết code (ví dụ: logger.info("Hello")), bạn chỉ đang tương tác với phần mặt ổ cắm này. SLF4J không hề biết cách ghi file hay in ra màn hình.

  • Logback / Log4j2 (Implementation) đóng vai trò là dòng điện thực sự đằng sau bức tường. Đây là bộ máy nhận lệnh từ SLF4J và thực hiện việc ghi log vật lý.

B. Logback / Log4j2 (Implementation)

  • Logback: Được viết bởi chính tác giả của Log4j 1.x và SLF4J. Nó được thiết kế để trở thành bản nâng cấp hoàn hảo, tích hợp trực tiếp (native) với SLF4J mà không cần qua lớp trung gian nào. Đây là lý do Spring Boot chọn nó làm mặc định.

  • Log4j2: Một dự án tách biệt của Apache, được viết lại hoàn toàn từ đầu. Điểm ăn tiền lớn nhất của nó là kiến trúc Asynchronous (bất đồng bộ) xử lý cực tốt trong môi trường đa luồng, giúp ứng dụng không bị khựng lại khi phải ghi hàng vạn dòng log mỗi giây.

1. Cơ chế xếp hàng ghi Log (Xử lý đa luồng)

Khi có hàng ngàn người dùng truy cập cùng lúc, hàng ngàn luồng (thread) sẽ cùng lúc gọi lệnh log.info(). Việc quản lý luồng nào được ghi trước, luồng nào ghi sau quyết định tốc độ của toàn hệ thống.

  • 🪵 Logback (Dùng Khóa - Lock-based): Nền tảng của nó sử dụng ArrayBlockingQueue (một cấu trúc dữ liệu cơ bản của Java). Cấu trúc này hoạt động như một cánh cửa chỉ vừa một người đi. Khi một luồng muốn ghi log, nó phải lấy "khóa" (lock) cánh cửa lại. Các luồng khác phải xếp hàng chờ chớp nhoáng. Khi chịu tải cực cao, việc CPU phải liên tục cấp khóa và tước khóa khiến hệ thống bị nghẽn (Context Switching).

  • 🔥 Log4j2 (Không dùng Khóa - Lock-free): Đây là điểm "ăn tiền" nhất. Log4j2 tích hợp một công nghệ của ngành giao dịch chứng khoán gọi là LMAX Disruptor. Nó giống như một vòng xuyến giao thông khổng lồ (Ring Buffer) . Nhờ thuật toán đặc biệt ở cấp độ phần cứng, hàng ngàn luồng có thể "hòa vào vòng xuyến" cùng lúc mà không ai phải chờ ai, không cần bất kỳ chiếc "khóa" nào.

Nhờ LMAX Disruptor, hiệu năng Async của Log4j2 có thể nhanh gấp hàng chục lần Logback trong môi trường xử lý đa luồng (Multi-thread).

2. Cơ chế quản lý bộ nhớ (Garbage Collection - GC)

🪵 Logback: Mỗi khi in ra một dòng log, nó sẽ tạo ra các đối tượng (Object) chuỗi tạm thời. Khi log ghi xong, các chuỗi này trở thành "rác". Bộ dọn rác của Java (GC) sẽ phải chạy liên tục để dọn dẹp. Mỗi lần GC chạy, ứng dụng sẽ bị khựng lại một khoảnh khắc siêu nhỏ (Stop-the-world).

🔥 Log4j2 (Garbage-free): Từ phiên bản 2.6, Log4j2 giới thiệu cơ chế "không xả rác". Thay vì tạo object mới liên tục, nó cấp phát một vùng nhớ cố định (ThreadLocal) và tái sử dụng chúng. Hậu quả là rác sinh ra gần như bằng 0, giúp hệ thống không bị khựng lại do GC.

3. Có phải lúc nào cũng Log4j2

Như các bạn đã biết, Logback và Log4j2 cả hai đều dùng một hàng đợi (Queue) trên RAM để giải phóng luồng chính (Main Thread) khỏi việc chờ ghi dữ liệu ra ổ cứng. Tuy nhiên nhờ LMAX Disruptor, hiệu năng Async của Log4j2 có thể nhanh gấp hàng chục lần Logback trong môi trường xử lý đa luồng (Multi-thread).

Dựa vào sự khác biệt về Queue này, giả sử chúng ta đang phải thiết kế hệ thống Logging cho một sàn thương mại điện tử vào ngày siêu sale 11/11, nơi có hàng trăm luồng xử lý đồng thời liên tục ghi log giao dịch, chúng ta nên ưu tiên chọn Logback hay Log4j2?

Trong kịch bản "siêu bão traffic" của ngày sale 11/11, lựa chọn số 1 và cũng là lựa chọn duy nhất cho các hệ thống lớn chính là Log4j2. 🏆

3.1 Căn bệnh "Nút thắt cổ chai" của Logback 🪵

Dưới đây là lời giải thích chi tiết tại sao Logback sẽ "hụt hơi" còn Log4j2 lại tỏa sáng rực rỡ trong tình huống ép xung này:

Hãy tưởng tượng cái rổ ArrayBlockingQueue của Logback giống như một trạm thu phí chỉ có một làn đường duy nhất. Khi hàng trăm luồng (tương đương với hàng nghìn khách hàng đang ấn nút "Thanh toán" cùng lúc) muốn ghi log, trạm thu phí này yêu cầu một "chiếc khóa" (Lock).

  • Luồng số 1 chớp được khóa để ném log vào rổ.
  • 99 luồng còn lại phải đứng khựng lại (bị hệ điều hành ép chuyển sang trạng thái Sleep) để xếp hàng chờ.
  • Sự cọ xát, tranh giành khóa và việc CPU phải liên tục đóng/mở các luồng (Context Switching) sẽ ngốn sạch tài nguyên. Hệ thống chốt đơn của bạn sẽ bị chậm lại ngay tại chính bước... ghi nhật ký!

3.2 Phép màu LMAX Disruptor của Log4j2 🔥

Cái rổ LMAX Disruptor của Log4j2 lại giống như một vòng xuyến giao thông khổng lồ nhiều làn, nơi các xe có thể hòa vào dòng chảy cùng lúc mà không cần dừng lại nhường nhau. Nó sử dụng cấu trúc vòng tròn khép kín (Ring Buffer) và thuật toán so khớp ở cấp độ phần cứng để hoàn toàn loại bỏ chiếc khóa (Lock-free).

Hàng trăm luồng có thể "đặt chỗ" trên vòng tròn này trong cùng một phần triệu giây mà không lo dẫm chân lên nhau.

Không ai phải xếp hàng, không ai bị ép ngủ đông. CPU tập trung 100% sức mạnh cho việc xử lý thanh toán, còn dòng log cứ thế trôi tuột vào vòng xuyến một cách êm ái.

(Lưu ý: Sự chênh lệch này chỉ thực sự lộ rõ khi Server chạy đa luồng với cường độ cực cao. Với các dự án traffic bình thường, Logback vẫn xử lý quá sức mượt mà).

3.3 Log4j2 tuyệt vậy, tại sao phải lăn tăn

Mới đọc qua, bạn có thể thấy, Log4j2 sở hữu sức mạnh vô song về hiệu năng, vậy thì tại sao chúng ta không mặc định sử dụng nó luôn đi - câu trả lời ngắn gọn là: "Tuyệt đối KHÔNG". Trong thực tế, Logback vẫn là thư viện được sử dụng nhiều nhất trên thế giới hiện nay. Việc lúc nào cũng "mặc định" chọn Log4j2 có thể biến bạn thành một người thợ dùng "dao mổ trâu để giết gà".

Dưới đây là 3 lý do khiến Log4j2 không phải là "chân ái" cho mọi dự án:

1. Định luật "Đủ dùng là tốt nhất" (Overkill)

  • Khoảng 80% các ứng dụng trên thế giới (web nội bộ, tool quản lý, app startup nhỏ...) không bao giờ đạt đến mức tải hàng nghìn Request/giây. Với mức tải bình thường, sự chênh lệch hiệu năng giữa Logback và Log4j2 là một con số vô nghĩa (vài mili-giây). Việc cố gắng nhồi nhét LMAX Disruptor vào một ứng dụng nhỏ chỉ làm tốn RAM và làm phình to dung lượng file chạy.

2. Chi phí thiết lập và đi ngược lại "tiêu chuẩn"

  • Spring Boot mặc định sử dụng Logback. Để dùng Log4j2, bạn phải làm thêm các bước: mở file pom.xml, loại bỏ (exclude) gói spring-boot-starter-logging mặc định, sau đó import gói spring-boot-starter-log4j2 vào. Nghe thì có vẻ đơn giản, nhưng khi làm việc nhóm, việc đi ngược lại cấu hình mặc định (Convention over Configuration) đòi hỏi bạn phải giải trình và đồng bộ với toàn bộ team.

3. Bóng ma tâm lý mang tên "Log4Shell" 👻

Cuối năm 2021, thế giới công nghệ chấn động bởi Log4Shell (CVE-2021-44228) - lỗ hổng bảo mật tồi tệ nhất lịch sử được tìm thấy ngay bên trong Log4j2. Dù lỗ hổng này đã được vá ngay sau đó, nhưng nó để lại một "vết sẹo tâm lý" cực lớn. Rất nhiều tập đoàn tài chính, ngân hàng đã đưa Log4j2 vào "danh sách đen" hoặc yêu cầu quy trình kiểm duyệt bảo mật cực kỳ gắt gao mới cho phép sử dụng. Trong khi đó, Logback hoàn toàn bình yên vô sự qua cơn bão này.

Lỗ hổng Log4Shell (CVE-2021-44228) xảy ra do tính năng JNDI Lookup trong thư viện Log4j2 cho phép máy chủ thực thi mã từ xa. Kẻ tấn công chỉ cần gửi một chuỗi văn bản chứa lệnh ${jndi:ldap://...} vào ứng dụng. Khi chuỗi này được ghi lại vào log, Log4j2 sẽ tự động kết nối đến máy chủ của kẻ tấn công, tải về và chạy đoạn mã độc hại ngay trên máy chủ của bạn. Điều này cho phép tin tặc chiếm toàn quyền điều khiển hệ thống mà không cần mật khẩu.

Tóm lại: Hãy coi Logback là chiếc xe Honda đi làm hàng ngày (ổn định, có sẵn, dễ bảo trì), còn Log4j2 là chiếc xe đua F1 (chỉ lấy ra dùng khi phải bước vào đường đua tốc độ cao).

Tổng kết Ưu - Nhược điểm

Tiêu chí Logback 🪵 Log4j2 🔥
Ưu điểm Tích hợp sẵn (mặc định của Spring), cực kỳ ổn định, cấu hình dễ hiểu, ít lỗi vặt. Tốc độ phi mã trong môi trường đa luồng, độ trễ (latency) cực thấp, không làm quá tải bộ dọn rác (GC).
Nhược điểm Hụt hơi khi hệ thống bị ép xung (tải cực cao). Cấu hình phức tạp hơn, file thư viện nặng hơn. Từng dính lỗ hổng bảo mật lịch sử (Log4Shell) khiến nhiều người e ngại.

4. Các implemet khác

Thực tế, Logback và Log4j2 chiếm đến 95% các dự án doanh nghiệp hiện nay. Tuy nhiên, SLF4J (với vai trò là một giao diện chung) vẫn hỗ trợ kết nối với một số bộ thực thi khác cho các mục đích đặc thù:

  • JUL (java.util.logging): Đây là thư viện ghi log mặc định được tích hợp sẵn bên trong lõi của Java (từ phiên bản 1.4). Ưu điểm là không cần tải thêm bất kỳ dependency nào, nhưng nhược điểm là tính năng khá cơ bản và cấu hình kém linh hoạt.

  • SLF4J Simple (slf4j-simple): Một bộ thực thi cực kỳ tối giản. Nó ép toàn bộ log (từ mức INFO trở lên) in thẳng ra màn hình Console (System.err) và không hỗ trợ ghi file hay cắt file. Nó phù hợp cho các tool nhỏ gọn chạy bằng dòng lệnh (CLI).

  • SLF4J NOP (slf4j-nop): NOP viết tắt của "No Operation". Bộ thực thi này sẽ... âm thầm vứt bỏ toàn bộ log. Nghe có vẻ vô lý nhưng lại rất hữu ích: nếu bạn đang viết một thư viện mã nguồn mở để người khác dùng, bạn có thể dùng slf4j-nop để chặn không cho các thư viện con bên trong in log rác ra màn hình của người dùng.

C. Vấn đề "Cầu nối" (Bridges) trong dự án thực tế

Khi làm dự án Spring Boot, bạn không chỉ chạy code của mình mà còn sử dụng hàng chục thư viện bên ngoài (ví dụ: Hibernate, Zookeeper, AWS SDK). Vấn đề là:

  • Dự án của bạn dùng SLF4J + Logback.
  • Thư viện AWS SDK phiên bản cũ lại được viết cứng bằng JCL.
  • Thư viện Zookeeper lại tự ghi log bằng Log4j 1.x.
  • Hibernate lại một loại thư viện khác nữa.

Nếu để nguyên, log của hệ thống sẽ bay lung tung: một số in ra console theo format JCL, một số lại ghi ra file của Logback. Thậm chí bạn sẽ phải cấu hình file cho từng thằng một

Để thống nhất luồng chảy của log, hệ sinh thái SLF4J cung cấp các Bridges (cầu nối) như jcl-over-slf4j hay log4j-over-slf4j. Chức năng của chúng là "bắt cóc" các lời gọi log từ các thư viện cũ kia, và chuyển hướng (route) chúng chạy qua bộ SLF4J của bạn. Nhờ vậy, toàn bộ log của các thư viện bên thứ 3 cũng sẽ tuân theo cấu hình trong file logback-spring.xml của bạn.

Dựa trên nguyên lý tách biệt giữa Facade (ổ cắm) và Implementation (dòng điện) như trên, giả sử dự án của bạn đang dùng SLF4J và Logback, giờ sếp yêu cầu gỡ Logback đi và cài Log4j2 vào để hệ thống chạy nhanh hơn. Theo bạn, chúng ta có cần phải tìm và sửa lại các dòng code logger.info(...) nằm rải rác trong hàng trăm file .java của ứng dụng không?

KHÔNG. Bạn hoàn toàn không phải sửa dù chỉ một dòng code Java nào trong hàng trăm file ứng dụng cả!

Đó chính là sức mạnh lớn nhất của thiết kế Facade (SLF4J). Hãy cùng xem cách quá trình chuyển đổi này diễn ra:

  • 🔌 Tương tác qua Interface: Khi viết code, bạn luôn import các class từ SLF4J (ví dụ: import org.slf4j.Logger;). Code của bạn chỉ giao tiếp với SLF4J. Bản thân SLF4J không chứa logic ghi file hay xử lý ổ cứng, nó chỉ là một "bản hợp đồng" trung gian.

  • 🕵️ Quét Classpath: Khi ứng dụng khởi động, SLF4J sẽ tự động tìm kiếm trong project của bạn xem có thư viện Implementation nào đang có mặt (Logback hay Log4j2).

  • 🤝 Kết nối tự động (Binding): Khi tìm thấy Log4j2, SLF4J sẽ tự động thiết lập cầu nối. Từ đó, mọi lệnh logger.info() bạn gọi sẽ được SLF4J chuyển tiếp (route) thẳng xuống cho Log4j2 xử lý.

Để thực hiện việc chuyển đổi từ Logback sang Log4j2 trên thực tế, bạn chỉ cần làm 2 thao tác cấu hình:

  • Mở file pom.xml (hoặc build.gradle), loại bỏ dependency của Logback và khai báo dependency của Log4j2.

  • Xóa file cấu hình cũ logback-spring.xml và tạo file mới log4j2-spring.xml.

Việc này giống hệt như bạn tháo một bóng đèn cũ ra và lắp bóng đèn LED mới vào. Cái đui đèn (SLF4J) và công tắc trên tường (hàm logger.info()) vẫn giữ nguyên, không cần đập tường đi xây lại, nhưng công nghệ xử lý bên trong đã thay đổi hoàn toàn.

II. Các thành phần cốt lõi của một Framework Logging

Chúng ta cùng mổ xẻ "bộ ba quyền lực" cấu thành nên hệ thống bên dưới của bất kỳ thư viện logging nào (dù là Logback hay Log4j2). Để dễ hình dung, hãy tưởng tượng luồng xử lý log giống như quy trình làm việc của một tòa soạn báo:

  • 📝 Logger (Phóng viên): Đây là thành phần mà code của bạn trực tiếp tương tác (ví dụ: logger.info("User login")). Mỗi Logger thường được gắn với một Class cụ thể và có một "mức độ nhạy cảm" (Log Level) riêng. Nhiệm vụ của Logger là tiếp nhận thông điệp từ ứng dụng và đánh giá xem thông điệp đó có đủ điều kiện/độ quan trọng để được đi tiếp hay không.

  • 🎨 Layout / Encoder (Biên tập viên): Khi Logger cho phép thông điệp đi qua, Layout sẽ tiếp nhận và định dạng nó. Giống như biên tập viên thêm ngày giờ xuất bản, tên tác giả, định dạng in đậm in nghiêng vào bài báo. Layout biến dữ liệu thô thành một chuỗi văn bản theo format quy định (ví dụ: [Thời gian] [Thread] [Level] - Thông báo) hoặc đóng gói thành định dạng JSON.

  • 🚀 Appender (Kênh phát hành): Đây là điểm đến vật lý cuối cùng. Appender nhận bản tin đã được định dạng từ Layout và xuất nó ra ngoài. Có rất nhiều loại Appender: in ra màn hình máy tính (ConsoleAppender), lưu thành file trên ổ cứng (RollingFileAppender), hoặc bắn thẳng qua mạng tới máy chủ phân tích (SocketAppender, KafkaAppender). Một Logger có thể gửi dữ liệu cho nhiều Appender cùng lúc.

Sự tách biệt của ba thành phần này mang lại tính linh hoạt tuyệt đối. Bạn có thể thay đổi cách định dạng log (Layout) hoặc đổi nơi lưu trữ log (Appender) hoàn toàn thông qua file cấu hình XML/YAML mà không phải sửa lại code gọi Logger bên trong ứng dụng.

III. Các Cấp Độ Log (Log Levels) 🚦

A. Mức độ nghiêm trọng

Mỗi sự kiện log cần được gắn một mức độ nghiêm trọng. Hệ thống sẽ dựa vào cấu hình để quyết định xem có in mức độ đó ra hay không:

  • TRACE: Rất chi tiết, ghi lại mọi bước đi nhỏ nhất của chương trình. Thường chỉ bật khi cần theo dõi một luồng quá phức tạp.

  • DEBUG: Thông tin hữu ích cho quá trình phát triển (ví dụ: in ra payload của một request hoặc giá trị của biến). Thường bị tắt trên môi trường Production để tiết kiệm tài nguyên.

  • INFO: Các sự kiện quan trọng cho thấy hệ thống đang hoạt động bình thường (ví dụ: "User A đã đăng nhập", "Khởi động server thành công").

  • WARN: Cảnh báo về một tình huống bất thường (ví dụ: "API bên thứ 3 phản hồi chậm", "Sắp hết dung lượng đĩa") nhưng ứng dụng vẫn có thể tiếp tục chạy.

  • ERROR: Lỗi nghiêm trọng khiến một chức năng thất bại (ví dụ: "Không thể kết nối Database", NullPointerException). Cần đi kèm với Stacktrace để dễ trace lỗi.

Để xem chúng ta đã nắm rõ luồng chảy của dữ liệu qua 3 thành phần kết hợp với log level ở trên chưa nhé

Giả sử hệ thống đang cấu hình một Logger chỉ chấp nhận mức INFO trở lên, và nó được kết nối với một Appender ghi ra file ổ cứng. Nếu trong code, bạn thực thi lệnh logger.debug("Chi tiết biến X");, theo bạn thông điệp này sẽ bị chặn lại và hủy bỏ ở bộ phận nào trong 3 bộ phận mà ta đã tìm hiểu ở phần II?

Câu trả lời là thông điệp sẽ bị chặn lại và hủy bỏ ngay tại Logger (Phóng viên). 🛑

Vì Logger là chốt chặn đầu tiên (gatekeeper). Thứ tự các cấp độ log (Log Levels) từ thấp đến cao thường là: TRACE < DEBUG < INFO < WARN < ERROR.

Khi Logger được cấu hình ở mức INFO, nó chỉ cho phép các thông điệp từ mức INFO trở lên (INFO, WARN, ERROR) đi qua. Lệnh gọi logger.debug(...) ở cấp độ thấp hơn, nên Logger sẽ lập tức từ chối. Thông điệp này sẽ không bao giờ đến được tay Layout (để định dạng) hay Appender (để ghi ra file).

Việc chặn từ sớm này có ý nghĩa sống còn đối với hiệu năng. Hệ thống sẽ không lãng phí tài nguyên CPU hay bộ nhớ để định dạng và ghi những dòng log không cần thiết.

Tuy nhiên, nói về hiệu năng, có một cạm bẫy rất phổ biến khi gọi Logger mà chúng ta cần tránh. Giả sử hệ thống vẫn đang ở mức INFO, và bạn viết dòng code sau trong Java:

logger.debug("Thông tin chi tiết của giỏ hàng: " + cart.getDetails());

Dù biết chắc chắn dòng log này sẽ bị chặn ở Logger, nhưng theo bạn, Java có phải tốn tài nguyên để chạy hàm cart.getDetails() và thực hiện phép cộng chuỗi + trước khi truyền kết quả vào hàm debug() không?

Câu trả lời là: CÓ! Java sẽ tiêu tốn toàn bộ tài nguyên cho việc đó, và đây là một trong những nguyên nhân gây sụt giảm hiệu năng "âm thầm" nhưng cực kỳ tàn khốc trong các hệ thống lớn.

B. Giải phẫu cạm bẫy "Cộng chuỗi" (String Concatenation)

Chúng ta cùng "mổ xẻ" cơ chế hoạt động của Java để hiểu tại sao cạm bẫy này lại xảy ra và cách các framework logging hiện đại giải quyết nó nhé.

  • Bước 1: Kích hoạt hàm cart.getDetails(). Nếu hàm này phải chui xuống Database để lấy lịch sử mua hàng, hệ thống sẽ mất thời gian chờ DB.

  • Bước 2: Thực hiện phép cộng chuỗi. Java sẽ tạo ra các object StringBuilder tạm thời trong bộ nhớ RAM để nối chữ "Thông tin chi tiết..." với kết quả của Bước 1, tạo ra một chuỗi (String) hoàn chỉnh.

  • Bước 3: Gọi hàm logger.debug(chuoi_hoan_chinh).

  • Bước 4: Bên trong hàm debug(), Logger kiểm tra cấu hình. Nó thấy cấu hình hiện tại là INFO, lớn hơn DEBUG. Nó lẩm bẩm: "À, không cần ghi log này". Sau đó nó ném cái chuoi_hoan_chinh đi và kết thúc.

☢️Hậu quả: Hệ thống vừa mất CPU để xử lý logic lấy chi tiết giỏ hàng, vừa rác bộ nhớ RAM để cộng chuỗi. Khi có hàng nghìn request mỗi giây, bộ dọn rác (Garbage Collector - GC) của Java sẽ phải chạy liên tục để dọn dẹp hàng nghìn cái chuỗi "vô dụng" này, dẫn đến hiện tượng giật lag hệ thống (GC Pause).

C. Ba giải pháp "Cứu rỗi" hiệu năng

Để khắc phục vấn đề ở trên, các lập trình viên Enterprise sử dụng 3 cấp độ tối ưu sau:

Cấp độ 1: Parameterized Logging (Dùng dấu ngoặc nhọn {})

Đây là tính năng "ăn tiền" nhất của SLF4J. Thay vì cộng chuỗi, bạn truyền dữ liệu dưới dạng tham số (arguments).

Code chuẩn:

logger.debug("User id {} vừa đăng nhập từ IP {}", userId, ipAddress);

Tại sao nó nhanh? Lúc này, bạn truyền vào hàm debug() 3 tham số riêng biệt: một chuỗi mẫu (template string) và 2 biến. Bên trong hàm debug(), nó sẽ kiểm tra Log Level trước. Vì cấu hình đang là INFO, nó thấy không cần in log nên kết thúc luôn. Hoàn toàn không có phép cộng chuỗi nào diễn ra, tiết kiệm đáng kể CPU và RAM.

Cấp độ 2: Bao bọc bằng lệnh if (Dùng cho các hàm tính toán nặng)

Tuy nhiên, dấu {} không cứu được bạn nếu tham số truyền vào là một hàm tốn kém (như cart.getDetails()). Dù dùng {} thì Java vẫn phải chạy hàm đó để lấy giá trị truyền vào. Lúc này, ta phải quay về phương pháp cổ điển:

if (logger.isDebugEnabled()) {
    logger.debug("Thông tin chi tiết của giỏ hàng: {}", cart.getDetails());
}

Mặc dù nhìn hơi rườm rà, nhưng lệnh if đảm bảo rằng nếu Log Level không phải là DEBUG, toàn bộ khối code bên trong (bao gồm cả hàm tốn kém kia) sẽ bị bỏ qua hoàn toàn.

Cấp độ 3: Sử dụng Lambda Expression (Kỹ thuật hiện đại)

Từ Java 8 và Log4j2 (hoặc các phiên bản mới của thư viện khác), chúng ta có thể dùng Lambda (Supplier) để viết code vừa gọn vừa tối ưu:

// Log4j2 hỗ trợ truyền vào một Lambda Expression
logger.debug("Thông tin chi tiết của giỏ hàng: {}", () -> cart.getDetails());

Lúc này, bạn không truyền kết quả của hàm, mà bạn truyền chính cái hàm đó (một object chứa logic) vào. Logger sẽ kiểm tra Level trước. Chỉ khi nào Level đúng là DEBUG, nó mới thực thi (execute) cái khối Lambda đó để lấy chuỗi. Cực kỳ gọn gàng và hiệu suất cao!

IV. Thực hành cấu hình Logback/Log4j2

Chúng ta hãy cùng nhau tìm hiểu cách cấu hình Logback và SLF4J trong Spring Boot. Trong quá trình này, mình sẽ đưa ra các câu hỏi hướng dẫn từng bước để giúp bạn nắm bắt vấn đề một cách rõ ràng nhất nhé.

Như các bạn đã biết ở trên, Spring Boot mặc định đã tích hợp sẵn SLF4J làm giao diện chung (facade) và Logback làm thư viện ghi log thực tế (implementation). Do đó, nếu bạn đang sử dụng spring-boot-starter, hệ thống đã sẵn sàng để ghi log mà không cần thêm thư viện nào khác. Việc cấu hình có thể từ mức độ rất đơn giản đến việc quản lý file log phức tạp cho các hệ thống lớn.

A. Cấu hình cơ bản qua application.properties (hoặc .yml)

Mặc định, Spring Boot (sử dụng Logback) sẽ tự động in log ra Console (màn hình terminal) ở mức INFO.

Các mức log (Log Levels) phổ biến theo thứ tự từ chi tiết nhất đến ít chi tiết nhất thì mình cũng đã nhắc đến ở trên rồi:

TRACE > DEBUG > INFO > WARN > ERROR

Nếu bạn đặt mức log là INFO, hệ thống sẽ in ra các log ở mức INFO, WARN, và ERROR (bỏ qua TRACE và DEBUG).

Bạn có thể dễ dàng thay đổi điều này ngay trong file application.properties:

# Đổi mức log của toàn bộ ứng dụng (root) thành WARN
logging.level.root=WARN

# Đổi mức log riêng cho một package cụ thể của bạn thành DEBUG
logging.level.com.vidu.ungdung=DEBUG

Lưu log ra file: Thay vì chỉ nhìn trên màn hình bị trôi đi mất, bạn có thể lưu lại log vào file bằng cách thêm:

# Chỉ định tên và đường dẫn file log
logging.file.name=logs/ungdung-cua-toi.log

(Chỉ cần cấu hình dòng này, Spring Boot sẽ tự động ghi log vào file đó).

Trước khi chúng ta chuyển sang cấu hình bằng file XML nâng cao (để tự động cắt file log theo ngày), hãy cùng thực hành một chút nhé:

Giả sử ứng dụng của bạn đang bị lỗi ở phần xử lý thanh toán thuộc package com.cuahang.thanhtoan. Bạn muốn hệ thống in ra chi tiết nhất có thể (mức DEBUG) cho riêng package này, nhưng lại muốn toàn bộ các thư viện khác của hệ thống chỉ in ra ở mức ERROR cho đỡ rác màn hình.

Bạn sẽ viết cấu hình đó vào file application.properties như thế nào?

# Đặt mức log mặc định cho toàn bộ hệ thống là ERROR
logging.level.root=ERROR

# Ghi đè mức log riêng cho package cần debug
logging.level.com.cuahang.thanhtoan=DEBUG

Cách làm này cực kỳ hữu hiệu trên thực tế khi bạn muốn tập trung "săn bug" ở một module cụ thể mà không bị xao nhãng bởi hàng ngàn dòng log rác từ các thư viện khác.

B. Cấu hình nâng cao bằng logback-spring.xml

File application.properties rất tiện lợi, nhưng nó có giới hạn. Nếu bạn muốn hệ thống lưu log một cách thông minh hơn—chẳng hạn như chia nhỏ các file log ra để không làm đầy ổ cứng—chúng ta cần tạo một file tên là logback-spring.xml và đặt nó vào thư mục src/main/resources.

Spring Boot khi khởi động sẽ tự động tìm thấy file này và sử dụng các cấu hình bên trong thay vì dùng cấu hình mặc định.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOG_DIR" value="./logs/core-service" />
    <property name="CONSOLE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} %magenta([%thread]) %highlight(%-5level) %cyan(%logger{36}) - %msg%n" />
    <property name="FILE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n" />

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_PATTERN}</pattern>
        </encoder>
    </appender>

    <appender name="MAIN_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_DIR}/application.log</file>
        <encoder>
            <pattern>${FILE_PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_DIR}/archived/app-%d{yyyy-MM-dd}-%i.log.gz</fileNamePattern>
            <maxFileSize>50MB</maxFileSize>
            <maxHistory>15</maxHistory>
            <totalSizeCap>2GB</totalSizeCap>
        </rollingPolicy>
    </appender>

    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_DIR}/error.log</file>
        
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        
        <encoder>
            <pattern>${FILE_PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_DIR}/archived/error-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>

    <appender name="ASYNC_MAIN" class="ch.qos.logback.classic.AsyncAppender">
        <queueSize>1024</queueSize>
        <discardingThreshold>0</discardingThreshold>
        <appender-ref ref="MAIN_FILE" />
    </appender>

    <springProfile name="dev | local">
        <root level="INFO">
            <appender-ref ref="STDOUT" />
        </root>
        <logger name="org.hibernate.SQL" level="DEBUG" />
    </springProfile>

    <springProfile name="prod | staging">
        <root level="INFO">
            <appender-ref ref="ASYNC_MAIN" />
            <appender-ref ref="ERROR_FILE" /> </root>
        <logger name="org.apache.kafka" level="WARN" />
        <logger name="com.zaxxer.hikari" level="WARN" />
    </springProfile>
</configuration>

Đây là file cấu hình khá tiêu chuẩn và đầy đủ cho một dự án thực tế. Phần tiếp theo chúng ta hãy cùng đi vào phân tích cách cấu hình từng thành phần nhé.

1. Thiết lập Pattern (định dạng log)

Việc thiết lập Pattern (định dạng log) giống như bạn đang thiết kế một "bảng biểu mẫu" chuẩn chỉnh cho anh Nhân viên ghi sổ. Nếu không có quy tắc, anh ta sẽ ghi chép lộn xộn, lúc thì quên ghi ngày tháng, lúc thì quên ghi tên Đầu bếp.

Trong Logback, chúng ta sử dụng các Ký tự đại diện (Conversion Word) bắt đầu bằng dấu % để chỉ định thông tin cần in ra.

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

hoặc

<property name="CONSOLE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} %magenta([%thread]) %highlight(%-5level) %cyan(%logger{36}) - %msg%n" />

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
          <pattern>${CONSOLE_PATTERN}</pattern>
     </encoder>
</appender>
Ký tự đại diện Ý nghĩa & Giải thích Ví dụ kết quả thực tế
%d{...} Thời gian (Date): Bạn có thể tùy chỉnh định dạng bên trong ngoặc nhọn. Phổ biến nhất là yyyy-MM-dd HH:mm:ss.SSS (thêm số mili-giây để truy vết siêu chuẩn). 2023-11-20 15:30:45.123
%thread Luồng xử lý: Vô cùng quan trọng trong môi trường web (nhiều người dùng cùng lúc). Nhìn vào đây bạn biết dòng log này thuộc về Request của khách hàng nào. [http-nio-8080-exec-1]
%-5level Mức độ (Level): In ra chữ INFO, DEBUG, ERROR... (Sẽ giải thích con số -5 ở phần câu hỏi). INFO hoặc ERROR
%logger{length} Tên Class (Logger): Nơi phát ra dòng log. Số đằng sau giúp thu gọn tên package nếu nó quá dài (VD: org.springframework... thành o.s...). --------
%msg hoặc %m Nội dung (Message): Chính là đoạn text mà bạn viết trong ngoặc log.info("..."). Đã tạo đơn hàng thành công
%n Xuống dòng (New line): Bắt buộc phải có ở cuối mỗi pattern, nếu không các dòng log sẽ dính liền vào nhau thành 1 hàng ngang. (xuống dòng)

Bạn có để ý, tại sao người ta lại dùng %-5level (có thêm dấu trừ và số 5) thay vì chỉ dùng %level cho đơn giản? Việc thêm số -5 này mang lại lợi ích gì về mặt "thị giác" khi bạn phải đọc một file log chứa hàng ngàn dòng?

Bí mật của con số -5 nằm ở tính năng căn lề trái và cố định độ rộng.

  • Các mức độ log vốn có độ dài ký tự khác nhau: INFO (4), WARN (4), DEBUG (5), ERROR (5). Nếu bạn chỉ dùng %level, phần nội dung văn bản phía sau sẽ bị xô lệch, thò ra thụt vào.

  • Khi bạn thêm -5 (dấu trừ đại diện cho lề trái, số 5 là độ rộng bắt buộc), hệ thống sẽ tự động bù thêm khoảng trắng vào những từ ngắn hơn 5 ký tự.

3. Tô màu cho Log ở Console

Màn hình Console một màu sẽ rất "đau mắt" khi bạn tìm bug. Spring Boot cung cấp sẵn một công cụ tô màu trong Logback thông qua cú pháp %clr(). Bạn có thể bọc các biến trong pattern lại để chỉ định màu sắc mong muốn:

<property name="COLOR_PATTERN" value="%clr(%d{yyyy-MM-dd HH:mm:ss}){faint} %clr(%-5level) %clr(%logger{36}){cyan} - %msg%n" />

Dựa vào ví dụ trên bạn sẽ thấy cú pháp để tô màu trong Spring Boot Logback là bọc nội dung cần tô màu vào %clr(...) và chỉ định màu ở phía sau {...}. Ví dụ: %clr(%logger{36}){cyan} sẽ in ra tên class với màu xanh lơ (cyan).

Dựa vào quy luật đó, nếu bây giờ bạn muốn phần thời gian %d{yyyy-MM-dd HH:mm:ss} hiển thị bằng màu vàng (yellow) thay vì màu mặc định, bạn sẽ viết lại đoạn mã đó như thế nào?

Cú pháp chính xác sẽ là: %clr(%d{yyyy-MM-dd HH:mm:ss}){yellow}.

Lưu ý: Màu sắc chỉ có tác dụng khi in ra màn hình Console. Khi ghi ra file, bạn nên dùng một pattern bình thường (không có %clr()) vì các trình đọc file text sẽ hiển thị mã màu thành các ký tự rác. Còn nếu bạn vẫn muốn in ra console có màu, còn in ra log thì in bình thường không chứa các kí tự rác thì chúng ra hoàn toàn có thể định nghĩa hai property pattern riêng biệt trong file cấu hình: một cho Console (có màu) và một cho File (không màu).

<property name="CONSOLE_LOG_PATTERN" value="%clr(%d{yyyy-MM-dd HH:mm:ss}){yellow} %clr(%-5level) %clr(%logger{36}){cyan} - %msg%n" />

<property name="FILE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n" />

Sau đó, bạn chỉ cần gắn CONSOLE_LOG_PATTERN vào appender CONSOLE, và FILE_LOG_PATTERN vào appender FILE là xong.

4. Cấu hình cách File Log được in ra

Một trong những kịch bản phổ biến nhất khi dùng file XML này là thiết lập cơ chế Rolling (tự động cắt file log). Ví dụ, cứ qua ngày mới, hệ thống sẽ tự động tạo ra một file log mới (như app-2023-10-25.log, app-2023-10-26.log).

Theo bạn, ngoài việc tự động tạo file mới dựa trên thời gian (ngày/tháng), chúng ta còn có thể thiết lập cắt file log dựa trên tiêu chí vật lý nào khác của file để đảm bảo server không bao giờ bị "sập" vì hết dung lượng không?

Đáp án chính xác chính là kích thước file (file size).

Bên cạnh việc cắt file theo ngày, chúng ta cần giới hạn dung lượng tối đa của mỗi file log (ví dụ: 10MB). Nếu trong một ngày, file log phình to vượt quá 10MB, hệ thống sẽ tự động đóng file đó lại, đánh số thứ tự mới và ghi tiếp vào một file khác. Điều này giúp ổ cứng không bị "ngốn" trọn bởi một file text khổng lồ và cũng giúp bạn mở file ra xem dễ dàng hơn (mở một file text vài GB thường sẽ làm treo máy).

Dưới đây là cách cấu hình chi tiết trong file src/main/resources/logback-spring.xml để kết hợp cả hai yếu tố: Thời gian và Dung lượng.

Cấu hình RollingFileAppender trong logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n" />

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/ungdung.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>logs/ungdung-%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            
            <maxFileSize>10MB</maxFileSize>
            
            <maxHistory>30</maxHistory>
            
            <totalSizeCap>1GB</totalSizeCap>
        </rollingPolicy>

        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="FILE" />
    </root>

</configuration>

Giải thích các thông số quan trọng:

  • <fileNamePattern>: Đuôi .gz báo cho Logback biết: "Khi nào cắt file, hãy nén ZIP file cũ lại luôn để tiết kiệm ổ cứng".

  • <maxFileSize>10MB</maxFileSize>: Ngay khi ungdung.log đạt 10MB, nó sẽ bị đổi tên thành ungdung-2023-10-25.0.log. File tiếp theo trong ngày sẽ là .1.log.

  • <maxHistory>30</maxHistory>: Sang ngày thứ 31, hệ thống sẽ tự động xóa các file log của ngày đầu tiên để giải phóng dung lượng.

  • <totalSizeCap>1GB</totalSizeCap>: Đây là chốt chặn an toàn cuối cùng. Nếu đợt tấn công DDOS khiến log sinh ra quá nhiều, tổng thư mục đạt 1GB thì nó sẽ xóa dần các file cũ nhất dù chưa đến 30 ngày.

5. Cấu hình mức độ ghi log (Log Level)

Trong Logback, chúng ta quản lý cấp độ log bằng hai thẻ chính:

  • Thẻ <root>: Quy định mức log mặc định cho toàn bộ hệ thống 🪵.

  • Thẻ <logger>: Quy định mức log riêng cho một package hoặc class cụ thể 📂. Thẻ này sẽ ghi đè lên cấu hình của <root>.

<root level="INFO">
    <appender-ref ref="CONSOLE" />
</root>

<logger name="org.springframework" level="ERROR" />

<logger name="com.cuahang" level="DEBUG" />

Sau khi thử nghiệm với trình mô phỏng, bạn hãy thử trả lời: Nếu cấu hình Root ở mức INFO và cấu hình Package com.cuahang ở mức WARN, thì một dòng code log.debug("Đang kết nối database..."); nằm trong package com.cuahang có được in ra màn hình không? Vì sao?

Câu trả lời là Không. Dòng log đó sẽ không được in ra màn hình. 🚫

  • Sự ghi đè (Override): Mặc dù hệ thống chung (<root>) đang được đặt ở mức INFO, nhưng cấu hình riêng của package com.cuahang đã được thiết lập là WARN. Cấu hình riêng này sẽ ghi đè lên cấu hình chung. 📂

  • Dựa vào thứ tự ưu tiên, khi bộ lọc hoạt động: Dòng code của bạn gọi lệnh log.debug(...), tức là ở mức DEBUG. Bởi vì DEBUG nằm ở mức thấp hơn WARN, Logback sẽ tự động lọc bỏ và không in dòng này ra.

Cơ chế này rất quan trọng trên môi trường thực tế để đảm bảo hệ thống chỉ giữ lại những cảnh báo (WARN) hoặc lỗi (ERROR) cần thiết của một module cụ thể mà không bị nhiễu bởi các log gỡ lỗi.

6. Phân tách cấu hình theo môi trường (Spring Profiles)

Trong file logback-spring.xml, Spring Boot cung cấp một thẻ đặc biệt mang tên <springProfile>. Thẻ này cho phép bạn "bật" hoặc "tắt" các cấu hình ghi log tùy thuộc vào môi trường ứng dụng đang chạy.

(Nếu bạn không sử dụng thẻ <springProfile>, thì mọi thiết lập trong file logback-spring.xml sẽ trở thành cấu hình chung cho toàn bộ các môi trường.)

Ví dụ, ở môi trường phát triển (profile tên là dev), chúng ta chỉ muốn in log ra màn hình CONSOLE để dễ debug. Cấu hình sẽ trông như thế này:

<springProfile name="dev">
    <root level="INFO">
        <appender-ref ref="CONSOLE" />
    </root>
</springProfile>

Dựa vào ví dụ trên, nếu bạn đang cấu hình cho môi trường Production (môi trường thực tế chạy trên server, tên profile là prod), và bạn chỉ muốn hệ thống lưu log ra file thông qua appender ASYNC_FILE (để tối ưu hiệu suất) chứ không in ra màn hình CONSOLE nữa, bạn sẽ viết đoạn thẻ <springProfile> đó như thế nào?

Đoạn mã cấu hình chi tiết sẽ trông như thế này:

<springProfile name="prod">
    <root level="INFO">
        <appender-ref ref="ASYNC_FILE" />
    </root>
</springProfile>

Cách hoạt động: Khi ứng dụng Spring Boot khởi động và nhận diện đang ở môi trường prod, nó sẽ áp dụng cấu hình này. Bất cứ khi nào có lệnh in log (ví dụ: log.info("Khách hàng thanh toán")), dòng log đó sẽ không hiện lên màn hình server nữa mà đi thẳng vào hàng đợi RAM (queue) của ASYNC_FILE, sau đó được luồng chạy ngầm ghi an toàn ra file ổ cứng. Điều này giúp tối đa hóa hiệu năng (performance) 🚀 cho hệ thống thực tế.

Bây giờ chúng ta đã có file logback-spring.xml hoàn chỉnh với các cấu hình linh hoạt cho từng môi trường. Tuy nhiên, còn một mảnh ghép cuối cùng để hệ thống hoạt động trơn tru.

Khi bạn mang file .jar của ứng dụng lên chạy trên Server, theo bạn, chúng ta cần thêm câu lệnh hay tham số nào lúc khởi động để "báo" cho Spring Boot biết rằng ứng dụng cần kích hoạt profile prod?

Để kích hoạt profile prod khi chạy file .jar trên máy chủ, chúng ta có hai cách phổ biến sau:

Tham số dòng lệnh (Command-line argument): Bạn thêm tham số ở ngay cuối câu lệnh chạy file

java -jar ungdung.jar --spring.profiles.active=prod`

Thừa số hệ thống JVM (JVM System Property): Bạn thêm tham số ngay sau lệnh java và trước -jar:

java -Dspring.profiles.active=prod -jar ungdung.jar

Khi nhận được một trong hai lệnh trên, Spring Boot sẽ hiểu là ứng dụng cần chạy ở môi trường Production 🌐. Lúc này, khối mã <springProfile name="prod"> mà chúng ta cấu hình trong file logback-spring.xml sẽ được kích hoạt:

  • 🖥️ Màn hình Console sẽ không còn in log nữa để tiết kiệm tài nguyên cho CPU.
  • 📂 Hệ thống bật tính năng ghi log bất đồng bộ (ASYNC_FILE) để lưu log an toàn vào ổ cứng với tốc độ nhanh nhất.

C. Cấu hình chuyển đổi (switch) từ Logback sang Log4j2

Ở trên mình cũng có đề cập đến cách chuyển đổi giữa 2 thư viện này rồi, ở phần này chúng ta cùng đi vào thực hành nhé

Trong Spring Boot, công cụ quản lý thư viện (Maven hoặc Gradle) mặc định luôn tự động tải Logback (gói spring-boot-starter-logging) về thông qua gói spring-boot-starter (hoặc spring-boot-starter-web).

Để "dọn đường" cho Log4j2, thao tác bắt buộc là chúng ta phải loại bỏ (exclude) thư viện ghi log mặc định của Spring Boot ra khỏi dự án.

Dưới đây là cách khai báo trong file pom.xml (Maven) để thực hiện việc chuyển đổi này một cách mượt mà:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

Sau khi dọn dẹp file pom.xml xong, bước tiếp theo bạn chỉ cần tạo một file tên là log4j2-spring.xml (thay vì logback) với các cấu hình cắt file, chia môi trường tương tự là hệ thống siêu tốc Log4j2 sẽ chính thức tiếp quản dự án của bạn.

Sau khi tạo file log mới, bước tiếp theo sẽ là cấu hình, tư duy cấu hình sẽ hoàn toàn tương tự Logback (cũng quản lý theo Appender, cắt file, giới hạn dung lượng, Root, Profile). Tuy nhiên, cú pháp thẻ XML sẽ khác đi. File cấu hình chuẩn trông sẽ thế này:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">

    <Properties>
        <Property name="LOG_DIR">./logs/core-service</Property>
        <Property name="CONSOLE_PATTERN">%d{yyyy-MM-dd HH:mm:ss} %style{[%thread]}{magenta} %highlight{%-5level} %style{%logger{36}}{cyan} - %msg%n</Property>
        <Property name="FILE_PATTERN">%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Property>
    </Properties>

    <Appenders>
        
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout pattern="${CONSOLE_PATTERN}" />
        </Console>

        <RollingFile name="MAIN_FILE" fileName="${LOG_DIR}/application.log" 
                     filePattern="${LOG_DIR}/archived/app-%d{yyyy-MM-dd}-%i.log.gz">
            <PatternLayout pattern="${FILE_PATTERN}" />
            <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="50 MB" />
            </Policies>
            <DefaultRolloverStrategy>
                <Delete basePath="${LOG_DIR}/archived" maxDepth="1">
                    <IfFileName glob="app-*.log.gz" />
                    <IfAny>
                        <IfLastModified age="15d" />
                        <IfAccumulatedFileSize exceeds="2 GB" />
                    </IfAny>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <RollingFile name="ERROR_FILE" fileName="${LOG_DIR}/error.log" 
                     filePattern="${LOG_DIR}/archived/error-%d{yyyy-MM-dd}.log.gz">
            <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY" />
            <PatternLayout pattern="${FILE_PATTERN}" />
            <Policies>
                <TimeBasedTriggeringPolicy />
            </Policies>
            <DefaultRolloverStrategy>
                <Delete basePath="${LOG_DIR}/archived" maxDepth="1">
                    <IfFileName glob="error-*.log.gz" />
                    <IfLastModified age="30d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <Async name="ASYNC_MAIN" bufferSize="1024">
            <AppenderRef ref="MAIN_FILE" />
        </Async>

    </Appenders>

    <Loggers>
        
        <SpringProfile name="dev | local">
            <Root level="INFO">
                <AppenderRef ref="STDOUT" />
            </Root>
            <Logger name="org.hibernate.SQL" level="DEBUG" />
        </SpringProfile>

        <SpringProfile name="prod | staging">
            <Root level="INFO">
                <AppenderRef ref="ASYNC_MAIN" />
                <AppenderRef ref="ERROR_FILE" />
            </Root>
            <Logger name="org.apache.kafka" level="WARN" />
            <Logger name="com.zaxxer.hikari" level="WARN" />
        </SpringProfile>

    </Loggers>

</Configuration>

V. Các kỹ thuật Logging nâng cao cho Backend Developer

Khi ứng dụng của bạn bước vào môi trường Production thực tế, logging không chỉ dừng lại ở việc in thông tin ra màn hình. Chính vì thế, những kỹ thuật dưới đây sẽ đóng vai trò là 'trợ thủ đắc lực', giúp hệ thống của bạn vận hành trơn tru ngay cả dưới áp lực tải cao và giúp đội ngũ vận hành bóc tách sự cố một cách nhanh chóng

A. Asynchronous Logging (Ghi log bất đồng bộ)

Để hiểu tại sao ghi log cũng cần "bất đồng bộ", trước tiên hãy cùng phân tích cơ chế hoạt động mặc định của hầu hết các framework logging hiện nay. Việc nắm rõ căn nguyên của các nút thắt cổ chai trong kiến trúc đồng bộ là bước đầu tiên để bạn tối ưu hóa hiệu năng cho hệ thống.

1. Nỗi đau của hệ thống Đồng bộ (Synchronous)

Mặc định, lệnh ghi log (như log.info(...)) hoạt động theo cơ chế Đồng bộ.

  1. Xử lý nghiệp vụ (Main Thread): Ứng dụng (luồng chính) nhận Request từ người dùng, thực hiện tính toán logic code và tạo ra một dòng log cần ghi lại.

  2. Khựng lại để ghi file (Blocking): Ngay lập tức, luồng chính bắt buộc phải tạm dừng mọi công việc đang làm để trực tiếp đem dòng log đó ghi xuống ổ cứng vật lý.

  3. Chờ đợi lãng phí: Tốc độ đọc/ghi vật lý của ổ cứng cực kỳ chậm so với tốc độ xử lý siêu tốc của CPU. Trong suốt khoảng thời gian ổ cứng lạch cạch ghi file, luồng chính bị "kẹt" cứng hoàn toàn, khiến các Request tiếp theo của người dùng phải xếp hàng đứng chờ.

👉 Hậu quả: Hệ thống phản hồi chậm chạp, tài nguyên CPU bị lãng phí do phải đứng chờ ổ cứng, rất dễ dẫn đến nghẽn cổ chai (bottleneck) khi lượng truy cập tăng cao.

2. Sự giải thoát mang tên Bất đồng bộ (Asynchronous)

Nói một cách ngắn gọn nhất: Đây là cơ chế "ủy quyền" việc ghi log cho một luồng khác để ứng dụng rảnh tay xử lý công việc chính.

Thay vì bắt ứng dụng phải khựng lại, đứng đợi ổ cứng vật lý ghi xong một dòng log rồi mới được chạy tiếp code (gọi là Đồng bộ - Synchronous), Async Logging hoạt động theo 3 bước siêu tốc:

  1. Ném vào giỏ (Queue): Ứng dụng (luồng chính) tạo ra câu log và ném ngay nó vào một cái "giỏ" (Hàng đợi lưu trên bộ nhớ RAM).

  2. Chạy tiếp lập tức: Ném xong, luồng chính lập tức đi xử lý Request tiếp theo của người dùng mà không cần chờ đợi.

  3. Người dọn dẹp (Worker Thread): Ở phía sau, có một luồng phụ chạy ngầm sẽ thong thả nhặt từng câu log trong "giỏ" ra và ghi từ từ xuống ổ cứng.

3. Cấu hình Async cho Log

Trong logback-spring.xml, Async không phải là một đích đến độc lập (như Console hay File). Nó đóng vai trò là một Appender bọc ngoài (Wrapper). Bạn vẫn cấu hình ghi file bình thường, sau đó dùng AsyncAppender bọc nó lại.

<appender name="FILE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>logs/app.log</file>
    </appender>

<appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>512</queueSize>
    
    <discardingThreshold>0</discardingThreshold>
    
    <appender-ref ref="FILE_APPENDER" />
</appender>

  • queueSize: Dung lượng của "cái rổ" trên RAM. Số lượng càng lớn, ứng dụng càng mượt vì luồng chính ít khi bị chặn, nhưng lại ngốn nhiều RAM hơn. (Mặc định thường là 256).

  • discardingThreshold: Tính năng tự động vứt bỏ log khi rổ gần đầy. Mặc định của Logback là 20 (tức là khi rổ đầy 80%, nó sẽ bắt đầu âm thầm vứt các log ở mức TRACE, DEBUG, INFO và chỉ giữ lại ERROR). Đặt là 0 nếu bạn muốn giữ lại mọi dấu vết.

  • appender-ref: Liên kết "cái rổ" này với file vật lý cụ thể.

Log4j2 có cú pháp gọn gàng hơn và cung cấp thẻ <Async> chuyên dụng. Tương tự như Logback, nó cũng bọc lấy Appender đích.

<Appenders>
    <RollingFile name="FILE_APPENDER" fileName="logs/app.log" filePattern="...">
        <PatternLayout pattern="%d %-5level %logger - %msg%n" />
        </RollingFile>

    <Async name="ASYNC_FILE" bufferSize="1024" blocking="true">
        <AppenderRef ref="FILE_APPENDER" />
    </Async>
</Appenders>

  • bufferSize: Tương đương queueSize của Logback. Điểm khác biệt là Log4j2 sử dụng mảng sức chứa lớn hơn rất nhiều (mặc định lên tới 1024) nhờ cấu trúc tối ưu của nó.

  • blocking: Cách xử lý khi "rổ" đầy.

    • Bằng true (mặc định): Luồng chính (Đầu bếp) sẽ phải đứng khựng lại chờ đến khi có chỗ trống. Điều này bảo toàn dữ liệu nhưng làm chậm hệ thống.

    • Bằng false: Luồng chính sẽ vứt bỏ luôn dòng log đó ra thùng rác và chạy tiếp ngay lập tức. Đánh đổi dữ liệu lấy tốc độ tối đa.

Nhìn vào cách các tham số lưu trữ trên RAM này hoạt động, hãy thử đặt mình vào một bài toán thực tế: Giả sử Server của bạn có dung lượng RAM rất khiêm tốn (ví dụ chỉ có 1GB cho toàn bộ ứng dụng), nhưng vì tham tốc độ, bạn lại thiết lập queueSize hoặc bufferSize lên tới con số hàng triệu. Theo bạn, rủi ro lớn nhất hệ thống sẽ gặp phải là gì trước khi ổ cứng kịp ghi log?

Rủi ro lớn nhất và tàn khốc nhất chính là tràn bộ nhớ RAM (OutOfMemoryError - OOM), dẫn đến việc toàn bộ ứng dụng bị sập (crash) ngay lập tức!

Để hiểu bản chất kỹ thuật, chúng ta cần nhìn vào những gì thực sự được lưu trong hàng đợi (Queue):

Log không chỉ là một chuỗi văn bản (String): Khi luồng chính đẩy log vào Queue, nó không chỉ ném vào một đoạn text. Hệ thống phải đóng gói một đối tượng sự kiện (LogEvent) chứa rất nhiều dữ liệu đi kèm: nội dung message, thời gian (timestamp), tên luồng (thread name), mức độ (level), tên Class (logger), và đôi khi là một StackTrace dài dằng dặc nếu đó là một ngoại lệ (Exception).

Sự cạn kiệt Heap Space: Một đối tượng LogEvent như vậy có thể chiếm từ vài trăm Byte đến vài Kilobyte bộ nhớ. Nếu bạn đặt kích thước hàng đợi lên đến hàng triệu, và lưu lượng truy cập tăng đột biến lấp đầy hàng đợi này, chúng sẽ ngốn hàng trăm Megabyte, thậm chí vài Gigabyte bộ nhớ Heap của Java.

Hậu quả kép: Với một Server chỉ có 1GB RAM, bộ nhớ sẽ cạn kiệt rất nhanh trước khi luồng phụ (Worker Thread) kịp ghi dữ liệu ra ổ cứng. JVM sẽ ném ra lỗi java.lang.OutOfMemoryError và "giết chết" tiến trình. Tệ hại hơn, khi ứng dụng sập, toàn bộ hàng triệu dòng log quý giá đang nằm chờ trên RAM cũng "bay hơi" vĩnh viễn.

Đây chính là lý do các thông số mặc định thường được thiết lập rất nhỏ (như 256, 512 hay 1024) kết hợp với các cơ chế xử lý khi hàng đợi đầy (Drop hoặc Block) mà chúng ta đã phân tích. Cấu hình Async Logging luôn là bài toán đánh đổi và tính toán dung lượng, chứ không phải cứ "càng to càng tốt".

4. Hai mặt của một đồng xu: Rủi ro khi dùng Async

Nghe thì tuyệt vời, nhưng nếu bạn không hiểu rõ cấu hình, Async có thể biến thành thảm họa. Điểm mấu chốt nằm ở cái Rổ (Queue).

Bởi vì hàng đợi (Queue) được lưu trữ trên RAM, kích thước của nó luôn có giới hạn (Ví dụ: Logback cấu hình queueSize="512", Log4j2 cấu hình bufferSize="1024").

Vậy bài toán cốt lõi đặt ra là: Nếu hệ thống phải chịu tải cao, luồng chính (Main Thread) tạo ra log nhanh hơn tốc độ luồng phụ (Worker Thread) kịp ghi xuống đĩa, khiến HÀNG ĐỢI BỊ ĐẦY, thì ứng dụng sẽ xử lý dòng log tiếp theo như thế nào?

Hệ thống cung cấp cho bạn 2 cơ chế giải quyết (đây chính là ý nghĩa của các thông số cấu hình trong file XML):

  • Cách 1 - Vứt bỏ (Drop): Hệ thống sẽ vứt bỏ luôn dòng log mới để không làm chậm ứng dụng. Mặc định, Logback sẽ bắt đầu vứt bỏ các log ở mức TRACE, DEBUG, INFO để nhường chỗ trống cho log mức ERROR. (Đó là lý do chúng ta phải thiết lập <discardingThreshold>0</discardingThreshold> để cấm hệ thống tự ý vứt bỏ dữ liệu).

  • Cách 2 - Chặn lại (Block): Luồng chính của ứng dụng bắt buộc phải khựng lại, đứng chờ đến khi hàng đợi có chỗ trống thì mới được nhét thêm log vào. Lúc này, cơ chế Bất đồng bộ (Async) vô tình bị biến ngược trở lại thành Đồng bộ (Synchronous), gây sụt giảm hiệu năng. Log4j2 mặc định sử dụng cơ chế an toàn này.

Như vậy, Asynchronous đổi "độ an toàn của dữ liệu" để lấy "hiệu năng tối đa".

Dựa vào cách hoạt động của cái Hàng đợi (Queue) nằm trên RAM mà chúng ta vừa phân tích, theo bạn: Nếu máy chủ Server đột ngột bị mất điện hoặc sập nguồn (Crash), điều gì sẽ xảy ra với những dòng log đã được Đầu bếp ném vào rổ nhưng anh Nhân viên chưa kịp ghi ra ổ cứng?

Câu trả lời phũ phàng nhất là: Toàn bộ số log đó sẽ "bay màu" vĩnh viễn! 💨

Queue mà chúng ta nhắc đến ở đây thực chất chính là bộ nhớ RAM của máy chủ. Đặc tính của RAM là toàn bộ dữ liệu sẽ bị xóa ngay lập tức khi mất nguồn điện. Vì dòng logc chưa được người dọn dẹp (Worker Thread) lưu xuống ổ cứng, nó sẽ mất tích không để lại dấu vết.

Sự thật trớ trêu nhất của Async Logging: Giả sử hệ thống của bạn đột ngột gặp một sự cố chí mạng (ví dụ: tràn bộ nhớ - OutOfMemoryError). Luồng chính (Main Thread) của ứng dụng kịp thời tạo ra một dòng log ERROR cực kỳ quan trọng và đẩy nó vào hàng đợi (Queue) trên RAM. Tuy nhiên, ngay khoảnh khắc đó, ứng dụng bị sập (crash) hoàn toàn trước khi luồng phụ (Worker Thread) kịp lấy dòng log sinh tử này để ghi xuống ổ cứng vật lý.

Hậu quả là khi bạn khởi động lại máy và mở file log ra tìm nguyên nhân, bạn sẽ hoàn toàn mù tịt. Hệ thống trông như vừa "chết đứng" một cách đầy bí ẩn mà không có lời trăng trối nào. 👻

Đó chính là sự đánh đổi (Trade-off) trong kỹ thuật phần mềm. Bạn lấy hiệu năng xử lý tốc độ cao ở điều kiện bình thường, và chấp nhận rủi ro mất đi một vài dòng log ở khoảnh khắc hệ thống "hấp hối". Đối với các dự án ngân hàng yêu cầu độ chính xác tuyệt đối (không được mất bất kỳ log giao dịch nào), họ thường phải ghi log đồng bộ hoặc kết hợp các giải pháp cứu hộ phức tạp hơn.

Từ đặc tính đánh đổi này, theo bạn, chúng ta có nên bật Async Logging cho ứng dụng khi đang code và chạy thử trên máy cá nhân (môi trường dev / local) không? Hãy thử suy luận dựa trên mục tiêu của quá trình code nhé.

Câu trả lời là Không nên. Trên thực tế, các dự án chuẩn không bao giờ bật Async Logging ở môi trường máy cá nhân (dev hoặc local). 🚫

Đây là lý do chi tiết:

  1. Khác biệt về mục tiêu cốt lõi

    • Trên Production: Mục tiêu số 1 là Hiệu năng. Server phải phục vụ hàng ngàn người dùng cùng lúc nên không thể để CPU rảnh rỗi chờ ghi ổ cứng. Đánh đổi một chút rủi ro mất log để lấy tốc độ là xứng đáng.

    • Trên môi trường Dev: Mục tiêu số 1 là Gỡ lỗi (Debug). Bạn code một mình trên máy, nên ứng dụng chạy chậm đi một vài mili-giây cũng chẳng sao. Nhưng bạn cần sự toàn vẹn tuyệt đối của dữ liệu. Mọi dòng log.info hay log.error phải xuất hiện ngay lập tức và không bao giờ được biến mất.

  2. Rủi ro mất "dấu vết tội phạm"

    • Khi bạn đang code, rủi ro tạo ra những lỗi nghiêm trọng làm sập cả ứng dụng (như vòng lặp vô hạn gây tràn RAM - OutOfMemoryError) là rất cao. Nếu dùng Async, dòng log báo lỗi cuối cùng (thứ quan trọng nhất để bạn biết code sai ở đâu) có thể đang nằm trong "rổ" trên RAM và... bay hơi luôn cùng với sự cố sập nguồn ứng dụng. Bạn sẽ nhìn vào màn hình và hoàn toàn mù tịt vì không có manh mối nào cả.

💡 Sự kết nối với thực hành:

Nếu bạn để ý kỹ lại file cấu hình logback-spring.xml hay log4j2-spring.xml chuẩn mà chúng ta đã làm ở các bước trước, bạn sẽ thấy sự phân chia này cực kỳ rõ ràng:

  • Trong thẻ <SpringProfile name="dev | local">: Chúng ta chỉ gọi thẻ in ra màn hình STDOUT (chạy Đồng bộ - an toàn tuyệt đối).

  • Chỉ khi vào thẻ <SpringProfile name="prod | staging">: Chúng ta mới gọi thẻ ASYNC_MAIN (chạy Bất đồng bộ - tối ưu tốc độ).

Mọi cấu hình đều có lý do của nó, và bây giờ bạn đã hoàn toàn hiểu tận gốc rễ lý do đó! 🌟

B. Tracing và Contextual Logging với MDC (Mapped Diagnostic Context)

Trong môi trường multithreading hoặc microservices, một request có thể đi qua hàng tá class khác nhau. Làm sao biết dòng log nào thuộc về user nào? MDC là một công cụ sử dụng ThreadLocal để gắn metadata vào toàn bộ luồng xử lý của một thread.

1. MDC là gì và cơ chế hoạt động (Under the hood)

MDC bản chất là một chiếc hộp lưu trữ dữ liệu dạng Key-Value (tương tự Map<String, String>) được cung cấp sẵn bởi SLF4J/Logback/Log4j2.

Điều làm nên sự đặc biệt của MDC là nó sử dụng cơ chế ThreadLocal của Java. Nghĩa là, chiếc hộp này là độc quyền cho mỗi Thread. Khi một Thread (luồng xử lý một Request của người dùng) cất một thông tin vào MDC, thì thông tin đó sẽ đi theo Thread đó xuyên suốt mọi ngóc ngách của ứng dụng, và các Thread khác tuyệt đối không thể nhìn thấy hay ghi đè lên được.

Hãy hình dung MDC giống như việc bạn phát một chiếc "thẻ tên có mã số" (Trace ID) cho mỗi request ngay từ cổng bảo vệ. Bất cứ bộ phận nào bên trong xử lý request đó cũng phải in cái mã số đó ra.

2. Ba bước triển khai MDC chuẩn Enterprise

Để hệ thống tự động gắn Trace ID vào mọi dòng log, chúng ta thường làm theo 3 bước sau:

Bước 1: Chặn đầu Request để gắn thẻ (Dùng Filter hoặc Interceptor)

import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import javax.servlet.*;
import java.io.IOException;
import java.util.UUID;

@Component
public class TraceIdFilter implements Filter {

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) 
            throws IOException, ServletException {
        
        // Tạo một mã định danh duy nhất cho request này
        String traceId = UUID.randomUUID().toString();
        
        // Nhét vào MDC
        MDC.put("traceId", traceId);
        // Có thể nhét thêm các thông tin hữu ích khác nếu đã có
        // MDC.put("userId", "user-123");

        try {
            // Cho phép request đi tiếp vào Controller / Service
            chain.doFilter(request, response);
        } finally {
            // TUYỆT ĐỐI QUAN TRỌNG: Phải dọn dẹp sau khi xử lý xong
            MDC.clear();
        }
    }
}

Bước 2: Sử dụng trong code (Hoàn toàn tự động)

Trong các file Controller, Service hay Repository, bạn cứ log bình thường, không cần phải truyền biến traceId đi đâu cả.

logger.info("Bắt đầu gọi API ngân hàng..."); // Không cần nhắc đến traceId

Bước 3: Cấu hình Logback lôi dữ liệu từ MDC ra để in

Trong file logback-spring.xml, bạn sử dụng cú pháp %X{key} (chữ X viết hoa) để trích xuất dữ liệu từ MDC.

<pattern>%d{HH:mm:ss} %-5level [%thread] [%X{traceId}] %logger{36} - %msg%n</pattern>

Kết quả in ra file sẽ cực kỳ gọn gàng:

14:05:01 INFO [http-nio-8080-exec-1] [a1b2c3d4-xxxx] OrderService - Bắt đầu gọi API ngân hàng...

Lúc này, trên hệ thống phân tích log (như Kibana), bạn chỉ cần gõ traceId: "a1b2c3d4-xxxx" là toàn bộ vòng đời của request đó sẽ hiện ra trước mắt.

Như bạn thấy ở Bước 1, trong khối finally, tôi đã đặt một dòng chữ "TUYỆT ĐỐI QUAN TRỌNG" cho lệnh MDC.clear().

Dựa vào việc Spring Boot mặc định sử dụng một Thread Pool (hồ chứa luồng) gồm khoảng 200 thread tái sử dụng lại cho các request bằng Tomcat, theo bạn, nếu chúng ta quên không gọi MDC.clear() thì hệ thống sẽ gặp phải "thảm họa" gì ở các request tiếp theo?

"Thảm họa" ở đây chính là hiện tượng Ô nhiễm chéo dữ liệu (Cross-Contamination).

Hãy cùng mổ xẻ cơ chế gây ra lỗi này:

  1. Bản chất của Thread Pool: Spring Boot (thông qua Tomcat) không tạo ra một luồng (Thread) mới tinh cho mỗi request. Nó duy trì một "hồ chứa" khoảng 200 threads. Xử lý xong request của khách hàng này, thread đó không chết đi mà được trả về hồ để tái sử dụng cho khách hàng tiếp theo.

  2. MDC dính chặt vào Thread: MDC lưu dữ liệu bằng ThreadLocal, nghĩa là thông tin được gắn "chết" vào Thread đó cho đến khi có lệnh xóa trực tiếp.

  3. Hiệu ứng domino: Giả sử User A (có TraceID là A-123) truy cập và được Tomcat giao cho Thread số 1. Nếu ở cuối request bạn quên gọi MDC.clear(), mã A-123 vẫn dính chặt vào Thread 1. Vài phút sau, User B truy cập hệ thống, Tomcat vô tình lấy đúng Thread số 1 ra để phục vụ User B. Lúc này, mọi thao tác của User B sẽ tự động bị gắn mác TraceID A-123 của User A!

Hậu quả: Khi hệ thống xảy ra sự cố, bạn copy TraceID A-123 lên hệ thống kiểm tra và thấy một mớ logic phi lý: User A đang ở bước thanh toán thì tự nhiên có dòng log "đổi mật khẩu thất bại" (thực chất là thao tác của User B). Tính năng truy vết lỗi (Tracing) lúc này hoàn toàn vô dụng.

Bây giờ hệ thống của chúng ta đã có TraceID chuẩn xác cho từng request để giải quyết bài toán Microservices.

Tuy nhiên, nếu chúng ta xuất log ra file dưới dạng văn bản thuần túy (ví dụ: INFO [A-123] [OrderService] Xử lý đơn hàng), các hệ thống gom log tập trung (như Elasticsearch hay Datadog) sẽ phải dùng các bộ Regex (biểu thức chính quy) rất phức tạp và tốn CPU để cắt xén, bóc tách chuỗi văn bản đó ra thành các trường dữ liệu.

Để giải quyết triệt để nút thắt này, các dự án Enterprise bắt buộc phải dùng Structured Logging (Ghi log định dạng JSON). Theo bạn, khi một dòng log được in ra dưới dạng một cục JSON (với các key-value rõ ràng), điều này giúp ích gì cho các bộ máy tìm kiếm log so với việc đọc văn bản thuần túy?

C. Structured Logging (Log định dạng JSON)

Sự khác biệt cốt lõi nằm ở chi phí xử lý (CPU) và độ chính xác khi truy vấn của các hệ thống phân tích trung tâm (như Elasticsearch, Datadog, hay Splunk).

Việc in log ra dạng text thuần (Plain text) là "ác mộng" cho các hệ thống phân tích log tập trung. Thay vì phải viết các bộ Regex phức tạp để bóc tách dữ liệu (Parsing) theo từng dòng, hãy thiết lập Appender xuất log trực tiếp ra dạng JSON.

Việc này giúp các hệ thống thu thập và phân tích (như Elasticsearch, DataDog, hoặc các nền tảng SIEM/SOAR) có thể dễ dàng map các trường (fields) để tạo rule cảnh báo (correlation rules) mà không tốn tài nguyên xử lý text.

Chúng ta cùng so sánh hai cách tiếp cận để thấy rõ sự chênh lệch này:

1. Nỗi ám ảnh mang tên "Văn bản thuần túy" (Plain Text)

Giả sử bạn có dòng log sau:

2023-10-27 14:00:00 INFO [A-123] OrderService - User u99 vừa mua SP-01 giá 500k

Đối với con người, dòng này rất dễ đọc. Nhưng đối với máy chủ Elasticsearch, nó chỉ là một chuỗi ký tự vô nghĩa. Để bạn có thể tìm kiếm được những user nào đã mua "SP-01", hệ thống phải trải qua một quá trình gọi là Parsing (Bóc tách dữ liệu).

Người quản trị hệ thống sẽ phải viết các bộ biểu thức chính quy (Regex) hoặc Grok pattern cực kỳ phức tạp để dạy máy tính cắt chuỗi trên ra:

  • Lấy 19 ký tự đầu làm timestamp.
  • Cắt phần chữ nằm giữa 2 dấu ngoặc vuông [] làm traceId.
  • Tìm chữ "User", lấy từ tiếp theo làm userId.

Hậu quả: Việc chạy Regex trên hàng tỷ dòng log ngốn một lượng CPU khổng lồ. Hơn nữa, nó rất "giòn" (brittle) – chỉ cần một Developer vui tay sửa lại format in log (ví dụ thêm một dấu phẩy), toàn bộ bộ Regex sẽ gãy, và log ngày hôm đó sẽ bị đánh dấu là lỗi không thể phân tích.

2. Quyền năng của Structured Logging (Log cấu trúc JSON)

Với JSON, dòng log trên sẽ được ứng dụng Spring Boot xuất ra hệ thống quản lý dưới dạng:

{
  "@timestamp": "2023-10-27T14:00:00.000Z",
  "level": "INFO",
  "traceId": "A-123",
  "logger": "com.company.OrderService",
  "userId": "u99",
  "productId": "SP-01",
  "amount": 500000,
  "message": "User u99 vừa mua SP-01 giá 500k"
}

Tại sao nó lại bá đạo?

  • Không cần Parsing: Các hệ thống như Elasticsearch "nói" ngôn ngữ JSON. Khi nhận được cục JSON này, nó không cần chạy bất kỳ Regex nào. Nó tự động hiểu traceId là một trường (field) riêng biệt và đưa thẳng vào chỉ mục (Indexing).
  • Truy vấn chính xác tuyệt đối: Bạn có thể dễ dàng viết query: "Tìm tất cả log có level = ERROR VÀ amount > 100000". Điều này là bất khả thi với văn bản thuần túy.

3. Cách triển khai trong Spring Boot

Để biến toàn bộ log thành JSON cực kỳ đơn giản, bạn chỉ cần thêm một thư viện có tên là Logstash Logback Encoder.

Bước 1: Thêm dependency vào pom.xml

<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.4</version>
</dependency>

Bước 2: Sửa lại Appender trong logback-spring.xml

Thay vì dùng thẻ <pattern> để định dạng chữ thông thường, ta chuyển sang dùng LogstashEncoder:

<appender name="JSON_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>logs/app-json.log</file>
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
        <includeMdcKeyName>traceId</includeMdcKeyName> 
    </encoder>
</appender>

Đến đây, bạn đã trang bị cho hệ thống của mình Asynchronous Logging (hiệu năng cao), MDC (truy vết Request) và JSON (tối ưu hóa tìm kiếm).

Tuy nhiên, với việc ghi lại chi tiết mọi dữ liệu dưới dạng JSON rõ ràng như vậy, một rủi ro cực lớn về bảo mật xuất hiện. Giả sử hệ thống vô tình ghi lại chuỗi JSON chứa field "password": "my_secret_pass" hoặc "credit_card": "1234-5678-...".

Theo bạn, làm cách nào để chúng ta có thể Che giấu dữ liệu nhạy cảm (Data Masking) ngay từ trong code trước khi các thông tin này bị ghi xuống ổ cứng và bay lên hệ thống log tập trung, nơi hàng chục nhân viên có quyền truy cập?

D. Che giấu dữ liệu nhạy cảm (Data Masking)

Để giải quyết triệt để bài toán rò rỉ dữ liệu (Data Leakage), nguyên tắc tối thượng là: Phải tiêu diệt dữ liệu nhạy cảm ngay trong bộ nhớ RAM của ứng dụng, trước khi nó kịp ghi xuống ổ cứng hay gửi qua mạng.

Trong các hệ thống Enterprise, chúng ta thiết lập 2 lớp phòng ngự để đảm bảo an toàn tuyệt đối (Data Masking).

1. Lớp phòng ngự 1: Kiểm soát tại nguồn (Mức Code) 🛡

Lỗi phổ biến nhất của Developer là tiện tay in toàn bộ Object ra log:

logger.info("Thông tin user đăng ký: {}", userDto);

Khi hàm này chạy, Java sẽ tự động gọi hàm userDto.toString(), kéo theo cả mật khẩu, số thẻ tín dụng in ra file. Để chặn đứng việc này, nếu dự án của bạn dùng thư viện Lombok, hãy dùng các annotation sau:

  • @ToString.Exclude: Loại bỏ hoàn toàn trường đó khỏi chuỗi log.
  • Viết hàm toString() tùy chỉnh: Chỉ in ra 4 số cuối của thẻ tín dụng (ví dụ: ****-****-****-1234).
@Data
public class UserRegisterDto {
    private String username;
    private String email;
    
    @ToString.Exclude // Tuyệt đối không bao giờ cho phép in biến này ra log
    private String password; 
    
    private String creditCard;
    
    // Viết đè để che giấu thẻ tín dụng
    @Override
    public String toString() {
        return "UserRegisterDto(username=" + username + 
               ", card=****-****-****-" + creditCard.substring(creditCard.length() - 4) + ")";
    }
}

2. Lớp phòng ngự 2: Tấm lưới an toàn (Mức Cấu hình Logback) 🕸️

Lớp 1 rất hiệu quả nhưng phụ thuộc vào trí nhớ và sự cẩn thận của con người. Nếu một Dev mới vào nghề quên gắn @ToString.Exclude hoặc cố tình gõ một câu log text thuần chứa chuỗi password, dữ liệu vẫn sẽ bị lộ.

Lớp phòng ngự 2 là một "bộ lọc tự động" quét qua mọi dòng log trước khi chúng được xuất ra ngoài. Tùy thuộc vào định dạng log dự án đang dùng, chúng ta có cách xử lý khác nhau.

Kịch bản A: Nếu dự án in log định dạng JSON (Dùng Logstash Encoder)

Khi xuất log dạng JSON, dữ liệu được chia thành các cặp Key-Value rõ ràng. Ta có thể chặn theo Tên Key hoặc theo Định dạng Value (Regex).

Bước 1: Viết class MaskingDecorator

package com.yourcompany.config;

import com.fasterxml.jackson.core.JsonGenerator;
import net.logstash.logback.decorate.JsonGeneratorDecorator;
import net.logstash.logback.mask.MaskingJsonGeneratorDecorator;
import net.logstash.logback.mask.RegexValueMasker;

public class MaskingDecorator implements JsonGeneratorDecorator {
    @Override
    public JsonGenerator decorate(JsonGenerator generator) {
        MaskingJsonGeneratorDecorator maskingDecorator = new MaskingJsonGeneratorDecorator();

        // Luật 1: Quét theo Tên Key - Nếu key là "password" hoặc "credit_card", che toàn bộ Value thành "****"
        maskingDecorator.addPath("password");
        maskingDecorator.addPath("credit_card");

        // Luật 2: Quét theo Regex - Tìm bất cứ chuỗi nào giống thẻ tín dụng 13-16 số nằm ở bất cứ đâu trong JSON
        RegexValueMasker regexMasker = new RegexValueMasker();
        regexMasker.addPattern("\\b(?:\\d[ -]*?){13,16}\\b");
        maskingDecorator.addValueMasker(regexMasker);

        return maskingDecorator.decorate(generator);
    }
}

Bước 2: Gắn vào logback-spring.xml

<appender name="JSON_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
        <jsonGeneratorDecorator class="com.yourcompany.config.MaskingDecorator"/>
    </encoder>
</appender>

Kịch bản B: Nếu dự án in log định dạng Plain Text (Văn bản thuần)

Vì log chỉ là một chuỗi văn bản dài, không có cấu trúc Key-Value, ta bắt buộc phải dùng Regex để tìm và đè chữ **** lên các thông tin nhạy cảm.

Bước 1: Viết custom MessageConverter

package com.yourcompany.config;

import ch.qos.logback.classic.pattern.MessageConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import java.util.regex.Pattern;

public class MaskingPatternConverter extends MessageConverter {

    private static final Pattern CREDIT_CARD_PATTERN = Pattern.compile("\\b(?:\\d[ -]*?){13,16}\\b");
    private static final Pattern PASSWORD_PATTERN = Pattern.compile("(password[=:]\\s*)[^\\s,)]+");

    @Override
    public String convert(ILoggingEvent event) {
        String message = super.convert(event);
        if (message == null) return null;

        // Masking thẻ tín dụng
        message = CREDIT_CARD_PATTERN.matcher(message).replaceAll("****");
        // Masking password (chỉ thay thế phần value, giữ lại chữ "password=")
        message = PASSWORD_PATTERN.matcher(message).replaceAll("$1****");

        return message;
    }
}

Bước 2: Định nghĩa từ khóa mới trong logback-spring.xml

<conversionRule conversionWord="maskedMsg" converterClass="com.yourcompany.config.MaskingPatternConverter" />

<appender name="PLAIN_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{HH:mm:ss} [%thread] %-5level %logger{36} - %maskedMsg%n</pattern>
    </encoder>
</appender>

Nhờ hai lớp phòng ngự này, dù có ai đó vô tình gọi lệnh log chứa mật khẩu, file JSON cuối cùng được tạo ra vẫn an toàn tuyệt đối. Các hệ thống như Kibana hay Datadog sẽ chỉ nhận được những thông tin đã được làm mờ.

Lời kết

Logging là một phần không thể thiếu, nhưng cách chúng ta làm chủ nó mới là thứ định hình sự khác biệt giữa một developer "chỉ biết code" và một kỹ sư chuyên nghiệp. Khi bạn hiểu tường tận về sự phân lớp giữa SLF4J và các Implementation như Log4j2 hay Logback, bạn đã sở hữu một "chìa khóa" để kiểm soát hiệu năng, tiết kiệm tài nguyên và bảo vệ hệ thống khỏi những rủi ro bất ngờ trên môi trường Production.

Đừng dừng lại ở việc copy-paste cấu hình trên mạng. Hãy thử "mổ xẻ" hệ thống của bạn, tinh chỉnh các appender và biến file log thành một công cụ đắc lực thay vì một gánh nặng cho ổ cứng.

java springboot Log4J log4j2 Logging SLF4j

All rights reserved

Mục lục


Viblo
Hãy đăng ký một tài khoản Viblo để nhận được nhiều bài viết thú vị hơn.
Đăng kí