Logging cơ bản — SLF4J facade, Logback, log level và hierarchy

TL;DR: Boot logging stack gồm 4 layer — SLF4J facade (API duy nhất code app dùng), Logback implementation, bridge libs redirect log từ JUL/Log4j legacy, và output. Facade pattern tồn tại để đổi implementation không sửa code: swap Logback sang Log4j2 là đổi 2 dòng pom, không chạm business code. 5 log level từ TRACE đến ERROR tạo thành hierarchy theo package — set com.example: DEBUG bật toàn bộ package đó, child override parent bằng config cụ thể hơn. Tại sao dùng log.info("{}", x) thay log.info("val=" + x): placeholder lazy — nếu level INFO tắt, string concat không bao giờ chạy.

Mỗi app Boot in log từ giây đầu — không cần config. Đó là vì Boot đã pre-wire toàn bộ logging stack qua spring-boot-starter-logging. Bài này bóc cơ chế đó: 4 layer trong stack là gì, façade pattern giải quyết vấn đề gì, log level + hierarchy hoạt động ra sao, và cấu hình qua property.

Bài trước — Profile groups & patterns — giải thích cách Boot chọn config theo môi trường. Bài này nối tiếp: logging cũng cấu hình theo môi trường, và hiểu stack là nền để Structured logging ở bài sau thêm JSON output cho production.

1. Stack logging Boot — 4 layer

Boot không tự code logger. Nó tích hợp sẵn 4 component thành một stack:

Ba layer đầu:

• SLF4J (Simple Logging Facade for Java): interface thuần tuý — Logger, LoggerFactory. Code app chỉ dùng SLF4J, không import Logback trực tiếp.
• Logback: implementation mặc định Boot chọn. Nhận log từ SLF4J, format, ghi ra console/file.
• Bridge libs: capture log từ thư viện cũ (Tomcat dùng java.util.logging, Hibernate dùng Log4j 1.x, Spring cũ dùng Commons Logging) rồi redirect qua SLF4J. Nhờ đó toàn bộ log từ mọi thư viện đều unified qua Logback.

spring-boot-starter-logging (transitive của mọi spring-boot-starter-*) pull cả 4 layer:

spring-boot-starter-logging
├── logback-classic        (implementation)
├── logback-core
├── slf4j-api              (facade API)
├── jul-to-slf4j           (bridge JUL)
├── log4j-to-slf4j         (bridge Log4j)
└── jcl-over-slf4j         (bridge Commons Logging)

Không cần khai báo gì — add bất kỳ starter nào thì logging stack sẵn sàng.

2. Tại sao cần facade — vấn đề không có SLF4J

Trước SLF4J ra đời (2004), mỗi thư viện Java dùng logging framework riêng: Hibernate dùng Log4j, Spring dùng Commons Logging, Tomcat dùng JUL. App muốn log phải chọn 1 trong số đó — và nếu đổi framework log, phải sửa mọi import trong codebase.

SLF4J giải quyết bằng facade pattern (hay còn gọi abstraction layer): code viết theo interface chung của SLF4J, implementation thật (Logback, Log4j2...) chỉ khai báo ở pom/gradle, không xuất hiện trong source. Nhìn lại hình ở mục 1: vì mọi nguồn log đã hội tụ về một mắt xích, đổi implementation là đổi đúng một hộp nằm dưới mắt xích đó.

Hệ quả thực tế: đổi từ Logback sang Log4j2 chỉ cần:

1. Exclude spring-boot-starter-logging trong pom.
2. Add spring-boot-starter-log4j2.

Không một dòng business code nào thay đổi — vì tất cả đều import org.slf4j.Logger, không phải ch.qos.logback.Logger hay org.apache.log4j.Logger.

3. Dùng SLF4J đúng cách

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

@Service
public class OrderService {
    private static final Logger log = LoggerFactory.getLogger(OrderService.class);

    public void place(Order order) {
        log.debug("Placing order {}", order.id());
        log.info("Order placed: id={}, total={}", order.id(), order.total());

        try {
            payment.charge(order);
        } catch (PaymentException e) {
            log.error("Payment failed for order {}", order.id(), e);  // exception la param cuoi
        }
    }
}

Hoặc dùng Lombok @Slf4j để tự generate dòng khai báo logger:

@Slf4j   // generate: private static final Logger log = LoggerFactory.getLogger(OrderService.class);
@Service
public class OrderService {
    public void place(Order order) {
        log.info("Order placed: id={}", order.id());
    }
}

3.1 Tại sao placeholder {} thay vì string concat

Đây là lý do cơ chế, không chỉ style:

// SAI: string concat chay ngay ca khi DEBUG tat
log.debug("Processing order " + order.id() + " for user " + order.userId());

// DUNG: placeholder lazy — chi substitute khi DEBUG bat
log.debug("Processing order {} for user {}", order.id(), order.userId());

Khi level là INFO (DEBUG tắt), dòng thứ nhất vẫn tạo string trung gian rồi bỏ đi — lãng phí CPU cho mỗi call trong hot path. Dòng thứ hai: SLF4J kiểm tra level trước, nếu DEBUG không bật thì không gọi toString() trên các arguments, không tạo string nào cả.

Trong loop xử lý nghìn record/giây, sự khác biệt này có thể đo được.

3.2 Exception phải là param cuối

// SAI: chi in message, MAT stack trace
log.error("Payment failed: " + e.getMessage());
log.error("Payment failed: {}", e.getMessage());

// DUNG: SLF4J detect param cuoi la Throwable, log ca stack trace
log.error("Payment failed for order {}", order.id(), e);

SLF4J có xử lý đặc biệt: nếu param cuối cùng là Throwable, nó log toàn bộ stack trace. Khi debug bug production, stack trace là thông tin không thể thay thế — dùng hai cách sai trên sẽ chỉ thấy một dòng message, không biết lỗi từ đâu.

4. Năm log level và hierarchy theo package

4.1 Năm level

SLF4J định nghĩa 5 level theo thứ tự từ chi tiết nhất đến quan trọng nhất:

Quy tắc: khi level được set là INFO, chỉ INFO/WARN/ERROR đi qua. TRACE và DEBUG bị chặn trước khi format.

4.2 Hierarchy theo package

Logger có hierarchy tự động theo tên package — child inherit level từ parent gần nhất có config:

# application.yml
logging:
  level:
    root: WARN                              # default cho tat ca logger
    com.example: INFO                       # moi class trong com.example
    com.example.payment: DEBUG              # override — payment DEBUG
    com.example.payment.StripeGateway: INFO # override lai — class cu the INFO
    org.hibernate.SQL: DEBUG                # log SQL query
    org.springframework.web: WARN           # giam noise Spring web

Cách resolve level cho com.example.payment.StripeGateway:

1. Tìm config cho com.example.payment.StripeGateway → có, INFO. Apply.

Cách resolve cho com.example.payment.PaypalGateway:

1. Tìm com.example.payment.PaypalGateway → không có.
2. Walk up: com.example.payment → có, DEBUG. Apply.

Hai ô bên phải là phần đáng để ý: chúng không khai gì cả, nhưng level của chúng khác nhau vì tổ tiên gần nhất khác nhau. Đó cũng là cách một dòng com.example.payment: DEBUG làm log production phình ra — nó bật DEBUG cho cả những class bạn chưa nghĩ tới.

4.3 Cấu hình qua logging.level.*

logging:
  level:
    root: INFO
    com.example: DEBUG
    com.example.security: INFO           # tiet che hon — security class log it hon
    org.hibernate.SQL: DEBUG
    org.hibernate.orm.jdbc.bind: TRACE   # log SQL parameter

Không cần logback-spring.xml cho việc này — property đủ cho 90% case điều chỉnh level.

5. Cơ chế bên dưới — vì sao log level check nhanh

Khi bạn gọi log.debug("..."), Logback không lập tức format và ghi — nó kiểm tra level trước. Đặt hai cách viết ở mục 3.1 lên cùng một trục thời gian thì thấy chỗ khác nhau nằm ở thứ tự, không phải ở cú pháp:

Level được lưu dưới dạng integer (TRACE=0, DEBUG=10, INFO=20, WARN=30, ERROR=40). Kiểm tra level là so sánh integer — O(1), gần như không có overhead. Nhưng phép kiểm tra rẻ đó chỉ cứu được bạn nếu nó chạy trước phần tốn kém: với placeholder, SLF4J không gọi bất kỳ .toString() nào khi level check fail; với nối chuỗi, JVM đã làm xong việc trước khi logger kịp từ chối.

Logger hierarchy cũng được cache sau lần resolve đầu tiên — không phải walk up tree mỗi lần log.

6. Pitfall phổ biến

❌ Nhầm 1 — String concat trong log call:

log.debug("user " + userId + " action " + action);     // concat luon, ngay ca khi DEBUG tat

✅ Placeholder lazy:

log.debug("user {} action {}", userId, action);

❌ Nhầm 2 — Log exception thiếu stack trace:

log.error("Payment failed: " + e.getMessage());     // mat stack trace
log.error("Payment failed: {}", e);                 // toString() cua exception, van mat stack trace

✅ Exception là param cuối:

log.error("Payment failed for order {}", order.id(), e);   // log + full stack trace

❌ Nhầm 3 — Tưởng log.info(...) có overhead khi level INFO:

Có lẽ bạn nghĩ: "INFO là level mặc định, nên log.info(...) chắc tốn kém?" Không — INFO call có overhead gần bằng 0 khi level INFO bật, chỉ format + write. Overhead cần lo là log.debug(...) trong hot path khi level INFO (vì tốn chi phí kiểm tra + placeholder không chạy nhưng args vẫn được đánh giá nếu dùng concat).

❌ Nhầm 4 — Logger không static final:

private Logger log = LoggerFactory.getLogger(OrderService.class);  // SAI — tao moi moi instance

✅ Logger là stateless, dùng chung an toàn giữa các instance:

private static final Logger log = LoggerFactory.getLogger(OrderService.class);

LoggerFactory.getLogger() cache logger theo tên — static final đảm bảo chỉ lookup một lần per class.

Liên hệ các bài khác

• Profile groups & patterns: config logging hay thay đổi theo profile — logging.level.com.example: DEBUG ở profile dev, WARN ở profile prod. Hiểu profile trước giúp tổ chức logging.level.* config hợp lý.
• Structured logging: bài tiếp theo đi sâu vào JSON log cho production (Boot 3.4 ECS format), MDC correlation ID, và dynamic log level qua Actuator. Cơ chế 4-layer stack + hierarchy bài này là nền để hiểu structured logging build trên đó.
• Externalized configuration: logging.level.* là một trong hàng trăm property Boot expose qua application.yml. Bài đó giải thích cơ chế @ConfigurationProperties và thứ tự ưu tiên nguồn config — quan trọng khi override logging.level qua environment variable trong K8s.

Tóm tắt

• Boot pre-wire 4-layer logging stack qua spring-boot-starter-logging: SLF4J facade → Logback impl → bridge libs (JUL/Log4j/Commons Logging) → output.
• Facade pattern (SLF4J): code chỉ import org.slf4j.Logger — đổi implementation không sửa business code.
• Dùng SLF4J đúng: static final logger, placeholder {} thay concat (lazy — chỉ substitute khi level bật), exception là param cuối (log.error("msg", e) để có stack trace).
• 5 level TRACE/DEBUG/INFO/WARN/ERROR. Production default: INFO+. DEBUG tắt khi deploy — dùng cho diagnostics tạm thời.
• Hierarchy theo package: logger child inherit level từ parent gần nhất có config. Set com.example: INFO làm baseline; override package/class cụ thể.
• Cấu hình qua logging.level.* property — không cần logback-spring.xml cho 90% case điều chỉnh level.

Tự kiểm tra

Bài tiếp theo: Structured logging (Boot 3.4) + production