Nginx 응답 시간 분석: 느린 요청의 p95와 업스트림 지연 찾기

AI Editter

평균 응답시간이 200ms인데 사용자는 종종 몇 초씩 기다릴 수 있습니다. 느린 요청이 일부에 몰려 있으면 평균만으로는 잘 드러나지 않습니다. Nginx 접근 로그에 시간 정보를 남기고 경로별 분포를 보면 확인할 범위를 좁힐 수 있습니다.

다만 요청 전체 시간에서 upstream 시간을 단순히 빼서 “네트워크 지연”이라고 부르는 것은 부정확할 수 있습니다. 요청 본문 수신, 응답 전송, 버퍼링, 재시도 등이 함께 영향을 줍니다.

평균이 정상이어도 특정 경로는 느릴 수 있다

로그인 API 100건이 느린데 정적 파일 수만 건이 빠르면 전체 평균에서 장애가 가려질 수 있습니다. 먼저 경로와 상태 코드를 나누고 동일한 기간의 요청 수·p50·p95를 봅니다. 표본이 너무 적은 경로에서는 p95 한 값으로 결론을 내리지 않습니다. 시간 단위와 누락 행 처리도 기록해야 변경 전후 수치를 비교할 수 있습니다.

분석에 필요한 값만 JSON으로 기록

다음은 Nginx http 문맥에 넣는 로그 형식 예시입니다. 실제 적용 위치와 기존 로그 정책을 확인한 뒤 문법 검사와 재로드를 수행합니다.

log_format timing escape=json
  '{"time":"$time_iso8601","method":"$request_method",'
  '"uri":"$uri","status":$status,"rt":"$request_time",'
  '"uct":"$upstream_connect_time","uht":"$upstream_header_time",'
  '"urt":"$upstream_response_time","ua":"$upstream_addr"}';
access_log /var/log/nginx/timing.log timing;

쿼리 문자열과 인증 헤더는 이 예제에 넣지 않았습니다. URI 경로 자체에도 사용자 식별자나 민감한 값이 들어갈 수 있으므로 수집·마스킹·보관 정책을 확인합니다.

로그 형식과 JSON 이스케이프는 Nginx log 모듈 문서, upstream 시간 변수는 upstream 모듈 문서를 기준으로 해석합니다.

한 요청의 숫자를 읽는 순서

rt는 요청 전체 처리 시간, uct는 upstream 연결, uht는 upstream 응답 헤더, urt는 upstream 응답 관련 시간입니다. 정확한 측정 범위와 재시도 표현을 공식 변수 정의에 맞춰 봅니다.

upstream을 사용하지 않은 요청에는 -가 있을 수 있습니다. 여러 upstream 시도가 있으면 값이 쉼표 등으로 연결될 수 있으므로 단일 float로 무조건 변환하면 안 됩니다. 아래 집계는 rt만 계산하고 upstream 값은 원본 로그에서 해당 요청을 분석하는 데 사용합니다.

Python으로 경로별 p95 계산

아래 스크립트는 JSON Lines 로그 파일을 읽고 최근접 순위 방식으로 p95를 계산합니다. Python 표준 라이브러리만 사용합니다. 큰 로그 전체를 메모리에 올리는 운영 분석 도구는 아니므로, 먼저 시간 범위를 잘라 제한된 파일에 사용합니다.

import json
import math
import sys
from collections import defaultdict

groups = defaultdict(list)
invalid = 0
with open(sys.argv[1], encoding="utf-8") as stream:
    for line in stream:
        try:
            row = json.loads(line)
            value = float(row["rt"])
            if not math.isfinite(value) or value < 0:
                raise ValueError("invalid duration")
            if not isinstance(row["method"], str) or not isinstance(row["uri"], str):
                raise ValueError("invalid request fields")
            key = (row["method"], row["uri"], int(row["status"]))
            groups[key].append(value)
        except (ValueError, TypeError, KeyError):
            invalid += 1

for key, values in sorted(groups.items()):
    values.sort()
    p95 = values[math.ceil(len(values) * 0.95) - 1]
    print(*key, "n=", len(values),
          "avg=", round(sum(values) / len(values), 4),
          "p95=", p95, "max=", values[-1])
print("invalid_rows=", invalid, file=sys.stderr)

python analyze_timing.py sample.log 형식으로 실행합니다. 가상 시간 0.1, 0.2, 0.3, 0.4, 3.0초 다섯 건의 평균은 0.8초, 이 방식의 p95는 3.0초입니다. 표본이 다섯 건뿐이므로 안정적인 서비스 지연 분포라고 해석하지 않습니다.

동적 ID가 들어간 /orders/123와 /orders/124를 같은 기능으로 비교하려면 라우트 패턴으로 정규화하는 별도 기준이 필요합니다. 숫자가 들어간 모든 경로를 임의로 합치면 서로 다른 기능이 섞일 수 있습니다.

느린 요청을 upstream과 대조

로그 시간 변수는 구간이 겹칠 수 있어 단순 합산하지 않습니다. 느린 요청의 시각과 경로를 앱·DB 로그에 연결하고, 가능하면 개인정보가 없는 요청 ID로 대조합니다.

비교할 때는 분모를 맞춘다

배포 전후 같은 시간대와 경로, 상태 코드, 요청량을 비교합니다. 성공 요청만 빠르게 남고 실패가 늘어난 경우 평균이 좋아 보일 수 있으므로 오류율도 봅니다. 분석에서 제외된 행 수를 반드시 확인합니다.

캐시 적중과 원본 요청을 섞으면 해석이 달라집니다. 필요하면 캐시 상태를 별도 필드로 수집하되 로그 크기와 노출 정보를 검토합니다.

개선 후 같은 예제로 다시 확인

원인을 좁힌 뒤 한 변경을 적용하고 p95·최대값·오류율·처리량을 다시 봅니다. 평균만 좋아졌는지, 실제 느린 구간이 줄었는지 구분합니다.

운영 로그에는 접근 제한과 순환 보관을 적용합니다. 진단을 위해 만든 로그가 디스크를 채워 새 장애를 만들지 않도록 사용량과 보관 기간을 함께 관리해야 합니다.

관련 절차: Nginx 502·504 오류 해결: upstream 로그로 원인 찾는 순서