LabHub
배우기 러닝패스 코스

로그가 미래에서 왔다 — 시계가 만든 다섯 사건 · 한 번만 돌았어야 할 정산이 두 번 돌았다 · 실습

시계 사건 노트 — 아홉 개의 기록을 읽는다

LabHub 에서 이어서 보기

목표

시계가 어긋난 채로 남은 기록 묶음을 읽어, 무엇이 어긋났는지 숫자로 재고 시각을
올바르게 다루는 함수를 직접 씁니다. JSON 과 CSV 를 파이썬으로 읽을 수 있는
중급 학습자를 위한 60분 조사입니다.

왜 중요한가

이 사건에서 서비스는 내내 정상이었습니다. 고장 난 것은 프로세스가 아니라 시각을
적어 둔 종이입니다. 그런데 사람은 그 종이를 읽고 원인을 정하기 때문에, 어긋난
기록은 멀쩡한 시스템을 범인으로 만들고 진짜 원인을 숨깁니다. 여기서 배우는 것은
시계를 맞추는 법이 아닙니다 — 시계를 맞추는 일은 대개 남이 하고, 이 실습 파드에는
그럴 권한도 없습니다. 배우는 것은 어긋난 기록을 읽는 법 과 **어긋나도 무너지지
않는 코드를 쓰는 법** 입니다.

사건 배경

2025년 11월 1일 저녁, 결제 API 한 대(api-2)의 응답이 4분 37초로 찍히기 시작했습니다.
같은 시각 워커(worker-1)의 로그에는 받은 적 없는 요청을 처리한 기록이 남았습니다.
그날 밤 새 인증서를 배포했더니 한 대에서만 몇 초 동안 handshake 가 실패했다가
저절로 나았고, 다음 날 미국 고객 알림이 네 건 두 번 나갔습니다. 그리고 며칠 뒤
정산 집계가 하루치만 두 배로 잡혔습니다. 전부 같은 원인에서 나온 다섯 갈래입니다.

재료

/opt/fixtures/clocklab/ 아래에 있습니다. 읽기만 하고 고치지 마세요.

logs/api-1.log  logs/api-2.log  logs/worker-1.log  logs/cache-1.log    네 대가 각자 자기 시계로 찍은 왕복 기록. 한 왕복에 네 줄(send·recv·reply·ack).tls-handshakes.jsonl   새 인증서를 배포한 뒤 2초마다 시도한 handshake 결과timers.jsonl           작업들의 시작·끝. 벽시계와 단조 시계를 함께 남겼다tokens.jsonl           발급한 쪽과 검증한 쪽이 다른 토큰 60개alerts-local.csv       지역 시각(America/New_York)으로만 남은 알림 발송 기록cron-runs.csv          매시 5분에 도는 정산 작업의 실행 이력certs/edge-1.pem       유효 구간이 못박힌 인증서

사건 코드표 (마지막 단계에서 쓸 이름)

사건마다 「무엇을 잘못 믿었는가」와 「그래서 무엇을 바꿀 것인가」를 한 쌍으로 둡니다.

단계

1. /opt/fixtures/clocklab/logs/ 의 네 로그(api-1 · api-2 · cache-1 · worker-1)를 읽어 /root/clock-lab/survey.json 에 개요를 적으세요. 호스트마다 host · 줄 수 lines · 서로 다른 요청 수 requests · 파일의 첫 줄과 마지막 줄의 시각 first_ts last_tshosts 목록에 담고, 네 파일의 줄 수 합을 total_lines 에 적습니다. 시각은 파일에 적힌 문자열 그대로 옮기세요.
2. 요청 하나는 네 줄을 남깁니다 — api-1 의 send, 상대의 recv, 상대의 reply, api-1 의 ack. 두 쌍(send 보다 이른 recv, reply 보다 이른 ack) 중 하나라도 어긋난 요청을 찾아 /root/clock-lab/inversions.json 에 적으세요. 뒤집힌 요청 수 inverted_requests, 상대 호스트별 뒤집힌 쌍의 수 by_peer(뒤집힌 쌍이 없는 상대도 0으로 적습니다), 가장 크게 뒤집힌 요청 worst_request 와 그 폭 worst_gap_ms (밀리초, 원인 시각 빼기 결과 시각)를 담습니다.
3. api-1 만 시각 동기가 확인된 기준입니다. 상대 호스트마다 왕복 네 시각으로 theta = 1/2 * [(T2-T1) + (T3-T4)] 를 구하고, 그 중앙값 을 초 단위 소수점 첫째 자리까지 반올림해 /root/clock-lab/skew.json 에 적으세요. 호스트마다 host · 쓴 표본 수 samples · offset_sec · 표본이 흩어진 폭 spread_ms(최댓값 빼기 최솟값, 밀리초)를 hosts 에 담고, reference 에 기준 호스트를, methodrfc5905-theta 를 적습니다.
4. /root/clock-lab/clocklab.pyrealign(records, offsets) 을 쓰세요. recordshostts_ms(그 호스트 시계 기준 epoch 밀리초)를 가진 딕셔너리 목록이고 offsets호스트 → 오차 밀리초 입니다. 각 기록의 사본에 true_ms = ts_ms - 오차 를 더해 true_ms 오름차순으로 정렬한 새 목록 을 돌려줍니다. 입력은 건드리지 않고, 오차 목록에 없는 호스트는 0으로 보고, 보정 시각이 같으면 들어온 순서를 지킵니다. 그 함수로 네 로그 480줄을 보정해 /root/clock-lab/aligned.jsonrecords · 보정 뒤에도 뒤집혀 있는 쌍의 수 inverted_after · first_true_ms · last_true_ms 를 적으세요.
5. /opt/fixtures/clocklab/alerts-local.csv 는 미국 동부(America/New_York) 지역 시각으로만 남은 알림 발송 기록입니다. 이 규칙은 하루 96번, 00:00 부터 15분 간격으로 나갑니다. 파일에 등장하는 날들의 격자를 만들어 판정하고 /root/clock-lab/dst.json 에 적으세요. zone · 줄 수 rows · 존재하지 않는 지역 시각 nonexistent_locals · 두 번 오는 지역 시각 ambiguous_locals(둘 다 YYYY-MM-DD HH:MM:SS 문자열 목록) · 그래서 빠진 발송 수 missing_rows · 겹친 발송 수 duplicate_rows · 서머타임이 끝나는 전환의 앞뒤 오프셋 fallback_offset_before fallback_offset_after(-04:00 꼴).
6. /opt/fixtures/clocklab/timers.jsonl 은 한 호스트에서 돌던 작업들의 시작·끝을 벽시계와 단조 시계로 함께 남긴 것입니다. /root/clock-lab/clocklab.pyelapsed_ms(record) 를 더하세요 — 단조 시계 값으로 경과 밀리초를 돌려주고, start_mono_msend_mono_ms 가 없으면 None 을 돌려줍니다. 그리고 /root/clock-lab/monotonic.jsonhost · total_ops · 벽시계 경과가 음수인 작업 이름 negative_ops 와 그 수 negative_count · 벽시계가 점프한 폭 step_seconds(초, 뒤로 갔으면 음수) · 벽시계와 단조 시계 경과의 차이 중 가장 큰 절댓값 max_error_ms 를 적으세요.
7. /opt/fixtures/clocklab/certs/edge-1.pem 의 유효 구간을 읽고, 3단계에서 잰 오차와 이어 /root/clock-lab/deadline.json 에 적으세요. cert_not_before cert_not_after(YYYY-MM-DDTHH:MM:SSZ) · 새 인증서를 잠시 거절한 호스트 not_yet_valid_host 와 그 길이 not_yet_valid_sec · /opt/fixtures/clocklab/tls-handshakes.jsonl 에서 실제로 거절당한 횟수 handshake_rejects · 남보다 먼저 만료로 볼 호스트 expires_early_host 와 그 폭 expires_early_sec · /opt/fixtures/clocklab/tokens.jsonl 에서 읽은 토큰 수명 token_ttl_sec · 앞선 시계에서 실제로 쓸 수 있는 시간 token_usable_sec · 검증하는 쪽과 발급하는 쪽에서 각각 거절될 토큰 수 tokens_rejected_on_verifier tokens_rejected_on_issuer.
8. /opt/fixtures/clocklab/cron-runs.csv 는 매시 5분에 도는 정산 작업의 실행 이력입니다. period 는 그 실행이 처리한 기간의 이름표입니다. 이력에 나오는 날들의 매시 기간을 모두 만들어 대조하고 /root/clock-lab/recurring.json 에 적으세요. expected_periods · actual_runs · 한 번도 처리되지 않은 missing_periods · 두 번 처리된 duplicate_periods · 앞 실행이 끝나기 전에 시작한 overlapping_runs(run_id 목록)와 그중 가장 크게 겹친 초 max_overlap_sec · 중복 기간에서 두 번째 실행이 다시 쓴 행 수 double_counted_rows. 그리고 /root/clock-lab/clocklab.pyrun_key(record) 를 더하세요 — 같은 기간의 재실행이면 같은 값, 다른 일이면 다른 값이 나와야 합니다.
9. 앞 여덟 단계의 산출물을 그대로 둔 채 /root/clock-lab/report.json 에 사건 여섯 건(skew · causality · dst · monotonic · deadline · recurring)을 cause · prevention · evidence 로 이으세요. 원인과 예방 코드는 아래 참고에 있고, evidence 는 그 사건의 근거가 담긴 산출물 파일 이름입니다. 마지막 채점은 보고서만 보지 않습니다 — 앞 단계의 기록이 여전히 재료와 맞는지, /root/clock-lab/clocklab.py 의 함수 세 개가 그대로 살아 있는지도 함께 확인합니다.

참고

단계 9개

  1. 네 대의 로그를 펼쳐 놓는다
  2. 원인보다 먼저 일어난 결과를 찾는다
  3. 어긋난 크기를 네 시각으로 되잰다
  4. 보정해서 다시 세우면 순서가 돌아온다
  5. 새벽 한 시가 두 번 온 날
  6. 경과 시간이 음수로 찍힌 작업들
  7. 멀쩡한 인증서가 거절당한 12초
  8. 개수는 맞는데 한 번은 빠지고 한 번은 두 번 돌았다
  9. 여섯 사건을 원인과 예방으로 닫는다