실습 노트 2 요청 시간의 영수증 만들기

31장의 로컬 서버를 실행해 둔 상태에서 진행한다. 새 프로그램을 설치하거나 외부 사이트에 요청을 보낼 필요는 없다. 목적은 특정 제품의 성능 점수를 얻는 것이 아니라 연결과 응답, 전체 완료 시간을 구분해 보는 것이다. 루프백 측정 결과를 인터넷의 지연이라고 부르지 않는다.

한 번에 너무 많은 것을 재지 않기

먼저 /health가 성공하는지 확인한다. 그다음 /slow를 요청해 의도한 지연이 보이는지 확인한다. 그 뒤에 시간 제한을 바꾼다. 한 번에 주소, 서버 코드, 시간 제한을 모두 바꾸면 결과가 달라진 이유를 알기 어렵다. 실험의 변수는 가능하면 하나씩 바꾸고 나머지 조건을 기록한다.

curl의 시간 출력은 여러 구간의 누적 시각을 제공한다. time_namelookup, time_connect, time_starttransfer, time_total 같은 값을 함께 보면 어디까지 기다렸는지 가늠할 수 있다. HTTPS에서는 TLS 준비 시간도 별도로 볼 수 있다. 도구 버전에 따른 정확한 정의는 공식 문서를 확인해야 한다. 누적값을 모두 더하면 전체 시간이 중복 계산될 수 있다는 점을 특히 주의하자.

# POSIX shell example. Use curl.exe in Windows if needed.
curl --silent --show-error --output /dev/null \
  --max-time 2 \
  --write-out 'code=%{http_code} dns=%{time_namelookup} connect=%{time_connect} first=%{time_starttransfer} total=%{time_total}\n' \
  http://127.0.0.1:8765/slow

위의 /dev/null은 POSIX 계열의 출력 버리기 장치다. Windows에서는 해당 부분을 NUL로 바꿀 수 있다. 여러 줄 이어 쓰기 기호도 셸마다 다르므로 Windows에서는 한 줄로 적는 편이 간단하다. 서로 다른 셸의 따옴표와 줄 연결 문법을 섞지 않는다. 명령이 해석되지 않는 문제와 네트워크 실패는 다른 문제다.

curl.exe --silent --show-error --output NUL --max-time 2 --write-out "code=%{http_code} connect=%{time_connect} first=%{time_starttransfer} total=%{time_total}" http://127.0.0.1:8765/slow

측정값을 어떻게 읽을까

예를 들어 연결 누적 시간이 작고 첫 바이트까지 약 0.4초가 걸린다면, 이 실습에서는 서버의 의도적인 대기와 맞는 결과다. 전체 시간이 첫 바이트 시간과 거의 같을 수 있는 이유는 응답 본문이 매우 작기 때문이다. 큰 파일이라면 첫 바이트 이후의 전송 시간이 길어질 수 있다. 작은 JSON의 측정으로 대용량 다운로드 성능을 대표할 수는 없다.

첫 바이트 시간에는 서버의 순수 계산 시간만 들어 있는 것이 아니다. 앞선 준비와 요청 전달, 서버 대기, 응답 전달이 영향을 준다. 따라서 이 값을 곧바로 데이터베이스 질의 시간으로 부르면 안 된다. 서버 내부의 추적 자료와 함께 봐야 더 세밀하게 나눌 수 있다. 클라이언트 측정과 서버 측정은 서로 보완한다.

반복 측정과 분포

한 번의 결과는 우연한 스케줄링이나 다른 작업의 영향을 받는다. 작고 제한된 횟수로 반복해 분포를 보자. 아래 코드는 로컬 서버에 순차적으로 여섯 번 요청한다. 초당 수천 건을 보내는 부하 시험이 아니며, 예외가 발생하면 그 사실을 보여 준다. 네트워크 주소를 외부 사이트로 바꾸어 반복 실험하지 않는다.

from urllib.request import urlopen
from time import perf_counter, sleep
from statistics import mean, median

durations = []
for attempt in range(6):
    started = perf_counter()
    with urlopen("http://127.0.0.1:8765/slow", timeout=2) as response:
        content = response.read()
        status = response.status
    elapsed = perf_counter() - started
    durations.append(elapsed)
    print(attempt + 1, status, len(content), round(elapsed, 4))
    sleep(0.1)

print("mean seconds:", round(mean(durations), 4))
print("median seconds:", round(median(durations), 4))
print("maximum seconds:", round(max(durations), 4))

표본 여섯 개로 정밀한 p99를 주장할 수는 없다. 여기서는 반복 결과가 정확히 같지 않다는 점과 평균, 중앙값, 최댓값의 차이를 관찰한다. 보고서에는 횟수와 환경을 함께 적는다. 소수점 자릿수를 많이 표시한다고 자료의 신뢰성이 높아지는 것은 아니다. 불확실성이 큰 측정에 지나치게 정밀한 표현을 붙이지 말자.

시간 예산을 나누는 연습

가상의 검색 요청이 전체 1초 안에 끝나야 한다고 하자. 인증 확인, 데이터 조회, 결과 생성, 전송에 각각 필요한 시간을 측정하고 여유를 남긴다. 내부 API마다 1초를 주면 여러 호출을 순서대로 기다리며 전체 한도를 넘길 수 있다. 남은 시간을 아래 호출에 전달하고 불필요한 작업을 취소하는 방식이 필요하다.

시간 제한을 너무 짧게 잡으면 정상적인 느린 요청까지 실패해 재시도가 늘 수 있다. 너무 길게 잡으면 실패한 의존성을 기다리는 요청이 자원을 묶는다. 현재 지연 분포와 사용자 기대, 재시도 정책을 함께 보고 정해야 한다. 실습의 0.1초와 2초는 차이를 관찰하기 위한 값이지 실제 서비스의 권장 설정이 아니다.

마지막으로 서버를 종료하고 반복 코드를 실행하지 말고 단일 요청만 보내 보자. 응답 시간이 없는 연결 실패와 느린 성공을 구분할 수 있을 것이다. 측정 표에는 실패를 0초 성공처럼 넣지 않는다. 성공한 요청의 지연만 좋아지고 실패율은 높아지는 왜곡을 피하려면 지연과 성공률을 함께 보고해야 한다.