Engineering Note
로그가 병목이 될 때: Log4j2 Appender의 무거운 일을 요청 경로 밖으로 밀어내기
Log4j2 Custom Appender를 만들 때 hot path, bounded queue, AsyncAppender, throttling을 어떻게 바라보면 좋은지 실전 관점으로 정리합니다.
로그는 문제를 찾기 위해 남깁니다. 그런데 가끔은 로그를 남기는 코드가 문제를 만들기도 합니다.
예를 들어 주문 API가 평소보다 느려졌는데, 원인은 DB도 아니고 외부 결제 API도 아니고 “로그 전송 Appender가 수집 서버 응답을 기다리고 있었기 때문”이라면 어떨까요. 로그는 관측성을 위한 도구인데, 어느 순간 서비스의 요청 경로를 붙잡는 새 장애 지점이 됩니다.
이 글은 Log4j2 Custom Appender를 “어떻게 구현하나”보다 “어떻게 애플리케이션을 방해하지 않게 만드나”에 초점을 둡니다.
먼저 가져갈 결론
바쁘다면 이 다섯 가지만 기억해도 됩니다.
append()에서 네트워크 I/O를 하지 않습니다.- queue는 반드시 bounded로 둡니다.
- queue가 찼을 때 block, drop, failover 중 무엇을 할지 정합니다.
- drop이나 실패 보고도 throttling합니다.
AsyncAppender는 좋은 완충재지만 느린 Appender를 무해하게 만드는 마법은 아닙니다.
Custom Appender는 “로그를 어디로 보낼까”보다 “로그 때문에 서비스가 느려지지 않게 어떻게 막을까”가 먼저입니다.
Appender는 어디에 있나
Log4j2에서 Appender는 로그 이벤트를 목적지로 전달하는 컴포넌트입니다. 콘솔에 찍거나, 파일에 쓰거나, HTTP/Kafka/DB로 보내는 일이 Appender의 책임입니다.
흐름을 단순화하면 이렇습니다.
application code
-> Logger
-> LoggerConfig
-> Filter
-> AppenderRef
-> Appender.append(LogEvent)
-> destination
대부분의 Custom Appender는 Appender 인터페이스를 직접 구현하기보다 AbstractAppender를 확장합니다. 이름, filter, layout, lifecycle 같은 공통 기능을 이미 제공하기 때문입니다.
단, append(LogEvent event)가 호출되는 위치를 가볍게 보면 안 됩니다. 이 함수는 로그 호출 경로와 가까운 곳에 있습니다. 여기서 느린 일을 하면 로그 호출자가 같이 느려집니다.
Hot path에는 아무것도 올리지 않는다
append() 안에서 피해야 할 일부터 정해두면 설계가 쉬워집니다.
- HTTP 요청
- DB insert
- Kafka send 결과 대기
- DNS 조회
- 긴 retry loop
- 동기 압축
- 복잡한 JSON 변환
- 파일 시스템 상태를 반복 조회하는 일
- Appender 내부에서 application logger를 다시 호출하는 일
로그 호출은 코드 곳곳에 숨어 있습니다. 한 Appender가 느려지면 특정 기능 하나가 아니라 서비스 전체 tail latency가 흔들릴 수 있습니다.
좋은 append()는 보통 이 정도만 합니다.
started 상태 확인
필요한 데이터 스냅샷
bounded queue에 offer
실패하면 drop count 증가
가끔만 상태 보고
여기서 중요한 단어는 offer입니다. put처럼 오래 기다리는 호출은 hot path 보호와 잘 맞지 않습니다.
가장 단순한 구조
운영 로그용 Custom Appender라면 기본 구조는 다음처럼 잡을 수 있습니다.
Appender.append()
-> bounded queue offer
-> worker thread
-> batch
-> external sink
샘플 코드는 핵심만 남기면 이렇습니다.
@Plugin(
name = "Telemetry",
category = Node.CATEGORY,
elementType = Appender.ELEMENT_TYPE,
printObject = true
)
public final class TelemetryAppender extends AbstractAppender {
private static final StatusLogger STATUS = StatusLogger.getLogger();
private final BlockingQueue<LogEvent> queue;
private final AtomicLong dropped = new AtomicLong();
private final AtomicLong nextDropReportAt = new AtomicLong();
private final long dropReportIntervalNanos;
private TelemetryAppender(
String name,
Filter filter,
Layout<? extends Serializable> layout,
boolean ignoreExceptions,
int queueCapacity,
long dropReportIntervalMillis
) {
super(name, filter, layout, ignoreExceptions, Property.EMPTY_ARRAY);
this.queue = new ArrayBlockingQueue<>(queueCapacity);
this.dropReportIntervalNanos = TimeUnit.MILLISECONDS.toNanos(dropReportIntervalMillis);
}
@Override
public void append(LogEvent event) {
if (!isStarted()) {
return;
}
LogEvent snapshot = event.toImmutable();
if (!queue.offer(snapshot)) {
reportDropIfNeeded(dropped.incrementAndGet());
}
}
private void reportDropIfNeeded(long droppedNow) {
long now = System.nanoTime();
long next = nextDropReportAt.get();
if (now >= next && nextDropReportAt.compareAndSet(next, now + dropReportIntervalNanos)) {
STATUS.warn("TelemetryAppender queue is full; dropped {} events", droppedNow);
}
}
}
실제 운영 코드는 worker thread, batch 전송, timeout, 종료 drain, metrics가 더 필요합니다. 하지만 방향은 같습니다. append()는 얇게 두고, 무거운 일은 밖으로 밀어냅니다.
LogEvent는 복사해서 넘긴다
worker thread에서 나중에 이벤트를 읽을 거라면 event.toImmutable() 같은 스냅샷을 고려해야 합니다. Log4j2는 비동기 로깅과 이벤트 재사용 최적화를 갖고 있어서, 원본 LogEvent를 다른 thread에서 뒤늦게 읽는 방식은 위험해질 수 있습니다.
더 안전하고 비용을 예측하기 쉬운 방법은 아예 필요한 필드만 작은 객체로 떼어내는 것입니다.
record LogRecord(
long timestampMillis,
String level,
String loggerName,
String message,
String thrown
) {}
이렇게 하면 layout 변환을 worker로 미룰지, append()에서 최소 문자열만 만들지 같은 판단도 명확해집니다. 단, append()에서 문자열 변환을 많이 하면 다시 hot path 비용이 커집니다.
Queue가 찰 때가 진짜 설계다
평상시에는 어떤 Appender도 멀쩡해 보입니다. 차이는 장애 상황에서 납니다.
수집 서버가 느려지고 queue가 찼을 때 선택지는 대략 세 가지입니다.
| 정책 | 장점 | 위험 |
|---|---|---|
| block | 로그 유실이 적다 | 요청 thread가 멈출 수 있다 |
| drop | 애플리케이션 보호가 쉽다 | 로그가 사라진다 |
| failover | 다른 경로로 보낼 수 있다 | 구성과 운영이 복잡해진다 |
운영 로그라면 보통 drop + counter + throttled warning이 가장 예측 가능합니다. 감사 로그나 결제 증적처럼 유실이 비즈니스 문제라면 이 모델을 쓰면 안 됩니다. 그런 로그는 outbox, 트랜잭션 저장, 동기 failover 같은 별도 설계를 먼저 봐야 합니다.
Throttling은 친절이 아니라 안전장치다
queue가 찰 때마다 경고 로그를 찍으면 어떤 일이 생길까요?
로그가 많아서 queue가 찼는데, queue가 찼다는 로그를 다시 찍습니다. 그리고 그 로그도 Appender를 탑니다. 장애를 설명하려다 장애를 키우는 셈입니다.
그래서 Appender 내부의 상태 보고는 제한해야 합니다.
10초에 한 번만 보고
누적 drop count만 요약
일반 application logger 재호출 금지
가능하면 metrics counter로 노출
전송 실패 경고도 마찬가지입니다. 실패할 때마다 stack trace를 남기는 코드는 장애 상황에서 매우 시끄럽고 비쌉니다.
AsyncAppender로 감싸면 충분할까
Log4j2에는 Async Appender가 있습니다. Custom Appender 앞에 둘 수 있습니다.
Application thread
-> Logger
-> AsyncAppender queue offer
-> background thread
-> TelemetryAppender.append()
-> external sink
XML 설정은 이렇게 됩니다.
<Appenders>
<Telemetry
name="Telemetry"
queueCapacity="8192"
dropReportIntervalMillis="10000"
ignoreExceptions="true">
<PatternLayout pattern="%d{ISO8601} %-5level [%t] %logger - %msg%n%throwable"/>
</Telemetry>
<Async
name="AsyncTelemetry"
bufferSize="8192"
blocking="false"
shutdownTimeout="5000"
includeLocation="false">
<AppenderRef ref="Telemetry"/>
</Async>
</Appenders>
<Loggers>
<Root level="INFO" includeLocation="false">
<AppenderRef ref="AsyncTelemetry" level="WARN"/>
</Root>
</Loggers>
YAML은 다음처럼 쓸 수 있습니다.
Configuration:
status: WARN
Appenders:
Telemetry:
name: Telemetry
queueCapacity: 8192
dropReportIntervalMillis: 10000
ignoreExceptions: true
PatternLayout:
pattern: "%d{ISO8601} %-5level [%t] %logger - %msg%n%throwable"
Async:
name: AsyncTelemetry
bufferSize: 8192
blocking: false
shutdownTimeout: 5000
includeLocation: false
AppenderRef:
ref: Telemetry
Loggers:
Root:
level: INFO
includeLocation: false
AppenderRef:
ref: AsyncTelemetry
level: WARN
여기서 blocking이 중요합니다. Async Appender는 queue가 찼을 때 기다릴 수 있습니다. hot path 보호가 목표라면 blocking="false"를 검토해야 합니다. 대신 이 경우 이벤트가 errorRef로 가거나 손실될 수 있으니 운영 요구사항과 맞춰야 합니다.
그럼 Custom Appender 내부 queue와 AsyncAppender를 둘 다 둬야 할까요?
대부분은 둘 중 하나를 먼저 선택하는 편이 좋습니다.
- 빠르게 caller thread와 분리하고 싶다:
AsyncAppender로 감싼다. - drop, batch, retry, metrics를 세밀하게 통제하고 싶다: Custom Appender 내부 bounded queue를 둔다.
- 둘 다 둔다: double queue가 되므로 지연, drop 위치, 종료 drain, metrics 의미를 명확히 정한다.
플러그인 등록에서 자주 막히는 곳
Log4j2 설정 파일에서 <Telemetry>를 쓰려면 Appender가 plugin으로 발견되어야 합니다.
필요한 것은 두 가지입니다.
- 클래스에
@Plugin을 붙입니다. - 빌드 시
Log4j2Plugins.dat가 생성되도록 annotation processor를 실행합니다.
Maven 예시는 다음과 같습니다.
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-compiler-plugin</artifactId>
<configuration>
<annotationProcessorPaths>
<path>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>${log4j2.version}</version>
</path>
</annotationProcessorPaths>
<annotationProcessors>
<processor>org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor</processor>
</annotationProcessors>
</configuration>
</plugin>
Gradle이라면:
dependencies {
implementation("org.apache.logging.log4j:log4j-api:${log4j2Version}")
implementation("org.apache.logging.log4j:log4j-core:${log4j2Version}")
annotationProcessor("org.apache.logging.log4j:log4j-core:${log4j2Version}")
}
YAML 설정을 사용한다면 런타임 classpath에 YAML parser도 필요합니다. 일반적으로 com.fasterxml.jackson.dataformat:jackson-dataformat-yaml을 함께 둡니다.
마지막 체크리스트
배포 전에 이 질문에 답할 수 있어야 합니다.
append()에서 외부 I/O를 하지 않는가?- queue는 bounded인가?
- queue가 찼을 때 block, drop, failover 중 무엇을 하는가?
- drop count를 metrics로 볼 수 있는가?
- drop warning과 전송 실패 warning은 throttling되는가?
- Appender 내부에서 application logger를 다시 호출하지 않는가?
- worker 종료 시 남은 이벤트를 어떻게 처리하는가?
- 외부 client timeout은 짧고 명확한가?
- retry는 bounded인가?
includeLocation이 정말 필요한가?ignoreExceptions정책이 로그의 비즈니스 중요도와 맞는가?
마무리
Custom Appender는 기능을 붙이는 지점이 아니라 책임을 제한하는 지점입니다.
좋은 Appender는 장애 상황에서 조용히 애플리케이션을 보호합니다. 빨리 받고, 제한된 큐에 넣고, 너무 많으면 정해진 정책대로 버리거나 우회하고, 그 사실을 metrics와 제한된 경고로 알려줍니다.
Konduo가 다루는 운영 관점도 이와 닿아 있습니다. 로그, 메트릭, 알림은 따로 흩어진 신호가 아니라 문제를 판단하고 대응하기 위한 근거이므로, Konduo는 여러 인프라 리소스의 상태와 메트릭·로그 근거, 알림 대응을 하나의 흐름으로 연결하는 통합 관리 운영 플랫폼으로 설계되어 있습니다.
로그는 서비스를 보기 위한 창이어야 합니다. 서비스가 그 창을 닦느라 멈추면 안 됩니다.
참고 자료
- Apache Log4j Appenders
- Apache Log4j Delegating Appenders
- Apache Log4j Plugins
- Apache Log4j Asynchronous Loggers
- Apache Log4j Configuration
함께 읽기 좋은 글
이 글의 관점과 이어지는 주제를 더 보려면 아래 글도 함께 읽어볼 수 있습니다.
- 수정하지 않을 YAML 로그를 왜 전부 객체로 만들까 - immutable 로그를 전체 객체로 만들지 않고 선별하는 관점을 다룹니다.
- JVM 메트릭만으로는 컨테이너를 설명할 수 없다 - JVM 밖의 cgroup, filesystem, fd, I/O 신호를 함께 봐야 하는 이유를 다룹니다.
- Consumer Lag은 건강 점수가 아니다: Kafka Consuming Pressure라는 관점 - consumer lag을 처리 압력 관점으로 다시 해석합니다.