적히지 않은 전제 위의 관찰

배치 하나의 동작을 리포트로 정리하는 일이었다. 하루에 몇 건을 처리하고 몇 건을 건너뛰는지와 제외되는 건이 어떤 성격인지를 로그를 근거로 쓰는 작업인데, 쓰다가 그 로그의 레벨이 무엇인지가 걸렸다.

Table of contents

로그 레벨이라는 전제

프레임워크의 전역 로거 헬퍼는 인자를 주면 디버그 레벨로 기록한다. 배치가 남기는 요약과 개별 결과와 스킵과 제외 네 종류가 전부 그 헬퍼를 쓰고 있었다.

그러면 이 관찰은 스케줄러 호스트의 로그 레벨이 디버그라는 조건 위에 서 있다. 그 전제가 배포 문서에도 코드 주석에도 리포트에도 적혀 있지 않았다.

대조군 실측

전제가 실제로 얼마나 중요한지 추측하지 않고 돌려서 재 봤다. 콘솔 커널을 실제로 띄우고 배치를 실행한 뒤 로그 파일에 추가된 바이트를 직접 읽었고 핸들러가 하나뿐이며 레벨이 디버그인 것도 그때 확인했다. 그다음 레벨을 한 단계 올려 같은 것을 돌렸다.

한 단계 올렸을 뿐인데 관찰이 통째로 없어졌다. 명시적으로 오류로 남긴 것만 살아남았고 그것은 파일과 라인과 스택트레이스까지 함께 남으므로 급이 다르다.

요약만으로 못 보는 것

리포트를 쓰면서 하나 더 알았다. 특정 채널에서 매일 30건가량이 같은 이유로 처리된다는 것을 발견했는데 그 식별이 요약 로그가 아니라 개별 결과 로그에서 나왔다. 요약에는 총계만 있어서 그 건들이 한 묶음이라는 것이 안 보인다.

요약 로그가 아예 없던 관측일도 있었다. 그날 스킵과 제외가 몇 건이었는지 모르므로 0으로 적지 않고 측정 불가로 남겼다. 로그가 없는 날을 0건으로 세면 합계가 틀리고 없는 것과 0인 것은 다르다.

비대칭이 정당한 이유

개선안으로 실패 로그만 오류로 승격하는 안과 요약 로그도 함께 승격하는 안이 나왔는데 첫 번째만 하는 것이 맞다고 봤다.

실패 로그를 오류로 올리는 것은 기준선 복원이다. 실패는 원래 오류로 남아야 하는 것이고 지금 디버그인 것이 이상한 상태다. 요약을 올리는 것은 근거가 다르다. 요약은 원래 디버그가 자연스럽고 이것을 올리면 관찰을 보호했다는 느낌은 생기지만 레벨을 실제로 올렸을 때 스킵과 제외와 개별 결과는 여전히 사라진다.

절반만 보호하는 조치가 위험한 것은 보호했다고 생각하게 만들기 때문이다. 그럴 바에는 이 관찰이 디버그 레벨에 의존한다는 사실을 명시하는 편이 낫다.

못 증명한 것의 기록

부수적으로 이 로그 그룹에 알람이 걸려 있는지도 봤다. 인프라 코드 저장소의 메트릭 필터 정의를 찾았는데 대상 로그 그룹이 없었다.

그런데 이것을 알람 없음으로 쓰면 안 된다. 콘솔에서 손으로 만든 필터나 구독 필터는 코드에 없으므로 코드에 없다는 것이 존재하지 않는다는 뜻이 아니다. 그래서 인프라 코드 정의에는 없으나 콘솔 생성분과 구독 필터를 배제하지 못하므로 알람이 없다는 완전한 증명은 아니라고 적었다.

리포트에 붙인 전제

관찰 결과 앞에 전제를 한 줄 붙였다. 이 관찰이 스케줄러 호스트의 로그 레벨에 의존하며 한 단계만 올라가도 요약과 개별과 스킵과 제외가 전부 기록되지 않는다는 것을 대조군 실측과 함께 적었다.

이 한 줄이 없으면 나중에 누가 로그 레벨을 올리고 나서 리포트 수치가 왜 안 맞는지를 처음부터 조사하게 된다.

정리

• 전역 로거 헬퍼는 디버그 레벨이므로 관찰이 로그 레벨에 의존하게 된다
• 그 전제는 대개 어디에도 적혀 있지 않다
• 레벨을 한 단계 올리는 것만으로 관찰이 통째로 사라질 수 있다
• 추측하지 말고 대조군으로 확인한다
• 로그가 없던 날을 0건으로 세지 않고 측정 불가로 남긴다
• 절반만 보호하는 조치는 보호했다는 인상만 남긴다
• 코드에 정의가 없다는 것이 존재하지 않는다는 증명은 아니다
• 관찰 결과를 근거로 쓸 때 그 관찰의 전제를 함께 적는다