세상 단순한 로그 구축하기 - 로그 저장

이번에는 이전 편에 이어서 좀 더 디테일한 설정을 해보려고 합니다.

추가 로그 수집

Error 로그 커스텀

지금까지 Spring에서 로그로 출력하는 값은 크게 REQUEST, RESPONSE, FUNCTION이 있었습니다. 이렇게 수집을 했을 때 제가 빼먹었다고 생각한 부분이 있습니다.
바로 ERROR에 관련된 로그는 정형화되지 않은 형태로 수집이 되고 있다는 것입니다. 정확하게는 기존에 에러가 발생했을 때 표시를 하기는 하지만, 수집하는 형식과는 다르게 단순히 문자열 형태에 여러줄로 표시되어 로그 분석 과정에서 활용하기에는 상당히 불편함이 있었습니다.
따라서 우선 해당 부분을 변경해서 에러 메시지 또한 구조화된 형태로 보여질 수 있도록 하였습니다.

현재 제가 구성한 스프링 프로젝트에서 에러를 관리하는 코드는 대충 다음과 같이 구성되어있습니다. 모든 코드를 가져오기에는 이곳저곳에 뿌려져있기 때문에, 핵심으로 보여지는 부분만 가져왔습니다.

아래 부분은 Valid 어노테이션에서의 검증이 실패했을 때 발생하는 예외 코드입니다.

    @Override
    public ResponseEntity<Object> handleMethodArgumentNotValid(
        MethodArgumentNotValidException e, HttpHeaders headers, HttpStatusCode status,
        WebRequest request) {

        Map<String, String> errors = new LinkedHashMap<>();

        e.getBindingResult().getFieldErrors()
            .forEach(fieldError -> {
                String fieldName = fieldError.getField();
                String errorMessage = Optional.ofNullable(fieldError.getDefaultMessage())
                    .orElse("");
                errors.merge(fieldName, errorMessage,
                    (existingErrorMessage, newErrorMessage) -> existingErrorMessage + ", "
                        + newErrorMessage);
            });

        return handleExceptionInternalArgs(e, HttpHeaders.EMPTY,
            ErrorStatus.valueOf("_BAD_REQUEST"), request, errors);
    }

이 Valid로 인해 에러가 발생한 경우에는 굳이 로그를 남기지 않기 때문에 마찬가지로 구조화된 로깅 처리를 하지 않아도 될거라 생각했습니다. Valid는 입력값이 검증 과정에서 통과되지 못했을 경우 나타나는 것인데, 거의 서버 내에서 허용될 수 없는 값들이 해당 오류를 발생시키는 것이기 때문입니다.
물론 로깅은 많으면 많을수록 언젠가 활용하기 좋을 수도 있지만, 현재에는 여기까지 신경쓰고 싶지는 않았습니다.
만약 로깅이 필요하다면 정말 간결하게 표현하게 되거나, 아니면 모든 로그를 저장하지 않고, 해당 에러에서는 일부만 Sampling해서 저장하는것도 괜찮다고 생각합니다.
아무튼 현재는 해당 함수에서는 따로 처리는 하지 않았습니다.

다음으로, 아래 부분은 예상하지 못한 모든 에러가 나타났을 때 발생하는 예외 코드입니다.

    @ExceptionHandler
    public ResponseEntity<Object> exception(Exception e, WebRequest request) {
        e.printStackTrace();

        return handleExceptionInternalFalse(e, ErrorStatus._INTERNAL_SERVER_ERROR,
            HttpHeaders.EMPTY, ErrorStatus._INTERNAL_SERVER_ERROR.getHttpStatus(), request,
            e.getMessage());
    }

예상치 못한 모든 에러란 Index 범위 초과 에러, 0으로 나누기 에러와 같이 시스템 상에서 받아들여질 수 없는 그런 에러들이 많습니다. 따라서 해당 부분은 명백하게 서버에서 발생하면 안되는 결과값인 것이고, 이 부분은 필수적으로 로깅이 필요하다고 느꼈습니다.
다만 현재는 e.printStackTrace()를 통해서 로그를 받게 된는데, 해당 부분은 예외가 발생했을 때 정말정말 긴 에러 코드를 발생시키는 주범입니다. 아무리 많은 데이터를 저장하는게 좋다고는 해도, 출력되는 값 중 코드의 위치는 초반 일부만 필요하기 때문에, 다 가져올 필요도 없다고 생각했습니다.

따라서 다음과 같이 코드를 일부 수정했습니다.

    @ExceptionHandler
    public ResponseEntity<Object> exception(Exception e, WebRequest request) {

        log.error("[   ERROR] rid {} | msg {} | loc {}", MDC.get(MdcKey.REQUEST_ID.name()),
            e.getMessage(), e.getStackTrace()[0]);

        return handleExceptionInternalFalse(e, ErrorStatus._INTERNAL_SERVER_ERROR,
            HttpHeaders.EMPTY, ErrorStatus._INTERNAL_SERVER_ERROR.getHttpStatus(), request,
            e.getMessage());
    }

Error 수준의 로그를 발생시켜서 빠르게 조치가 필요함을 알리고자 했습니다.

마지막으로, 아래 부분은 직접 정의한 커스텀 에러가 나타났을 때 발생하는 예외 코드입니다.

    @ExceptionHandler(value = GeneralException.class)
    public ResponseEntity onThrowException(GeneralException generalException,
        HttpServletRequest request) {
        ErrorReasonDto errorReasonHttpStatus = generalException.getErrorReasonHttpStatus();
        return handleExceptionInternal(generalException, errorReasonHttpStatus, null, request);
    }

GeneralEeception이라는 클래스로 에러 메시지를 다루는데, 해당 에러가 발생한다면 저희가 의도적으로 해당 부분에 대한 접근을 막아야하기 때문에 발생을 한 경우가 대다수일 겁니다. 물론 예외사항으로 인해서 400번대 에러가 발생하게 되는 상황은 FE 작업에서 대부분 막을것이라 해당 부분도 자주 발생해서는 안되는 코드이긴 합니다.
따라서 발생했을 때 FE나 BE에서 막아주는 처리를 해야하기 때문에, 해당 부분도 꽤나 중요하게 로그를 저장해야한다고 생각했습니다.
다만 위의 의도하지 못한 상황에서 에러가 발생하는 500번대 에러보다는 처리에서의 우선순위가 높지는 않습니다. 의도적으로 발생시킨 에러이기 때문이죠. 그래서 해당 로그는 다음과 같이 처리하였습니다.

    @ExceptionHandler(value = GeneralException.class)
    public ResponseEntity onThrowException(GeneralException generalException,
        HttpServletRequest request) {

        log.info("[   ERROR] rid {} | code {} | message {}", MDC.get(MdcKey.REQUEST_ID.name()),
            generalException.getErrorReasonHttpStatus().getCode(),
            generalException.getErrorReasonHttpStatus().getMessage());

        ErrorReasonDto errorReasonHttpStatus = generalException.getErrorReasonHttpStatus();
        return handleExceptionInternal(generalException, errorReasonHttpStatus, null, request);
    }

Info 수준의 로그를 발생시켜서 에러가 발생했을 때 어떤 상황에서 발생한건지에 대한 정보를 수집할 수 있도록 하였습니다.

로그 저장 위치 설정

이제 명확하게 구조화된 형태로 로그가 수집될 것입니다. 하지만 현재 상황에서 로그는 서버가 새로 배포될 때마다 초기화되는 상황에 처해있습니다.
현재 저희는 도커 컨테이너를 통해서 서버를 배포하고 있습니다. 따라서 Spring에서 출력되는 로그를 확인하려면 다음과 같은 명령어를 사용할 수 있죠.

sudo docker logs --tail 1000 cozymate-container

docker logs는 도커 컨테이너마다의 저장되는 로그 파일을 조회하는 명령어입니다. 바로 위에서 언급했다시피 컨테이너가 사라지게 되면 같이 사라지는 부분이기도 하죠.

docker는 stateless하다

이는 모두 docker container가 stateless하게 데이터가 관리되기 때문입니다. 이 상황을 방지하기 위해서 우리는 docker volume을 관리하여 persistence를 보장해줄 수 있습니다.

이 사이트를 참고하면 대략적인 설명이 가능할 것으로 보입니다.

docker-compose

이러한 volume을 연결하기 위해 저는 docker-compose를 사용했습니다.

기존에 Actions에서 실행하던 docker 명령어는 다음과 같습니다.

sudo docker run --name cozymate-container -d -e SPRING_PROFILE=dev -e TZ=Asia/Seoul -e SERVER=true -p 8080:8080 ${{ secrets.ECR_URI }}:${{ github.sha }}

이걸 아래처럼 바꿨습니다.

version: '3'

services:
  web:
    container_name: cozymate-container
    image: "${ECR_URI}:${GITHUB_SHA}"
    ports:
      - 8080:8080
    environment:
      - "SPRING_PROFILE=${SPRING_PROFILES}"
      - "TZ=Asia/Seoul"
      - "SERVER=true"
    volumes:
      - /home/ubuntu/cozymate/log:/log

거의 차이점은 거의 없고, volumes에 대한 설정이 추가된 것만 보시면 될 것 같습니다.
docker-compose나 명령어나 차이는 거의 없습니다. 제 프로젝트처럼 1개의 컨테이너만 띄울 생각이라면 말이죠.
하지만 docker-compose는 github actions의 값을 바꿀 필요 없이 해당 파일만 바꾸면 설정을 바꿀 수 있기 때문에, 꽤나 편하긴 합니다.

이제 이렇게 설정을 해두고 서버를 올리게 되면 /cozymate/log 경로에 컨테이너의 /log 경로의 저장소가 매핑되게 됩니다.

application.yml

하지만 이렇게만 추가해두면 로그가 알아서 /log에 저장될 리가 없겠죠.
로그 파일을 /log 경로에 저장하라는 설정을 또 해주어야합니다.
이건 application.yml에서 알 수 있습니다.

logging:
  rollingpolicy:
    max-file-size: 100MB
    max-history: 7
    total-size-cap: 1GB
  file:
    name: /log/cozymate.log

위처럼 말이죠.
간단하게 설명하자면 로그 파일은 /log/cozymate.log의 형식으로 저장을 하고 싶은데, 한 로그 파일의 크기는 최대 100MB로 넘치면 다른 파일로 바꾸고 싶고, 최대 파일 개수는 7개까지만 저장하고 싶습니다.
또한 전체 로그 파일의 크기는 1GB가 넘지 않았으면 좋겠습니다.
라는 의미입니다.

사실 디테일한 설정을 한 부분은 아닙니다. 아직 어느정도가 모이는지도 잘 모르고, 어떻게 활용될지도 잘 모르기 때문이죠.
그래서 이렇게 일단 해두고, 점점 수정해나가려고 합니다.

정리

로그 파일에 대해서 간단하게 분석하는 과정까지를 설명하려고 했는데, 쓸데없이 할말이 많아서 또 한번 끊고 가려고 합니다.
다음에는 정말로 저장된 로그 파일을 이용해서 간단하게 분석하는 방식에 대해 소개해보도록 하겠습니다.