NGINX JavaScript 모듈을 사용한 로그 진단
이번 포스트는 Production 배포의 어려운 점 중 하나인 로깅에 대해 설명하며 NGINX JavaScript 모듈을 사용하여 로그를 수집하는 사례와 구성 방법을 제시하여 불필요한 데이터에 휩싸이지 않고 문제 해결을 위해 적절한 양의 상세 로그를 수집하는 작업에 대해 논의합니다.
NGINX는 모든 규모의 조직이 미션 크리티컬(Mission Critical) 웹 사이트, 애플리케이션 및 API를 실행할 수 있도록 지원합니다. 구축 인프라의 규모 선택에 관계없이 Production을 구현하는 것은 쉽지 않습니다.
목차
1. 로깅의 기본구성
2. Production 로깅의 현실
3. 오류에 대한 두 번째 Access Log 사용
4. NGINX JavaScript 를 사용한 JSON 로깅
5. 요약
1. 로깅의 기본구성
NGINX는 클라이언트 요청에 대한 Access Logging과 문제가 발생할 때의 Error Logging이라는 두 가지 로깅 메커니즘을 제공합니다. 이러한 메커니즘은 HTTP 및 Stream(TCP/UDP) 모듈 모두에서 사용할 수 있지만 여기서는 HTTP 트래픽에 중점을 두고 있습니다. (Debug Severity Level을 사용하는 세 번째 로깅 메커니즘도 있지만 이번에 논의하지 않습니다.)
일반적인 NGINX 로깅의 기본구성은 다음과 같습니다.
http {
log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for"';
access_log /var/log/nginx/access.log main; # Log using the 'main' format
error_log /var/log/nginx/error.log warn; # Log up to 'warn' severity level
...
}log_format Directive(지시문)는 access_log Directive가 구성에 포함될 때 생성되는 로그 항목의 내용과 구조를 설명합니다. 위의 예는 많은 웹 서버에서 사용되는 CLF(Common Log Format)의 확장입니다. error_log Directive을 사용하 기록할 메시지의 심각도 수준(Severity Level)을 지정할 수 있지만 고정된 항목의 내용이나 형식은 지정할 수 없습니다. 다음 섹션에서 자세히 설명합니다.
NGINX 로깅의 다른 주목할만한 측면은 다음과 같습니다.
- 로깅 Directive은 하위 수준 구성 Context(컨텍스트)에서 자동으로 상속됩니다. 예를 들어 http Context의 access_log Directive은 모든 server{} 블록에 적용됩니다.
- 하위 Context의 로깅 Directive은 상속된 Directive를 재정의합니다.
- 동일한 Context에 여러 로깅 Directive가 존재할 수 있습니다. 예를 들어 두 개의 access_log Directive를 사용하여 표준 CLF 로그 파일과 두 번째로 상세 로그를 만들 수 있습니다.
2. Production 로깅의 현실
일반적으로 Access Log를 사용하여 분석 및 사용량 통계를 제공하고 Error Log를 사용하여 Error 감지 및 문제 해결을 수행하고자 합니다. 그러나 Production 시스템을 운영하는 것은 그렇게 간단하지 않습니다. 다음은 몇 가지 일반적인 문제입니다.
- Access Log에는 문제 해결을 위한 세부 정보가 충분하지 않습니다.
- Error Log는 정보 심각도 수준에서 좋은 세부 정보를 공개하지만 일반 작업에는 너무 장황합니다.
- Error Log의 항목은 요청 Context를 포함하지 않으며 해당 Access Log 항목과 일치시키기 어렵습니다.
또한 Production 환경에서 로깅 세부 정보를 추가하거나 제거하기 위해 NGINX 구성(Conf)을 변경하려면 a change‑control process를 수행하고 구성을 다시 배포해야 할 수도 있습니다. 전적으로 안전하지만 “4xx/5xx Error가 급증하는 이유는 무엇입니까?”와 같은 실시간 문제를 해결할 때 다소 번거롭습니다. 이것은 물론 클러스터 전체에서 동일한 트래픽을 처리하는 여러 NGINX 인스턴스가 있을 때 확대됩니다.
3. Error에 대한 두 번째 Access Log 사용
Access Log의 형식을 사용자 지정하여 각 요청에 대해 수집된 데이터를 풍부하게 하는 것은 고급 분석을 위한 일반적인 접근 방식이지만 진단이나 문제 해결을 위한 확장에는 적합하지 않습니다. 일반적인 분석보다 문제 해결을 위해 훨씬 더 많은 정보를 원하기 때문에 기본 Access Log에 두 가지 작업을 요청하는 것이 해결책입니다. 기본 Access Log에 여러 변수를 추가하면 유용한 데이터 로그 양을 크게 늘릴 수 있습니다.
대신 두 번째 Access Log를 사용하여 디버깅이 필요한 Error가 발생할 때만 기록할 수 있습니다. access_log Directive는 if 매개 변수를 사용하여 조건부 로깅을 지원합니다. 지정된 변수가 0이 아닌 비어 있지 않은 값으로 평가되는 경우에만 요청이 기록됩니다.
map $status $is_error {
400 1; # Bad request, including expired client cert
495 1; # Client cert error
502 1; # Bad gateway (no upstream server could be selected)
504 1; # Gateway timeout (couldn't connect to selected upstream)
default 0;
}
access_log /var/log/nginx/access_debug.log access_debug if=$is_error; # Diagnostic logging
access_log /var/log/nginx/access.log main;이 구성에서는 map 블록을 통해 $status 변수를 전달하여 $is_error 변수의 값을 결정한 다음 access_log Directive의 if 매개변수에 의해 평가됩니다. $is_error가 1로 평가되면 access_debug.log 파일에 특수 로그 항목을 기록합니다.
그러나 이 구성은 상태 200 OK가 되는 요청 처리 중에 발생한 Error를 감지하지 않습니다. 예 중 하나는 NGINX가 여러 Upstream 서버 간에 Load Balancing을 수행하는 경우입니다. 선택한 서버에서 Error가 발생하면 NGINX는 proxy_next_upstream Directive에 의해 구성된 조건에 따라 요청을 다음 서버로 전달합니다. Upstream 서버 중 하나가 성공적으로 응답하는 한 클라이언트는 성공적인 응답을 수신하고 이 응답은 상태 200으로 기록됩니다. Upstream 서버가 비정상이지 않을 수도 있지만 결국 200을 기록하게됩니다.
NGINX가 여러 Upstream 서버에 Proxy를 시도하면 해당 서버 주소가 모두 $upstream_addr 변수에 캡처됩니다. 시도된 각 서버에서 응답 코드를 캡처하는 $upstream_status와 같은 다른 $upstream_* 변수에 대해서도 마찬가지입니다. 따라서 이러한 변수에 여러 항목이 표시되면 문제가 발생했음을 알 수 있습니다. 즉, 적어도 하나 이상의 Upstream 서버에 문제가 있을 수 있습니다.
요청이 여러 Upstream 서버에 Proxy되었을 때 access_debug.log에도 기록하는 것은 어떨까요?
map $upstream_status $multi_upstreams {
"~," 1; # Has a comma
default 0;
}
map $status $is_error {
400 1; # Bad request, including expired client cert
495 1; # Client cert error
502 1; # Bad gateway (no upstream server could be selected)
504 1; # Gateway timeout (couldn't connect to selected upstream)
default $multi_upstreams; # If we tried more than one upstream server
}
access_log /var/log/nginx/access_debug.log access_debug if=$is_error; # Diagnostic logging
access_log /var/log/nginx/access.log main; # Regular logging여기에서 다른 map 블록을 사용하여 $upstream_status에 쉼표(,)가 있는지 여부에 따라 값이 달라지는 새 변수($multi_upstreams)를 생성합니다. 쉼표는 둘 이상의 상태 코드가 있으므로 둘 이상의 Upstream 서버가 발견되었음을 의미합니다. 이 새 변수는 $status가 나열된 Error Code 중 하나가 아닌 경우 $is_error의 값을 결정합니다.
이 시점에서 일반적인 Access Log와 잘못된 요청이 포함된 특수 access_debug.log 파일이 있지만 아직 access_debug 로그 형식을 정의하지 않았습니다. 이제 문제를 진단하는 데 도움이 되도록 access_debug.log 파일에 필요한 모든 데이터가 있는지 확인하겠습니다.
4. NGINX JavaScript 를 사용한 JSON 로깅
진단 데이터를 access_debug.log로 가져오는 것은 어렵지 않습니다. NGINX는 HTTP 처리와 관련된 100개 이상의 변수를 제공하며, 필요한 만큼 많은 변수를 캡처하는 특별한 log_format Directive를 정의할 수 있습니다. 그러나 이 목적을 위해 로그 형식을 구축하는 데는 몇 가지 단점이 있습니다.
- 사용자 지정 형식입니다. 로그 Parser를 읽는 방법을 교육해야 합니다.
- 실시간 문제 해결 중에 사람이 읽기에는 항목이 매우 길고 어려울 수 있습니다.
- 항목을 해석하려면 로그 형식을 지속적으로 참조해야 합니다.
- “모든 요청 헤더”와 같은 비결정론적 값은 기록할 수 없습니다.
NGINX JavaScript 모듈(njs)을 사용하여 JSON과 같은 구조화된 형식으로 로그 항목을 작성하여 이러한 문제를 해결할 수 있습니다. JSON 형식은 Splunk, LogStash, Graylog 및 Loggly와 같은 로그 처리 시스템에서도 널리 지원됩니다. log_format 구문을 JavaScript 함수로 Offload으로써 모든 NGINX 변수 및 njs ‘r’ 개체의 추가 데이터에 Access 할 수 있는 기본 JSON 구문의 이점을 누릴 수 있습니다.
js_import conf.d/json_log.js;
js_set $json_debug_log json_log.debugLog;
log_format access_debug escape=none $json_debug_log; # Offload to njs
access_log /var/log/nginx/access_debug.log access_debug if=$is_error;js_import Directive은 JavaScript 코드가 포함된 파일을 지정하고 이를 모듈로 가져옵니다. 코드 자체는 여기에서 찾을 수 있습니다. access_debug 로그 형식을 사용하는 Access Log 항목을 작성할 때마다 $json_debug_log 변수가 평가됩니다. 이 변수는 js_set Directive에 의해 정의된 대로 DebugLog JavaScript 함수를 실행하여 평가됩니다.
JavaScript 코드와 NGINX 구성의 조합은 다음과 같은 진단 로그를 생성합니다.
$ tail --lines=1 /var/log/nginx/access_debug.log | jq
{
"timestamp": "2020-09-21T11:25:55+00:00",
"connection": {
"request_count": 1,
"elapsed_time": 0.555,
"pipelined": false,
"ssl": {
"protocol": "TLSv1.2",
"cipher": "ECDHE-RSA-AES256-GCM-SHA384",
"session_id": "b302f76a70dfec92f6bd72de5732692481ebecbbc69a4d81c900ae4dc928485c",
"session_reused": false,
"client_cert": {
"status": "NONE"
}
}
},
"request": {
"client": "127.0.0.1",
"port": 443,
"host": "foo.example.com",
"method": "GET",
"uri": "/one",
"http_version": 1.1,
"bytes_received": 87,
"headers": {
"Host": "foo.example.com:443",
"User-Agent": "curl/7.64.1",
"Accept": "*/*"
}
},
"upstreams": [
{
"server_addr": "10.37.0.71",
"server_port": 443,
"connect_time": null,
"header_time": null,
"response_time": 0.551,
"bytes_sent": 0,
"bytes_received": 0,
"status": 504
},
{
"server_addr": "10.37.0.72",
"server_port": 443,
"connect_time": 0.004,
"header_time": 0.004,
"response_time": 0.004,
"bytes_sent": 92,
"bytes_received": 4161,
"status": 200
}
],
"response": {
"status": 200,
"bytes_sent": 186,
"headers": {
"Content-Type": "text/html",
"Content-Length": "4161"
}
}
}JSON 형식을 사용하면 전체 HTTP 연결(SSL/TLS 포함), 요청, Upstream 및 응답과 관련된 정보에 대해 별도의 개체를 가질 수 있습니다. NGINX가 성공적으로 응답한 다음 Upstream(10.37.0.72)을 시도하기 전에 첫 번째 Upstream(10.37.0.71)이 어떻게 상태 504(Gateway 시간 초과)를 반환한 방법에 주목하십시오. 0.5초의 제한 시간(Upstreams 개체의 첫 번째 요소에서 response_time으로 보고됨)은 이 성공적인 응답(연결 개체에서 elapsed_time으로 보고됨)에 대한 전체 대기 시간의 대부분을 차지합니다.
다음은 만료된 클라이언트 인증서로 인해 발생한 클라이언트 Error에 대한 일부 로그 항목의 또 다른 예입니다.
{
"timestamp": "2020-09-22T10:20:50+00:00",
"connection": {
"ssl": {
"protocol": "TLSv1.2",
"cipher": "ECDHE-RSA-AES256-GCM-SHA384",
"session_id": "30711efbe047c38a98c2209cc4b5f196988dcf2d7f1f2c269fde7269c370432e",
"session_reused": false,
"client_cert": {
"status": "FAILED:certificate has expired",
"serial": "1006",
"fingerprint": "0c47cc4bd0fefbc2ac6363345cfbbf295594fe8d",
"subject": "emailAddress=liam@nginx.com,CN=test01,OU=Demo CA,O=nginx,ST=CA,C=US",
"issuer": "CN=Demo Intermediate CA,OU=Demo CA,O=nginx,ST=CA,C=US",
"starts": "Sep 20 12:00:11 2019 GMT",
"expires": "Sep 20 12:00:11 2020 GMT",
"expired": true,
...
"response": {
"status": 400,
"bytes_sent": 283,
"headers": {
"Content-Type": "text/html",
"Content-Length": "215"
}
}5. 요약
Error가 발생한 경우에만 풍부한 진단 데이터를 생성함으로써 재구성을 수행하지 않고도 실시간 문제 해결이 가능합니다. 마지막 바이트가 클라이언트에 전송된 후 로깅 단계에서 Error를 감지한 경우에만 NGINX JavaScript 코드가 실행되기 때문에 성공적인 요청에는 영향을 미치지 않습니다.
전체 NGINX JavaScript 구성은 GitHub에서 사용할 수 있습니다. 지금 사용해 보십시오. NGINX Plus 성능을 직접 테스트 및 사용해 보려면 지금 30일 무료 평가판을 신청하거나 사용 사례에 대해 최신 소식을 빠르게 전달받고 싶으시면 아래 뉴스레터를 구독하세요.
