平常値を知らなければ急増も分からない

한 줄 요약

로그에서 숫자 하나를 뽑았을 때 그것이 나쁜 값인지 아닌지는, 평소 값을 알아야만 판정할 수 있다.

왜 이게 필요했나

"오류가 103건 있습니다" 는 정보가 아닙니다. 평소가 5건이었으면 심각하고, 평소가 120건이었으면 오히려 좋아진 것입니다. 지금 응답 시간이 200밀리초라는 사실만으로는 좋은지 나쁜지 알 수 없습니다. 평소가 40밀리초였다면 심각하고, 220밀리초였다면 아무 일도 아닙니다.

그래서 로그 분석의 첫 단계는 원인 찾기가 아니라 기준선 만들기입니다. 그리고 낯선 고객사에서는 기준선이 문서로 존재하지 않으므로, 같은 로그 안에서 만들어야 합니다. 사고 시각을 제외한 나머지 구간이 곧 평시값입니다.

어떻게 동작하나

접근 로그를 처음 열었을 때의 순서는 이렇습니다.

1. 전체 규모를 잰다. 몇 줄인지, 어느 구간을 덮는지. 6시간짜리 로그에서 어제 오후 사건을 찾고 있다면 그 로그는 애초에 답을 갖고 있지 않습니다.

2. 상태 코드 분포를 본다. 200 이 몇 건, 4xx 가 몇 건, 5xx 가 몇 건. 여기서 4xx 와 5xx 를 반드시 나눠 봅니다. 4xx 는 클라이언트가 잘못 보낸 것이고 5xx 는 서버가 망가진 것이라서, 두 숫자가 같이 움직이는지 따로 움직이는지가 곧 원인의 방향입니다. 배포 후에 4xx 만 늘었다면 API 계약이 바뀐 것이고, 5xx 만 늘었다면 내부가 깨진 것입니다.

3. 시간축으로 자른다. 5xx 를 분 단위로 세어 봅니다. 고르게 퍼져 있으면 만성적인 문제이고, 한 지점에 몰려 있으면 사건입니다. 이 구분이 대응을 완전히 바꿉니다. 몰려 있다면 그 시각에 무엇이 있었는지를 묻는 것으로 조사가 끝날 수 있습니다.

4. 경로별로 자른다. 오류가 특정 엔드포인트에 몰려 있는지, 전체에 퍼져 있는지. 몰려 있으면 그 기능의 문제이고, 퍼져 있으면 공통 의존성(데이터베이스, 인증, 네트워크)의 문제입니다.

5. 기준선을 뺀다. 사고 구간을 제외한 나머지의 오류 수를 셉니다. 이 숫자가 있어야 "평소 33건이던 것이 1분 만에 70건" 이라는 문장을 쓸 수 있고, 그 문장이 보고서의 첫 줄이 됩니다.

현장에서 만나는 모습

여기서 실무 감각 하나를 덧붙입니다. 평균에 속지 마십시오.

응답 시간 평균이 1380밀리초라고 해서 사용자들이 평균적으로 1.4초를 기다린 것이 아닙니다. 340건 중 240건이 260밀리초 이하이고 70건이 3초를 넘는 상황에서도 평균은 그 값이 나옵니다. 평균은 존재하지 않는 사용자를 묘사합니다.

그리고 이 왜곡은 한 방향으로만 작동합니다. 평균은 꼬리가 나빠지는 것을 거의 감지하지 못합니다. 느린 요청 100건이 3초에서 6초로 두 배 나빠져도 전체 평균은 30밀리초쯤 오를 뿐이고, 그 정도로는 어떤 알림 임계값도 넘지 않습니다.

그래서 고객이 "가끔 몇 초씩 멈춘다" 고 말하는데 대시보드의 평균은 정상인 상황은 모순이 아닙니다. 둘 다 참이고, 서로 다른 것을 보고 있을 뿐입니다.

로그가 답을 갖고 있지 않을 때

조사를 하다 보면 로그 자체가 신뢰할 수 없는 경우를 만난다. 이것을 모르고 계속 파면 없는 답을 몇 시간씩 찾게 되므로, 먼저 확인해야 할 것들이 있다.

유실. 로그가 버퍼에 모였다가 전송되는 구조라면, 프로세스가 강제 종료될 때 마지막 몇 초가 통째로 사라진다. 그런데 장애의 결정적 순간이 바로 그 몇 초다. "죽기 직전 로그가 없다" 는 것은 단서가 없다는 뜻이 아니라 비정상 종료였다는 강한 단서다. 정상 종료였다면 마무리 로그가 남았을 것이기 때문이다.

잘림. 수집기가 한 줄의 길이를 제한하는 경우가 흔하다. 긴 스택 트레이스나 JSON 본문이 중간에서 끊기고, 그 뒤에 이어지는 줄이 별개의 항목으로 잡힌다. 파싱하는 쪽에서는 형식이 깨진 줄로 보여서 조용히 버려진다. 오류 건수를 셌는데 실제보다 적게 나오는 원인 중 하나가 이것이다.

시각. 여러 장비의 로그를 합칠 때 시계가 어긋나 있으면 인과가 뒤집혀 보인다. 결과가 원인보다 먼저 기록된 것처럼 보이면 시계를 의심해야지 이상한 가설을 세우면 안 된다. 그리고 시간대가 섞이면 아홉 시간짜리 착시가 생긴다. 로그의 시각은 UTC 로 남기고 보여 줄 때만 변환하는 것이 이 문제를 없애는 유일한 방법이다.

표본. 트래픽이 많은 서비스는 로그를 전부 남기지 않고 일부만 기록하기도 한다. 이때 "그 사용자의 요청이 로그에 없다" 는 것은 요청이 없었다는 뜻이 아니다. 표본 비율을 모르는 채로 건수를 세면 그 숫자는 아무 의미가 없다.

정리하면, 로그를 열기 전에 네 가지를 먼저 확인합니다. 어느 구간을 덮는가, 어디까지 온전한가, 시계가 맞는가, 전부인가 일부인가. 이 확인에 드는 몇 분이, 없는 답을 찾는 몇 시간을 막아 줍니다. 그리고 확인 결과 로그가 답을 갖고 있지 않다면, 그것을 보고서에 그대로 적는 것이 추측을 적는 것보다 훨씬 값어치 있습니다. 다음번에 무엇을 더 남겨야 하는지가 그 문장에서 나오기 때문입니다.

다음 실습에서 할 것

1269줄짜리 웹 접근 로그에서 오류 총량과 사고 시각과 원인 경로를 찾아내고, 마지막에 평시값을 따로 계산해 급증 폭을 숫자로 만듭니다.