예외처리에 대한 고찰 - 2편 (로깅 기능 설계)

이제 예외처리에 자신감이 생겼으니 애플리케이션에서 발생하는 예외들을 수집하는 '로깅 시스템'을 설계해보자.

 

로깅 시스템 설계

 

1. 예외 Coverage 100% 만들기

보통 애플리케이션에서 예외를 잡기 위해서 try-catch 를 사용한다. 이보다 중복 코드를 줄이고 가독성을 높히는 방법은 @ExceptionHandler 를 사용하는 방법이 있다. 이렇게 비즈니스 로직에서 발생할 수 있는 예외들은 개발자가 직접 잡아내면 되지만 예상하지 못한 예외들은 어떻게 해야할까? 이때는 @ControllerAdvice를 사용하면 애플리케이션 전역에서 발생하는 예외들을 처리할 수 있어서 예상하지 못한 예외까지 잡아낼 수 있다.

 

2. 로그 수집 방법 정하기

그러면 로그는 어떻게 수집할 수 있을까? 우선 우리는 보통 로그를 log.error() 를 사용해서 남긴다. (@log4j, @slf4j, etc)

이 로그들을 수집할 수 있는 방법은 logback-spring.xml 설정으로 저장하는 방법과 AOP에서 예외가 발생했을때 @AfterThrowing 으로 예외를 캐치한다음 로그를 저장하는 두 가지 방법이 있다. (물론 logback, aop 두 방식 모두 로그를 파일이나 디비에 저장할 수 있다)

처음에는 AOP에서 DB에 저장하는 방식을 사용하려고 했지만 ELK를 사용한 모니터링 시스템의 확장을 고려하게 되었고 logback 과 바로 연동할 수 있는 Logstash를 사용하기로 했다.

 

3. 로그 남기기

logback 에서는 timestamp, log_level, thread_name, logger_name, process_id, message, throwing(예외내용) 등을 기록할 수 있다. 만약 사용자의 요청부터 응답까지의 트랜잭션을 기록하고 싶거나 비즈니스 로직에서 기록하고 싶은 값이 있다고 하면 어떻게 해야될까? 이때는 MDC(Mapped Diagnostic Context)를 사용해 동적으로 원하는 데이터를 기록할 수 있다. (참고로 MDC는 %X로 기록한다)

logback-spring.xml

위와같이 logback 설정을 하고 애플리케이션을 실행하면 아래와같은 결과물을 확인할 수 있다.

Result in console

 

로깅 시스템 개발

 

1. build.gradle 설정

멀티 모듈로 구성된 애플리케이션은 build.gradle에서 모듈간의 의존관계를 설정할 수 있다.

최상위 모듈에 라이브러리를 등록하면 sub module에서도 라이브러리를 사용할 수 있다.

implementation 'org.springframework.boot:spring-boot-starter-aop' // aop
implementation 'org.springframework.boot:spring-boot-starter-logging' // MDC
implementation 'net.logstash.logback:logstash-logback-encoder:6.6' // logstash

 

2. AOP 사용하기

사용자 트랜잭션별로 로그를 기록하려면 컨트롤러에서 어떤 기록을 해줘야한다. 그런데 모든 컨트롤러에서 각각 로직을 처리한다면 유지보수 비용이 매우 클 것이다. 한 비즈니스 로직은 종단 관심사의 개념으로 처리되는데 AOP를 사용하면 종관 관심사에 횡단으로 개입해서 공통 기능들을 여러 관점에 따라 실행할 수 있다.

로깅에 필요한 관점들로 @Before, @AfterReturn, @AfterThrowing 세가지를 선택했다. @Before, @After 는 메소드 실행 전, 후에 실행 되는 시점을 정의한다. @AfterReturn, @AfterThrowing는 @After를 좀 더 상세하게 나눈 것인데 @AfterReturn는 정상적으로 결과를 리턴한 이후에 실행되는 시점을 의미하고 @AfterThrowing은 예외 발생 후에 실행되는 시점을 의미한다.

 

LoggingAop.java

@Pointcut 으로 controller에 들어오는 트랜잭션들만 기록하고 MDC에 트랜잭션 고유값을 trxId로 기록한다. @Pointcut을 쓰면 패키지 경로를 공통으로 관리할 수 있다는 장점이 있다. @Pointcut을 안쓰면 @Before("경로") 에 직접 입력해주면 된다.

• Tip 1 : 패키지를 찾을 수 없다는 "warning no match for this type name" 에러가 나와서 고생을 좀 했다.
          이유는 com.kep.skillbuilder.* 이렇게 설정을 했는데 메소드가 있는 경로까지 다 입력해줘야 한다.
• Tip 2 : 트랜잭션에 필요한 user_id, request_uri 등은 HttpServletRequest 객체에서 얻어낼 수 있는데 인자로 받으면 에러가 발생한다. 인자로 받는 대신 아래처럼 선언하면 객체의 정보를 얻을 수 있다.

HttpServletRequest request = 
((ServletRequestAttributes)RequestContextHolder.currentRequestAttributes()).getRequest();

HttpServletResponse response = 
((ServletRequestAttributes)RequestContextHolder.currentRequestAttributes()).getResponse();

 

 

@AfterThrowing 으로 예외가 발생한 후에 실행될 로직을 작성할 수 있다. 패키지 경로는 애플리케이션의 모든 범위로 설정했다.

LoggingAop.java

 

 

3. Elk 설치 (ElasticSearch, Logstash, Kibana)

이제 수집한 로그들을 시각화할 방법이 필요하다.

초기에는 그냥 개발할까 했지만 향후 APM 확장이나 유지보수 편리성을 생각해서 오픈소스 ELK/EFK 를 고려하게 됐다. EFK는 Logstash 대신 Fluentd 를 사용한 스택인데, Fluentd와 logstash는 구축 방법과 지원 언어등의 차이가 있지만 성능의 차이는 없다. EFK는 팀 내에서 구축한 사례가 있기 때문에 ELK를 사용해보기로 했다.

 

git clone https://github.com/deviantony/docker-elk.git
cd docker-elk

 

키바나 설정에 한글 분석기 nori를 설치한다.

vi kibana/config/kibana.yml
xpack.monitoring.ui.container.elasticsearch.enabled: true

 

기본 접속 정보는 .env 파일에서 확인한다.

vi .env

 

접속방법은 아래와 같다.

ElasticSearch : localhost:9200
Logstash : localhost:9600/
Kibana : localhost:5601

* 참고로 포트를 바꾸고 싶다면, docker-compose.yml 파일에서 포트를 바꾸면 되는데 
  예를들어 kibana 포트를 8080으로 바꾸고 싶다면, 5601:5061 을 8080:5061로 변경하면 된다.
  "호스트포트:컨테이너포트" 순서로 포트가 맵핑되어있다.

Kibana 접속 화면

 

4. logstash와 logback 연결하기

우선 build.gradle에 아래와같은 설정이 필요하다.

implementation 'net.logstash.logback:logstash-logback-encoder:6.6'

 

그리고 logback 설정을 아래와같이 해준다.

<!-- Logstash -->
<appender name="LOGSTASH" class="net.logstash.logback.appender.LogstashTcpSocketAppender">
    <destination>localhost:5000</destination>
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <mdc />
            <pattern>
                <!-- 아래와 같은 키밸류 타입이 들어가면서 나중에 키바나에서 찾기 수월함-->
                <pattern>{"appName":"appName", "profile":"local"}</pattern>
            </pattern>
            <timestamp />
            <!--<version />-->
            <context />
            <threadName />
            <logLevel />
            <message />
            <loggerName />
            <logstashMarkers />
            <stackTrace />
            <callerData />
        </providers>
    </encoder>
</appender>

 

결과는 Kibana의 Discovery 탭에서 아래와 같이 확인할 수 있다.

Kibana > Discovery screen

 

5. logstash 설정으로 message 파싱하기

바로 위의 키바나 화면을 보면 message : {} 블럭에 MDC 데이터들이 모두 들어가있다.

kibana message field

 

메세지 필드의 key들을 모두 꺼내서 새로운 필드로 등록하려면 어떻게 해야할까? 일단 필드로 등록을 해야 조회할때 필터링을 할 수 있으니 꼭 필요한 설정이다. logstash에서는 filter 라는 명령어로 필드를 추가할 수 있다.

vi logstash/pipeline/logstash.conf

 

logstash.conf

 

위와같이 설정하고 컨테이너들을 재 구동하면 test 라는 필드가 생성된 것을 볼 수 있다.

docker-compose down -v && docker-compose build && docker-compose up -d && watch docker ps

 

kibana test field

 

필드 생성 방법에는 대표적으로 split 과 grok 가 있다. split은 message 필드의 데이터를 말그대로 쪼개서 각각의 필드로 만들거나 대체할 수 있고 grok는 정규식을 사용해서 데이터를 쪼개는 방식이다. 이 방식들은 Kibana의 dev tools에서 바로 테스트해볼 수 있어서 컨테이너 재실행 시간을 줄여준다.

 

Dev Tools 패널

Grok Debugger

좌측 하단에 보면 Dev Tools가 있고, 우측 패널에서 Grok 디버깅을 해볼 수 있다. 다만 logstash.config 에 정규식을 넣을때는 클론에 백슬래시 처리를 해줘야 오류가 나지 않는다. (" -> \")

 

최종적인 logstash.conf 설정은 아래와같다.

input {
    tcp {
        port => 5000
    }
}

filter {
    grok {
        match => {
            "message" => "level\":\"%{DATA:level}\",\"thread_name\":\"%{DATA:thread_name}\",\"logger_name\":\"%{DATA:logger_name}\",\"profile\":\"%{DATA:profile}\",\"trxId\":\"%{DATA:trxId}\",\"user\":\"%{DATA:user}\",\"httpMethod\":\"%{DATA:httpMethod}\",\"uri\":\"%{DATA:uri}\",\"skillName\":\"%{DATA:skillName}\",\"skillId\":\"%{DATA:skillId}\",\"message\":\"%{DATA:res_message}\""
        }
        remove_field => ["message"]
    }
}

output {
    elasticsearch {
        hosts => "elasticsearch:9200"
        user => "logstash_internal"
        password => "${LOGSTASH_INTERNAL_PASSWORD}"
    }
}

 

이제 결과물을 확인해보자.

message에서 파싱된 field 들을 확인할 수 있다.

 

 

감사합니다.