타임라인 재구성

한 줄 요약

타임라인은 기억이 아니라 증거로 세웁니다. 서로 다른 시간대와 어긋난 시계를 하나의 기준 시계로 맞춘 뒤에야 「무엇이 먼저였나」 를 말할 수 있고, 같은 증상이 서로 다른 원인에서 올 수 있다는 것을 알아야 엉뚱한 것을 되돌리지 않습니다.

왜 이게 필요했나

사고가 끝나면 모두 「배포 직후부터 오류가 났다」 고 기억합니다. 그런데 그 「직후」 는 서버 시계로 찍힌 로그를 사람이 눈으로 맞춘 결과입니다. 한 서버의 시계가 3분 뒤처져 있으면 그 서버의 오류는 배포보다 먼저 난 것처럼 보이고, 다른 서버는 KST, 배포 기록은 커밋한 사람의 시간대(+0900 과 -0800 이 섞임), 플래그 기록은 또 다른 시간대입니다. 이 상태로 순서를 정하면 멀쩡한 배포를 범인으로 만들거나 진짜 원인을 창 밖으로 밀어냅니다.

그리고 「배포 무렵부터 오류」 라는 같은 증상이 서로 다른 원인에서 옵니다. 새 판의 버그, 같은 무렵 들어간 설정 변경, 하위 의존 서비스의 지연 — 셋 다 그래프에서는 똑같이 5xx 가 솟습니다. 그런데 정답 행동은 각각 앱 롤백, 설정 롤백, 아무것도 되돌리지 않기입니다.

어떻게 동작하나

첫째, 기준 시계를 하나 고릅니다. NTP 로 맞춘 로드밸런서나 지표 시스템이 보통 기준입니다. 같은 요청이 기준과 서버 양쪽에 찍혀 있으면(요청 id) 두 시각의 차이가 그 서버 시계의 어긋남입니다. 한 쌍이 아니라 여러 쌍의 가운데 값을 써야 처리 지연에 흔들리지 않습니다. 시간대는 어긋남이 아닙니다 — 시간대 표시를 읽어 같은 순간으로 바꾸는 것이 먼저입니다.

둘째, 변경을 한 줄에 세웁니다. 배포·설정·플래그를 모두 UTC 순간으로 바꿔 정렬하고, 맞춘 시계의 첫 오류 앞 일정 창 (예: 30분) 안의 변경을 용의자로 둡니다.

셋째, 패턴으로 원인을 가릅니다. 롤링 배포의 버그는 새 판이 들어간 서버부터 차례로 오류가 시작됩니다. 설정은 보통 모든 서버에 한꺼번에 들어가므로 오류도 동시에 시작합니다. 의존 서비스 문제는 그 서비스의 지연 지표가 먼저 솟고, 오류의 모양 (시간 초과 코드, 수 초에 걸린 응답)이 다릅니다.

넷째, 구간에 이름을 붙입니다. 탐지 지연(첫 오류 → 경보), 완화 시각(오류율이 기준 아래로 내려가 유지된 첫 시점)을 데이터의 정의로 정해 두면 사람마다 다른 숫자가 나오지 않습니다.

어긋남을 재는 계산은 이렇게 생겼습니다. 같은 요청이 양쪽에 찍혀 있다면 차이를 여러 개 모아 가운데 값을 씁니다.

req=r0700123  기준(LB) 05:21:40.112Z   web-2 가 찍은 시각 05:18:12.125Z   차이 -207.987
req=r0700131  기준(LB) 05:21:44.530Z   web-2 가 찍은 시각 05:18:16.541Z   차이 -207.989
…                                                         가운데 값 ≈ -208초 (web-2 가 208초 뒤처짐)
맞춘 시각 = 서버가 찍은 시각 − 어긋남  →  05:18:12 − (−208) = 05:21:40

그리고 같은 증상의 세 원인은 신호와 행동이 다릅니다.

원인	오류가 시작되는 모양	함께 보이는 신호	할 일
새 앱 판의 결함	새 판이 들어간 서버부터 차례로	롤링 간격만큼 서버별 시작이 벌어짐	앱을 직전 판으로
설정 배포	모든 서버가 같은 초에	설정 배포 직후, 앱 배포보다 앞섬	설정을 직전 리비전으로
의존 서비스 지연	모든 서버가 함께, 시간 초과 코드	의존 서비스의 p99 가 먼저 솟음	되돌리지 않고 의존 쪽 대응

현장에서 만나는 모습

흔한 장면은 「셋 다 배포 탓이니 전부 롤백하자」 입니다. 그런데 의존 서비스 때문에 난 오류는 롤백해도 그대로이고, 롤백 자체가 또 하나의 변경이라 새 위험을 들입니다. 다른 흔한 장면은 시계가 어긋난 서버 하나가 「배포 전부터 오류가 있었다」 는 착시를 만들어 배포를 무죄로 만드는 것입니다. 둘 다 시계를 맞추고 패턴을 보면 몇 분 안에 가려집니다.

git 기록도 함정입니다. 기본 git log 는 커밋한 사람의 시간대로 날짜를 찍고 최신이 위에 옵니다. 미국에서 밤 9시에 한 커밋은 Tue Nov 3 21:14 -0800 으로 보이지만 UTC 로는 11월 4일 새벽입니다. 날짜 글자로 정렬하면 이 배포가 하루 앞선 것처럼 밀려나고, 「사고 직전 30분 안의 변경」 목록에서 빠집니다. 변경 기록을 모을 때는 항상 순간(UTC)으로 바꾼 뒤에 정렬합니다.

탐지 지연은 경보 규칙이 정합니다. 「분당 오류율 5% 초과가 3분 연속」 이라는 규칙은 아무리 빨라도 셋째 분이 끝나야 울리고, 오류가 천천히 오르면 그보다 늦습니다. 타임라인에서 탐지 지연을 숫자로 뽑아 두면, 포스트모템에서 「경보가 늦었다」 는 느낌이 「규칙 때문에 최소 3분, 실제 4분 12초」 라는 사실로 바뀌고, 고칠 곳(규칙의 기준이나 지속 시간)이 분명해집니다.

다음 실습에서 할 것

두 서버 로그(시간대와 시계가 다름), 로드밸런서 표본, git 배포 기록, 플래그 기록, 경보·지표를 맞대어 시계 어긋남을 재고, 기준 시계의 첫 오류와 용의 변경, 탐지 지연과 완화 시각을 구합니다. 마지막에는 세 서비스의 같은 증상을 원인별로 가르고 되돌릴 것만 되돌립니다.