NGINX $request_id 변수로 애플리케이션 추적하기

애플리케이션 성능 관리를 위한 변수 사용
변수는 NGINX 구성에서 중요하지만 가끔 간과되는 측면입니다. 약 150개의 변수를 사용할 수 있으므로 구성의 모든 부분을 개선할 수 있는 변수가 있습니다. 이 포스트에서는 애플리케이션의 성능 병목 현상을 발견하는 데 중점을 두고 애플리케이션 추적 및 애플리케이션 성능 관리(APM)에 NGINX $request_id 변수를 사용하는 방법에 대해 설명합니다. 이 포스트는 NGINX Open Source와 NGINX Plus 모두에 적용됩니다. 간결함을 위해 두 버전 간에 차이가 있는 경우를 제외하고 전체적으로 NGINX Plus를 참조합니다.

목록

1. 애플리케이션 제공 환경
2. 종단간 요청 추적
3. $request_id 종단간 로깅
3-1. NGINX Plus 구성
3-2. 백엔드 애플리케이션 구성
4. 정밀한 타이밍
5. 결론

1. 애플리케이션 제공 환경

샘플 애플리케이션 제공 환경에서 NGINX Plus는 애플리케이션의 리버스 프록시로 작동합니다. 애플리케이션 자체는 수많은 마이크로서비스가 있는 웹 프런트엔드로 구성됩니다.

샘플 애플리케이션 제공 환경

샘플 애플리케이션 제공 환경

2. 종단간 요청 추적

NGINX Plus R10(NGINX 1.11.0)이상부터는 $request_id 변수가 도입되었습니다. 이 변수는 임의로 생성된 32개의 16진수 문자열로 각 HTTP 요청이 도착하면 자동으로 할당됩니다(예: 444535f9378a3dfa1b8604bc9e05a303). 믿을 수 없을 정도로 단순한 이 메커니즘은 추적 및 문제 해결을 위한 강력한 도구를 제공합니다. $request_id 값을 전달하도록 NGINX Plus 및 모든 백엔드 서비스를 구성하면 모든 요청을 종단간 추적할 수 있습니다. 이 샘플 구성은 NGINX Plus 서버용입니다.

upstream app_server {
    server 10.0.0.1:80;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id; # Pass to app server
    }
}

요청 추적을 위해 NGINX Plus를 구성하려면 먼저 upstream 블록에서 애플리케이션 서버의 네트워크 위치를 정의합니다. 단순화를 위해 여기서는 단일 애플리케이션 서버만 표시하지만 일반적으로 고가용성 및 로드 밸런싱 목적을 위해 여러 개를 사용합니다.

애플리케이션 server 블록은 NGINX Plus가 들어오는 HTTP 요청을 처리하는 방법을 정의합니다. listen 지시문은 NGINX Plus에 HTTP 트래픽의 기본값인 포트 80에서 수신하도록 지시하지만 프로덕션 구성에서는 일반적으로 SSL/TLS를 사용하여 전송 중인 데이터를 보호합니다.

add_header 지시문은 $request_id 값을 응답의 사용자 지정 헤더로 클라이언트에 다시 보냅니다. 이는 클라이언트 측 오류를 서버 로그와 정확히 일치시킬 수 있도록 모바일 앱과 같이 자체 로그를 생성하는 클라이언트 애플리케이션 및 테스트에 유용합니다.

마지막으로 location 블록은 전체 애플리케이션 공간(/)에 적용되며 proxy_pass 지시문은 단순히 애플리케이션 서버에 대한 모든 요청을 프록시합니다. proxy_set_header 지시문은 애플리케이션에 전달되는 HTTP 헤더를 추가하여 프록시된 요청을 수정합니다. 이 경우 X-Request-ID라는 새 헤더를 만들고 여기에 $request_id 변수의 값을 할당합니다. 따라서 우리 애플리케이션은 NGINX Plus에서 생성된 요청 ID를 받습니다.

3. $request_id 종단간 로깅

애플리케이션 추적의 목표는 애플리케이션 성능 관리의 일부로 요청 처리 수명 주기에서 성능 병목 현상을 식별하는 것입니다. 처리 중에 중요한 이벤트를 기록하여 나중에 예기치 않거나 비합리적인 지연을 분석할 수 있습니다.

3-1. NGINX Plus $request_id 구성

먼저 access_trace.log 파일에 사용되는 사용자 지정 로깅 형식인 trace에 $request_id를 포함하도록 프런트엔드 NGINX Plus 서버를 구성합니다.

log_format trace '$remote_addr - $remote_user [$time_local] "$request" '
                 '$status $body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id';

upstream app_server {
    server 10.0.0.1;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id;        # Pass to app server
        access_log /var/log/nginx/access_trace.log trace; # Log $request_id
    }
}

3-2. 백엔드 애플리케이션 구성

요청 ID를 애플리케이션에 전달하는 것은 모두 훌륭하지만 애플리케이션이 무언가를 수행하지 않는 한 실제로 애플리케이션 추적에 도움이 되지 않습니다. 이 예제에는 uWSGI에서 관리하는 Python 애플리케이션이 있습니다. 요청 ID를 로깅 변수로 가져오도록 애플리케이션 진입점을 수정해 보겠습니다.

from uwsgi import set_logvar

def main(environ, start_response):
    set_logvar('requestid', environ['X_REQUEST_ID'])

그런 다음 표준 로그 파일에 요청 ID($requestid)를 포함하도록 uWSGI 구성을 수정할 수 있습니다.

log-format = %(addr) - %(user) [%(ltime)] "%(method) %(uri) %(proto)" %(status) 
%(size) "%(referer)" "%(uagent)" %(requestid)

이 구성을 사용하여 이제 수많은 시스템에서 단일 요청에 연결할 수 있는 로그 파일을 생성하고 있습니다.

NGINX의 로그(Log) :

172.17.0.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.1" 200 90 "-" "-" "-" 5f222ae5938482c32a822dbf15e19f0f

애플리케이션의 로그(Log) :

192.168.91.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.0" 200 123 "-" "-" 5f222ae5938482c32a822dbf15e19f0f

요청 ID($requestid) 필드와 트랜잭션을 일치시켜 Splunk 및 Kibana와 같은 도구를 사용하면 애플리케이션 서버의 성능 병목 현상을 식별할 수 있습니다. 예를 들어 완료하는 데 2초 이상 소요된 요청을 검색할 수 있습니다. 그러나 일반 타임스탬프에서 1초의 기본 시간 해상도는 대부분의 실제 분석에 충분하지 않습니다.

4. 정밀한 타이밍

종단간 요청을 정확하게 측정하기 위해서는 밀리초(ms) 수준의 정밀도를 가진 타임스탬프가 필요합니다. 로그 항목에 $msec 변수를 포함하면 각 항목의 타임스탬프에서 밀리초(ms) 단위의 해상도를 얻을 수 있습니다. 애플리케이션 로그에 밀리초 타임스탬프를 추가하면 완료하는 데 2초가 아닌 200밀리초 이상 걸리는 요청을 찾을 수 있습니다.

그러나 NGINX Plus는 각 요청 처리가 끝날 때만 $msec 타임스탬프를 작성하기 때문에 전체 그림을 볼 수 없습니다. 다행히 처리 자체에 대한 더 많은 통찰력을 제공하는 밀리초 정밀도의 다른 NGINX Plus 타이밍 변수가 몇 가지 있습니다.

  • $request_time – NGINX Plus가 클라이언트에서 첫 번째 바이트를 읽을 때 시작하여 NGINX Plus가 응답 본문의 마지막 바이트를 보낼 때 끝나는 전체 요청 시간
  • $upstream_connect_time – 업스트림 서버와의 연결 설정에 소요된 시간
  • $upstream_header_time – 업스트림 서버에 대한 연결 설정과 응답 헤더의 첫 번째 바이트 수신 사이의 시간
  • $upstream_response_time – 업스트림 서버에 대한 연결 설정과 응답 본문의 마지막 바이트 수신 사이의 시간

추적 로그 형식에 이러한 고정밀 타이밍 변수를 모두 포함하도록 log_format 지시문을 확장해 보겠습니다.

log_format trace '$remote_addr - $remote_user [$time_local] "$request" $status '
                 '$body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id $msec $request_time '
                 '$upstream_connect_time $upstream_header_time $upstream_response_time';

선호하는 로그 분석 도구를 사용하여 변수 값을 추출하고 다음 계산을 수행하여 NGINX Plus가 애플리케이션 서버에 연결하기 전에 요청을 처리하는 데 걸린 시간을 확인할 수 있습니다.

NGINX Plus processing time = $request_time - $upstream_connect_time - $upstream_response_time

또한 $upstream_response_time의 가장 높은 값을 검색하여 특정 URI 또는 업스트림 서버와 연결되어 있는지 확인할 수 있습니다. 그런 다음 동일한 요청 ID를 가진 애플리케이션 로그 항목에 대해 추가로 확인할 수 있습니다.

5. $request_id 결론

새로운 $request_id 변수와 일부 또는 모든 밀리초(ms) 정밀도 변수를 활용하면 애플리케이션의 성능 병목 현상에 대한 뛰어난 통찰력을 제공하여 무거운 에이전트 및 플러그인에 의존하지 않고도 애플리케이션 성능 관리를 개선할 수 있습니다.

NGINX Plus로 애플리케이션 추적을 직접 사용해 보십시오. 지금 무료로 30일 평가판을 시작하거나 당사에 연락하여 사용 사례에 대해 논의하십시오.

사용 사례에 대해 최신 소식을 빠르게 전달받고 싶으시면 아래 뉴스레터를 구독하세요.

NGINX STORE 뉴스레터 및 최신 소식 구독하기

* indicates required