← 개발 로그 목록

website: 운영 원인추적용 로깅 우선 도입

/ 7분 분량 / 개발 로그

서버에서 에러가 나도 로그 파일에 아무 흔적이 안 남는 상태였다. GlobalExceptionHandler가 예외를 30개 넘게 처리하고 있었는데, 정작 그 안 어디에도 log.error 같은 코드가 없었다. 사용자에게는 "에러났어요" 응답이 나가지만, 서버 로그 파일을 열어봐도 언제 무슨 이유로 실패했는지 알 수 없는 구조였다.

전 기능에 로깅을 일괄로 넣는 건 범위가 너무 크다고 판단해서, 사고 시 원인추적 가치가 큰 곳만 우선 골랐다. 예상 못한 버그(NPE, DB 에러 같은 것)를 위한 마지막 안전망, 로그인 실패(무차별 대입 공격 탐지용), 이메일 발송 실패(SMTP 문제인지 우리 코드 문제인지 구분하기 위한 것) 세 가지다. 반대로 흔한 4xx는 의도적으로 뺐다 — NotFoundException 같은 정상적인 클라이언트 흐름까지 로그로 남기면, 로그 볼륨만 늘어나고 정작 찾아야 할 에러가 파묻힌다.

첫 커밋에서는 GlobalExceptionHandler에 @ExceptionHandler(Exception.class) catch-all을 추가하는 방식으로 시작했다. 그런데 이렇게 하니 AccessDeniedException(403)이나 NoResourceFoundException(404)처럼 이미 Spring Security 필터나 Spring MVC 표준 예외 처리에서 정확히 처리되던 것들까지 이 catch-all이 먼저 가로채서 500으로 바뀌는 회귀가 발생했다. 처음엔 이걸 rethrow하거나 instanceof로 분기해서 하나씩 빼주는 식으로 땜질했는데, 이 방식의 문제는 앞으로 또 다른 예외 타입이 나타나면 똑같은 문제가 재발할 수 있다는 점이었다. 예외 타입을 나열해서 관리하는 구조 자체가 계속 늘어날 수밖에 없었다.

그래서 두 번째 커밋에서 구조를 바꿨다. Spring Boot 공식 문서에 "@ExceptionHandler로 처리 못한 예외는 ErrorController가 받는다"는 내용이 있길래, 이걸 그대로 따르기로 했다. GlobalExceptionHandler에서 catch-all과 재던지기 코드를 걷어내고, 대신 DefaultErrorAttributes를 상속한 LoggingErrorAttributes를 새로 만들어 Spring Boot의 기본 마지막 처리기(BasicErrorController) 안에서 로깅과 응답 형태를 맞추게 했다.

@Override
public Map<String, Object> getErrorAttributes(WebRequest webRequest, ErrorAttributeOptions options) {
    Map<String, Object> defaults = super.getErrorAttributes(webRequest, options);
    int status = defaults.get("status") instanceof Integer s ? s : 500;

    if (status >= 500) {
        log.error("예상하지 못한 서버 에러", getError(webRequest));
        return Map.of("success", false, "message", "일시적인 오류가 발생했어요. 잠시 후 다시 시도해주세요.");
    }
    return Map.of("success", false, "message", "요청을 처리할 수 없어요.");
}

이 경로는 "정말 아무도 처리 못 한 것"만 자동으로 도달하는 자리라서, 다른 곳에서 이미 처리되는 예외를 가로챌 여지가 구조적으로 없다. 직접 ErrorController를 구현하는 방법도 있었지만, 상태 코드를 판단하는 로직 자체는 Spring Boot가 이미 검증해둔 걸 그대로 쓰고 응답 내용(로깅 + JSON 형태)만 바꾸고 싶었기 때문에, DefaultErrorAttributes를 상속해서 오버라이드하는 쪽을 택했다.

로깅을 늘리다 보니 개인정보 문제가 바로 걸렸다. 로그인 실패 로그나 이메일 발송 실패 로그에는 계정 이메일이나 학번이 그대로 들어갈 수 있는데, 로그 파일은 서버 디스크에 최대 30일 평문으로 쌓인다. 그래서 LogMasker라는 유틸을 만들어서 ab***@domain.com 형태로 마스킹해서 남기도록 했다. backend/SECURITY.md 파일이 지금까지 비어 있었는데, 이번에 처음으로 규칙이 하나 기록됐다.

그 외에 prod 환경에서만 show-sql을 끄는 작업도 같이 했다. 매 쿼리마다 로그가 찍히면 20MB×14개로 롤링되는 로그 파일 용량을 SQL 로그가 다 잡아먹어서, 정작 필요한 에러 로그가 더 빨리 밀려나 삭제되는 문제가 있었다. stage나 로컬은 디버깅 편의를 위해 그대로 뒀다.

이후 dev 브랜치와 머지하는 과정에서 충돌이 나서 병합 커밋을 만들었는데, 충돌을 풀면서 @Slf4j 애너테이션이 중복으로 남는 실수가 있었다. 로컬에서는 git add 전 상태로 재컴파일해서 통과했다고 착각했는데, 실제 커밋된 내용에는 중복이 그대로 남아 있어서 CI 빌드가 깨졌다. javac가 "Slf4j is not a repeatable annotation"으로 애너테이션 처리 자체를 실패시키면서, 무관한 클래스들의 Lombok getter까지 전부 "cannot find symbol"로 번지는 걸 보고서야 원인을 알았다. 별도 커밋으로 중복을 제거해서 해결했다.

마지막으로 테스트 하나를 더 고쳤다. 모집 안내메일 링크 테스트가 href="https://dev.likelion-khu.com"(뒤에 /apply 없이 바로 닫는 형태)를 기대하고 있었는데, 실제 메일 템플릿의 링크는 처음부터 /apply 경로까지 포함해서 나가고 있었다. 이 PR과는 무관하게 dev에 이미 있던 낡은 단정이었는데, 로컬 환경에는 Docker가 없어서 이 테스트 자체가 실행이 안 돼 여태 발견되지 않았고, CI에서만 매번 100% 재현되던 결정적 버그였다. 발견한 김에 같이 고쳤다.

전체 테스트는 255개 중 7개가 실패했는데, 전부 Docker(Testcontainers/Mailpit)가 필요한 이메일 통합 테스트였고 이 환경에 Docker가 없어서 나는 실패라 이번 변경과는 무관했다. 특히 AdminAuthControllerTest와 MemberAuthControllerTest로 401/403/404 같은 상태 코드가 그대로 유지되는지 확인해서, 마지막 안전망을 추가한 게 기존 예외 처리 경로를 깨지 않는다는 걸 검증했다.

요청추적 ID(같은 요청의 로그 여러 줄을 하나로 묶는 식별자)는 이번에 넣지 않았다. 지금 트래픽 규모에서는 로그 파일 하나 grep으로도 충분해 보였고, 나중에 로그 양이 정말 많아지면 그때 추가하는 쪽으로 미뤘다. catch-all을 GlobalExceptionHandler 안에 직접 두는 방식에서 ErrorAttributes로 옮기는 방식으로 바꾼 게 이번 작업에서 가장 중요한 판단이었는데, 프레임워크가 이미 처리 경로를 나눠둔 지점을 존중해서 거기에 얹는 편이, 우리가 예외 타입을 하나씩 나열하며 관리하는 것보다 구조적으로 안전하다는 걸 확인한 작업이었다.