콘텐츠로 이동

Postman의 300ms는 어디에서 생겼을까

Postman의 응답 시간과 서버 로그의 차이를 곧바로 “네트워크”라 부르지 않고, 도구마다 다른 측정 경계를 맞춰 원인을 좁힙니다.

예상 읽기 시간 8분 · 핵심 질문: 전체 시간에서 어느 구간이 실제로 길었는가

Postman에는 350ms가 보이고 Spring 서비스 로그에는 50ms가 남았다고 하자. 흔히 둘을 빼서 “네트워크가 300ms”라고 결론 내린다. 그러나 300ms에는 DNS·TCP·TLS뿐 아니라 프록시 연결 대기, 서버 작업 대기, 보안 필터, 데이터베이스 연결 대기, JSON 직렬화와 응답 전송이 모두 들어갈 수 있다.

두 숫자의 차이는 원인이 아니라 아직 측정하지 않은 구간의 합이다. 지연 분석의 첫 단계는 설정을 바꾸는 일이 아니라 각 타이머가 어디서 시작하고 끝나는지 문장으로 적는 일이다.

클라이언트 전체 시간
≈ 연결 준비
+ 요청 업로드
+ 엣지·프록시 처리와 대기
+ 서버 런타임 대기
+ 업무 로직과 의존 서비스
+ 직렬화·압축·버퍼 비우기
+ 응답 다운로드

Postman의 숫자는 사용자에 가까운 전체 시간이다

Postman은 한 요청을 재현하고 응답 헤더·인증서·프로토콜과 구간별 타이밍을 빠르게 확인하기 좋다. 하지만 애플리케이션의 스레드 풀이나 데이터베이스 잠금이 왜 느렸는지를 자동으로 알려 주지는 않는다. 큰 JSON을 화면에 그리거나 응답 뒤 스크립트를 실행하는 비용도 서버 처리와 분리해서 봐야 한다.

반면 애플리케이션의 서비스 메서드 타이머는 대개 서버 안쪽의 일부만 잰다. 요청이 작업 스레드를 기다린 시간과 보안 필터를 이미 지난 뒤 시작하고, 객체를 반환하면 JSON 직렬화와 실제 소켓 전송 전에 끝날 수 있다. 따라서 postman_total - service_time에 “network”라는 이름을 붙이면 미측정 서버 구간까지 감춰진다.

먼저 같은 URL·메서드·헤더·본문을 사용하고 VPN과 회사 프록시 사용 여부, 응답 크기, 첫 요청인지 반복 요청인지를 기록한다. 조건이 다르면 두 측정은 같은 요청을 설명하지 않는다.

연결 준비 시간은 누적 시각을 빼서 구한다

curl은 요청 시작부터 DNS 완료, TCP 연결 완료, TLS 완료, 첫 바이트, 전체 완료까지의 누적 시간을 제공한다. 각 값을 독립된 구간처럼 더하면 같은 시간을 여러 번 계산한다.

DNS 조회              = time_namelookup
DNS 뒤 TCP 연결       = time_connect - time_namelookup
TCP 뒤 TLS 협상       = time_appconnect - time_connect
전송 준비 뒤 첫 바이트 = time_starttransfer - time_pretransfer
응답 본문 전송        = time_total - time_starttransfer

time_starttransfer - time_pretransfer에도 요청 업로드, 프록시 대기와 서버 처리가 섞일 수 있다. 이 값을 “서버 시간”이라고 부르지 않고 전송 준비 뒤 첫 바이트까지라고 경계 그대로 기록해야 한다.

첫 요청만 느리면 DNS 캐시 미적중, 새 TCP·TLS 연결, 애플리케이션의 차가운 캐시를 분리한다. 매번 새 curl 프로세스를 실행하면 기존 연결을 재사용하지 못할 수 있다. 실제 연결 풀을 쓰는 클라이언트와 같은 조건인지 num_connects, 원격 주소와 HTTP 버전을 함께 확인한다.

프록시는 새 대기열과 재시도를 만든다

Nginx나 클라우드 부하 분산기는 사용자의 연결을 끝내고 상위 서버와 별도 연결을 만든다. 상위 연결 풀에 빈 연결이 없으면 기다리고, 시간 제한에 걸리면 다른 서버로 재시도할 수 있다. 사용자가 한 번 보낸 요청이 상위 서버에는 여러 번 도착하는 이유다.

시간 제한은 각 계층에 큰 숫자를 독립적으로 넣는 방식으로 설계하면 안 된다. 사용자가 기다릴 수 있는 전체 마감 시각 안에서 연결, 상위 서버 처리와 재시도 예산을 나눈다. 바깥 프록시가 세 번, 애플리케이션이 하위 서비스를 세 번 재시도하면 원래 한 요청이 최대 아홉 번으로 증폭될 수 있다.

프록시 로그에는 전체 요청 시간, 상위 서버 연결 시간, 첫 응답 헤더 시간, 전체 응답 시간을 함께 남긴다. 여러 상위 서버 시도가 있으면 값이 여러 개 기록될 수 있으므로 마지막 숫자만 저장해 재시도를 숨기지 않는다.

첫 바이트가 늦은 것과 본문이 늦은 것을 나눈다

TTFB(Time To First Byte, 최초 바이트 수신 시간)는 클라이언트가 요청을 시작한 뒤 첫 응답 바이트를 받을 때까지다. 새 연결에서는 DNS·TCP·TLS를 포함하고, 요청 업로드·프록시·서버·데이터베이스가 첫 결과를 만드는 시간도 포함한다. 순수한 백엔드 실행 시간이 아니다.

TTFB는 큰데 첫 바이트 뒤 전송은 짧다면 연결 준비와 서버 앞쪽을 본다. TTFB는 짧은데 전체 시간이 길다면 응답 크기, 전송률, 압축과 스트리밍을 본다. 둘 다 길면 첫 바이트 이전과 본문 전송에 서로 다른 문제가 동시에 있을 수도 있다.

CPU가 낮아도 대기열은 길 수 있다

서버 런타임의 작업 스레드, Netty 이벤트 루프, 데이터베이스 연결 풀, 데이터베이스 잠금은 모두 실행 기회를 기다리는 지점이다. 이 대기는 컨트롤러와 SQL 실행 타이머 바깥에 놓이기 쉽다.

각 풀에는 사용 중인 자원 수, 대기 요청 수와 자원을 얻는 데 걸린 시간을 남긴다. 풀을 늘려 대기 시간을 없애는 것은 해결이 아닐 수 있다. 하위 데이터베이스의 CPU와 잠금이 이미 포화라면 더 많은 동시 요청이 들어가 전체 p99와 오류율을 높인다. 대기열은 병목을 보여 주는 신호이자 하위 시스템을 보호하는 완충 장치다.

객체를 반환한 뒤에도 응답은 끝나지 않았다

컨트롤러가 객체를 반환하면 JSON 인코딩, 압축, 버퍼 비우기, 프록시 버퍼링과 네트워크 다운로드가 남는다. 큰 객체 그래프를 순회하거나 지연 로딩이 추가 SQL을 만들면 이 구간이 업무 로직보다 길 수 있다.

응답 바이트 수와 전체 시간 - 첫 바이트 시간을 함께 본다. 필요한 필드만 보낸 응답, 압축한 응답과 원본을 비교하면 계산과 전송 가운데 무엇이 줄었는지 알 수 있다. 스트리밍은 첫 결과를 빠르게 보내지만 중간 프록시가 본문을 모두 모아 전달하면 효과가 사라진다.

네 개의 시계를 같은 요청으로 연결한다

클라이언트는 전체 시간과 연결 구간을, 프록시는 전체 요청과 상위 서버 구간을, 서버는 작업 대기·업무 로직·직렬화를, 데이터베이스는 연결·잠금 대기와 SQL 실행을 측정한다. 공통 요청 식별자를 전달해 한 요청의 기록을 묶는다.

flowchart TB
  C["클라이언트<br/>DNS·연결·TLS·첫 바이트·전체"] --> P["프록시<br/>전체 요청·상위 연결·상위 응답"]
  P --> A["애플리케이션<br/>작업 대기·필터·업무 로직·직렬화"]
  A --> D["데이터베이스<br/>연결 대기·잠금 대기·SQL 실행"]
  C -. "같은 요청 식별자로 연결" .-> D

정확히 동기화된 절대 시각이 없어도 각 시스템 안에서 측정한 소요 시간과 같은 요청 식별자를 결합하면 병목을 좁힐 수 있다. 소수점 단위 시계를 억지로 맞추기보다 각 숫자의 시작·끝을 분명히 하는 편이 먼저다.

300ms를 줄이는 실제 순서

첫째, 한 번만 측정하지 말고 첫 연결과 재사용 연결을 나눠 충분한 표본에서 p50·p95·p99를 본다. 평균은 정상인데 p99만 크다면 일부 요청이 재시도·잠금·특정 데이터 분할에 걸리는지 찾는다.

둘째, 가장 큰 구간에 가설 하나를 세운다. 연결 준비가 크다면 같은 연결 재사용 전후를, 프록시와 상위 서버 차이가 크다면 연결 풀과 재시도를, 서버 내부 대기가 크다면 동시 실행 상한을 비교한다. 한 번에 여러 설정을 바꾸면 무엇이 효과였는지 알 수 없다.

셋째, 개선과 함께 오류율과 처리량을 본다. 시간 제한을 짧게 해 평균 지연이 줄었지만 정상 요청까지 실패한다면 개선이 아니다. 연결 풀을 키워 중간 대기는 줄었지만 데이터베이스 p99가 늘어도 마찬가지다.

마지막으로 사용자 SLO(Service Level Objective, 서비스 수준 목표)에서 전체 지연 예산을 나눈다. 하위 호출마다 사용자 전체 제한 시간과 같은 300ms를 주면 연쇄 호출이 마감 시각을 훨씬 넘는다. 남은 시간을 하위 요청에 전달하고, 재시도도 그 예산 안에서만 수행한다.

지연 분석의 결론은 “네트워크가 느렸다”가 아니라 다음처럼 남아야 한다.

첫 연결의 p95 340ms 중 DNS·TCP·TLS가 180ms였고, 재사용 연결에서는 35ms로 줄었다. 상위 서버 응답은 두 조건 모두 70ms 안팎이었다. 모바일 클라이언트의 연결 재사용 실패와 프록시 유휴 시간 제한 불일치를 먼저 수정하고, 서버 질의 최적화는 이번 병목에서 제외한다.

참고 자료