chore: 로그 출력을 비동기 appender 로 분리

[tnals0924]

#️⃣연관된 이슈

• Closes chore: 로그 출력을 비동기 appender 로 분리 #153

🎯 해결하려는 문제가 무엇인가요?

로그를 쓰는 비용이 응답시간에 그대로 실리고 있습니다.

이 레포에는 logback-spring.xml 이 없어 Spring Boot 기본 CONSOLE appender 로 동작합니다. Logback 의 ConsoleAppender 는 OutputStreamAppender 를 상속하고 write 가 동기화돼 있습니다. 톰캣 스레드 100개가 한 스트림에 쓰면 그 락에서 직렬화됩니다.

#151 에서 dev 의 SQL 콘솔 출력을 껐더니 GET /admin/members/payers 의 p95 가 452ms → 240ms 로 줄었습니다 (100 VU / 5분, payer 2천 건). 쿼리 자체는 1ms 미만인데 응답시간의 절반이 stdout 쓰기였다는 뜻입니다.

출력량을 줄여 절반을 회수했지만 구조는 그대로입니다. LoggingFilter 가 요청마다 남기는 한 줄이 여전히 같은 경로로 나갑니다.

❓ 왜 해결해야 하나요?

출력을 더 줄이는 건 한계가 있습니다. LoggingFilter 의 요청 로그는 운영에 필요하고, 이걸 지우면 응답시간은 좋아져도 관측성을 잃습니다.

로그를 줄이는 대신 요청 경로에서 빼는 게 맞습니다. 그러면 로그를 유지하면서 응답시간에서 I/O 를 분리할 수 있습니다.

⭐ 어떻게 해결했나요?

src/main/resources/logback-spring.xml 을 추가해 CONSOLE 을 AsyncAppender 로 감쌌습니다. 요청 스레드는 큐에 넣기만 하고 실제 출력은 워커 스레드가 맡습니다.

<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

<appender name="ASYNC_CONSOLE" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="CONSOLE"/>
    <neverBlock>true</neverBlock>
    <discardingThreshold>0</discardingThreshold>
    <queueSize>4096</queueSize>
    <includeCallerData>false</includeCallerData>
</appender>

기본값 두 개는 의도와 맞지 않아 명시적으로 바꿨습니다. 이 부분이 이 PR 의 핵심입니다.

옵션	기본값	기본값의 문제	선택
discardingThreshold	20	큐가 80% 차면 INFO 이하를 조용히 버린다. LoggingFilter 의 요청 로그가 INFO 라 정작 부하가 걸린 순간의 로그가 사라진다	0 — 레벨과 무관하게 큐에 자리가 있는 한 남긴다
neverBlock	false	큐가 가득 차면 요청 스레드를 블로킹한다. 비동기로 만든 이유가 사라진다	true — 넘치면 버린다
includeCallerData	false	true 면 이벤트마다 스택 트레이스를 떠서 동기보다 느려질 수 있다	기본값 유지 (명시만)

discardingThreshold: 0 + neverBlock: true 조합은 "큐에 자리가 있는 한 다 남기고, 완전히 차면 블로킹 대신 버린다" 는 뜻입니다.

커스텀 설정 파일이 있으면 Spring Boot 기본 로깅 설정이 통째로 대체되므로, 로그 포맷과 CONSOLE appender 정의는 defaults.xml / console-appender.xml 을 include 해 그대로 씁니다. 기존 로그 포맷은 바뀌지 않습니다.

🧩 이 PR의 한계 & 트레이드오프

개선 효과를 아직 측정하지 않았습니다. 배포 후 같은 조건(100 VU / 5분)으로 재측정이 필요합니다. #151 에서 SQL 출력(요청당 2~3줄)을 없애 절반을 회수했으니, 남은 1줄을 비동기로 빼는 효과는 그보다 작을 것으로 예상합니다. 240ms 가 전부 로깅 때문은 아닐 것이고, 남는 부분은 별도로 봐야 합니다.

로그가 유실될 수 있습니다. neverBlock: true 라 큐(4096)가 가득 차면 이벤트를 버립니다. 응답시간을 지키는 게 목적이라 블로킹보다 유실을 택했습니다. 감사 로그처럼 유실되면 안 되는 게 생기면 그건 별도 동기 appender 로 빼야 합니다.

비정상 종료 시 큐에 남은 로그가 사라집니다. 정상 종료(server.shutdown: graceful + Spring Boot 의 로깅 종료 훅)에서는 maxFlushTime(기본 1초) 동안 비웁니다. SIGKILL 은 해당하지 않습니다.

로그 순서가 미세하게 달라질 수 있습니다. 로깅 프레임워크를 통한 출력끼리는 순서가 보장되지만, println 같은 직접 출력과 섞이면 인터리빙이 달라질 수 있습니다.

⛓️ 기존 기능에 미치는 영향

애플리케이션 동작에는 영향이 없습니다.

로그 포맷·목적지는 그대로입니다. Spring Boot 기본 정의를 include 해서 씁니다.

logging.level.* 설정은 계속 동작합니다. Spring Boot 의 LogbackLoggingSystem 이 설정 파일을 읽은 뒤 logging.level.* 프로퍼티를 덧씌우는 순서라, #151 에서 추가한 org.hibernate.SQL 레벨 조정도 그대로 먹습니다.

모든 프로파일에 적용됩니다. local 포함입니다 (아래 대안 참고).

🔀 Edge Case & 실패 시나리오

상황	동작
큐에 자리 있음 (정상)	요청 스레드는 큐에 넣고 즉시 반환
큐가 80% 참	discardingThreshold: 0 이라 계속 다 받는다 (기본값이면 INFO 유실)
큐가 가득 참	neverBlock: true 라 이벤트를 버리고 요청 스레드는 진행 (기본값이면 블로킹)
정상 종료	maxFlushTime 기본 1초 동안 큐를 비운다
비정상 종료	큐에 남은 로그 유실
ERROR 로그 폭증	스택 트레이스가 커도 includeCallerData: false 라 추가 비용 없음. 큐가 차면 유실

📋 검토한 대안과 선택 이유

LoggingFilter 를 없애거나 로그를 더 줄이는 방법 — 응답시간은 확실히 좋아지지만 요청 단위 관측성을 잃습니다. 문제는 로그의 존재가 아니라 로그가 요청 스레드를 붙잡는 구조라 봤습니다.

파일 appender 로 목적지를 바꾸는 방법 — 콘솔보다 빠르지만 여전히 동기이고, CapRover(Docker) 가 stdout 을 수집하는 구조라 로그 수집 파이프라인을 새로 만들어야 합니다. 얻는 것에 비해 변경이 큽니다.

local 은 동기로 두고 dev/prod 만 비동기로 하는 방법 — <springProfile> 로 나눌 수 있습니다. 로컬 디버깅 시 로그가 즉시·순서대로 보이는 이점이 있습니다. 다만 spring.profiles.active: ${profile} 이 환경변수라, 값이 예상 밖이면 어느 <springProfile> 도 매칭되지 않아 root 에 appender 가 하나도 안 붙어 로그가 통째로 사라지는 경로가 생깁니다. 그 위험이 로컬 편의보다 크다고 보고 전 프로파일 공통으로 두었습니다.

queueSize 를 더 크게 잡는 방법 — 유실 가능성은 줄지만, 지속적으로 큐가 차는 상황이면 크기를 늘려도 결국 버립니다(소비 속도가 문제). 버스트 흡수용으로 4096 이면 충분하다고 봤습니다. 이벤트당 약 1KB 로 가득 차도 4MB 남짓입니다.

💬 리뷰 포인트

• [r] neverBlock: true 로 로그 유실을 허용한 판단을 봐주세요. 응답시간 > 로그 완전성으로 정했는데, 이 서비스에서 유실되면 곤란한 로그가 있다면 알려주세요.
• [c] queueSize: 4096 이 적절한지 봐주세요. 인스턴스 메모리가 빠듯하면 줄이겠습니다.
• [c] local 까지 비동기로 둔 게 불편하면 <springProfile> 로 나누되, 매칭 실패 시 폴백을 두는 형태로 바꾸겠습니다.
• [a] 지금은 콘솔만 있습니다. 나중에 파일이나 외부 수집기를 붙일 때도 이 AsyncAppender 안쪽에 appender-ref 를 추가하는 형태로 확장됩니다.

🧪 테스트

설정 검증

• XML well-formed 확인 (xmllint --noout)
• include 대상 리소스가 실제로 존재하는지 확인 — spring-boot-3.4.1.jar 안에 defaults.xml, console-appender.xml 존재
• console-appender.xml 이 정의하는 appender 이름이 CONSOLE 인지 확인
• AsyncAppender 클래스 존재 확인 — logback-classic-1.5.12.jar

하지 않은 것

• 애플리케이션 기동 확인
• 부하 테스트 재측정 (배포 후 필요)