Opened 3 months ago

Closed 3 months ago

#2221 closed defect (invalid)

log_format with escape=json doesn't encode $status correctly

Reported by: silvpol@… Owned by:
Priority: minor Milestone:
Component: nginx-module Version: 1.17.x
Keywords: log_format json Cc:
uname -a: Linux 47acd776dd23 5.10.25-linuxkit #1 SMP Tue Mar 23 09:27:39 UTC 2021 x86_64 Linux
nginx -V: nginx version: nginx/1.17.10
built by gcc 9.2.0 (Alpine 9.2.0)
built with OpenSSL 1.1.1d 10 Sep 2019 (running with OpenSSL 1.1.1g 21 Apr 2020)
TLS SNI support enabled
configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --with-perl_modules_path=/usr/lib/perl5/vendor_perl --user=nginx --group=nginx --with-compat --with-file-aio --with-threads --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_flv_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_random_index_module --with-http_realip_module --with-http_secure_link_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --with-mail --with-mail_ssl_module --with-stream --with-stream_realip_module --with-stream_ssl_module --with-stream_ssl_preread_module --with-cc-opt='-Os -fomit-frame-pointer' --with-ld-opt=-Wl,--as-needed

Description

When logging status code 000, the number is not encoded to just single 0, creating invalid JSON. The status needs to be numeric in Stackdriver so encoding as text is not possible as a workaround.
Not sure how to cause the 000 code, but this periodically shows up in the logs.

Logging config:

log_format proxy escape=json '{'
'"timestamp":"$msec",'
'"site":"$host",'
'"httpRequest":{'
'"requestMethod":"$request_method",'
'"requestUrl":"$request_uri",'
'"requestSize":"$request_length",'
'"status":$status,'
'"responseSize":"$body_bytes_sent",'
'"userAgent":"$http_user_agent",'
'"remoteIp":"$remote_addr",'
'"referer":"$http_referer",'
'"latency":"${request_time}s"'
'},'
'"logging.googleapis.com/operation":{'
'"id":"$request_id",'
'"producer":"nginx"'
'},'
'"xff":"$http_x_forwarded_for",'
'"rtt":$tcpinfo_rtt,'
'"proxy":{'
'"connectionLatencies":"$upstream_connect_time",'
'"responseLatencies":"$upstream_response_time",'
'"user":"$upstream_http_x_user_id"'
'}'
'}';

Example output:

{
  "timestamp": "1617591631.057",
  "site": "example.com",
  "httpRequest": {
    "requestMethod": "GET",
    "requestUrl": "/test/wp-includes/wlwmanifest.xml",
    "requestSize": "511",
    "status": 000,
    "responseSize": "0",
    "userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.108 Safari/537.36",
    "remoteIp": "XX.XX.XX.XX",
    "referer": "",
    "latency": "37.362s"
  },
  "logging.googleapis.com/operation": {
    "id": "a0d31a9b3f5dd16feeb6ee2925da3450",
    "producer": "nginx",
    "first": true
  },
  "xff": "XX.XX.XX.XX, XX.XX.XX.XX",
  "rtt": 878
}

Change History (1)

comment:1 by Maxim Dounin, 3 months ago

Resolution: invalid
Status: newclosed

The $status variable is a 3-digit status code, and it's evaluated to 000 when the response status is not known for some reason, or can be 009 if a backend returns an HTTP/0.9 response.

If you want to use $status in a JSON, consider encoding it as a string. If it's not possible for some reason, you can use a map to transform 3-digit combinations with leading zeros to something without leading zeros.

The escape=json is not expected to help here. As explained in the documentation, it only escapes characters not allowed in JSON strings. If you encode a variable as a number, it is your responsibility to ensure that the variable can only evaluate to valid JSON numbers, which is certainly not true for $status.

Note: See TracTickets for help on using tickets.