[Tech Stack] 로그 추적기란? - 1

 

안녕하세요 ! 우기의 정신차린 취준 일기입니다.

프로젝트를 하다보니 조금은 블로그 활동에 더딘감이 있었네요..😂

 

우기의 정신차린 취준일기는 3가지 단계로 적용해보겠습니다

 

1. 무엇인가?

2. 왜쓰는가?

3 어떤상황에 쓰이는가?

 

😀 로그 추적기란 무엇인가 ? 

- "프로젝트의 로직 흐름 또는 예외 발생 (병목 현상 or 오류)을 직접적으로 관찰할수있는 기술 스택"

- 직접적으로 관찰할때 개발자가 직접적으로 로그를 남기는 힘듦을 개선하고 자동화 할수있게 만드는 기술 스택

라고 정의하자.

 

😀 로그 추적기, 과연 왜 사용하는가 ?

- 프로젝트를 개발하다보면 점점 규모가 커지면서 엔티티의 확장성, 복잡한 비즈니스 로직을 맞닥뜨리는 경우가 비일비재하다. 프로젝트가 커지다보면 모니터링과 운영이 중요해진다. 

- 모니터링과 운영을 함으로써 프로젝트의 병목현상과 오류현상들을 로그로 확인하여 잡아내기위해 로그 추적기를 사용한다.

 

😀 로그 추적기, 어떤 상황에 사용하는가?

- 특정 상황에 사용 한다기 보단 프로젝트 규모가 커지면서 모니터링와 운영을 할 시점에 사용해야한다고 생각한다.

 

😀 로그 추적기 ! 구현해보자 

로그추적기를 구현하기위해서 고려사항들

- 1. 모든 public 메서드의 호출과 응답 정보를 로그로 출력

- 2. 어플리케이션의 흐름을 변경하면 안됨

   -  로그를 남긴다고해서 비지니스 로직의 동작에 영향을 주면 안됨

- 3. 메서드 호출에 걸린 시간을 적어놓자 

- 4. 정상 흐름과 예외 흐름을 구분해야한다.

   -  예외 발생 시 예외 정보가 남아야 함

- 5. 메서드 호출의 깊이 표현

- 6. HTTP 요청을 구분 

   -  HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함

   -  트랜잭션 ID (DB 트랜잭션이 아님) 여기서는 하나의 HTTP 요청이 시작해서 끝날때 까지를 하나의 트랜잭션이라고 생각하자.

 

✅ 결론부터! 구현하면 어떤 결론이 도출되어야할까?

- 로그 추적기의 정상 흐름

 

- 로그 추적기의 예외 흐름 

 

❤ 1. 로그 추적기의 version1, version2를 위한 기본 설정

- 프로젝트 모든 로직에 단순한 로그를 남겨도 된다. 하지만 트랜잭션ID (어떤 로직을 사용하고있는지)와 로직의 깊이를 표현해야하기때문에 기존 정보를 이어받아야 한다. 단순히 로그는 옳지 않아 보인다.

- 그렇다면 Controller - Servie - Repository 의 Data 교환을 어떻게 주고받는지에 대한 로그 추적기에대한 정보 Class를 

생성해야 하지 않을까?

 

🧡TraceId Class, 로그 추적기를 위한 기반 데이터

public class TraceId {

	private String id;
	private int level;

	//traceId의 초기값 -> 처음 만들어질때
	public TraceId() {
		this.id = createId();
		this.level = 0;
	}

	//이 클랜스 내부에서만 사용할거기때문에 private 선언
	private TraceId(String id, int level) {
		this.id = id;
		this.level = level;
	}

	//toString은 String으로 만든다는 의미
	private String createId() {
		//abcdefgi-3cdee-sd3edf-f4fgfdsf-dfe
		//=> abcdefgi로 만들겠다는 의미
		return UUID.randomUUID().toString().substring(0,8);
	}

	//계층 추가
	public TraceId createNextId(){
		return new TraceId(id, level+1);
	}

	//계층 차감
	private TraceId createPrevId(){
		return new TraceId(id, level-1);
	}

	//맨처음 계층인지?
	private boolean isFirstLevel() {
		return level==0;
	}
	//Getter 생략
}

//존재이유
// trace의 id는 트랜잭션 id로 생각해야하고
// level은 계층을 의미한다

TraceStatus, 로그의 상태 정보를 나타내는 클래스

public class TraceStatus {

	private TraceId traceId;
	private Long startTimeMs;
	private String message;

	public TraceStatus(TraceId traceId, Long startTimeMs, String message) {
		this.traceId = traceId;
		this.startTimeMs = startTimeMs;
		this.message = message;
	}

	public TraceId getTraceId() {
		return traceId;
	}

	public Long getStartTimeMs() {
		return startTimeMs;
	}

	public String getMessage() {
		return message;
	}
}

🧡HelloTraceV2, 로그의 시작과 끝, 계층을 계산하는 Class  

public class HelloTraceV2 {

	private static final String START_PREFIX = "-->";
	private static final String COMPLETE_PREFIX = "<--";
	private static final String EX_PREFIX = "<X-";
    
	public TraceStatus begin(String message) {
		TraceId traceId = new TraceId();
		Long startTimeMs = System.currentTimeMillis();
		log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX,
			traceId.getLevel()), message);
		return new TraceStatus(traceId, startTimeMs, message);
	}

	public TraceStatus beginSync(TraceId beforeTraceId, String message) {
		TraceId nextId = beforeTraceId.createNextId();
		Long startTimeMs = System.currentTimeMillis();
		log.info("[{}] {}{}", nextId.getId(), addSpace(START_PREFIX,
			nextId.getLevel()), message);
		return new TraceStatus(nextId, startTimeMs, message);
	}

	public void end(TraceStatus status) {
		complete(status, null);
	}

	public void exception(TraceStatus status, Exception e) {
		complete(status, e);
	}


	private void complete(TraceStatus status, Exception e) {
		Long stopTimeMs = System.currentTimeMillis();
		long resultTimeMs = stopTimeMs - status.getStartTimeMs();
		TraceId traceId = status.getTraceId();
		if (e == null) {
			log.info("[{}] {}{} time={}ms", traceId.getId(),
				addSpace(COMPLETE_PREFIX, traceId.getLevel()), status.getMessage(),
				resultTimeMs);
		} else {
			log.info("[{}] {}{} time={}ms ex={}", traceId.getId(),
				addSpace(EX_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs,
				e.toString());
		}
	}

	private static String addSpace(String prefix, int level) {
		StringBuilder sb = new StringBuilder();
		for (int i = 0; i < level; i++) {
			sb.append( (i == level - 1) ? "|" + prefix : "| ");
		}
		return sb.toString();
	}
}

 

💚TraceStatus begin(String message)

맨처음 시작할때 호출 TraceId를 가져와 새로운 TraceId를 만들고, 시스템 현재시각까지 가져오는 메서드

제일 처음 traceId와 addSpace 로직을 가져와 화살표의 개수가 표현이 됨

 

💚TraceStatus beginSync(TraceId beforeTraceId, String message)

기존 Controller에 들어온 TraceId와 level을 Service, Repository가 그대로 매개변수로 받아와 

비지니스 흐름에서 traceId와 level을 동일하게 보여주기 위한 메소드 

 

💚 void end(TraceStatus status)

end와 exception 함수는 비슷하지만 Exception e 함수가 존재하기때문에 단순히 complete 함수로 핸들링 함

 

💚 void exception(TraceStatus status, Exception e)

end와 exception 함수는 비슷하지만 Exception e 함수가 존재하기때문에 단순히 complete 함수로 핸들링 함

 

💚 void complete(TraceStatus status,  Exception e)

현재 시간과 시작시간을 고려하여 끝난 시간을 가져옴.  정상 흐름과 오류 흐름을 판단하여 화살표의 상태를 표시함

이 depth 또한 level을 고려하여 만듦 

 

💚 static String addSpace(String prefix, int level)

for문의 i가 level-1 일때, 즉 반복문의 마지막이 현재 level 과 똑같다면 | --> (마지막 o ) , 똑같지않다면 | (마지막 x) 을 의미

🧡 OrderController (비지니스 로직에 대한 흐름)

 

🧡 OrderService (비지니스 로직에 대한 흐름)

public class OrderServiceV2 {

	private final OrderRepositoryV2 orderRepositoryV0;
	private final HelloTraceV2 trace;

	public void orderItem(TraceId traceId, String itemId){

		TraceStatus status = null;
		try {
			status = trace.beginSync(traceId,"OrderService.request()");
			orderRepositoryV0.save(status.getTraceId(),itemId);
			trace.end(status);
		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}

}

🧡 OrderRepository (비지니스 로직에 대한 흐름)

public class OrderRepositoryV2 {

	private final HelloTraceV2 trace;

	public void save(TraceId traceId,String itemId){

		TraceStatus status = null;
		try {
			status = trace.beginSync(traceId,"OrderRepository.request()");

			if (itemId.equals("ex")){
				throw new IllegalStateException("예외 발생");
			}

			sleep(1000);

			trace.end(status);

		} catch (Exception e) {
			trace.exception(status, e);
			throw e;
		}
	}

	private void sleep(int millis){
		try{
			Thread.sleep(millis);
		} catch (InterruptedException e){
			e.printStackTrace();
		}
	}
}

 

로그추적기를 구현하기위해서 고려사항들

- 1. 모든 public 메서드의 호출과 응답 정보를 로그로 출력

- 2. 어플리케이션의 흐름을 변경하면 안됨

   -  로그를 남긴다고해서 비지니스 로직의 동작에 영향을 주면 안됨

- 3. 메서드 호출에 걸린 시간을 적어놓자 

- 4. 정상 흐름과 예외 흐름을 구분해야한다.

   -  예외 발생 시 예외 정보가 남아야 함

- 5. 메서드 호출의 깊이 표현

- 6. HTTP 요청을 구분 

   -  HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함

   -  트랜잭션 ID (DB 트랜잭션이 아님) 여기서는 하나의 HTTP 요청이 시작해서 끝날때 까지를 하나의 트랜잭션이라고 생각하자.

 

❤ 결론과 회고

- 모든 요구사항을 만족하고나니 궁금증이 생겨버렸다. 이게 왜 자동화인가? 비지니스 로직이 더 이상해져버렸다 라는 생각이 들었다. 비지니스 로직은 좀더 간결해야한다고 생각한다. 로그가 생기다보니 try-catch문, 많아진 매개변수.... 어떻게 처리해야할까? 

 

-  이제 처음 호출할때는 begin()을 호출, 그 이후로부터는 beginSync()를 호출해야한다. 컨트롤러에서 호출하는것이 아닌 A서비스가 B서비스를 호출할때도 traceId가 필요하게 된다는 불편함이 존재한다.

 

- 결론 : HTTP 요청을 구분하고 깊이를 표현하기 위해서 TraceId를 파라미터로 넘기는것말고는 다른 대안은 없을까? 

- 회고 : 아직 로그 추적기에대한 자동화, 로그 추적기에대한 불편함만이 존재하는거같다. 좀더 코드를 디벨롭 또는 방안을 찾는 쪽으로 생각해야 로그 추적기가 왜 사용해야되는지 알아봐야겠다.