時計事件ノート — 九つの記録を読む

한국어 원문으로 표시합니다.

목표

시계가 어긋난 채로 남은 기록 묶음을 읽어, 무엇이 어긋났는지 숫자로 재고 시각을 올바르게 다루는 함수를 직접 씁니다. 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       유효 구간이 못박힌 인증서

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

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

unsynced-clock / monitor-offset — 기계의 시계가 맞다고 믿었다. 오차를 재서 감시한다.
merge-by-timestamp / order-by-causal-chain — 시각순이 곧 인과순이라고 믿었다. 인과 사슬을 함께 남긴다.
stored-local-time / store-utc-display-local — 지역 시각이 순간을 가리킨다고 믿었다. 저장은 UTC 로 한다.
wall-clock-elapsed / use-monotonic-clock — 벽시계 뺄셈이 경과라고 믿었다. 경과는 단조 시계로 잰다.
clock-outside-validity / renew-with-margin — 내 시계로 남의 기한을 판정했다. 여유를 두고 미리 갱신한다.
local-time-period-label / idempotent-run-key — 지역 시각 이름표가 기간을 유일하게 가리킨다고 믿었다. 멱등한 실행 열쇠를 쓴다.

단계

/opt/fixtures/clocklab/logs/ 의 네 로그(api-1 · api-2 · cache-1 · worker-1)를 읽어 /root/clock-lab/survey.json 에 개요를 적으세요. 호스트마다 host · 줄 수 lines · 서로 다른 요청 수 requests · 파일의 첫 줄과 마지막 줄의 시각 first_ts last_ts 를 hosts 목록에 담고, 네 파일의 줄 수 합을 total_lines 에 적습니다. 시각은 파일에 적힌 문자열 그대로 옮기세요.
요청 하나는 네 줄을 남깁니다 — 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 (밀리초, 원인 시각 빼기 결과 시각)를 담습니다.
api-1 만 시각 동기가 확인된 기준입니다. 상대 호스트마다 왕복 네 시각으로 theta = 1/2 * [(T2-T1) + (T3-T4)] 를 구하고, 그 중앙값 을 초 단위 소수점 첫째 자리까지 반올림해 /root/clock-lab/skew.json 에 적으세요. 호스트마다 host · 쓴 표본 수 samples · offset_sec · 표본이 흩어진 폭 spread_ms(최댓값 빼기 최솟값, 밀리초)를 hosts 에 담고, reference 에 기준 호스트를, method 에 rfc5905-theta 를 적습니다.
/root/clock-lab/clocklab.py 에 realign(records, offsets) 을 쓰세요. records 는 host 와 ts_ms(그 호스트 시계 기준 epoch 밀리초)를 가진 딕셔너리 목록이고 offsets 는 호스트 → 오차 밀리초 입니다. 각 기록의 사본에 true_ms = ts_ms - 오차 를 더해 true_ms 오름차순으로 정렬한 새 목록 을 돌려줍니다. 입력은 건드리지 않고, 오차 목록에 없는 호스트는 0으로 보고, 보정 시각이 같으면 들어온 순서를 지킵니다. 그 함수로 네 로그 480줄을 보정해 /root/clock-lab/aligned.json 에 records · 보정 뒤에도 뒤집혀 있는 쌍의 수 inverted_after · first_true_ms · last_true_ms 를 적으세요.
/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 꼴).
/opt/fixtures/clocklab/timers.jsonl 은 한 호스트에서 돌던 작업들의 시작·끝을 벽시계와 단조 시계로 함께 남긴 것입니다. /root/clock-lab/clocklab.py 에 elapsed_ms(record) 를 더하세요 — 단조 시계 값으로 경과 밀리초를 돌려주고, start_mono_ms 나 end_mono_ms 가 없으면 None 을 돌려줍니다. 그리고 /root/clock-lab/monotonic.json 에 host · total_ops · 벽시계 경과가 음수인 작업 이름 negative_ops 와 그 수 negative_count · 벽시계가 점프한 폭 step_seconds(초, 뒤로 갔으면 음수) · 벽시계와 단조 시계 경과의 차이 중 가장 큰 절댓값 max_error_ms 를 적으세요.
/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.
/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.py 에 run_key(record) 를 더하세요 — 같은 기간의 재실행이면 같은 값, 다른 일이면 다른 값이 나와야 합니다.
앞 여덟 단계의 산출물을 그대로 둔 채 /root/clock-lab/report.json 에 사건 여섯 건(skew · causality · dst · monotonic · deadline · recurring)을 cause · prevention · evidence 로 이으세요. 원인과 예방 코드는 아래 참고에 있고, evidence 는 그 사건의 근거가 담긴 산출물 파일 이름입니다. 마지막 채점은 보고서만 보지 않습니다 — 앞 단계의 기록이 여전히 재료와 맞는지, /root/clock-lab/clocklab.py 의 함수 세 개가 그대로 살아 있는지도 함께 확인합니다.

참고

산출물은 전부 /root/clock-lab/ 아래에 만듭니다. 세션이 끝나면 사라지니 필요하면 따로 보관하세요.
이 실습은 60분으로 잡혀 있어 기본 세션 길이와 같습니다. 시작할 때 미리 시간을 연장해 두세요.
파이썬 표준 라이브러리만으로 충분합니다. json · csv · datetime · zoneinfo · subprocess 를 씁니다.
로그의 시각은 2025-11-01T18:30:00.694+09:00 꼴이라 datetime.fromisoformat 이 그대로 읽습니다.
채점기는 여러분이 적은 숫자를 재료에서 다시 계산해 대조합니다. 그럴듯한 숫자를 지어 쓰면 걸립니다.
채점기는 clocklab.py 의 함수를 직접 부릅니다. 재료가 아닌 입력을 주므로 결과만 맞춰 둘 수 없습니다.
jq 로 먼저 훑어보면 감이 빨리 옵니다. 예: jq -r .event logs/api-2.log | sort | uniq -c.
흔한 실수 둘 — 오차의 부호를 반대로 적는 것, 그리고 없는 시각을 파일에서 찾으려는 것(파일에 없습니다).

네 대의 로그를 펼쳐 놓는다

/opt/fixtures/clocklab/logs/ 의 네 로그(api-1 · api-2 · cache-1 · worker-1)를 읽어 /root/clock-lab/survey.json 에 개요를 적으세요. 호스트마다 host · 줄 수 lines · 서로 다른 요청 수 requests · 파일의 첫 줄과 마지막 줄의 시각 first_ts last_ts 를 hosts 목록에 담고, 네 파일의 줄 수 합을 total_lines 에 적습니다. 시각은 파일에 적힌 문자열 그대로 옮기세요.

각 로그는 JSON Lines 입니다. 한 줄이 한 사건이고 req 가 요청 아이디입니다. 파일은 그 호스트의 시계 순서로 정렬되어 있으니 첫 줄과 마지막 줄을 그대로 쓰면 됩니다. 네 파일의 시각 범위를 나란히 놓고 무엇이 이상한지 먼저 눈으로 보세요.

원인보다 먼저 일어난 결과를 찾는다

요청 하나는 네 줄을 남깁니다 — 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 (밀리초, 원인 시각 빼기 결과 시각)를 담습니다.

네 줄을 요청 아이디로 묶어 놓고 보세요. 상대 호스트는 api-1 이 남긴 줄의 peer 에 있습니다. 뒤집힘이 어느 쌍에서 나타나는지가 상대마다 다른데, 그 차이가 다음 단계의 실마리입니다. 상대 하나는 아무 문제도 없습니다.

어긋난 크기를 네 시각으로 되잰다

api-1 만 시각 동기가 확인된 기준입니다. 상대 호스트마다 왕복 네 시각으로 theta = 1/2 * [(T2-T1) + (T3-T4)] 를 구하고, 그 중앙값 을 초 단위 소수점 첫째 자리까지 반올림해 /root/clock-lab/skew.json 에 적으세요. 호스트마다 host · 쓴 표본 수 samples · offset_sec · 표본이 흩어진 폭 spread_ms(최댓값 빼기 최솟값, 밀리초)를 hosts 에 담고, reference 에 기준 호스트를, method 에 rfc5905-theta 를 적습니다.

T1 은 api-1 의 send, T2 는 상대의 recv, T3 는 상대의 reply, T4 는 api-1 의 ack 입니다. 왜 두 항을 더해 반으로 나누는지 읽기 자료에서 확인하세요. 표본 하나로 정하면 안 되는 이유가 spread_ms 에 그대로 드러납니다. 양수는 그 호스트가 앞선 것입니다.

보정해서 다시 세우면 순서가 돌아온다

/root/clock-lab/clocklab.py 에 realign(records, offsets) 을 쓰세요. records 는 host 와 ts_ms(그 호스트 시계 기준 epoch 밀리초)를 가진 딕셔너리 목록이고 offsets 는 호스트 → 오차 밀리초 입니다. 각 기록의 사본에 true_ms = ts_ms - 오차 를 더해 true_ms 오름차순으로 정렬한 새 목록 을 돌려줍니다. 입력은 건드리지 않고, 오차 목록에 없는 호스트는 0으로 보고, 보정 시각이 같으면 들어온 순서를 지킵니다. 그 함수로 네 로그 480줄을 보정해 /root/clock-lab/aligned.json 에 records · 보정 뒤에도 뒤집혀 있는 쌍의 수 inverted_after · first_true_ms · last_true_ms 를 적으세요.

채점기가 이 함수를 재료가 아닌 입력으로 직접 부릅니다. 결과만 맞추는 것으로는 통과하지 않습니다. 오차는 3단계에서 적은 값을 밀리초로 바꿔 쓰면 됩니다. 정렬을 제자리에서 하면 입력이 바뀌니 조심하세요.

새벽 한 시가 두 번 온 날

/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 꼴).

zoneinfo 와 fold 로 판정합니다. 두 후보의 오프셋이 갈린다는 것만으로는 없는 시각과 두 번 오는 시각이 구분되지 않습니다 — 왕복을 시켜 보세요. 없는 시각의 줄은 파일에 아예 없으므로, 파일만 훑어서는 찾을 수 없고 격자를 직접 만들어야 합니다.

경과 시간이 음수로 찍힌 작업들

/opt/fixtures/clocklab/timers.jsonl 은 한 호스트에서 돌던 작업들의 시작·끝을 벽시계와 단조 시계로 함께 남긴 것입니다. /root/clock-lab/clocklab.py 에 elapsed_ms(record) 를 더하세요 — 단조 시계 값으로 경과 밀리초를 돌려주고, start_mono_ms 나 end_mono_ms 가 없으면 None 을 돌려줍니다. 그리고 /root/clock-lab/monotonic.json 에 host · total_ops · 벽시계 경과가 음수인 작업 이름 negative_ops 와 그 수 negative_count · 벽시계가 점프한 폭 step_seconds(초, 뒤로 갔으면 음수) · 벽시계와 단조 시계 경과의 차이 중 가장 큰 절댓값 max_error_ms 를 적으세요.

점프 폭은 외우지 말고 재료에서 구하세요 — 벽시계 경과에서 단조 시계 경과를 뺀 값이 0이 아닌 작업들이 답을 갖고 있습니다. 채점기는 elapsed_ms 를 벽시계가 뒤로 간 기록과 단조 시계 값이 없는 기록으로도 불러 봅니다.

멀쩡한 인증서가 거절당한 12초

/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.

openssl x509 -noout -startdate -enddate 로 유효 구간을 읽습니다. 뒤처진 시계는 구간의 앞쪽 끝에, 앞선 시계는 뒤쪽 끝에 걸립니다. 토큰은 검증하는 쪽 시계로 지금이 exp 보다 이른지를 봅니다 — 그 시계가 앞서 있으면 수명에서 오차만큼이 사라집니다.

개수는 맞는데 한 번은 빠지고 한 번은 두 번 돌았다

/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.py 에 run_key(record) 를 더하세요 — 같은 기간의 재실행이면 같은 값, 다른 일이면 다른 값이 나와야 합니다.

총 실행 횟수와 기대한 기간 수를 먼저 견줘 보세요. 두 숫자가 같다고 정상이 아닙니다. 열쇠에 run_id 나 started_utc 를 넣으면 두 번 돈 것을 두 번 다 새 일로 봅니다 — 채점기가 이력 전체에 적용해 겹치는 열쇠가 몇 개인지 셉니다.

여섯 사건을 원인과 예방으로 닫는다

앞 여덟 단계의 산출물을 그대로 둔 채 /root/clock-lab/report.json 에 사건 여섯 건(skew · causality · dst · monotonic · deadline · recurring)을 cause · prevention · evidence 로 이으세요. 원인과 예방 코드는 아래 참고에 있고, evidence 는 그 사건의 근거가 담긴 산출물 파일 이름입니다. 마지막 채점은 보고서만 보지 않습니다 — 앞 단계의 기록이 여전히 재료와 맞는지, /root/clock-lab/clocklab.py 의 함수 세 개가 그대로 살아 있는지도 함께 확인합니다.

여섯 사건을 헷갈리지 않게 나누는 기준은 「무엇을 잘못 믿었는가」 입니다. 어긋난 시계 자체와, 그 시각으로 순서를 정한 것과, 지역 시각으로 저장한 것은 서로 다른 잘못입니다. 보고서만 새로 써서는 통과하지 않으니 앞 산출물을 지우지 마세요.