로그 마스킹 뒤 사라진 에러코드

에러 로그에 찍히던 자격증명을 가리도록 코드를 고쳤습니다.
그 뒤 13일 동안 모든 예외의 에러코드가 빈 값(null)으로 기록됐습니다.
수정된 메시지에는 code=401이 남아 있었는데도요.
경고는 하나도 나오지 않았고 테스트도 전부 통과했습니다.

수정 전 에러 메시지

외부 API 호출이 실패하면 서버는 API 응답 본문을 에러 메시지에 그대로 붙였습니다.
응답 본문은 JSON이었습니다.
아래는 실제 값 대신 메시지 형태만 옮긴 예시입니다.

API 호출 실패: {"code":401,"message":"...","token":"..."}

사람은 장애가 나면 이 메시지를 읽고 원인을 파악했습니다.
그런데 서버의 다른 코드도 같은 메시지를 읽고 있었습니다.
이 코드는 메시지에서 "code":숫자 모양을 찾아 에러코드를 뽑아냈습니다.
서버는 뽑은 에러코드를 예외 정보에 함께 기록했습니다.
이 글에서는 이 코드를 에러코드 파서라고 부르겠습니다.

읽는 쪽	읽는 이유
사람	장애가 났을 때 원인 파악
에러코드 파서	에러코드를 뽑아 예외 정보에 기록

마스킹 수정

응답 본문에는 인증 토큰 같은 자격증명이 섞여 있었습니다.
로그에 자격증명이 남지 않도록 본문을 가렸습니다.
민감한 값을 이렇게 가리는 처리를 마스킹이라고 합니다.
수정 뒤 메시지는 이렇게 바뀌었습니다.

API 호출 실패: code=401 (본문 생략)

사람이 보기에는 괜찮아 보였습니다.
에러코드 401은 그대로 남아 있고 토큰은 사라졌으니까요.

그런데 파서는 빈 값(null)을 돌려줬습니다.
파서가 찾던 것은 숫자 401만이 아니었습니다.
"code": 다음에 숫자가 오는 모양까지 맞아야 했습니다.
code=401에는 따옴표도 콜론도 없습니다.
본문을 가리는 수정이 파서의 입력 형식까지 바꾼 겁니다.

문제가 13일 동안 드러나지 않은 이유

파서가 에러코드를 읽을 수 없었다면, 예외나 테스트에서 문제가 드러날 법도 합니다.
하지만 이번에는 예외도 나지 않았고 테스트도 계속 통과했습니다.
메시지 형식에 관한 조건을 문서에서도 확인할 수 없었습니다.

첫째, 파서는 실패해도 예외를 던지지 않았습니다.
에러코드를 찾을 수 없으면 빈 값만 돌려주고 끝났습니다.
그래서 파싱에 실패했다는 기록도 남지 않았습니다.

둘째, 테스트에서는 마스킹 전 메시지를 썼습니다.
파서 테스트에는 미리 만들어 둔 JSON 메시지를 넣었습니다.
이 메시지는 마스킹을 거치지 않아 "code":숫자 모양을 그대로 유지했습니다.
파서는 테스트에서 에러코드를 뽑을 수 있었고, 테스트도 계속 통과했습니다.
반면 실제 서버에서는 이미 code=401로 바뀐 메시지를 파서에 넘기고 있었습니다.
테스트에서 확인한 입력과 실제 입력이 달랐던 겁니다.

셋째, 메시지가 JSON이어야 한다는 약속이 어디에도 적혀 있지 않았습니다.
문서에도 테스트에도 이 조건은 없었습니다.
마스킹 수정을 넣은 사람은 코드 전체를 검색해야 다른 코드도 이 메시지를 읽는다는 사실을 알 수 있었습니다.

재발 방지 방법

사람이 읽으라고 만든 메시지라도 코드가 파싱하고 있다면, 메시지 형식을 바꿀 때 그 코드의 입력도 함께 바뀝니다.
이번에는 에러코드 401을 남겨뒀지만, 파서가 기대하던 따옴표와 콜론을 바꿨습니다.
따라서 메시지를 수정할 때는 사람이 읽을 수 있는지와 함께, 그 메시지를 읽는 코드가 있는지도 확인해야 합니다.

에러코드를 메시지와 분리하는 구조는 2부에서, 실제 처리 흐름을 거치는 테스트는 3부에서 다룹니다.

파서가 빈 값만 돌려줄 때 왜 문제를 오래 알아채기 어려운지는 에러가 없다고 문제가 없는 건 아니다에서 따로 다뤘습니다.