Ghi log trong các ứng dụng đa luồng và web

1. Tính an toàn luồng khi ghi log

Trong các chương trình đơn luồng thì mọi thứ đơn giản: một luồng ghi log, không ai cản trở nó. Còn trong các ứng dụng thực tế — dịch vụ web, microservice — hàng chục và hàng trăm luồng chạy đồng thời. Hãy tưởng tượng nếu nhiều người cùng lúc viết bút vào cùng một dòng trong cùng một quyển sổ — kết quả, nói nhẹ nhàng, sẽ rất khó đọc.

Tính an toàn luồng (thread safety) là sự đảm bảo rằng ngay cả khi 100500 luồng đồng thời ghi log, các thông điệp sẽ không bị lẫn, không dính vào nhau và không bị mất.

Điều này được các thư viện thực hiện như thế nào?

Các thư viện ghi log hiện đại (Log4j 2, Logback, java.util.logging) ngay từ đầu đã được thiết kế để thread-safe. Điều đó có nghĩa là:

• Mỗi luồng có thể gọi các phương thức của logger một cách an toàn.
• Bên trong thư viện sử dụng đồng bộ hóa và hàng đợi để các thông điệp không cản trở nhau.
• Ngay cả khi nhiều luồng đồng thời ghi vào cùng một tệp, log cũng không bị lẫn lộn.

QUAN TRỌNG: Chính logger (ví dụ, đối tượng Logger từ SLF4J hoặc Log4j) có thể được dùng như một trường static final trong bất kỳ lớp nào — điều này sẽ không gây vấn đề về luồng.

Ví dụ

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

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

    public static void main(String[] args) {
        Runnable task = () -> {
            for (int i = 0; i < 5; i++) {
                logger.info("Luồng {} ghi thông điệp {}", Thread.currentThread().getName(), i);
            }
        };

        Thread t1 = new Thread(task, "Thứ nhất");
        Thread t2 = new Thread(task, "Thứ hai");
        t1.start();
        t2.start();
    }
}

Trong log bạn sẽ thấy các thông điệp gọn gàng từ cả hai luồng — không lẫn lộn hay chồng chéo.

2. Ngữ cảnh ghi log: MDC (Mapped Diagnostic Context)

Hãy hình dung: ứng dụng của bạn xử lý hàng trăm yêu cầu đồng thời, mỗi yêu cầu — trong một luồng riêng. Trong log xuất hiện nhiều thông điệp, nhưng không rõ cái nào thuộc về yêu cầu nào. Ta muốn thấy không chỉ “điều gì đã xảy ra”, mà còn là với ai và trong yêu cầu nào điều đó đã xảy ra.

MDC (Mapped Diagnostic Context) là một cơ chế đặc biệt cho phép “đính kèm” thông tin bổ sung vào log, gắn với luồng hiện tại. Mọi thông điệp mà luồng ghi ra sẽ tự động nhận các dữ liệu bổ sung này.

Ví dụ: log ID của yêu cầu

Trong ứng dụng web, mỗi yêu cầu có thể được gán một ID duy nhất (ví dụ, UUID). Với MDC, ID này sẽ tự động được thêm vào tất cả log mà luồng phục vụ yêu cầu đó ghi ra.

Trông như thế nào trong code (SLF4J + Logback):

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

import java.util.UUID;

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

    public static void main(String[] args) {
        Runnable task = () -> {
            // Sinh ID yêu cầu (request) duy nhất
            String requestId = UUID.randomUUID().toString();
            MDC.put("requestId", requestId); // thêm vào MDC

            logger.info("Đang xử lý yêu cầu");
            doSomeWork();
            logger.info("Đã hoàn tất xử lý");

            MDC.clear(); // nhất định phải xóa sau khi kết thúc!
        };

        Thread t1 = new Thread(task, "Luồng-1");
        Thread t2 = new Thread(task, "Luồng-2");
        t1.start();
        t2.start();
    }

    static void doSomeWork() {
        logger.debug("Đang thực hiện công việc...");
    }
}

Cấu hình định dạng log (ví dụ, logback.xml):

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

Kết quả:

12:01:23 [Luồng-1] INFO  MdcExample [requestId=ad8d...f3] - Đang xử lý yêu cầu
12:01:23 [Luồng-1] DEBUG MdcExample [requestId=ad8d...f3] - Đang thực hiện công việc...
12:01:23 [Luồng-1] INFO  MdcExample [requestId=ad8d...f3] - Đã hoàn tất xử lý

Quan trọng!

• MDC chỉ hoạt động trong phạm vi một luồng. Nếu bạn chuyển công việc sang luồng khác (ví dụ, qua pool luồng), bạn cần truyền thủ công các giá trị MDC (hoặc dùng các thư viện chuyên dụng thực hiện việc này tự động).
• Đừng quên xóa MDC! Nếu không xóa, dữ liệu có thể “chảy” sang yêu cầu tiếp theo trong cùng luồng (ví dụ, trong pool luồng của web server). Hãy dùng MDC.clear() trong khối finally.

3. Ghi log trong ứng dụng web

Ứng dụng web không chỉ là một chương trình chạy rồi để đó. Nó là một dây chuyền thực thụ: yêu cầu đến, được xử lý, phản hồi được gửi đi. Tất cả — đồng thời, hàng trăm cái. Ở đây, ghi log không phải là xa xỉ, mà là cần thiết!

Cần log những gì trong ứng dụng web?

• HTTP request và response: method, URL, tham số, trạng thái phản hồi, thời gian xử lý.
• Lỗi và ngoại lệ: mọi sự cố bất ngờ, stack trace.
• Sự kiện nghiệp vụ: đăng ký, đăng nhập, đặt hàng, thanh toán, v.v.
• Chi tiết kỹ thuật: tương tác với cơ sở dữ liệu, dịch vụ bên ngoài, thời gian thực thi các thao tác.

Quy tắc then chốt: hãy log sao cho một tháng sau, khi có thứ gì đó hỏng lúc 3 giờ sáng, bạn vẫn có thể lần ra được điều gì đã xảy ra.

Ví dụ: log HTTP request (Spring Boot)

Cách đơn giản nhất là dùng một filter hoặc aspect để log mỗi yêu cầu đi vào.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
import java.util.UUID;

@Component
public class RequestLoggingFilter implements Filter {
    private static final Logger logger = LoggerFactory.getLogger(RequestLoggingFilter.class);

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        String requestId = UUID.randomUUID().toString();
        MDC.put("requestId", requestId);

        HttpServletRequest httpRequest = (HttpServletRequest) request;
        logger.info("Yêu cầu: {} {}", httpRequest.getMethod(), httpRequest.getRequestURI());

        long start = System.currentTimeMillis();
        try {
            chain.doFilter(request, response); // tiếp theo trong chuỗi (đến controller)
        } finally {
            long duration = System.currentTimeMillis() - start;
            logger.info("Đã gửi phản hồi, thời gian xử lý: {} ms", duration);
            MDC.clear();
        }
    }
}

Ghi log lỗi và ngoại lệ

Trong các web framework (ví dụ, Spring) người ta thường dùng các trình xử lý lỗi chuyên dụng (@ExceptionHandler) để ghi log gọn gàng mọi sự cố bất ngờ.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.ControllerAdvice;
import org.springframework.web.bind.annotation.ExceptionHandler;

@ControllerAdvice
public class GlobalExceptionHandler {
    private static final Logger logger = LoggerFactory.getLogger(GlobalExceptionHandler.class);

    @ExceptionHandler(Exception.class)
    public String handleException(Exception ex) {
        logger.error("Đã xảy ra lỗi: ", ex); // ghi log kèm toàn bộ stack trace!
        return "error"; // trả về trang lỗi
    }
}

Tích hợp với web framework

Hầu hết các web framework hiện đại (Spring, Jakarta EE, Micronaut, v.v.) đều tích hợp với logger “out of the box”. Thông thường chỉ cần thêm phụ thuộc SLF4J/Logback vào dự án — và mọi thông điệp chuẩn (khởi động ứng dụng, xử lý yêu cầu, lỗi) sẽ được log tự động.

4. Thực hành: Ví dụ ghi log trong tác vụ đa luồng

Hãy thêm xử lý đa luồng vào ứng dụng học tập của chúng ta (ví dụ, dịch vụ xử lý đơn hàng) và xem việc ghi log giúp ta “giữ cái đầu lạnh” như thế nào.

Ví dụ: xử lý đơn hàng trên nhiều luồng với MDC

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

import java.util.UUID;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

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

    public static void main(String[] args) {
        ExecutorService executor = Executors.newFixedThreadPool(3);

        for (int i = 1; i <= 5; i++) {
            final int orderId = i;
            executor.submit(() -> {
                String requestId = UUID.randomUUID().toString();
                MDC.put("requestId", requestId);

                try {
                    logger.info("Bắt đầu xử lý đơn hàng {}", orderId);
                    processOrder(orderId);
                    logger.info("Đơn hàng {} được xử lý thành công", orderId);
                } catch (Exception ex) {
                    logger.error("Lỗi khi xử lý đơn hàng " + orderId, ex);
                } finally {
                    MDC.clear();
                }
            });
        }
        executor.shutdown();
    }

    static void processOrder(int orderId) throws InterruptedException {
        if (orderId % 2 == 0) {
            throw new RuntimeException("Mô phỏng lỗi cho đơn hàng chẵn");
        }
        Thread.sleep(500); // mô phỏng công việc
    }
}

Điều gì đang xảy ra:

• Mỗi đơn hàng được xử lý trong một luồng riêng.
• Với mỗi luồng, tạo một requestId duy nhất (qua MDC).
• Mọi log của một đơn hàng có thể được tìm theo định danh này.
• Lỗi được log kèm toàn bộ stack.

Định dạng log được cấu hình để hiển thị requestId.

5. Những lưu ý và đặc điểm quan trọng

• Luồng, pool và MDC. Nếu bạn làm việc với thread pool (và khả năng cao là có), hãy nhớ: các luồng trong pool được tái sử dụng! Nếu quên xóa MDC, dữ liệu từ một yêu cầu có thể lọt sang log của yêu cầu khác. Luôn gọi MDC.clear() khi kết thúc công việc.
• MDC và tác vụ bất đồng bộ. Trong các web framework bất đồng bộ (ví dụ, Spring WebFlux) MDC không phải lúc nào cũng hoạt động “out of the box”, vì việc xử lý yêu cầu có thể nhảy giữa các luồng. Cho các trường hợp như vậy có các phần mở rộng hay adapter chuyên dụng.
• Ghi log trong microservice. Trong kiến trúc microservice, thông lệ là log không chỉ định danh yêu cầu cục bộ mà cả định danh toàn cục (traceId) được truyền giữa các dịch vụ. Điều này cho phép theo dõi đường đi của yêu cầu qua toàn hệ thống (distributed tracing). Thường dùng các hệ thống như Zipkin, Jaeger, OpenTelemetry.

6. Trình diễn: khác biệt giữa System.out.println và ghi log

System.out.println — chỉ in một dòng ra console. Trong môi trường đa luồng:

• Thông điệp có thể bị trộn lẫn.
• Không có thông tin về thời gian, luồng, mức độ, ngữ cảnh.
• Không thể cấu hình xuất ra tệp, định dạng, lọc theo mức độ.

Logger — ghi các thông điệp có cấu trúc, tính đến luồng, mức độ, định dạng, hỗ trợ xuất ra nhiều nơi (tệp, console, mạng).

Ví dụ so sánh

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

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

    public static void main(String[] args) {
        Runnable task = () -> {
            for (int i = 0; i < 3; i++) {
                System.out.println("System.out: " + Thread.currentThread().getName() + " bước " + i);
                logger.info("Logger: bước {}", i);
            }
        };
        new Thread(task, "T1").start();
        new Thread(task, "T2").start();
    }
}

Kết luận:

• System.out — thông điệp có thể đi lẫn lộn, không có thời gian và mức độ.
• Logger — mỗi thông điệp có thời gian, luồng, mức độ; có thể lọc và nhanh chóng tìm điều cần thiết.

7. Các lỗi thường gặp khi ghi log trong ứng dụng đa luồng và web

Lỗi số 1: Dùng System.out.println thay vì logger. Trong môi trường đa luồng điều này dẫn tới “mớ hỗn độn” trên console, không thể lọc thông điệp và mất thông tin ngữ cảnh.

Lỗi số 2: Bỏ qua MDC hoặc dùng sai cách. Nếu không dùng MDC để truyền định danh yêu cầu/người dùng, log trở nên vô nghĩa — không thể hiểu lỗi thuộc về yêu cầu nào. Nếu quên xóa MDC, dữ liệu có thể “rò rỉ” sang yêu cầu khác.

Lỗi số 3: Tạo logger như biến cục bộ. Tốt hơn dùng private static final Logger — như vậy logger được tạo một lần cho mỗi lớp, không tốn bộ nhớ và giảm rủi ro lỗi.

Lỗi số 4: Ghi log dữ liệu nhạy cảm. Không được để mật khẩu, số thẻ ngân hàng, dữ liệu cá nhân vào log — đó là vi phạm an toàn!

Lỗi số 5: Chỉ log “INFO” hoặc chỉ “ERROR”. Hãy dùng mức độ phù hợp: DEBUG cho gỡ lỗi, INFO cho sự kiện nghiệp vụ, ERROR cho lỗi. Đừng ghi tất cả bằng một mức — nếu không log sẽ mất ý nghĩa.

Lỗi số 6: Không log stack trace của ngoại lệ. Nếu chỉ viết logger.error("Lỗi: " + ex.getMessage()), bạn sẽ mất thông tin về nguyên nhân lỗi. Luôn log toàn bộ ngoại lệ: logger.error("Lỗi", ex).

Lỗi số 7: Tự viết logger không thread-safe. Nếu ai đó quyết định “tự làm logger” mà không có đồng bộ hóa — trong môi trường đa luồng gần như chắc chắn sẽ mất hoặc hỏng log.