이번 글에서는 Log4j2 공식 문서를 읽어보려고 한다.
사실 해당 글을 위해서 LMAX Disruptor에 대해서 필자가 논문부터 User Guide까지 다 읽고왔다.
그래서 Log4j2 공식문서는 못읽고 LMAX Disruptor만 읽게 되어서... 시간이 많이 걸리게 되었다.
고로, 해당 문서를 읽으면서 Disruptor관련해서 내용이 나오면 다음 키메라가 정리한 글을 쭈욱 읽어보면 도움이 될 것이다.
[Java] LMAX Disruptor 공식문서 읽기 1 : 1. Overview ~ 2.6 Pipelines and Graphs
[Java] LMAX Disruptor 공식문서 읽기 2 : 3. Design of the LMAX Disruptor ~ 6. Conclusion
[Java] LMAX Disruptor 공식문서 읽기 3 : Disruptor 개발자의 블로그 글 읽기
[Java] LMAX Disruptor 공식문서 읽기 4 - 마지막 : Disruptor 코드 탐방하기
목표
1. Log4j2의 에 대해 알아본다.
1. Log4j2는 뭔가?
Apache Log4j 2는 이전 버전인 Log4j 1.x에 비해 상당한 개선 사항을 제공하는 Log4j의 업그레이드 버전이며, Logback에서 제공되는 많은 개선 사항을 포함하는 동시에 Logback 아키텍처의 고유한 문제점을 해결합니다.
출처 : https://logging.apache.org/log4j/2.12.x/
------------
Apache Log4j는 다양한 사용 사례에 맞춰 배포를 지원하는 API, 구현체 및 구성 요소로 이루어진 다목적 산업용 Java 로깅 프레임워크입니다.
이 프로젝트는 자원봉사자 팀에 의해 활발하게 유지 관리되고 있으며, 대규모 커뮤니티의 지원을 받고 있습니다.
출처 : https://logging.apache.org/log4j/2.x/index.html
개인적으로는 log4j2를 검색하면 크게 다르지 않는 내용을 2개의 사이트가 설명을 하는데,
1번 사이트가 필자는 더 보기 좋았다. 뭔가 더 보기 좋고 더 많은 정보를 담고 있는 느낌?
여러가지 정보들을 한눈에 볼 수 있도록 잘 만들어놓았다는 개인적인 생각! 하여간...
사실 필자가 궁금한던 부분은 다른게 아니다.
개인적으로 필자가 궁금해하는 부분은 Log4j2 Introduction의 글이었다.
1. LMAX Disruptor가 뭔지
2. Garbage Free하게 어떻게 만들수 있는건지
이것이 궁금했다.
2. LMAX Disruptor
글을 시작하기에 앞서 LMAX Disruptor에 대해 이해하기 위해서 필자는 공식문서를 찾아서 읽어 정리했다.
그 글에서 Disruptor가 뭔지 정리를 했다.
Discruptor란 뭔가?(What is the discruptor)
LMAX는 세계에서 가장 빠른 트레이딩 플랫폼을 지향하는데 자바 플랫폼 위에서 저지연(low-latency), 고처리량(high-throughput) 작업을 해야하는데 일반적인 queue를 사용하면 이것이 잘 안되서 최적화를 하는데 집중했다고 한다.
Discruptor는 이러한 과정에서 나온 결과로 CPU-level에서 캐시 미스와 커널 관리(kernel arbitration)를 요구하는 락들이 극도록 비용이 많이 들어서 lock-free이면서 작동하는 하드웨어를 위한 기계적 동감(mechanical sympathy)을 만족하는 프레임워크를 만들었다.
LMAX Disruptor의 Technical Paper의 초록을 정리하면 다음과 같다.
기존 방식의 한계 (문제 제기)
기존 애플리케이션에서 프로세스 간 데이터 교환을 위해 사용하는 큐(Queue)는 디스크 I/O에 필적할 만큼 심각한 지연 시간(Latency)을 발생시킵니다.
특히 멀티스레드 구현 시 발생하는 구조적인 경합(Contention) 문제로 인해 고성능 시스템을 구축하는 데 근본적인 한계가 있었습니다.
해결책 (Disruptor의 원리)
이러한 문제를 해결하기 위해 CPU 하드웨어의 실제 동작 방식을 이해하고 최적화하는 '기계적 공감(Mechanical Sympathy)' 원칙을 적용했습니다.
복잡한 관심사를 분리하여 쓰기 경합을 최소화하고, CPU 캐시 친화적(Cache-friendly)으로 동작하는 새로운 데이터 구조이자 동시성 프로그래밍 패턴인 Disruptor를 고안했습니다.
압도적인 성능 개선
기존 큐 기반 아키텍처와 비교했을 때 지연 시간은 3자릿수(1/1000) 수준으로 감소했으며, 동일한 환경에서 처리량(Throughput)은 8배 증가했습니다.
적당한 클럭의 프로세서에서도 초당 2,500만 건 이상의 메시지를 처리하며 50 나노초(ns) 이하의 지연 시간을 기록했습니다.
범용성과 적용성
이는 단순히 금융 도메인(LMAX 거래소)에만 국한된 특수 기술이 아닙니다. 고처리량 및 초저지연이 필수적인 모든 비동기 이벤트 처리 아키텍처에 적용할 수 있는 범용적인 동시성 제어 메커니즘이며, 기존 메커니즘보다 오히려 구현이 더 단순합니다.
요약하자면, 멀티스레드 환경의 락(Lock)과 경합 병목을 하드웨어(CPU 캐시) 수준의 이해를 바탕으로 풀어내어, 소프트웨어의 극한 성능을 이끌어낸 아키텍처 패턴이라고 할 수 있습니다.
이렇게 고성능을 사용할 수 있도록 입증된 LMAX Disruptor를 채택함으로 성능을 올린 것이다.
3. Garbage Free하다?
IT 에서 Garbage 는 더이상 다른 객체에 의해 참조되지 않는 객체를 말한다.
JVM에서는 알아서 Garbage Collection으로 Garbage를 처리해준다. 그런데 Garbage Free 하다?
뭔가 ... Garbage자체가 발생하지 않도록 하는것 같은데... 확실히 알기 위해 검색을 해봤다.
뭔가 잘 안나오니 log4j2의 공식문서에서 garbage free 를 어덯게 설명하는지 보도록 하자.
가비지 컬렉션 일시 중지는 지연 시간 급증의 일반적인 원인이며, 많은 시스템에서 이러한 일시 중지를 제어하는 데 상당한 노력을 기울입니다.
이전 버전의 Log4j를 포함한 많은 로깅 라이브러리는 정상 상태 로깅 중에 로그 이벤트 객체, 문자열, 문자 배열, 바이트 배열 등과 같은 임시 객체를 할당합니다. 이는 가비지 컬렉터에 부담을 주고 GC 일시 중지가 발생하는 빈도를 높입니다.
Log4j는 버전 2.6부터 기본적으로 "가비지 프리(garbage free)" 모드로 실행됩니다. 이 모드에서는 객체와 버퍼가 재사용되고 임시 객체 할당이 최대한 줄어듭니다. 또한 완전히 가비지 프리는 아니지만 ThreadLocal 필드를 사용하지 않는 "로우 가비지(low garbage)" 모드도 있습니다.
Log4j가 웹 애플리케이션에서 실행 중임을 감지하면 기본적으로 이 모드가 사용됩니다. 마지막으로, 모든 가비지 프리 로직을 비활성화하고 "클래식 모드(classic mode)"로 실행할 수도 있습니다.
그러니까 가비지 컬렉터에 부담을 주지 않기 위해 객체와 버퍼를 재사용하는 특별한 모드를 garbage free 모드라고 한다.
Contribed Example(꾸며낸 예시) 섹션에서는 다음의 성능 차이를 보여준다.
여기서 이해가 안되는 부분이 있었으니... Configuration 에서 다음 부분이다.
Log4j 2.6의 가비지 없는 로깅은 ThreadLocal 필드의 객체 재사용과 텍스트를 바이트로 변환할 때 버퍼 재사용을 통해 부분적으로 구현됩니다. JDK 클래스가 아닌 클래스를 저장하는 ThreadLocal 필드는 웹 애플리케이션이 배포 해제된 후에도 애플리케이션 서버의 스레드 풀이 해당 필드를 계속 참조할 경우 웹 애플리케이션에서 메모리 누수를 일으킬 수 있습니다.
메모리 누수를 방지하기 위해 Log4j는 웹 애플리케이션에서 사용되는 경우(클래스 경로에 javax.servlet.Servlet 클래스가 있거나 시스템 속성 log4j2.isWebapp이 "true"로 설정된 경우) 해당 ThreadLocal을 사용하지 않습니다. 일부 가비지 감소 기능은 ThreadLocal에 의존하지 않으며 모든 애플리케이션에서 기본적으로 활성화됩니다.
Log4j 2.6에서는 로그 이벤트를 텍스트로, 텍스트를 바이트로 변환할 때 중간에 문자열, 문자 배열, 바이트 배열을 생성하지 않고 텍스트를 재사용 가능한 ByteBuffer에 직접 인코딩할 수 있습니다. 웹 애플리케이션의 로깅이 아직 완전히 가비지 없는 것은 아니지만, 가비지 컬렉터에 가해지는 부담은 여전히 크게 줄일 수 있습니다.
이게 도대체 무슨 말인가? ThreadLocal이 뭐? 메모리 누수를 일으킬 수 있다고? 어떻게 그렇지? ThreadLocal이 뭐길래?
이 부분은 필자가 자바의 메모리 참조 구조와 tomcat(was)의 동작 방식이 엮이면서 이해하지 못한 부분이다.
이를 잘 몰라서 Gemini에게 질문했다. 궁금하면 이를 열어보길 바란다.
이해하기 까다로운 부분이 맞습니다. `ThreadLocal` 자체가 메모리를 새게 만드는 것이 아니라, **자바의 메모리 참조 구조**와 **Tomcat(WAS)의 동작 방식**이 엮이면서 발생하는 연쇄 작용이기 때문입니다.
이 누수가 발생하는 원리와 구조를 가장 핵심적인 4단계로 끊어서 다시 설명해 드리겠습니다.
### 1단계: Tomcat 스레드의 생명주기 (스레드는 죽지 않는다)
일반적인 Spring Boot + 내장 Tomcat 환경(또는 외부 Tomcat 환경)에서는 요청이 들어올 때마다 스레드를 생성하지 않습니다. 미리 200개 정도의 스레드를 '스레드 풀(Thread Pool)'에 만들어 두고, 요청이 오면 빌려줬다가 끝나면 다시 풀로 회수합니다.
즉, **WAS의 스레드는 애플리케이션이 돌아가는 내내 절대 죽지 않고 살아있습니다.**
### 2단계: Log4j2의 객체 적재 (Garbage-Free 동작)
Garbage-Free 로깅이 켜져 있다고 가정해 보겠습니다.
사용자의 요청이 들어와서 Tomcat이 1번 스레드를 할당했습니다. 이 스레드가 로그를 남길 때, Log4j2는 객체 생성을 피하기 위해 1번 스레드의 고유한 주머니인 `ThreadLocal`에 로깅용 `StringBuilder` 객체를 쏙 넣어둡니다.
요청 처리가 끝난 뒤 1번 스레드는 스레드 풀로 돌아갑니다. **하지만 스레드의 주머니(`ThreadLocal`) 안에는 여전히 `StringBuilder` 객체가 남아있습니다.**
### 3단계: 애플리케이션 재배포 (문제의 발생)
개발자가 코드를 수정해서 애플리케이션(WAR)만 새롭게 재배포(Hot Deploy)했다고 가정해 보겠습니다.
이때 WAS는 이전 애플리케이션을 구동하던 **'구버전 클래스 로더(ClassLoader)'**를 버리고, 새 애플리케이션을 위한 **'신버전 클래스 로더'**를 생성합니다.
정상적인 상황이라면 구버전 클래스 로더와 그 안에 있던 수많은 클래스 정보들은 가비지 컬렉터(GC)에 의해 메모리에서 완전히 삭제되어야 합니다.
### 4단계: 꼬리를 무는 강력한 참조 (누수의 완성)
바로 여기서 가비지 컬렉터가 구버전 클래스 로더를 삭제하지 못하는 **'참조의 사슬'**이 발생합니다. 자바의 모든 객체는 자신을 생성한 클래스를 기억하고, 클래스는 자신을 메모리에 올린 클래스 로더를 기억하기 때문입니다.
메모리 안에서는 다음과 같이 참조가 이어져 있습니다.
1. **스레드 풀의 1번 스레드** (Tomcat이 쥐고 있으므로 죽지 않음)
2. **-> 스레드의 `ThreadLocal` 주머니** (스레드가 살아있으니 주머니도 살아있음)
3. **-> `StringBuilder` 객체** (Log4j2가 주머니에 넣어둔 채 안 지움)
4. **-> `StringBuilder` 객체의 클래스 정보** (객체가 살아있으니 클래스 정보도 살아있어야 함)
5. **-> 구버전 클래스 로더 (`WebappClassLoader`)** (클래스가 살아있으니 클래스 로더도 죽일 수 없음)
**결론적으로, 스레드 풀에 살아있는 스레드 단 하나가 무심코 주머니에 들고 있던 작은 로깅 객체 하나 때문에, 수십 MB에 달하는 구버전 애플리케이션의 메타데이터 전체(클래스 로더)가 메모리에서 지워지지 못하고 좀비처럼 남아있게 됩니다.**
이런 식으로 재배포가 몇 번 반복되면, 지워지지 못한 클래스 로더들이 JVM의 메타스페이스(Metaspace) 영역을 꽉 채워버리면서 결국 `OutOfMemoryError: Metaspace`를 발생시키고 서버를 다운시킵니다.
이것이 Log4j2가 WAS 환경임을 감지하면, 이런 구조적 대참사를 막기 위해 Garbage-Free(`ThreadLocal` 사용) 기능을 강제로 꺼버리는 이유입니다.
필자는 class loader의 역할을 전에 공부해서 정리했는데 찾지를 못해서... 다시 그려놓은걸 첨부한다.
Class Loader의 역할은 로딩, 링킹, 초기화인데 이중에서 한 하나의 객체만! 살아남아도 해당 애플리케이션의 클래스 로더 전체가 가비지 컬렉션 대상에서 제외된다고 한다.
아니 근데... GC대상이 원래 Heap영역의 Eden, Survivor 혹은 Old아니었어? 내가 그린 그림이 잘못된건가?
알아보니 Class Loader가 런타임 데이터 영역(메모리)밖에 그려진 이유는 메모리에 데이터를 집어넣는 주체임을 표현하기 위함이지 이것이 실제로 별도로 분리된것이 아니란다. 더 궁금하면 다음을 열어보길 바란다.
올려주신 다이어그램은 **전혀 틀리지 않았습니다.** 아주 정확한 표준 JVM 아키텍처 구조도입니다.
혼란이 오신 이유는, 이 다이어그램이 보여주는 **'기능적/개념적 구조'**와 실제 JVM이 메모리에 객체를 할당하는 **'물리적 메모리 구조'** 간의 차이 때문입니다.
그림에 있는 `Class Loader`와 제가 힙(Heap)에 있다고 말씀드린 `ClassLoader`의 차이를 로우 레벨 관점에서 분리해서 설명해 드리겠습니다.
### 1. 다이어그램의 Class Loader: "기능적 서브시스템 (Subsystem)"
올려주신 그림의 좌측에 있는 `Class Loader` 상자는 메모리 영역(Runtime Data Areas) 바깥에 존재합니다. 이는 데이터를 저장하는 공간이 아니라, **".class 파일을 읽어서 메모리(Method Area)에 적재하는 JVM의 동작 엔진(모듈)"**을 추상화하여 표현한 것입니다.
즉, "로딩 -> 링크 -> 초기화"라는 프로세스 자체를 담당하는 시스템 구성 요소로서 그려진 것입니다.
### 2. 제가 말씀드린 ClassLoader: "Java 객체 (Instance)"
그렇다면 저 서브시스템은 실제로 어떻게 구현되어 있을까요? JVM의 핵심 내장 로더를 제외한 거의 모든 클래스 로더는 **우리가 흔히 아는 평범한 Java 클래스(`java.lang.ClassLoader`를 상속받은 객체)**로 구현되어 있습니다.
여기서 핵심적인 구분이 들어갑니다.
* **Bootstrap ClassLoader:** JVM을 기동할 때 가장 먼저 실행되는 로더입니다. 보통 C나 C++ 같은 네이티브 코드로 작성되어 JVM 자체에 내장되어 있습니다. 따라서 이 녀석은 자바 객체가 아니며, 힙 메모리에 존재하지 않습니다.
* **Extension / Application / Custom ClassLoader (Tomcat의 WebappClassLoader 등):** 얘네들은 전부 `java.lang.ClassLoader` 클래스를 상속받아 만들어진 **순수 Java 객체**입니다. Java 객체이므로 당연히 `new` 키워드 등을 통해 생성되며, **Runtime Data Areas 내부의 Heap 영역**에 인스턴스로서 존재하게 됩니다.
### 3. 메모리 영역별 실제 적재 구조
Tomcat 환경을 예로 들어 다이어그램의 메모리 영역(Runtime Data Areas)과 매칭해 보겠습니다.
1. **Heap 영역:**
* Tomcat이 생성한 `WebappClassLoader` **객체 인스턴스**가 존재합니다.
* Log4j2의 `StringBuilder` 같은 일반적인 인스턴스들이 존재합니다.
2. **Method Area (자바 8 이후 Metaspace):**
* Heap에 있는 `WebappClassLoader` 객체가 `.class` 파일을 읽어들여 파싱한 **클래스의 메타데이터**(메서드 코드, static 변수 구조, 상수 풀 등)가 여기에 저장됩니다.
### 요약하자면
다이어그램에서 클래스 로더가 런타임 데이터 영역(메모리) 밖에 그려진 것은 **"메모리에 데이터를 집어넣는 주체(엔진)"**임을 표현하기 위함입니다.
하지만 엔진 역할을 수행하기 위해 동작하는 **"클래스 로더 프로그램 자체(Tomcat의 WebappClassLoader)"**는 Java로 작성된 객체이므로, 결국 자신이 관리하는 메모리인 Heap 영역 한편에 자리 잡고 동작하는 구조입니다.
그렇기 때문에 힙 영역에 있는 Log4j2 객체가 힙 영역에 있는 `WebappClassLoader` 객체를 강하게 참조(Strong Reference)하고 있으면, 가비지 컬렉터는 이 클래스 로더 객체를 지우지 못합니다. 그리고 클래스 로더 객체가 살아있으므로, 그 로더가 Method Area(Metaspace)에 올려둔 메타데이터들 역시 지워지지 않고 OOM을 유발하게 되는 것입니다.
그 다음으로는 다음과 같은 설명을 한다.
1. garbage-free 로깅을 하지 않도로 하는 방법 (Disabling garbage-free Logging)
2. garbage-free한 appender
3. garbage-free한 filters
4. garbage-free한 지원 layout
재미있는 부분이 있는데, Autoboxing이 일어나는 경우에는 garbage-free하게 만들기 위해서는 코드를 적용해줘야만 한다고한다.
import static org.apache.logging.log4j.util.Unbox.box;
...
public void garbageFree() {
logger.debug("Prevent primitive autoboxing {} {}", box(10L), box(2.6d));
}
Logj4는 Unbox utility를 제공하는데, garbage-free하게 하고 싶은 경우 autoboxing이 일어나는 곳에 이것을 사용하면 된다.
이번 글을 더 정리하려고 했는데, 사실 Log4j2를 사용사는건 그냥 AI 딸깍! 해서 사용하면 될 듯 하다.
내부 코드 코드도 파악하려고 했는데, 솔직히 재미가 없었다. AI 때문에 내 머리가 절여졌다! (brain cooked!)
그렇지만 2개의 핵심 사항이 있으니, 그냥 읽어보고 아하 이런 것도 있구나~ 하는 정도면 된다는 판단이다.
의문사항에 대해 AI에게 물어보고, 이를 정리하는 일상이 되다보니 Gemini가 내 최고의 학습 멘토이자 선생이 되어버렸다.
출처:
[Java] LMAX Disruptor 공식문서 읽기 1 : 1. Overview ~ 2.6 Pipelines and Graphs
[Java] LMAX Disruptor 공식문서 읽기 2 : 3. Design of the LMAX Disruptor ~ 6. Conclusion
[Java] LMAX Disruptor 공식문서 읽기 3 : Disruptor 개발자의 블로그 글 읽기
[Java] LMAX Disruptor 공식문서 읽기 4 - 마지막 : Disruptor 코드 탐방하기
https://logging.apache.org/log4j/2.x/manual/garbagefree.html
https://logging.apache.org/log4j/2.x/index.html