Logging — Logback default, structured logging, log level dynamic

Mọi app Boot in log từ giây đầu start. Bạn không config gì — log đã có pattern đẹp, level INFO, color console. Đó là vì Boot pre-configure Logback sẵn — 1 trong 5 trụ cột production-ready.

Bài này bóc cơ chế: Boot dùng Logback ra sao, pattern log decode thế nào, structured logging JSON (Boot 3.4 GA) cho ELK/Loki, MDC cho correlation ID, dynamic log level qua Actuator runtime (không restart), và pattern thực tế cho production.

1. Stack logging Boot — 4 layer

Boot không tự code logger. Nó tích hợp 4 component:

flowchart TB
    App[App code]
    SLF4J["SLF4J<br/>(Simple Logging Facade for Java)"]
    Logback["Logback<br/>(implementation)"]
    Output["Console / File / Cloud"]

    App -->|"Logger.info(...)"| SLF4J
    SLF4J -->|"binding"| Logback
    Logback --> Output

    Bridges["Bridge libs:<br/>jul-to-slf4j (java.util.logging)<br/>log4j-to-slf4j (Log4j 1.x/2.x)<br/>jcl-to-slf4j (commons-logging)"]
    App -->|"3rd-party lib"| Bridges
    Bridges --> SLF4J

    style SLF4J fill:#fef3c7
    style Logback fill:#d1fae5

Layer:

• SLF4J: facade interface (Logger, LoggerFactory). Code app chỉ dùng SLF4J — không bind vào implementation.
• Logback: default implementation. Có thể đổi sang Log4j2 mà không sửa code app.
• Bridge libs: capture log từ thư viện cũ (Apache Commons Logging, java.util.logging, Log4j 1.x) → redirect qua SLF4J.

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

spring-boot-starter-logging
├── logback-classic        (impl)
├── logback-core
├── slf4j-api
├── jul-to-slf4j           (bridge JUL)
├── log4j-to-slf4j         (bridge Log4j)
└── jcl-over-slf4j         (bridge commons-logging)

Hệ quả: dù bạn dùng lib X hay Y có log riêng (Tomcat dùng JUL, Hibernate dùng Log4j), tất cả log unified qua SLF4J → Logback → output.

2. SLF4J — cách dùng đúng

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());                        // OK — placeholder
        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 last param
        }
    }
}

4 quy tắc SLF4J:

1. Static final logger per class. Hoặc dùng Lombok @Slf4j để generate tự động.
2. Placeholder {} không string concatenation.
   log.debug("user " + userId + " did X");           // SAI — concat luon, ngay ca khi debug tat
   log.debug("user {} did X", userId);                // DUNG — lazy substitute, skip neu debug tat
   

3. Exception là param cuối, không format.
   log.error("failed", e);                           // log + stack trace
   log.error("failed: {}", e.getMessage());          // chi log message, MAT stack trace
   

4. Không log sensitive data (password, token, PII). Filter qua MDC hoặc custom appender.

2.1 Lombok @Slf4j

Thay vì khai báo logger manually:

@Slf4j                              // Lombok generate `private static final Logger log = ...`
@Service
public class OrderService {
    public void place(Order order) {
        log.info("Placing order {}", order);
    }
}

Khoá này dùng pattern này — gọn hơn 1 dòng / class, semantic giống.

3. Log level — 5 level + hierarchy

SLF4J có 5 level, từ chi tiết nhất → quan trọng nhất:

Quy tắc: log.debug(...) chỉ chạy khi level DEBUG bật. Nếu level INFO, debug call skip → no overhead (lazy substitute placeholder).

3.1 Hierarchy theo package

Logger có hierarchy theo package — child inherit level từ parent:

# application.yml
logging:
  level:
    root: INFO                            # default cho moi logger
    com.olhub: DEBUG                      # mọi class trong com.olhub
    com.olhub.security: INFO              # override — security INFO
    org.springframework.web: WARN         # tắt verbose web log
    org.hibernate.SQL: DEBUG              # log SQL
    org.hibernate.type.descriptor.sql: TRACE   # log SQL parameters

com.olhub.security.AuthService resolve level theo:

1. Tìm logger com.olhub.security.AuthService → không có config explicit.
2. Trỏ lên parent com.olhub.security → INFO. Apply.

Pattern hibernate SQL debug là kinh điển:

• org.hibernate.SQL DEBUG → log SQL query.
• org.hibernate.type.descriptor.sql TRACE → log parameter binding.

Bật khi debug N+1 hoặc query phức tạp.

3.2 Pattern log Boot default

2026-04-15T10:00:00.123 INFO 12345 --- [main] com.olhub.OrderService : Order placed: id=42, total=99.99

Decode:

• 2026-04-15T10:00:00.123 — ISO timestamp.
• INFO — level (5 char fixed width, color theo level).
• 12345 — process ID (PID).
• --- — separator.
• [main] — thread name (15 char fixed width).
• com.olhub.OrderService — logger name (40 char, abbreviated nếu dài).
• : Order placed... — message.

Pattern này set qua property:

logging:
  pattern:
    console: "%d{yyyy-MM-dd'T'HH:mm:ss.SSS} %-5level %pid --- [%15.15thread] %-40.40logger{39} : %msg%n"

Hoặc hoàn toàn tự config qua logback-spring.xml.

4. Cấu hình logging qua property

Boot expose ~30 property cho logging — đủ cho 90% case mà không cần logback-spring.xml:

4.1 Properties phổ biến

logging:
  # Level
  level:
    root: INFO
    com.olhub: DEBUG

  # File
  file:
    name: /var/log/app/app.log              # log to file
    # path: /var/log/app                     # alternative — auto-name spring.log

  # Pattern
  pattern:
    console: "%d{HH:mm:ss.SSS} %-5level [%thread] %logger{40} - %msg%n"
    file: "%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] %logger - %msg%n%ex"
    dateformat: "yyyy-MM-dd HH:mm:ss.SSS"

  # Rotation (Logback)
  logback:
    rollingpolicy:
      file-name-pattern: ${LOG_FILE}.%d{yyyy-MM-dd}.%i.gz
      max-file-size: 100MB
      max-history: 30
      total-size-cap: 10GB

  # Charset
  charset:
    console: UTF-8
    file: UTF-8

  # Group — nhom multiple package
  group:
    web: org.springframework.core.codec, org.springframework.http, org.springframework.web
    sql: org.hibernate.SQL, org.hibernate.orm.jdbc.bind

logging.group.web cho phép set level cho nhóm:

logging:
  level:
    web: DEBUG          # apply cho ca 3 package trong group

4.2 Khi nào cần logback-spring.xml

90% case dùng property là đủ. Khi cần logback-spring.xml:

• Custom appender (Kafka, ELK, Loki, custom JSON encoder).
• Conditional logger theo profile trong xml (Boot 2.0+ support <springProfile> tag).
• Multiple appender với pattern khác nhau.
• Async appender cho high-throughput.

<!-- src/main/resources/logback-spring.xml -->
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

    <springProfile name="prod">
        <appender name="JSON_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <file>/var/log/app/app.json</file>
            <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
            <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
                <fileNamePattern>/var/log/app/app.%d{yyyy-MM-dd}.%i.gz</fileNamePattern>
                <maxFileSize>100MB</maxFileSize>
                <maxHistory>30</maxHistory>
            </rollingPolicy>
        </appender>

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

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

<springProfile> tag cho phép conditional theo profile — power không có trong logback.xml thuần.

Tên file quan trọng: logback-spring.xml (Boot recognize) thay vì logback.xml — Boot có thể chỉnh tag <springProfile> trước khi Logback load.

5. Structured logging — Boot 3.4 GA

Production yêu cầu log JSON cho ELK/Splunk/Loki dễ index. Trước Boot 3.4, phải tự config Logstash encoder qua xml. Boot 3.4 thêm structured logging built-in:

logging:
  structured:
    format:
      console: ecs              # Elastic Common Schema
      file: ecs

3 format:

• ecs — Elastic Common Schema (Elasticsearch native).
• gelf — Graylog Extended Log Format.
• logstash — Logstash JSON.

Output:

{
  "@timestamp": "2026-04-15T10:00:00.123Z",
  "log.level": "INFO",
  "process.pid": 12345,
  "process.thread.name": "http-nio-8080-exec-1",
  "log.logger": "com.olhub.OrderService",
  "message": "Order placed: id=42, total=99.99",
  "service.name": "order-service",
  "service.version": "1.2.3",
  "service.environment": "prod",
  "ecs.version": "8.11"
}

ELK ingest trực tiếp — không phải parse pattern.

5.1 Custom field qua MDC

MDC (Mapped Diagnostic Context) — context per-thread cho log:

@Component
public class CorrelationIdFilter implements Filter {
    public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) {
        String requestId = ((HttpServletRequest) req).getHeader("X-Request-Id");
        if (requestId == null) requestId = UUID.randomUUID().toString();

        MDC.put("requestId", requestId);
        MDC.put("userId", extractUserId(req));        // tu JWT
        try {
            chain.doFilter(req, res);
        } finally {
            MDC.clear();          // QUAN TRONG — tranh leak sang request khac
        }
    }
}

Sau filter này, mọi log trong cùng request sẽ có requestId, userId trong MDC. Pattern log + MDC:

logging:
  pattern:
    console: "%d{HH:mm:ss} %-5level [%X{requestId:-no-request}] %logger : %msg%n"

%X\{requestId\} lấy từ MDC. :-no-request default nếu không có.

Output:

10:00:00 INFO  [a1b2c3] com.olhub.OrderService : Order placed: id=42
10:00:01 INFO  [a1b2c3] com.olhub.PaymentService : Charged $99.99
10:00:01 INFO  [d4e5f6] com.olhub.OrderService : Order placed: id=43

Trace 1 request qua nhiều service bằng requestId. Đây là pattern correlation ID — quan trọng cho distributed tracing manual (trước khi setup Micrometer Tracing).

5.2 MDC + Structured logging

Boot 3.4 structured logging tự include MDC fields:

{
  "@timestamp": "...",
  "log.level": "INFO",
  "message": "Order placed: id=42",
  "mdc": {
    "requestId": "a1b2c3",
    "userId": "user-42"
  }
}

ELK query: mdc.requestId: "a1b2c3" → trace toàn bộ request. Cực mạnh cho debug production.

5.3 Log custom field

Boot 3.4 thêm LoggingApplicationListener có thể inject custom field:

logging:
  structured:
    format:
      console: ecs
    json:
      add:
        environment: ${ENV:dev}
        region: ${REGION:asia-east}
        service.version: ${BUILD_VERSION:unknown}

Mọi log line tự include 3 field này. Đỡ phải đặt MDC manual cho field static.

6. Dynamic log level — Actuator runtime

Production scenario: bug xuất hiện, bạn cần bật DEBUG cho 1 package mà không restart app. Actuator /loggers endpoint:

management:
  endpoints:
    web:
      exposure:
        include: health, loggers

GET /actuator/loggers/com.olhub.OrderService:

{
  "configuredLevel": null,
  "effectiveLevel": "INFO"
}

POST /actuator/loggers/com.olhub.OrderService body:

{ "configuredLevel": "DEBUG" }

→ Logger com.olhub.OrderService ngay lập tức log DEBUG. Reset bằng null:

curl -X POST http://app:8080/actuator/loggers/com.olhub.OrderService \
  -H "Content-Type: application/json" \
  -d '{"configuredLevel": null}'

→ Trở về level từ config file.

Pattern thực tế: bug user X gặp tại 10:00. DevOps:

1. Bật DEBUG cho 1 logger cụ thể qua /actuator/loggers.
2. Reproduce (call lại API, check log với requestId của user X).
3. Tắt DEBUG (set null).
4. Tổng thời gian: 5 phút. So với restart deployment: 30 phút + impact users.

Cảnh báo: /actuator/loggers POST cần bảo vệ:

• Authentication (Spring Security).
• Tách port management khác port app: management.server.port=9090.
• Firewall: chỉ cho phép internal network access.

7. Đổi sang Log4j2

Logback default. Đổi sang Log4j2 (perf tốt hơn cho high-throughput):

<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>

Tạo src/main/resources/log4j2-spring.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger - %msg%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.olhub" level="DEBUG"/>
        <Root level="INFO">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Khi nào đổi:

• App high-throughput (>100k log/sec) — Log4j2 async logger nhanh hơn Logback ~2-3x.
• Cần feature Log4j2 specific (script-based filter, lookup mở rộng).

90% case Logback đủ. Đổi chỉ khi đo được benefit.

8. Pattern production cho ELK/Loki

Setup chuẩn 2026:

# application-prod.yml
logging:
  level:
    root: INFO
    com.olhub: INFO
    org.springframework.web: WARN
    org.hibernate.SQL: WARN

  structured:
    format:
      console: ecs                      # JSON cho ELK
    json:
      add:
        environment: ${ENV:prod}
        region: ${REGION}
        service.name: ${spring.application.name}
        service.version: ${BUILD_VERSION:unknown}

management:
  endpoints:
    web:
      exposure:
        include: health, loggers, metrics
  server:
    port: 9090                          # tach port management

K8s deployment:

spec:
  containers:
    - name: app
      ports:
        - containerPort: 8080            # app
        - containerPort: 9090            # management (internal only)
      env:
        - name: ENV
          value: "prod"
        - name: REGION
          value: "asia-east"
        - name: BUILD_VERSION
          value: "1.2.3"

ELK pipeline:

1. App in JSON ECS log → stdout.
2. Container runtime (Docker/Kubernetes) capture stdout → log file.
3. Filebeat/Fluentd ingest log file → Logstash hoặc trực tiếp Elasticsearch.
4. Kibana query: service.name: "order-service" AND mdc.requestId: "X".

Pattern này standard 2026 — JSON log + structured fields + correlation ID.

9. Pitfall tổng hợp

❌ Nhầm 1: String concatenation trong log call.

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

✅ Placeholder: log.debug("user {} did {}", userId, action); — lazy.

❌ Nhầm 2: Log exception sai cách.

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

✅ Exception là param cuối: log.error("failed", e); → log + stack trace đầy đủ.

❌ Nhầm 3: Log sensitive data.

log.info("Login: user={}, password={}", username, password);     // password vao log
log.info("User profile: {}", user);     // toString co the include email/phone

✅ Manual filter: log.info("Login: user={}", username);. Cho data structure phức tạp, override toString() mask sensitive field.

❌ Nhầm 4: Tin level INFO thấy log debug method nội bộ.

public void process() {
    log.info("processing started");          // ban thuong INFO ?? Dau cua method INFO?
    // ...
    log.info("processing finished");
}

✅ INFO cho business event (order placed, user login). DEBUG cho method entry/exit. Đừng spam INFO.

❌ Nhầm 5: Quên MDC.clear() trong filter.

public void doFilter(...) {
    MDC.put("requestId", id);
    chain.doFilter(req, res);
    // QUEN MDC.clear() — request sau ke thua MDC
}

✅ try-finally đảm bảo clear:

try { chain.doFilter(req, res); }
finally { MDC.clear(); }

❌ Nhầm 6: Đặt log file trong jar (không persist khi container restart).

logging:
  file:
    name: /app/logs/app.log     # bi mat khi container restart

✅ Mount volume hoặc dùng stdout (K8s standard) → container runtime forward log đến central:

# Khong config file, log ra stdout
logging:
  pattern:
    console: ...

❌ Nhầm 7: Bật DEBUG cho org.hibernate.SQL ở production. ✅ DEBUG SQL chỉ tạm thời debug N+1 hoặc bug query. Production: log volume bùng nổ → cost ELK + slow app. Tắt sau khi xong.

❌ Nhầm 8: Expose /actuator/loggers không auth. ✅ Bảo vệ endpoint qua Spring Security + tách management port. Attacker bật DEBUG → log volume DDoS app.

10. 📚 Deep Dive Spring Reference

11. Tóm tắt

• Boot logging stack: SLF4J facade + Logback impl + bridge libs (capture log từ JUL/Log4j 1.x/Commons Logging).
• Code app chỉ dùng SLF4J API — không bind vào implementation. Đổi Logback → Log4j2 không sửa code.
• 4 quy tắc SLF4J: static final logger / class, placeholder {} không concat, exception là param cuối, không log sensitive.
• 5 log level: TRACE/DEBUG/INFO/WARN/ERROR. Production default: INFO+. DEBUG tạm thời cho diagnostics.
• Hierarchy theo package — child inherit level. Set group qua logging.level.com.olhub.
• ~30 property logging.* đủ cho 90% config — pattern, file, rotation, level. logback-spring.xml cho custom appender phức tạp.
• <springProfile> tag trong logback-spring.xml cho conditional config theo profile.
• Structured logging Boot 3.4 GA: logging.structured.format.console=ecs → JSON output trực tiếp cho ELK. 3 format: ecs, gelf, logstash.
• MDC (Mapped Diagnostic Context) per-thread cho correlation ID. Pattern %X\{requestId\} trong layout. Filter try-finally MDC.clear().
• Dynamic log level runtime qua /actuator/loggers POST — debug production không restart.
• Đổi sang Log4j2 cho high-throughput app (>100k log/sec). Exclude logback starter, add log4j2 starter.
• Production pattern 2026: JSON log → stdout → container runtime capture → Filebeat/Fluentd → Elasticsearch/Loki. MDC correlation ID + ECS schema.

12. Tự kiểm tra

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

  public void place(Order o) {
      log.info("Placing order " + o.getId() + " for user " + o.getUserId());

      try {
          payment.charge(o);
      } catch (Exception e) {
          log.error("Failed: " + e.getMessage());
      }
  }
}

@Slf4j
@Service
public class OrderService {
  public void place(Order o) {
      log.info("Placing order {} for user {}", o.getId(), o.getUserId());

      try {
          payment.charge(o);
      } catch (PaymentException e) {
          log.error("Payment failed for order {}", o.getId(), e);
      }
  }
}

2026-04-15T10:00:00.123 INFO 12345 --- [main] com.olhub.OrderService : Order placed: id=42, total=99.99

{
"@timestamp": "2026-04-15T10:00:00.123Z",
"log.level": "INFO",
"process.pid": 12345,
"process.thread.name": "main",
"log.logger": "com.olhub.OrderService",
"message": "Order placed: id=42, total=99.99",
"service.name": "order-service",
"service.version": "1.2.3"
}

# Pattern log + Logstash
log_level:"INFO" AND service:"order-service" AND message:"Order placed"

# Structured ECS
log.level: "INFO" AND service.name: "order-service" AND message: "Order placed"

logging.structured.format.console: ecs

logging:
level:
  root: WARN
  com.olhub: INFO
  com.olhub.security: DEBUG
  com.olhub.security.AuthService: WARN

@Component
public class CorrelationIdFilter implements Filter {
  public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) throws IOException, ServletException {
      String requestId = ((HttpServletRequest) req).getHeader("X-Request-Id");
      if (requestId == null) requestId = UUID.randomUUID().toString();

      MDC.put("requestId", requestId);
      chain.doFilter(req, res);
      MDC.clear();
  }
}

@Component
public class CorrelationIdFilter implements Filter {
  public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) throws IOException, ServletException {
      String requestId = ((HttpServletRequest) req).getHeader("X-Request-Id");
      if (requestId == null) requestId = UUID.randomUUID().toString();

      MDC.put("requestId", requestId);
      try {
          chain.doFilter(req, res);
      } finally {
          MDC.clear();        // luon clear, ke ca khi exception
      }
  }
}

public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) throws IOException, ServletException {
  String requestId = ((HttpServletRequest) req).getHeader("X-Request-Id");
  if (requestId == null) requestId = UUID.randomUUID().toString();

  try (MDC.MDCCloseable mdc = MDC.putCloseable("requestId", requestId)) {
      chain.doFilter(req, res);
  }
}

Bài tiếp theo: Mini-challenge — trace 1 request từ main() qua từng layer + log mọi bean tạo