nginxのアクセスログをjson形式で出力する

初qiita失礼します。

問題

下記のようにログフォーマットを無理矢理jsonっぽくして出力していたが、リクエストのボディがjson形式だとダブルクォーテションが\x22にエスケープされたものがログに出力されていた。
このjsonログをそのままAWSのlambdaなどで処理しようするとするとjsonをパースできなくてエラーになっていた。

• nginxのconf

log_format json '{'
  '"time":"$time_local",'
  '"msec":"$msec",'
  '"remote":"$remote_addr",'
  '"forwardedfor":"$http_x_forwarded_for",'
  '"method":"$request_method",'
  '"uri":"$request_uri",'
  '"status":"$status",'
  '"size":"$body_bytes_sent",'
  '"referer":"$http_referer",'
  '"ua":"$http_user_agent",'
  '"reqtime":"$request_time",'
  '"cache":"$upstream_http_x_cache",'
  '"runtime":"$upstream_http_x_runtime",'
  '"host":"$host",'
  '"upstream_status":"$upstream_status",'
  '"set_cookie":"$sent_http_set_cookie",'
  '"x-uid":"$http_x_uid",'
  '"x-auth-token":"$http_x_auth_token",'
  '"request_body":"$request_body"'
  '}';

対応

nginx-http-json-log

• json形式でアクセスログを出力するモジュールを見つけたので、nginxに組み込んでみる。
• nginxはdocker(nginx:1.11.4-alpine)を使用する。

Dockerfile

nginxのDockerfileを編集してnginx-http-json-logを組み込む。

• モジュールを追加する(ngx_http_json_log_module.cとconfigはDockerfileと同じディレクトリに配置した)

RUN mkdir -p /usr/src/nginx-http-json-log
ADD ngx_http_json_log_module.c /usr/src/nginx-http-json-log/ngx_http_json_log_module.c
ADD config  /usr/src/nginx-http-json-log/config

• CONFIG=のところで--add-module=../nginx-http-json-log追記
• apk addのところでjansson-dev　\追記

FROM alpine:3.4

ENV NGINX_VERSION 1.11.4

RUN mkdir -p /usr/src/nginx-http-json-log
ADD ngx_http_json_log_module.c /usr/src/nginx-http-json-log/ngx_http_json_log_module.c
ADD config  /usr/src/nginx-http-json-log/config

RUN GPG_KEYS=B0F4253373F8F6F510D42178520A9993A1C052F8 \
	&& CONFIG="\
		--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 \
		--user=nginx \
		--group=nginx \
		--with-http_ssl_module \
		--with-http_realip_module \
		--with-http_addition_module \
		--with-http_sub_module \
		--with-http_dav_module \
		--with-http_flv_module \
		--with-http_mp4_module \
		--with-http_gunzip_module \
		--with-http_gzip_static_module \
		--with-http_random_index_module \
		--with-http_secure_link_module \
		--with-http_stub_status_module \
		--with-http_auth_request_module \
		--with-http_xslt_module=dynamic \
		--with-http_image_filter_module=dynamic \
		--with-http_geoip_module=dynamic \
		--with-http_perl_module=dynamic \
		--with-threads \
		--with-stream \
		--with-stream_ssl_module \
		--with-stream_realip_module \
		--with-stream_geoip_module=dynamic \
		--with-http_slice_module \
		--with-mail \
		--with-mail_ssl_module \
		--with-file-aio \
		--with-http_v2_module \
		--with-ipv6 \
    --add-module=../nginx-http-json-log \
	" \
	&& addgroup -S nginx \
	&& adduser -D -S -h /var/cache/nginx -s /sbin/nologin -G nginx nginx \
	&& apk add --no-cache --virtual .build-deps \
		gcc \
		libc-dev \
    jansson-dev \
		make \
		openssl-dev \
		pcre-dev \
		zlib-dev \
		linux-headers \
		curl \
		gnupg \
		libxslt-dev \
		gd-dev \
		geoip-dev \
		perl-dev \
	&& curl -fSL http://nginx.org/download/nginx-$NGINX_VERSION.tar.gz -o nginx.tar.gz \
	&& curl -fSL http://nginx.org/download/nginx-$NGINX_VERSION.tar.gz.asc  -o nginx.tar.gz.asc \
	&& export GNUPGHOME="$(mktemp -d)" \
	&& gpg --keyserver ha.pool.sks-keyservers.net --recv-keys "$GPG_KEYS" \
	&& gpg --batch --verify nginx.tar.gz.asc nginx.tar.gz \
	&& rm -r "$GNUPGHOME" nginx.tar.gz.asc \
	&& mkdir -p /usr/src \
	&& tar -zxC /usr/src -f nginx.tar.gz \
	&& rm nginx.tar.gz \
	&& cd /usr/src/nginx-$NGINX_VERSION \
        && ls -la /usr/src/nginx-http-json-log \
	&& ./configure $CONFIG --with-debug \
	&& make -j$(getconf _NPROCESSORS_ONLN) \
	&& mv objs/nginx objs/nginx-debug \
	&& mv objs/ngx_http_xslt_filter_module.so objs/ngx_http_xslt_filter_module-debug.so \
	&& mv objs/ngx_http_image_filter_module.so objs/ngx_http_image_filter_module-debug.so \
	&& mv objs/ngx_http_geoip_module.so objs/ngx_http_geoip_module-debug.so \
	&& mv objs/ngx_http_perl_module.so objs/ngx_http_perl_module-debug.so \
	&& mv objs/ngx_stream_geoip_module.so objs/ngx_stream_geoip_module-debug.so \
	&& ./configure $CONFIG \
	&& make -j$(getconf _NPROCESSORS_ONLN) \
	&& make install \
	&& rm -rf /etc/nginx/html/ \
	&& mkdir /etc/nginx/conf.d/ \
	&& mkdir -p /usr/share/nginx/html/ \
	&& install -m644 html/index.html /usr/share/nginx/html/ \
	&& install -m644 html/50x.html /usr/share/nginx/html/ \
	&& install -m755 objs/nginx-debug /usr/sbin/nginx-debug \
	&& install -m755 objs/ngx_http_xslt_filter_module-debug.so /usr/lib/nginx/modules/ngx_http_xslt_filter_module-debug.so \
	&& install -m755 objs/ngx_http_image_filter_module-debug.so /usr/lib/nginx/modules/ngx_http_image_filter_module-debug.so \
	&& install -m755 objs/ngx_http_geoip_module-debug.so /usr/lib/nginx/modules/ngx_http_geoip_module-debug.so \
	&& install -m755 objs/ngx_http_perl_module-debug.so /usr/lib/nginx/modules/ngx_http_perl_module-debug.so \
	&& install -m755 objs/ngx_stream_geoip_module-debug.so /usr/lib/nginx/modules/ngx_stream_geoip_module-debug.so \
	&& ln -s ../../usr/lib/nginx/modules /etc/nginx/modules \
	&& strip /usr/sbin/nginx* \
	&& strip /usr/lib/nginx/modules/*.so \
	&& rm -rf /usr/src/nginx-$NGINX_VERSION \
	\
	# Bring in gettext so we can get `envsubst`, then throw
	# the rest away. To do this, we need to install `gettext`
	# then move `envsubst` out of the way so `gettext` can
	# be deleted completely, then move `envsubst` back.
	&& apk add --no-cache --virtual .gettext gettext \
	&& mv /usr/bin/envsubst /tmp/ \
	\
	&& runDeps="$( \
		scanelf --needed --nobanner /usr/sbin/nginx /usr/lib/nginx/modules/*.so /tmp/envsubst \
			| awk '{ gsub(/,/, "\nso:", $2); print "so:" $2 }' \
			| sort -u \
			| xargs -r apk info --installed \
			| sort -u \
	)" \
	&& apk add --no-cache --virtual .nginx-rundeps $runDeps \
	&& apk del .build-deps \
	&& apk del .gettext \
	&& mv /tmp/envsubst /usr/local/bin/ \
	\
	# forward request and error logs to docker log collector
	&& ln -sf /dev/stdout /var/log/nginx/access.log \
	&& ln -sf /dev/stderr /var/log/nginx/error.log

COPY nginx.conf /etc/nginx/nginx.conf
COPY nginx.vh.default.conf /etc/nginx/conf.d/default.conf

EXPOSE 80 443

CMD ["nginx", "-g", "daemon off;"]

nginx.conf

• ログフォーマットの指定(json_log_fieldsを使う)

set $server "server1";

json_log_fields main 'time_local'
      'server'
      'msec'
      'remote_addr'
      'http_x_forwarded_for'
      'request_method'
      'request_uri'
      'status'
      'body_bytes_sent'
      'http_referer'
      'http_user_agent'
      'request_time'
      'upstream_http_x_cache'
      'upstream_http_x_runtime'
      'host'
      'upstream_status'
      'sent_http_set_cookie'
      'http_x_uid'
      'http_x_auth_token'
      'request_body';

シンプルなっていい！

• ログ出力の指定(access_json_logを使う)

server  {
---------
      access_log off;
      access_json_log /var/log/nginx/access.log main;
---------
}

実行確認

docker build -t nginx .
docker run -p 80:80 nginx
curl http://127.0.0.1 -X POST --data-ascii "{\"aaa\":\"111\"}"
 {
 "server":"server1",
 "status":"502",
 "time_local":"24/Sep/2016:01:20:29 +0000",
 "msec":"1474680029.126",
 "http_x_forwarded_for":"-",
 "remote_addr":"172.17.0.1",
 "request_method":"POST",
 "request_uri":"/",
 "body_bytes_sent":"173",
 "upstream_http_x_cache":"-",
 "http_referer":"-",
 "host":"127.0.0.1",
 "upstream_status":"502",
 "request_time":"0.000",
 "http_user_agent":"curl/7.47.0",
 "http_x_auth_token":"-",
 "upstream_http_x_runtime":"-",
 "sent_http_set_cookie":"-",
 "http_x_uid":"-",
 "request_body":"{\"aaa\":\"111\"}"
 }

request_bodyが\x22ではなく\"になっている。良かった良かった。