- Apache Software Foundation에서 개발한 Java 기반의 로깅 유틸리티이며 Log4J의 업그레이드 버전입니다.
- Log4j에 비해 로깅 기능을 더욱 향상한 것으로 향상된 멀티스레드 환경에서의 성능, 로그 메시지의 더 나은 파라미터화, 로그 이벤트에 대한 더 많은 메타데이터 제공 등을 통해 로깅의 유연성과 확장성을 증가시켰습니다. - Log4j2는 Java 7 이상에서만 동작하며 Log4J 1.x, SLF4J, Commons Logging 및 java.util.logging과의 호환성을 유지하면서도 더욱 향상된 로깅 기능을 제공합니다.
2) Log4j2 비동기 로거(Asynchronous Loggers)
💡 Log4j2 비동기 로깅
- Log4j2 새로 추가된 기능으로 ‘로그 이벤트를 생성하는 스레드’와 ‘로그 이벤트를 처리하는 스레드’를 분리하여 로깅 시스템의 성능을 향상하는 로깅 방법을 의미합니다.
- '로그 이벤트를 생성하는 스레드’는 애플리케이션에서 수행되는 스레드로 로그 이벤트에 필요한 모든 정보를 캡처하기 위해 ‘최소한의 작업만으로 이벤트를 생성‘합니다. - '로그 이벤트를 처리하는 스레드’는 고성능 큐에서 관리되며 로그 벤트는 큐에 추가되고 별도의 스레드가 큐에서 이벤트를 꺼내서 로깅 처리를 합니다. 이러한 처리방식을 나눔으로써 로그 이벤트를 추가하는 데 걸리는 시간만 대기하면 되고 처리가 되는 큐에서는 비동기식으로 처리가 되기에 상대적으로 동기식 로깅에 비해 빠르게 수행이 됩니다.
- 또한 기존에 사용하는 동기식 로깅과 비동기식 로깅을 함께 혼합하여 구성할 수 있습니다.
[ 더 알아보기 ] 💡 백그라운드에서 처리가 된다고 했는데 백그라운드는 어디인가?
- 내부적으로 별도의 스레드 풀을 사용하여 백그라운드에서 실행됩니다. - 비동기식 Log4j2는 자체적으로 관리하는 스레드 풀을 사용하며 이를 통해 로깅 작업을 효율적으로 처리합니다. 스레드 풀의 크기와 동작 방식은 Log4j2의 설정 파일에서 구성할 수 있습니다.
💡 큐는 어떤 큐를 의미하는가?
- Log4j2에서는 Disruptor 프레임워크를 이용하여 큐를 구현하였습니다. - 비동기 로깅 이벤트에서는 ‘RingBuffer’라는 큐를 사용하여 이벤트 처리에 사용되었으며, ‘ArrayBlockingQueue’를 이용하여 비동기 Appender에서 사용이 되었습니다. - 이를 통해 비동기 처리를 위한 대기열의 잠금이 없는 스레드 통신으로 FIFO 형태의 큐 처리를 수행합니다.
💡 [참고] Disruptor의 RingBuffer
- 원형 버퍼 형태로 고정 길이의 배열에서 시작과 끝이 연결된 구조를 가지고 있습니다. 이를 통해, 빠른 데이터 추가와 제거를 가능하게 합니다.
- 고정된 길이를 가지는 FIFO(First In, First Out) 데이터 구조입니다. 이는 다중 스레드 환경에서 안전하게 사용할 수 있으며, 큐가 가득 찬 경우에는 더 이상 항목을 추가할 수 없고, 비어 있는 경우에는 항목을 제거할 수 없습니다. 이러한 특징 때문에 주로 생산자-소비자 문제의 해결에 사용됩니다.
💡 비동기 로깅 - 최대 처리량 비교 - 최대 처리량은 ‘이벤트가 급증’에 대해 유연하게 처리가 가능합니다.
- 해당 그래프에서는 동기 로거(Sync), 비동기 어펜더(Async Appender), 비동기 로거(Loggers all async)에 대한 스레드 별 처리량을 의미합니다. - 64개의 스레드를 사용한 테스트에서는 비동기 로거는 비동기 어펜더보다 12배 처리량이 높고 동기 로거보다는 68배가 빠릅니다. - 비동기 로거의 처리량은 스레드 수에 따라 증가하는 반면, 동기 로거와 비동기 어펜더는 모두 로깅을 수행하는 스레드 수에 관계없이 다소 일정한 처리량을 갖습니다.
- 결론적으로 비동기 로깅의 경우 더 많은 스레드의 수가 많아질수록 더 처리량 면에서 우수함을 보여주고 있습니다.
- 비동기 로거와 비동기 어펜더는 모두 로그 이벤트를 비동기적으로 처리합니다. 그러나 비동기 로거는 로그 이벤트가 생성되는 즉시 이를 비동기로 처리하지만 비동기 어펜더의 경우는 로그 이벤트가 생성된 후에 이를 비동기적으로 처리합니다. - 따라서 비동기 로거와 비동기 어펜더 사이의 차이는 로그 이벤트가 비동기적으로 처리되는 시점과 방식에 있습니다.
4. 비동기 로깅: 응답 시간
💡 비동기 로깅: 응답 시간 - 해당 그래프는 동시에 4개의 스레드를 사용하여 초당 64,000개의 메시지 처리에 대한 응답 및 대기시간을 보여줍니다.
- 비동기 로거는 GC(Garbage Collection)에 대한 응답 시간에 큰 영향을 미치지 않습니다. 이는 비동기 로거가 로그 이벤트를 생성하는 즉시 내부 큐에 넣기 때문에, GC 작업이 로그 이벤트 생성 스레드의 성능에 영향을 미치는 것을 크게 줄일 수 있습니다.
- 결론적으로 GC가 없는 비동기 로거는 테스트한 모든 구성중에 가장 좋은 응답 시간을 보였습니다.
💡 라이브러리 추가 : build.gradle - spring-boot-starter-log4j2: log4j2를 이용하기 위한 라이브러리를 설치하였습니다. - jackson-dataformat-yaml: log4j2 환경파일을 yaml 파일 형태로 구성하기 위해 설치하였습니다. - com.lmax:disruptor: log4j2의 비동기 처리를 위한 큐 사용을 위해 설치하였습니다.
4. properties 파일 내의 로깅 설정을 합니다: application.properties
# default Logging 프레임워크 설정 파일을 참조
logging.config=classpath:log4j2/log4j2-local.yml
# or
spring:
# logging slf4j
logging:
# default Logging 프레임워크 설정 파일을 참조
config: classpath:log4j2/log4j2-local.yml
5. 비동기로 사용되는 요소부터 확인해 봅니다.
💡 Configutation > Loggers > AsyncLogger
1차 분류
2차 분류
3차 분류
속성
설명
Configuration
로거의 전반적인 설정을 결정하는 항목
Configuration
Loggers
일반적인 로거의 정의를 위한 항목
Configuration
Loggers
AsyncLogger
비동기 로깅을 처리하는 항목
Configuration
Loggers
AsyncLogger
name
비동기 로거의 이름을 설정하는 속성
Configuration
Loggers
AsyncLogger
level
비동기 로거의 로깅 수준을 설정하는 속성
Configuration
Loggers
AsyncLogger
additivity
로거의 추가성을 설정하는 속성 (true 또는 false)
Configuration
Loggers
AsyncLogger
AppenderRef
로거가 참조하는 Appender를 설정하는 속성
Configutation:
# 구성 이름
name: multiflex-api-local
# [Loggers] 로그 출력 범위를 정의
Loggers:
# [Loggers - Root] 모든 로그를 기록하는 최상위 로그를 정의
Root:
level: OFF
AppenderRef:
- ref: console-appender
- ref: rolling-file-appender
# [Loggers - AsyncLogger] 비동기 로그 정의
AsyncLogger:
name: async-logger
level: DEBUG
additivity: false
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
# [Loggers - Loggers] 특정 패키지나 클래스에 대한 로그를 정의
Logger:
# 1. Spring Framework 로그 레벨 'INFO' 정의
- name: org.springframework
additivity: "false"
level: INFO
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
# 2. Spring Framework 로그 레벨 'DEBUG' 정의
- name: "com.adjh.multiflexapi"
additivity: "false"
level: DEBUG
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
6. 해당 파일들을 구성해 줍니다: src/resources/log4j2-local.yml
💡 해당 파일들을 구성해 줍니다: src/resources/log4j2-local.yml
Configutation:
# 구성 이름
name: multiflex-api-local
# [Properties] 설정에 사용되는 속성들을 정의
Properties:
Property:
- name: "log-path"
value: "./logs"
- name: "charset-UTF-8"
value: "UTF-8"
- name: "layout-pattern"
value: "%style{%d{UTF-8}}{black} %highlight{%-5level} [%style{%t}{bright,blue}] %style{%C}{bright,yellow}: %msg%n%throwable"
- name: "info-log"
value: ${log-path}/multiflexApi/api-info.log
- name: "error-log"
value: ${log-path}/multiflexApi/api-error.log
- name: "auth-log"
value: ${log-path}/multiflexApi/api-auth.log
- name: "json-log"
value: ${log-path}/multiflexApi/api-json-info.log
# [Appenders] 로그 기록방식 정의
Appenders:
# [Appenders - Console] 콘솔에 로그를 출력하는 방식 정의
Console:
- name: console-appender
target: SYSTEM_OUT
PatternLayout:
pattern: ${layout-pattern}
# [Appenders - RollingFile] 로그를 파일들을 압축파일로 출력하는 방식 정의
RollingFile:
name: rolling-file-appender
fileName: "${log-path}/rolling-file-log.log"
filePattern: "${log-path}/archive/rollingFile.log.%d{yyyy-MM-dd-hh-mm}_%i.gz"
PatternLayout:
charset: ${charset-UTF-8}
pattern: ${layout-pattern}
Policies:
SizeBasedTriggeringPolicy:
size: "200KB"
TimeBasedTriggeringPolicy:
interval: "1"
DefaultRollOverStrategy:
max: "30"
fileIndex: "max"
# [Appenders - File] 로그를 파일로 기록하는 방식 정의
File:
- name: file-info-appender
fileName: ${info-log}
PatternLayout:
pattern: "%d %p %C{1.} [%t] %m%n"
- name: file-error-appender
fileName: ${error-log}
PatternLayout:
pattern: "%d %p %C{1.} [%t] %m%n"
- name: file-auth-appender
fileName: ${auth-log}
PatternLayout:
pattern: "%d %p %C{1.} [%t] %m%n"
- name: file-json-info-appender
fileName: ${json-log}
PatternLayout:
pattern: "%d %p %C{1.} [%t] %m%n"
# [Loggers] 로그 출력 범위를 정의
Loggers:
# [Loggers - Root] 모든 로그를 기록하는 최상위 로그를 정의
Root:
level: OFF
AppenderRef:
- ref: console-appender
- ref: rolling-file-appender
# [Loggers - AsyncLogger] 비동기 로깅에 대한 정의
AsyncLogger:
name: async-logger # logger key
level: DEBUG
additivity: false
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
# [Loggers - Loggers] 특정 패키지나 클래스에 대한 로그를 정의
Logger:
# 1. Spring Framework 로그 레벨 'INFO' 정의
- name: org.springframework
additivity: "false"
level: INFO
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
# 2. Spring Framework 로그 레벨 'DEBUG' 정의
- name: "com.adjh.multiflexapi"
additivity: "false"
level: DEBUG
AppenderRef:
- ref: console-appender
- ref: file-info-appender
- ref: file-error-appender
# 3. MyBatis 관련 로그 레벨 특정 패키지 외에는 모두 OFF
- name: jdbc
level: OFF
- name: jdbc.sqlonly
level: OFF
- name: jdbc.sqltiming
level: INFO
- name: jdbc.resultsettable
level: OFF
- name: jdbc.audit
level: OFF
- name: jdbc.resultset
level: OFF
- name: jdbc.connection
level: OFF
5) 환경 구성 테스트
1. 비동기 로깅에 대한 테스트
💡 비동기 로깅에 대한 테스트
1. endpoint로 api/v1/code/test로 호출 시 api가 호출이 됩니다.
2. 사전에 asyncLogger로 선언한 메서드를 호출하여 로깅을 수행합니다.
3. 로깅 출력을 확인합니다.
@Slf4j
@RestController
@RequestMapping(value = "/api/v1/code")
public class CodeController {
Logger asyncLogger = LoggerFactory.getLogger("async-logger");
/**
* [API] 로깅 테스트
*
* @return ApiResponseWrapper<ApiResponse> : 응답 결과 및 응답 코드 반환
*/
@PostMapping("/test")
public ResponseEntity<ApiResponse<Object>> test() {
int answer = 0;
asyncLogger.info("[+] 비동기 로깅이 출력이 잘 되는지 확인합니다.");
ApiResponse<Object> ar = ApiResponse.builder()
.result(answer)
.resultCode(SuccessCode.SELECT.getStatus())
.resultMsg(SuccessCode.SELECT.getMessage())
.build();
return new ResponseEntity<>(ar, HttpStatus.OK);
}
}
💡 작업 결과
- 아래와 같이 출력이 됨을 확인하였습니다.
2. 비동기 로깅에 대한 테스트 : 동기 로딩과 함께 테스트
💡 비동기 로깅에 대한 테스트: 동기 로딩과 함께 테스트
1. endpoint로 api/v1/code/test로 호출 시 api가 호출이 됩니다.
2. 사전에 asyncLogger로 선언한 메서드를 호출하여 로깅을 수행합니다.
3. 총 50건에 비동기 로깅을 수행하였고, 로깅이 끝난 뒤에 동기 로깅이 수행된다는 가정하에 수행하였습니다.
/**
* 코드 정보를 관리하는 Controller
*/
@Slf4j
@RestController
@RequestMapping(value = "/api/v1/code")
public class CodeController {
Logger asyncLogger = LoggerFactory.getLogger("async-logger");
/**
* [API] 로깅 테스트
*
* @return ApiResponseWrapper<ApiResponse> : 응답 결과 및 응답 코드 반환
*/
@PostMapping("/test")
public ResponseEntity<ApiResponse<Object>> test() {
int answer = 0;
for (int i = 0; i < 50; i++) {
// 비동기 로깅 시작
asyncLogger.info("[+] 비동기 로깅이 출력이 잘 되는지 확인합니다.");
}
log.debug("[+] 도중에 동기 로깅을 수행합니다.");
ApiResponse<Object> ar = ApiResponse.builder()
.result(answer)
.resultCode(SuccessCode.SELECT.getStatus())
.resultMsg(SuccessCode.SELECT.getMessage())
.build();
return new ResponseEntity<>(ar, HttpStatus.OK);
}
💡 작업 결과
- 비동기 로깅이 다 수행된 뒤에 동기 로깅이 수행되는 것이 아니라 비동기 로깅이 수행되면서 동기 로딩이 중간에 수행되었습니다.
