Spring/Spring Core Advanced

로그 추적기

민철킹 2021. 10. 28. 18:31
애플리케이션이 커질수록 모니터링과 운영이 중요해진다.

어떤 부분에서 병목현상이 발생하는지 어떤 부분에서 예외가 발생하는지를 로그로 확인하는 것은 매우 중요하다.

 

아래와 같은 요구사항을 가정한다.

  • 모든 Public 메서드의 호출과 응답 정보를 로그로 출력
  • 애플리케이션의 흐름을 변경하면 안됨
    • 비즈니스 로직에 영향 X
  • 메서드 호출에 걸린 시간
  • 정상 흐름과 예외 흐름 구분
    • 예외 발생시 예외 정보
  • 메서드 호출의 깊이 표현
  • HTTP 요청을 구분
    • HTTP 요청 단위로 특정 ID를 남겨 어떤 HTTP 요청에서 시작된 것인지를 구분 가능
    • 트랜잭션 ID ==> HTTP 트랜잭션을 의미

 

만들고자하는 로그 추적기 형식

 


로그 추적기 Version 0

트랜잭션의 깊이를 로그로 남기기 위해서는 이전의 정보를 이어받아 로그로 출력해야한다.

 

먼저, 트랜잭션 ID와 깊이를 표현하기 위한 클래스를 만든다.

트랜잭션 ID는 임의의 UUID를 생성하고 앞에서 8글자를 추출해 사용하도록 하겠다.

 

나머지 메소드들에 대한 설명은 생략한다.

 

다음으로 로그의 상태 정보를 나타내는 클래스를 만든다.

이 상태정보는 해당 트랜잭션이 종료되었을 때의 상태를 나타낸다.

 

이 두 클래스를 활용해 로그 추적기를 만들어보자.

 


로그 추적기 Version 1

begin

HTTP 트랜잭션이 시작될 때 호출된다.

기본 생성자를 통해 TraceId를 생성하고 시작한 시간과 메시지를 로그로 출력한다.

 

또한 이를 통해 TraceStatus를 만들어 반환한다.

 

end, exception

HTTP 트랜잭션이 종료될 때 호출된다. 예외가 발생했다면 exception, 정상 종료라면 end

 

현재 상태와 exception의 유무를 complete 메소드에 넘겨준다.

 

complete

HTTP 트랜잭션이 종료될 때의 시간과 TraceStatus 내의 startTimeMs와의 차를 통해 HTTP 트랜잭션이 종료되는데까지 걸린 시간을 추출한다.

 

또한 exception 유무에 따라 로그를 찍는다.

 

addSpace

TraceId의 level에 따라 호출된 깊이를 표현하기 위한 메소드이다.

 

level이 1이면 "|-->", level이 2이면 "|  |-->" 이런식으로 표현된다.

 

기본적으로 싱글 쓰레드 환경이기 때문에 StringBuilder를 사용하였다.

 


앞서 만든 로그 추적기를 애플리케이션에 적용시켜보자.

HelloTrace를 @Component를 사용해 스프링 빈으로 등록하였기 때문에 위와 같이 주입받아 사용할 수 있다.

 

만약 정상흐름이라면 try문으로 들어가 begin을 호출하고 Service를 통해 Repository에 save한뒤 end를 호출하고 브라우저에 "OK!"라는 문자를 반환할 것이다.

 

하지만 save하는 중 예외가 발생한다면 catch로 들어가 로그 추적기의 exception 메소드를 통해 예외를 출력하고 그 예외를 밖으로 던진다.

현재는 예외를 처리하는 부분이 없기 때문에 Servlet까지 예외가 던져져 500에러가 클라이언트에게 보여질 것이다.

 

 

정상흐름

브라우저 화면

 

예외흐름

브라우저 화면

 

마찬가지로 Service와 Repository 로직에도 로그 추적기를 추가한다.

정상 흐름
예외 흐름

 

각 레이어들이 호출된 흐름을 로그로 확인할 수는 있지만 현재 트랜잭션 ID가 동기화되지 않았고, 레벨 또한 출력되지 않는다. 현재 begin을 통해 매번 새로운 TraceId를 생성하고 있기 때문이다.

 

로그 상태 정보인 트랜잭션ID와 level를 다음으로 전달하고 레벨을 출력할 수 있도록 해보자.

 

 

 


로그 추적기 version 2

상태를 동기화하는 가장 간단한 방법은 당연히 파라미터로 값을 계속 넘겨주는 것이다.

 

로그 추적기에 beginSync 메소드를 추가해 이전 TraceId를 넘겨받을 수 있도록한다.

 

또한 createNextId를 통해 level을 1씩 증가시켜나간다.

 

간단한 테스트 코드를 만들어 확인해보면

이제 요구사항대로 레벨이 출력되는 것을 확인할 수 있다.

 


이를 애플리케이션에 적용시켜보자.

 

현재 만들어놓은 애플리케이션에서의 흐름을 생각해보면 요청은

 

Servlet -> Dispatcher Servlet -> Controller -> Service -> Repository 순으로 전달되고 

 

응답은 그 반대로 나간다.

 

즉, 맨 처음 요청을 받는 Controller에서 begin을 통해 TraceStatus를 생성하고 내부의 TraceId를 Service, Repository에 계속해서 전달해주면 된다.

 

Service와 Repository에서는 beginSync를 사용해 Status를 생성하고 그 안의 TraceId를 다음으로 전달해준다.

 

컨트롤러
서비스
레포지토리

 

정상 흐름

 

예외 흐름

 


하지만 아직 남은 문제들이 있다.

  • TraceId 동기화가 필요한데 이 과정에서 매번 새로운 객체를 생성한다.
  • 동기화를 위해선 관련 메소드의 파라미터를 수정해야한다.
    • 인터페이스가 존재한다면 인터페이스도 수정해야함
  • 로그를 처음 시작할 때는 begin()을, 처음이 아닐때는 beginSync()를 호출해야한다.
    • 만약 컨트롤러를 통해 서비스를 호출하는 것이 아니라면 넘길 TraceId가 존재하지 않는다.

 

로그 추적기를 TraceId를 파라미터로 넘기는 방식말고 다른 방법은 없을까?

 

 

바로 ThreadLocal이다!

 

반응형

'Spring > Spring Core Advanced' 카테고리의 다른 글

Spring의 프록시 기술  (0) 2021.12.16
동적 프록시 기술  (0) 2021.11.18
프록시 패턴과 데코레이터 패턴  (0) 2021.11.08
템플릿 메서드 패턴과 콜백 패턴  (0) 2021.11.01
ThreadLocal  (0) 2021.10.29