로그가 미래에서 왔다

한 줄 요약

타임스탬프는 사실이 아니라 그 기계가 그때 자기 시계를 보고 한 주장 이다. 주장을
여러 개 모아 시간순으로 줄 세우면, 사건의 순서가 조용히 뒤집힌다.

왜 이게 필요했나

장애 회고에서 가장 많이 쓰는 도구는 로그를 시간순으로 합치는 일이다. 서버 네 대의
로그를 한 화면에 모아 놓고 위에서부터 읽으면서 "여기서 시작됐네" 를 찾는다. 이
방법은 대부분의 날에 잘 듣는다. 그래서 안 듣는 날을 알아보기가 특히 어렵다.

안 듣는 날은 이렇게 생겼다. 워커의 "요청을 받았다" 가 API 의 "요청을 보냈다" 보다
위에 있다. 받은 적 없는 것을 처리한 셈이다. 이 화면을 보고 사람이 내리는 결론은
거의 정해져 있다 — "워커가 중복 요청을 재생한 것 같다", "메시지 큐가 순서를 깼다",
"누가 재시도를 잘못 걸었다". 세 가설 모두 그럴듯하고, 셋 다 틀렸다. 워커의 시계가
12초 뒤처져 있었을 뿐이다.

반대 방향은 더 고약하다. 시계가 앞선 기계의 줄은 미래에서 날아온 것처럼 보인다.
왕복 응답 시간이 4분 37초로 찍히고, 대시보드의 지연 그래프가 그 시각에 솟는다.
느려진 적이 없는데 느려진 증거가 남는다. 그리고 그 증거는 지워지지 않는다.

어떻게 동작하나

여기서 중요한 것은 오차가 한 줄에만 생기지 않는다 는 점이다. 시계가 어긋난
기계는 그 기계의 모든 줄 이 같은 크기로 어긋난다. 그래서 한 줄만 이상하면 그건
시계 문제가 아니라 다른 문제이고, 한 호스트의 줄이 통째로 일정하게 밀려 있으면 그건
거의 시계다. 이 구분이 조사의 첫 갈림길이다.

오차의 크기는 짐작하지 않고 잰다. 잴 수 있는 이유는 요청 하나가 네 개의 시각을
남기기 때문이다. 보낸 쪽이 보낸 시각(T1), 받은 쪽이 받은 시각(T2), 받은 쪽이 답한
시각(T3), 보낸 쪽이 답을 받은 시각(T4). NTP 가 30년째 쓰는 계산이 바로 이것이고,
[RFC 5905 8절](https://www.rfc-editor.org/rfc/rfc5905)에 이렇게 적혀 있다.

theta = T(B) - T(A) = 1/2 * [(T2-T1) + (T3-T4)]      두 시계의 차이delta = T(ABA)      = (T4-T1) - (T3-T2)              왕복에 걸린 시간

왜 두 항을 더해 반으로 나누는지가 이 식의 전부다. (T2-T1) 안에는 두 가지가 섞여
있다 — 진짜 시계 차이와 가는 편의 네트워크 지연. (T3-T4) 안에도 시계 차이가
들어 있는데 이번에는 오는 편의 지연이 반대 부호 로 들어 있다. 둘을 더하면 지연이
서로 상쇄되고 시계 차이만 두 배로 남는다. 그래서 반으로 나눈다.

상쇄는 가는 편과 오는 편의 지연이 같을 때만 완벽하다. 실제 망에서는 같지 않으므로
한 번 재서 나온 값은 (가는 지연 - 오는 지연)의 절반만큼 틀린다. 그래서 한 표본이
아니라 여러 표본의 중앙값 을 쓴다. 표본이 흩어진 폭까지 함께 보면, 이 추정을
얼마나 믿어도 되는지가 같이 나온다. 폭이 수십 밀리초인데 오차가 277초라면 결론은
흔들릴 여지가 없다.

실무에서 시계를 맞추는 일은 [chrony](https://chrony-project.org/documentation.html)
같은 데몬이 한다. 데몬은 오차가 작으면 시계의 속도 를 미세하게 바꿔 서서히
따라잡고(slew), 오차가 크면 시각을 한 번에 건너뛰게(step) 만든다. 두 방식의
차이가 다음 이야기로 이어진다.

현장에서 만나는 모습

컨테이너 환경에서 이 문제를 특히 자주 만난다. 컨테이너는 자기 시계를 갖지 않고
호스트 커널의 시계를 그대로 본다. 그래서 노드 한 대의 NTP 가 죽으면 그 노드에 뜬
파드 전부가 함께 어긋나고, 다른 노드의 파드는 멀쩡하다. 증상은 "특정 서비스가
이상하다" 가 아니라 "특정 노드에 뜬 것들만 이상하다" 로 나타나는데, 서비스 이름으로
로그를 모아 보는 습관 때문에 그 패턴이 잘 안 보인다.

기록을 남길 때 지킬 것이 두 가지 있다. 하나는 **시각을 항상 오프셋과 함께 적는
것** 이다. [RFC 3339](https://www.rfc-editor.org/rfc/rfc3339) 형식이 그래서 유용하다.
2025-11-01T18:30:00.694+09:00 은 어느 기계에서 읽어도 같은 순간을 가리키지만,
2025-11-01 18:30:00 은 읽는 사람의 짐작에 기댄다. 다른 하나는 **순서를 시각에만
맡기지 않는 것** 이다. 요청 아이디와 인과 사슬(무엇이 무엇을 낳았는가)을 함께 남기면,
시계가 어긋나도 순서는 복원된다. 분산 추적이 하는 일이 정확히 이것이다.

그리고 조사할 때의 순서가 있다. 시계가 어긋난 것을 알아냈다면, 로그를 지우거나 다시
찍지 말고 오차를 기록해 두고 읽을 때 보정한다. 원본은 그 기계가 그때 무엇을
믿고 있었는지에 대한 증거이고, 그 믿음이 사고의 원인일 수 있다.

다음 퀴즈에서 확인할 것

한 줄의 이상과 한 호스트 전체의 밀림을 어떻게 구분하는지, 네 시각으로 오차를 재는
식이 왜 지연을 상쇄하는지, 표본 하나가 아니라 여러 개의 중앙값을 쓰는 이유가
무엇인지 확인한다.