서론
프로세스가 진행되거나 오류가 발생하면 로그를 보면서 이력을 확인하고 에러 발생의 원인을 파악하는 것이 첫 번째 작업입니다.
NDC 초기 버전에서는 별도의 이력을 관리하지 않고 Console 또는 Grafana 통하여 로그를 확인하고 있었고, 여기에서는 Application의 모든 로그를 확인할 수 있습니다. 그로 인해 너무 많은 로그가 보여지고 필요로 하는 작업에 대한 로그 만을 찾는 것이 쉽지 않았습니다. (에러 발생 시 내가 원하는 로그를 보기 위해 온갖 특수 문자를 다 쓰면서 실시간 모니터링을 하죠…)
프로세스 진행 시 중요한 포인트에서 어떤 작업이 이루어지는지, 그 결과는 어떻게 나오는지, 한 눈에 확인할 수 있는 방법이 필요했고 여러 가지 대안을 조사하여 최종적으로 가장 적합하다고 생각하는 Logback의 DBAppender를 NDC에 적용하게 되었습니다.
관련 기술 조사
Custom Interceptor
•
Request가 들어오는 Flow에 따라 Controller로 요청이 넘어가기 전에 Interceptor에서 로그를 남길 수 있습니다.
•
HTTP 요청/응답에 대한 작업만 확인 할 수 있어 내부 로직에 대한 로그를 상세하게 확인할 수 없습니다.
AOP(Aspect Oriented Programming)
•
Spring에서 제공하는 AspectJ를 활용하여 Custom Annotation을 구현하여 사용할 수 있습니다.
•
레거시 코드가 존재하는 경우 필요한 메소드마다 Custom Annotation이 추가되어야 합니다.
•
메소드 내 작업 흐름 중간에 로그는 확인하기 어렵습니다.
•
Proxy 패턴을 사용하여 동작 하므로 Self Invocation에 유의 하여야 합니다.
TransactionalEventListener
•
Spring Transaction의 상태에 따라 발생하는 이벤트를 처리해주는 이벤트 리스너입니다.
•
마찬가지로 메소드 내 작업 흐름 중간에 로그 확인은 어렵습니다.
•
@Transaction 어노테이션이 존재하는 서비스에 대해서만 관리가 가능합니다.
•
기존 작업 흐름과 트랜잭션 분리를 위해 Propagation.REQUIRES_NEW 로 구성해야 합니다.
JPA Auditing
•
Spring Data JPA에서는 Entity에 대한 Auditing 기능을 제공합니다.
•
Entity의 생성 또는 수정이 발생하면 발생 시간을 자동으로 저장 해줍니다.
•
레거시 코드에 존재하는 Entity에 Audit 속성 추가을 위한 상속이 필요합니다.
•
전체 프로세스 흐름에 대한 로그 확인 용도는 아니라고 봅니다.
Hibernate Envers
•
Hibernate Envers 라이브러리 사용 시 컬럼의 생성, 수정, 삭제 이력을 남길 수 있다. JPA Audit와 비슷하게 생각할 수 있는데 Envers는 히스토리로 계속 남기기 때문에 변경 사항 추적이 가능합니다.
•
변경 이력이 대용량일 때는 권장 할만한 방법이 아닙니다.
•
DB와 관련 없는 전체 프로세스 흐름에 대한 로그는 확인할 수 없습니다.
Logback DBAppender
•
Spring Logback 설정 시 DBAppender를 사용하면 로그 정보를 DB에 Insert 할 수 있습니다.
•
작업 진행 중 개발자가 필요로 하는 포인트에 원하는 메시지를 남길 수 있습니다.
•
DBAppender에서 기본적으로 필요로 하는 LOGGING_EVENT, LOGGING_EVENT_PROPERTY, LOGGING_EVENT_EXCEPTION 3개의 테이블을 추가 해야 합니다.
•
로그 저장으로 인해 전체 프로세스에 영향이 가지 않도록 비동기 또는 Exception 처리에 신경 써야 합니다.
•
저장될 로그의 레벨을 적절하게 정의하지 않으면 데이터가 무분별하게 쌓일 수 있습니다.
필요 조건
전체 프로세스 진행 시 원하는 포인트에서 메시지나 결과 값에 대한 정보가 필요합니다.
레거시 코드에 영향을 주지 않는 최소한의 변경으로만 적용할 수 있어야 합니다.
중요한 데이터가 저장되고 필터링 되어 가시성 있게 보여져야 합니다.
적용 방법
•
Default 테이블 생성을 위한 JPA Entity 구현
DBAppender 적용을 위해 기본적으로 LOGGING_EVENT, LOGGING_EVENT_PROPERTY, LOGGING_EVENT_EXCEPTION 3개의 테이블을 필요로 합니다. 이것을 제공하기 위해 logback-classic jar 파일 내 ch/qos/logback/classic/db/script/ 폴더에 데이터베이스 별로 sql 파일을 제공하고 있습니다.
NDC에서는 JPA를 적용하고 PostgreSQL을 사용하고 있으므로 제공된 sql에 맞춰 Entity를 구현하여 Application 실행 시 자동으로 테이블이 만들어지도록 하였습니다. 관련 테이블에 대한 상세 컬럼은 아래와 같습니다.
logging_event : 로그 메시지, 저장 시간 등 일반적인 로그 이벤트 정보를 저장
필드 | 타입 | 설명 |
event_id | bigint | 로깅 이벤트 ID
Unique, Auto increment |
formatted_message | text | 로깅 이벤트의 메시지 |
logger_name | varchar(255) | 로깅 요청한 로거 이름 |
level_string | varchar(255) | 로깅 이벤트 레벨
TRACE/DEBUG/INFO/WARNING/ERROR |
reference_flag | integer | Exception 또는 MDC 속성 값 존재 여부
없음(0) / MDC(1) / Exception(2) / All(3) |
caller_filename | varchar(255) | 로깅 요청한 파일 이름 |
caller_class | varchar(255) | 로깅 요청한 클래스 |
caller_method | varchar(255) | 로깅 요청한 메소드 이름 |
caller_line | varchar(255) | 로깅 요청한 행 번호 |
thread_name | varchar(255) | 로깅 요청한 쓰레드 이름 |
timestmp | varchar(255) | 로그가 저장된 시간 |
arg0 | varchar(255) | 추가 속성 |
arg1 | varchar(255) | 추가 속성 |
arg2 | varchar(255) | 추가 속성 |
arg3 | varchar(255) | 추가 속성 |
logging_event_property : 로깅 이벤트가 발생했을 때 MDC에 저장된 정보를 저장
필드 | 타입 | 설명 |
event_id | bigint | 로깅 이벤트 ID |
mapped_key | varchar(255) | MDC 속성 키 |
mapped_value | varchar(255) | MDC 속성 값 |
MDC(Mapped Diagnostic Context)
logging_event_exception : 로깅 이벤트가 발생했을 때, 메시지와 함께 Exception 객체를 넘겨주는 경우 stack trace를 저장
필드 | 타입 | 설명 |
event_id | bigint | 로깅 이벤트 ID |
i | smallint | 전체 stack trace에서 행의 인덱스 |
trace_line | varchar(255) | stack trace 라인 메시지 |
•
Custom LoggingEvent
ILoggingEvent 객체를 상속 받은 NdcLoggingEvent 클래스를 구현 하였습니다. 해당 이벤트 클래스는 로그 저장 시 속성에 대한 커스텀이나 필터에서 사용될 수 있습니다.
NDC에서 사용 시 공통의 Prefix 메시지를 자르거나 StacTrace의 Caller Data를 추출하는 용도로 커스텀하여 사용하고 있습니다.
public class NdcLoggingEvent implements ILoggingEvent {
public static final String NDC_LOGGER_PREFIX = "#NdcLogger::";
private ILoggingEvent origEvent;
public NdcLoggingEvent(ILoggingEvent origEvent) {
this.origEvent = origEvent;
}
...
@Override
public String getFormattedMessage() {
return origEvent.getFormattedMessage().substring(NDC_LOGGER_PREFIX.length());
}
...
@Override
public StackTraceElement[] getCallerData() {
StackTraceElement stackTraceElement = Arrays.stream(origEvent.getCallerData())
.filter(element -> element.getClassName().contains(NdcLoggerHandler.class.getName()))
.findFirst().orElse(null);
StackTraceElement[] extractLoggerTrace = { stackTraceElement };
return extractLoggerTrace;
}
...
}
Plain Text
복사
•
Custom DBAppender
DBAppender를 상속 받고, 위에서 커스텀 구현한 NdcLoggingEvent를 사용하여 로그를 저장하는 역할을 수행하도록 NdcLogDBAppender를 구현 하였습니다.
public class NdcLogDBAppender extends DBAppender {
@Override
protected void subAppend(ILoggingEvent event, Connection connection, PreparedStatement insertStatement) throws Throwable {
NdcLoggingEvent loggingEvent = new NdcLoggingEvent(event);
super.subAppend(loggingEvent, connection, insertStatement);
}
}
Plain Text
복사
•
Custom Log Filter
ch.qos.logback.core.filter.Filter를 상속 받아 NdcLogFilter 클래스를 생성하고 이벤트 객체를 통해 해당 로그에 대한 Accept, Deny 등을 지정할 수 있습니다.
public class NdcLogFilter extends Filter<ILoggingEvent> {
@Override
public FilterReply decide(ILoggingEvent event) {
if (event.getMessage().startsWith(NdcLoggingEvent.NDC_LOGGER_PREFIX)) {
return FilterReply.ACCEPT;
}
return FilterReply.DENY;
}
}
Plain Text
복사
•
Spring Logback 설정
Project 별로 각각 logback-spring.xml을 설정하고 application.yml을 통해 필요한 속성 및 로그 레벨 정보를 받아 사용하고 있습니다. DBAppender는 로그를 Insert 할 때 마다 새로운 Connection을 생성하기 때문에 Connection Pool을 사용하도록 권장 합니다.
커스텀 구현한 NdcLogDBAppender와 NdcLogFilter를 적용한 appender 구성을 추가 하였습니다.
<springProperty name="ndcLogLevel" source="logging.level.ndc-logger"/>
<springProperty name="driverClass" source="spring.datasource.driver-class-name"/>
<springProperty name="url" source="spring.datasource.url"/>
<springProperty name="user" source="spring.datasource.username"/>
<springProperty name="password" source="spring.datasource.password"/>
<appender name="DB_LOG" class="com.ktnexr.datacloud.model.common.log.NdcLogDBAppender">
<filter class="com.ktnexr.datacloud.model.common.log.NdcLogFilter" />
<connectionSource class="ch.qos.logback.core.db.DriverManagerConnectionSource">
<dataSource class="com.zaxxer.hikari.HikariDataSource">
<driverClassName>${driverClass}</driverClassName>
<jdbcUrl>${url}</jdbcUrl>
<username>${user}</username>
<password>${password}</password>
</dataSource>
</connectionSource>
</appender>
<logger name="NdcLogger" additivity="false">
<level value="${ndcLogLevel}" />
<appender-ref ref="DB_LOG" />
</logger>
Plain Text
복사
•
Logger Handler
새롭게 만들어진 DBAppender 로그 모듈을 기존에 사용하던 log와 유사하면서 레거시 코드 내에서 최대한 간결하게 사용할 수 있도록 편의성을 제공합니다.
적용 결과
•
로깅 테스트 실행
•
logging_event
◦
기본적으로 모든 로그는 해당 테이블에 아래의 그림과 같은 형태로 저장됩니다. 위에서 설명된 바와 같이 reference_flag 속성에 따라 logging_event_exception, logging_event_property 테이블에 관련 데이터가 저장됩니다.
•
logging_property
◦
logging_event.reference_flag 속성 값이 '1' 인 경우 event_id 에 해당하는 MDC 정보가 저장됩니다.
•
logging_event_exception
◦
logging_event.reference_flag 속성 값이 '2' 인 경우 로그 저장 시 전달된 Exception의 stack trace 정보가 저장됩니다.
결론
Logback DBAppender를 활용하여 작업의 진행 이력에 대한 로그를 자유롭게 저장할 수 있고 원하는 정보를 필터링 할 수 있습니다. 더 이상 Console에 특수 문자를 무수히 찍거나 실시간 모니터링을 통해 에러를 확인하지 않아도 에러를 확인할 수 있고, 또한 과거에 발생 했던 오류에 대해서도 확인이 가능합니다.
개선이 필요한 부분들을 보완하여 더 나은 사용성을 위해 고도화하며, 추후 계획 중인 운영자 Application 에서 적극적으로 활용될 수 있길 바랍니다.
후속연구/차후계획
1.
현재는 로직 구현 시 개발자의 의한 수동 작업으로만 로그를 저장할 수 있지만, 추후 자동화를 포함할 수 있도록 개선이 필요합니다.
2.
일반 로그와 같이 자유로운 입력이 가능하여 저장된 데이터의 필터링 시 메시지 포맷의 통일성이 부족하여 이에 대한 정의가 필요합니다.
3.
오래된 로그에 대한 데이터 정리 작업 및 백업 전략이 필요합니다.
참고자료
본 기술블로그에 게재되는 모든 컨텐츠의 저작권은 케이티넥스알(kt NexR)에서 가지고 있으며, 동의 없는 컨텐츠 수정 및 무단 복제는 금하고 있습니다. 컨텐츠(글/사진/영상 등)를 공유하실 경우 반드시 출처를 밝혀주시기 바랍니다. Copyright(c) kt NexR, Inc. All Rights Reserved. |