로그 추적기 V1 - 프로토타입 개발

slee2·2022년 3월 2일

Spring

(인프런)스프링 MVC 고급편

목록 보기

3/23

애플리케이션의 모든 로직에 직접 로그를 남겨도 되지만, 그것보다는 더 효율적인 개발 방법이 필요하다.

특히 트랜잭션ID와 깊이를 표현하는 방법은 기존 정보를 이어 받아야 하기 때문에 단순히 로그만 남긴다고 해결할 수 있는 것은 아니다.

요구사항에 맞추어 애플리케이션에 효과적으로 로그를 남기기 위한 로그 추적기를 개발해보자.
먼저 프로토타입 버전을 개발해보자.

TraceId

package hello.advanced.trace;

import java.util.UUID;

public class TraceId {

    private String id; // 트렌젝션 ID
    private int level; // 0, 1, 2

    public TraceId() {
        this.id = createId();
        this.level = 0;
    }

    private TraceId(String id, int level) {
        this.id = id;
        this.level = level;
    }

    private String createId() {
        return UUID.randomUUID().toString().substring(0, 8);
    }

    public TraceId createNextId() {
        return new TraceId(id, level + 1);
    }

    public TraceId createPreviousId() {
        return new TraceId(id, level - 1);
    }

    public boolean isFirstLevel() {
        return level == 0;
    }

    public String getId() {
        return id;
    }

    public int getLevel() {
        return level;
    }
}

Id : 트랜잭션 ID
level : 깊이 이다.

다음 레벨로 들어가는 메서드, 이전 레벨로 가는 메서드, 첫번째 레벨인지 확인하는 메서드 등등 편의 메서드를 만들었다.

TraceStatus

package hello.advanced.trace;

public class TraceStatus {

    private TraceId traceId;
    private Long statusTimeMs;
    private String message;

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

    public TraceId getTraceId() {
        return traceId;
    }

    public Long getStatusTimeMs() {
        return statusTimeMs;
    }

    public String getMessage() {
        return message;
    }
}

startTimeMs : 로그 시작 시간. 로그 종료시 시작시간의 차로 값을 구할 수 있음.
message : 시작시 사용한 메세지. 이후 로그 종료시에도 이 메세지를 사용해서 출력한다.

HelloTraceV1

package hello.advanced.trace.hellotrace;

import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;

@Slf4j
@Component
public class HelloTraceV1 {

    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 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());
        }
    }

    //level=0
    //level=1 |-->
    //level=2 |   |-->
    //level=2 ex |   |<x-
    //level=1 ex |<x-
    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();
    }
}