이 문서를 통해 아래 질문들에 답할 수 있게 됩니다.
- DNS/connect/TLS/first byte/total 시간 중 어느 값이 길 때 어떤 계층을 의심해야 하는가?
- 평균 latency는 정상인데 사용자가 느리다고 할 때 p95/p99, queue, pool을 어떻게 봐야 하는가?
- timeout이 난 뒤에도 서버 작업이 계속되는 문제를 어떻게 찾고 줄이는가?
개요
지연 장애는 단순히 “서버가 느림”이 아니다. DNS 해석이 느릴 수도 있고, TCP 연결이 지연될 수도 있고, TLS handshake가 실패 직전까지 갈 수도 있고, 서버가 요청을 받은 뒤 DB나 외부 API를 기다릴 수도 있다. 사용자는 모두 “느리다”라고 말하지만 확인할 계층은 다르다.
Timeout은 지연의 결과로 자주 나타난다. 그러나 timeout 메시지는 최종 증상일 뿐이다. 어느 계층의 timeout인지, timeout 전에 어디서 시간을 썼는지, timeout 이후 서버 내부 작업이 계속되는지를 확인해야 한다.
왜 백엔드 개발자가 알아야 하는가
백엔드 장애에서 가장 흔한 착각은 평균 latency만 보는 것이다. 평균은 괜찮아도 p95, p99, 특정 endpoint, 특정 계정, 특정 region에서만 느릴 수 있다. 실제 사용자 불만은 대개 tail latency에서 나온다.
- first byte가 길면 앱 처리, DB, external API, lock, pool을 의심한다.
- connect가 길면 방화벽, routing, listener, port exhaustion을 본다.
- total만 길고 first byte는 정상이라면 큰 body download, client network, bandwidth를 본다.
- proxy timeout 후에도 app thread가 계속 처리하면 자원 누수가 생긴다.
- pool pending이 늘면 실제 처리 전 대기 시간이 latency에 포함된다.
지연 장애는 관측 지점이 없으면 추측으로 흐르기 쉽다.
요청 흐름에서의 위치
지연은 요청 경로 전체에 분포한다.
DNS lookup
→ TCP connect
→ TLS handshake
→ HTTP request send
→ server queue / app processing
→ DB / cache / external API
→ first byte
→ response body downloadcurl -w는 외부에서 보이는 시간 분해이고, APM trace는 애플리케이션 내부 시간 분해다. 둘을 함께 봐야 한다.
원리
구간별 시간은 이렇게 해석한다.
| 지표 | 길 때 의심할 것 |
|---|---|
time_namelookup | DNS resolver, authoritative DNS, 잘못된 AAAA, private DNS |
time_connect | TCP 연결, firewall, security group, listener, SYN 재전송 |
time_appconnect | TLS handshake, SNI, 인증서 chain, cipher, backend TLS |
time_pretransfer | proxy tunnel, TLS 이후 요청 준비 |
time_starttransfer | server processing, DB/API, queue, upstream latency |
time_total | 전체 지연, body download, slow client, streaming |
주의할 점은 time_starttransfer가 DNS/connect/TLS 시간을 포함한 누적 시간이라는 것이다. 각 구간의 순수 시간을 보려면 차이를 계산하거나 지표를 비교해야 한다.
Tail Latency와 Queueing
평균 latency가 낮아도 장애일 수 있다.
| 현상 | 의미 |
|---|---|
| p50 정상, p99 급증 | 일부 요청만 queue, lock, slow dependency를 만남 |
| 특정 endpoint만 느림 | route, query, external API, payload 차이 |
| 모든 endpoint first byte 증가 | worker/thread/DB/common dependency 의심 |
| error rate 전 p99 증가 | 고갈 장애의 초기 신호 |
| active max, pending 증가 | pool에서 대기 중 |
queueing은 지연을 조용히 키운다. pool이나 thread에 대기열이 생기면 실제 business logic이 느린 것이 아니라 시작도 못 하고 기다리는 시간이 늘어난다.
실무에서 자주 만나는 문제
- read timeout을 네트워크 지연으로만 해석한다.
- 연결은 됐고 요청도 보냈지만 server나 downstream이 응답을 늦게 준 것일 수 있다.
- app trace, DB slow query, external API span을 본다.
- proxy 504 이후 app이 계속 처리한다.
- 사용자에게는 실패했지만 app thread와 DB transaction은 계속 점유될 수 있다.
- request cancellation, app timeout, DB statement timeout을 맞춘다.
- p99 상승을 traffic 증가 탓으로만 본다.
- 특정 pool pending, lock wait, GC pause, noisy neighbor가 원인일 수 있다.
- saturation metric을 함께 본다.
- retry가 지연을 곱한다.
- 한 요청의 timeout과 retry 횟수를 곱한 최악의 점유 시간을 계산하지 않는다.
- 전체 deadline과 retry budget을 둔다.
디버깅 방법
외부에서 먼저 시간을 나눈다.
curl -sS -o /dev/null \
-w "code=%{http_code}\nremote_ip=%{remote_ip}\ndns=%{time_namelookup}\nconnect=%{time_connect}\ntls=%{time_appconnect}\nfirst_byte=%{time_starttransfer}\ntotal=%{time_total}\n" \
https://example.com/api/orders그 다음 내부 지표를 같은 시간대에 맞춘다.
request rate
error rate
p50 / p95 / p99 latency
worker thread busy
DB pool active / pending
HTTP client pool active / pending
GC pause
external API p95 / p99
retry countAPM trace에서는 요청 하나의 span을 본다.
HTTP server span: 3200ms
DB query span: 2400ms
payment API span: 200ms
serialization: 20msfirst byte가 3초이고 DB query span이 2.4초라면 “네트워크가 느림”보다 DB query나 lock을 먼저 봐야 한다.
코드로 확인하기
NGINX access log에 upstream timing을 남기면 proxy와 app 지연을 분리할 수 있다.
log_format upstream_timing
'$request_id "$request" status=$status '
'request_time=$request_time '
'upstream_status=$upstream_status '
'upstream_connect_time=$upstream_connect_time '
'upstream_header_time=$upstream_header_time '
'upstream_response_time=$upstream_response_time';
access_log /var/log/nginx/access.log upstream_timing;해석은 다음과 같다.
upstream_connect_time이 길면 proxy to app 연결 문제다.upstream_header_time이 길면 app이 첫 응답 header를 늦게 준 것이다.upstream_response_time이 길면 app 처리나 response streaming이 길어진 것이다.request_time은 client 전송까지 포함할 수 있으므로 slow client도 고려한다.
Spring에서는 느린 요청과 dependency 호출을 trace/span으로 남기는 것이 중요하다. 로그만 있으면 “어디서 기다렸는지”가 사라진다.
주니어가 자주 하는 오해
- 평균 latency가 낮으면 장애가 아니라고 생각한다.
- 사용자는 평균이 아니라 자기 요청의 tail latency를 경험한다.
- timeout이 나면 timeout 값을 늘리는 것이 첫 대응이라고 생각한다.
- timeout 증가는 자원 점유 시간을 늘릴 수 있으므로 원인과 완화 효과를 함께 봐야 한다.
curl한 번 빠르면 네트워크가 정상이라고 판단한다.- 간헐 지연은 반복 측정과 p95/p99가 필요하다.
- first byte 지연을 항상 네트워크 구간 지연으로 본다.
- first byte는 서버가 요청을 받은 뒤 처리하는 시간이 길 때도 늘어난다.
시니어의 설계 판단 기준
- endpoint별 SLO와 timeout을 연결한다.
- p99, queue length, pool pending을 alert 후보로 본다.
- proxy timeout, app timeout, DB query timeout, external API timeout을 한 표로 관리한다.
- 오래 걸리는 작업은 동기 요청보다 async job, 202 Accepted, polling으로 바꿀지 검토한다.
- retry를 넣기 전 최악의 점유 시간과 idempotency를 계산한다.
인프라 협업 포인트
- LB target response time과 app p99를 같은 시간대로 비교한다.
- proxy
request_time과 app access log latency가 다르면 client/proxy 구간과 app 구간을 분리한다. - 특정 region만 느리면 CDN edge, DNS resolver, cloud region, peering을 확인한다.
- node/pod saturation은 CPU만 보지 말고 network, file descriptor, conntrack, GC도 함께 본다.
실전 팁
curl -w결과는 장애방에 그대로 붙여 넣기 좋다.- 대시보드는 평균보다 p95/p99와 pool pending을 먼저 보이게 한다.
- 느린 요청 샘플에는 request id, user segment, endpoint, dependency span을 포함한다.
- 개인 프로젝트에서도 NGINX timing log와 Spring request timing log를 연결해 두면 학습 가치가 크다.
위험 신호!
- timeout 값을 늘렸는데 thread/connection 사용량을 보지 않는다.
- p99 알림이 없고 평균 latency 알림만 있다.
- proxy 504 이후 app 작업이 계속되는지 모른다.
- pool pending metric이 없다.
- “서버가 느림”이라는 장애 보고에 curl timing, trace, request id가 없다.
확인 질문
확인 질문
time_starttransfer가 길면 무엇을 의심하는가?
- 서버가 요청을 받은 뒤 첫 바이트를 내기까지의 처리, DB, 외부 API, lock, pool 대기를 의심한다.
- p50은 정상인데 p99가 급증하면 무엇을 봐야 하는가?
- 특정 endpoint, 특정 dependency, pool pending, lock, GC, retry, 일부 target 장애를 봐야 한다.
- proxy timeout 후 app이 계속 처리하면 왜 위험한가?
- 사용자는 실패를 받았지만 서버 자원과 DB transaction은 계속 점유되어 중복 처리나 추가 장애를 만들 수 있기 때문이다.