로그인 직후에만 401 이 나던 열흘, 서버 시계가 43초 뒤처져 있었다 — NTP 와 JWT 사후 분석

열흘을 순서대로 세우면

9월 1일 월요일, API 서버에 아웃바운드 방화벽 정책을 적용했습니다. 나가는 연결을 기본 차단으로 바꾸고 DNS 와 80, 443 만 허용 목록에 넣었습니다. 들어오는 쪽만 막던 서버라 나가는 쪽도 조이자는 취지였고, 적용 직후 배포·헬스체크·외부 API 호출을 모두 확인했습니다. 전부 정상이었습니다.

같은 날 오후, chronyd 가 시간 서버에 보낸 질의는 방화벽에서 조용히 버려졌습니다. UDP 123 을 허용 목록에 넣지 않았기 때문입니다. chronyd 는 죽지 않았습니다. 서비스는 active 였고 로그에는 소스를 고를 수 없다는 줄 하나가 남았을 뿐입니다. 그 순간부터 API 서버의 시계는 아무 보정 없이 자기 수정 진동자만 믿고 갔습니다.

9월 4일, 고객센터에 첫 문의가 옵니다. 로그인하면 한 번 튕기는데 다시 하면 된다는 내용입니다. 담당자가 재현해 보니 안 됩니다. 재현하는 사람은 다시 눌러 보기 마련이고, 그때는 이미 몇 초가 지나 있었으니까요. 클라이언트 캐시 문제로 분류돼 닫혔습니다.

9월 8일, 같은 문의가 하루 십수 건으로 늘었습니다. API 로그를 보니 jwt not active 오류가 눈에 띄게 많아져 있었습니다. 토큰이 아직 유효하지 않다는 뜻인데, 이 오류는 보통 사용자 기기 시계가 틀렸을 때 나오는 것으로 알려져 있어 또 한 번 클라이언트 쪽으로 넘어갔습니다. 다만 이 무렵 오류가 로그인 뒤 20초 안쪽에만 몰려 있다는 점은 아무도 세어 보지 않았습니다.

9월 12일, 로그인 직후 30초 넘게 모든 요청이 401 로 떨어지자 그제야 서버를 봤습니다. 인증 서버와 API 서버에서 date 를 나란히 찍어 보니 43초 차이가 났습니다. API 서버가 뒤처져 있었고, chronyc tracking 은 Not synchronised 를, chronyc sources 는 모든 소스의 Reach 를 0 으로 보여 줬습니다.

# 9/1 에 적용한 규칙 — 123/udp 가 빠져 있다
ufw default deny outgoing
ufw allow out 53
ufw allow out 80/tcp
ufw allow out 443/tcp

# 그날 chronyd 가 남긴 한 줄 (journalctl -u chrony)
# chronyd[812]: Can't synchronise: no selectable sources

# 9/12 에 두 서버의 시계를 나란히 본 것
for h in auth api; do printf '%s  ' "$h"; ssh "$h" date -u +%T; done
# auth  07:41:52
# api   07:41:09

# API 서버에서
chronyc tracking | grep -E 'Ref time|Frequency|Leap'
# Ref time (UTC)  : Mon Sep 01 06:12:41 2026
# Frequency       : 42.117 ppm slow
# Leap status     : Not synchronised
chronyc sources
# MS Name/IP address         Stratum Poll Reach LastRx Last sample
# ^? ntp.ubuntu.com                0   6     0     -     +0ns[   +0ns] +/-    0ns

Ref time 이 9월 1일에 멈춰 있고 Reach 가 0 입니다. 열하루 동안 한 번도 응답을 못 받은 겁니다

chronyd 는 살아 있었습니다. 살아 있는 것과 맞추고 있는 것은 다른 얘기였습니다.

무엇이 망가졌고 왜 매일 조금씩 나빠졌나

피해는 로그인 직후의 공백입니다. 인증 서버가 발급한 토큰에는 발급 시각이 nbf 로 들어갑니다. 그 토큰을 43초 뒤처진 API 서버가 받으면 아직 오지 않은 시각에 발급된 토큰으로 보입니다. RFC 7519 대로 nbf 이전에는 처리하면 안 되니 검증 라이브러리는 정직하게 거부합니다. 토큰이 발급되고 43초가 흐르면 API 서버 시계도 그 시각을 지나므로 그때부터는 통과합니다. 로그인 직후에만 실패하고 조금 기다리면 되는 증상은 정확히 이 모양입니다.

매일 나빠진 이유는 어긋남이 쌓이는 값이기 때문입니다. 이 서버의 진동자는 백만분의 42 만큼 느렸고, 하루로 환산하면 3.6초입니다. 첫날은 4초 차이라 재시도 한 번이면 지나갔고, 나흘째 14초, 열하루째 40초를 넘겼습니다. 장애가 한 번에 터지지 않고 문의 건수가 완만하게 늘어난 곡선 그대로입니다.

두 번째 피해는 로그입니다. 인증 서버와 API 서버의 로그를 시각으로 맞춰 보면 요청보다 응답이 먼저 찍혀 있었습니다. 문의를 추적하던 사람은 이 어긋남을 로그 수집 지연으로 여겼습니다. 시계가 틀리면 장애 자체만이 아니라 장애를 조사하는 도구도 같이 틀어집니다.

발견이 늦은 건 오류 이름이 원인을 가리키지 않았기 때문입니다. jwt not active 는 토큰이 이르다고 말할 뿐 누구 시계가 틀렸는지 말하지 않습니다. 그리고 그 오류를 자주 내는 쪽이 보통 사용자 기기라는 경험이 서버를 의심하는 걸 막았습니다. 서버 시계는 당연히 맞는다는 전제가 있었고, 그 전제를 확인하는 지표는 어디에도 없었습니다.

오류는 로그인 직후 몇십 초에만 몰려 있었습니다. 그 몇십 초가 곧 두 서버의 시계 차이였습니다.

원인은 세 겹으로 겹쳐 있었다

직접 원인은 방화벽 허용 목록에서 빠진 UDP 123 입니다. 나가는 연결을 적을 때 애플리케이션이 쓰는 포트만 떠올렸고, 운영체제가 뒤에서 쓰는 포트는 떠올리지 못했습니다. 적용 직후 확인한 항목도 전부 애플리케이션 것이었습니다. 시계는 그 순간엔 맞았으니 확인했더라도 통과했을 겁니다.

두 번째는 chronyd 가 실패를 조용히 삼킨 점입니다. 소스에 닿지 못해도 chronyd 는 종료하지 않습니다. 마지막으로 알던 주파수 보정값으로 계속 돌면서 다음 응답을 기다립니다. 설계로는 옳은 동작입니다. 잠깐 끊긴 네트워크 때문에 데몬이 죽으면 더 곤란하니까요. 하지만 그 덕에 systemctl status 는 열하루 내내 초록색이었고, 우리가 보던 지표는 그것뿐이었습니다.

세 번째는 검증 쪽에 여유가 없었던 점입니다. RFC 7519 는 exp 와 nbf 를 검사할 때 시계 차이를 감안해 몇 분 이내의 여유를 둘 수 있다고 적어 두었습니다. jsonwebtoken 에도 그 용도로 clockTolerance 옵션이 있습니다. 우리는 기본값인 0초로 두었습니다. 여러 서버가 각자 시계를 가진 구조에서 1초의 차이도 허용하지 않겠다고 선언한 셈인데, 그런 선언인 줄 몰랐습니다.

정리하면 시계를 맞추는 길이 막혔고, 막힌 걸 알려 주는 장치가 없었고, 어긋난 시계를 받아 줄 여유도 없었습니다. 셋 중 하나만 있었어도 이 열흘은 없었습니다.

시계가 맞는다는 건 전제였습니다. 전제를 지키는 데몬은 있었지만 전제를 재는 지표는 없었습니다.

그래서 세 군데를 고쳤다

첫 조치는 길을 다시 여는 것입니다. 허용 목록에 123/udp 를 넣자 chronyd 는 다음 폴링에서 바로 응답을 받았습니다. 다만 43초는 chronyd 가 알아서 건너뛰어 주는 크기가 아닙니다. 기본 설정의 makestep 은 시작 후 처음 몇 번의 갱신에서만 시계를 점프시키고, 그 뒤로는 큰 차이도 조금씩 늘리고 줄이는 방식으로 따라잡습니다. 열하루째 돌고 있는 데몬에게 그 조건은 이미 지났습니다.

그래서 chronyc makestep 을 손으로 쳤습니다. 남은 보정량을 한 번에 점프해 즉시 맞추는 명령입니다. 뒤처진 시계를 앞으로 당기는 것이라 타이머가 한 번 몰려 도는 정도로 끝났지만, 반대로 앞선 시계를 뒤로 돌리는 경우라면 같은 시각이 두 번 지나가므로 로그와 배치가 어떻게 반응할지 먼저 생각해야 합니다. 시계를 점프시키는 일은 서비스에 영향이 있는 작업으로 다루는 게 맞습니다.

두 번째 조치는 검증에 여유를 두는 것입니다. jwt.verify 에 clockTolerance 를 30초로 넣었습니다. 서버끼리 시계가 정상적으로 맞아 있으면 차이는 밀리초 단위라 30초는 넉넉하고, 토큰 수명이 15분인 구조에서 30초 더 받아 주는 건 보안상 의미 있는 차이가 아닙니다. 다만 이 값은 시계가 어긋났을 때 사용자가 겪는 시간을 줄여 주는 완충일 뿐 시계를 맞추는 대신이 아닙니다.

세 번째 조치는 시계 상태를 지표로 올리는 것입니다. chronyc tracking 의 Leap status 가 Normal 이 아니거나 System time 의 절댓값이 0.5초를 넘으면 알리도록 했습니다. chronyd 가 살아 있는지가 아니라 시계가 맞는지를 보는 겁니다. 아울러 방화벽 규칙을 바꾸는 절차에 시계·DNS·패키지 저장소처럼 운영체제가 쓰는 나가는 연결 목록을 점검 항목으로 넣었습니다.

# 1) 길을 연다
ufw allow out 123/udp

# 2) 동기화가 붙었는지 본다 — S 열이 * 로 바뀌고 Reach 가 올라간다
chronyc sources
# ^* ntp.ubuntu.com                2   6    17     3   (Last sample 에 -43초 근처 값)

# 3) 남은 43초를 조금씩 따라잡지 않고 즉시 점프한다
chronyc makestep
chronyc tracking | grep -E 'System time|Leap'
# System time     : 0.000214 seconds slow of NTP time
# Leap status     : Normal

# 4) 검증에 여유를 둔다 (jsonwebtoken)
# jwt.verify(token, key, { algorithms: ['RS256'], clockTolerance: 30 })

# 5) 감시 — Leap status 가 Normal 이 아니거나 System time 이 0.5초를 넘으면 종료 코드 1
chronyc tracking | grep -q 'Leap status *: Normal' \
  && chronyc tracking | awk '/^System time/ { exit !($4 < 0.5) }'

길을 열고, 한 번 점프하고, 검증에 완충을 두고, 시계 자체를 감시합니다

chronyd 가 살아 있는지가 아니라 Leap status 가 Normal 인지를 봅니다.

이번에 남은 것

첫째는 나가는 연결을 조일 때 운영체제 몫을 먼저 적게 된 점입니다. 시간 동기화, DNS, 패키지 저장소, 로그 전송처럼 애플리케이션 코드에는 없지만 서버가 늘 쓰는 연결이 있습니다. 이런 건 막힌 직후엔 아무 티가 안 나고 며칠 뒤에 엉뚱한 얼굴로 나타납니다. 허용 목록을 만들 때 이 목록부터 채우고 애플리케이션 포트를 그 뒤에 붙입니다.

둘째는 프로세스 상태와 일의 상태를 구분하게 된 점입니다. active 는 데몬이 떠 있다는 뜻이지 제 일을 하고 있다는 뜻이 아닙니다. chronyd 에게 그 일은 시계를 맞추는 것이고, 그건 Leap status 와 System time 으로만 알 수 있습니다. 다른 데몬도 마찬가지라, 이번에 몇 개 더 골라 살아 있느냐가 아니라 일하고 있느냐를 재는 지표로 바꿨습니다.

셋째는 로그인 직후에만 나는 오류를 보는 눈입니다. 시간이 지나면 저절로 풀리는 오류는 대개 어딘가의 시계 문제입니다. 토큰이든 인증서든 서명 요청이든, 발급 시각과 검증 시각을 비교하는 곳이면 어디서든 같은 모양으로 나타납니다. 앞으로 그런 문의가 오면 클라이언트를 의심하기 전에 서버 두 대의 date 부터 나란히 찍어 보기로 했습니다.

돌아보면 고친 건 방화벽 한 줄, 옵션 하나, 감시 항목 하나입니다. 그 셋이 없어서 열흘 동안 사용자가 로그인 뒤 반 분씩 기다렸고, 그 사이 조사하던 사람은 틀린 시계로 찍힌 로그를 믿고 엉뚱한 곳을 팠습니다. 시계는 맞는 게 당연해서 아무도 보지 않는 곳이고, 그래서 한 번 틀리면 오래 갑니다.

조치 후 확인할 것

시계는 아무도 보지 않는 곳에서 하루 몇 초씩 어긋납니다. 그 몇 초가 토큰 검증처럼 시각을 비교하는 자리에서 사용자 얼굴로 나타납니다. 시계를 맞추는 길이 열려 있는지, 맞고 있는지를 재는 지표가 있는지, 어긋났을 때 받아 줄 완충이 있는지. 이 셋을 한 번 갖춰 두면 다음에 방화벽을 조이는 날도 열흘 대신 알림 한 줄로 지나갑니다.