はじめに

ウェブサーバーを運用しているとアクセスログが気になるケースがあります。
必要な情報が足りないケースもありますが、拡張したい時にどうすればいいか、悩ましいものがあります。
力業で拡張するのもいいのですが、ＪＳＯＮ化することで、足りないと思ってる情報や追加で拡張した際に、楽で安全で簡単に解析するための方法について解説します。

検証環境

Apache: 2.4.59
Nginx: 1.24.0
H2O: 2.3.0 ベータ（2021-07-05 以降¹）

本資料の完成度

自分が運用したことのある主要ウェブサーバーの設定の解説（１００％）
簡易な解析方法についての解説（８０％程度、まぁまぁ最低限は説明した）
アクセスログ解析ツールの代わりとなるツールの案内（０％ ※考えてない）
ＵＮＩＸドメインソケット通信におけるログの表示に関する調査（３３％ ※Ｎｇｉｎｘしか情報無し、気が向いたら）
ログの取得事例（０％気が向いたら）
User Agent Client Hints について（０％これで何が取得できるのか、追加で得るための方法等の追記）
ＰＯＳＴ時のメッセージボディの記録方法（２５％、とは言えＨ２Ｏは取れなさそう？）

どのようなアクセスログを取るのか

combined と呼ばれるアクセスログ

アクセスログと言えば combined と呼ばれる従来の、デフォルトの、アクセスログは以下の構成となっています。

リモートホスト（ＩＰアドレスまたは逆引きしている場合は逆引きしたホスト名）²
- 固定³
リモートユーザー名⁴
リクエストを受け付けた日時
リクエストの最初の行
応答ステータス
レスポンスのバイト数
リファラー
ユーザーエージェント

いわゆるアクセスログ分析ツールの都合で、歴史的には上記の情報しか記録されません⁵⁶⁷。
また日時のフォーマットが機械的処理に不向きで一手間かける必要があるなど、問題が多いです。

提案するアクセスログ

今時、上記データだけでは足りないことが明確です。最低でも以下の情報が欲しいかと。

リクエストを受け付けた日時を「ミリ秒単位」まで見たい
ユーザーエージェント情報が無くなるかもしれない⁹
リモートホスト情報としてポート番号も欲しい¹⁰
応答にかかった時間が欲しい

個人的にはさらに以下の情報が欲しいです。

リモートログ名なんて要らない
自明ではあるが、ローカルホスト側の情報も欲しい（ポート番号・サーバー名含む）
リクエストの最初の行と言わず、メソッド、パス、クエリー文字列、プロトコルを個々に取りたい
応答が完了したときの接続ステータス
ＴＬＳ情報をもちっと
ついでにコネクション継続情報も（ＨＴＴＰセッションが途中で切れたか、接続維持かかどうかなど）

当然ですが、これら追加情報を現在のフォーマットに合わせて拡張した所で、どんなツールも対応してくれないので、この際だからＪＳＯＮ化します。

設定例

Ａｐａｃｈｅ

LogFormat '{"timestamp":"%{%FT%T}t.%{msec_frac}t%{%z}t","elapsed_time":"%{ms}T","user_name":"%u","status":"%>s","response_size":"%b","network":{"server_name":"%v","remote_ip":"%a","remote_port":"%{remote}p","local_ip":"%A","local_port":"%{local}p","connection_status":"%X"},"request":{"request":"%r","method":"%m","url":"%U","query_string":"%q","protocol":"%H","referer":"%{Referer}i"},"user_agent":{"UserAgent":"%{User-Agent}i","CH_UA":"%{Sec-CH-UA}i","CH-UA-Mobile":"%{Sec-CH-UA-Mobile}i","CH-UA-Bitness":"%{Sec-CH-UA-Bitness}i","CH-UA-Form-Factors":"%{Sec-CH-UA-Form-Factors}i","CH-UA-Full-Version-List":"%{Sec-CH-UA-Full-Version-List}i","CH-UA-WoW64":"%{Sec-CH-UA-WoW64}i","CH_Version":"%{Sec-CH-UA-Full-Version}i","CH_Platform":"%{Sec-CH-UA-Platform}i","CH_Platform-Version":"%{Sec-CH-UA-Platform-Version}i","CH_Arch":"%{Sec-CH-UA-Arch}i","CH_Model":"%{Sec-CH-UA-Model}i"},"ssl":{"https":"%{HTTPS}x","ssl_protocol":"%{SSL_PROTOCOL}x","ssl_cipher":"%{SSL_CIPHER}x","quic_version":null}}' jsonl

留意点

ＱＵＩＣ未対応のため、常に null とするようにしています。
Ａｐａｃｈｅのログでは " を \" とクォートしてくるため、ＪＳＯＮフォーマットと干渉しません。

わかりにくいのでＪＳＯＮとして展開すると下記の通りとなります。

{
  "timestamp": "%{%FT%T}t.%{msec_frac}t%{%z}t",
  "elapsed_time": "%{ms}T",
  "user_name": "%u",
  "status": "%>s",
  "response_size": "%b",
  "network":{
    "server_name": "%v",
    "remote_ip": "%a",
    "remote_port": "%{remote}p",
    "local_ip": "%A",
    "local_port": "%{local}p",
    "connection_status": "%X"
  },
  "request":{
    "request": "%r",
    "method": "%m",
    "url": "%U",
    "query_string": "%q",
    "protocol": "%H",
    "referer": "%{Referer}i"
  },
  "user_agent": {
    "UserAgent": "%{User-Agent}i",
    "CH_UA": "%{Sec-CH-UA}i",
    "CH-UA-Mobile": "%{Sec-CH-UA-Mobile}i",
    "CH-UA-Bitness": "%{Sec-CH-UA-Bitness}i",
    "CH-UA-Form-Factors": "%{Sec-CH-UA-Form-Factors}i",
    "CH-UA-Full-Version-List": "%{Sec-CH-UA-Full-Version-List}i",
    "CH-UA-WoW64": "%{Sec-CH-UA-WoW64}i",
    "CH_Version": "%{Sec-CH-UA-Full-Version}i",
    "CH_Platform": "%{Sec-CH-UA-Platform}i",
    "CH_Platform-Version": "%{Sec-CH-UA-Platform-Version}i",
    "CH_Arch": "%{Sec-CH-UA-Arch}i",
    "CH_Model": "%{Sec-CH-UA-Model}i"
  },
  "ssl": {
    "https": "%{HTTPS}x",
    "ssl_protocol": "%{SSL_PROTOCOL}x",
    "ssl_cipher": "%{SSL_CIPHER}x",
    "quic_version": null
  }
}

実際のアクセス例としては下記のようになる。

{
  "timestamp": "2024-04-08T09:00:00.000+0900",
  "elapsed_time": "0",
  "user_name": "-",
  "status": "200",
  "response_size": "1920",
  "network": {
    "server_name": "example.jp",
    "remote_ip": "XXX.XXX.XXX.XXX",
    "remote_port": "XXXXX",
    "local_ip": "XXX.XXX.XXX.XXX",
    "local_port": "443",
    "connection_status": "-"
  },
  "request": {
    "request": "GET / HTTP/2.0",
    "method": "GET",
    "url": "/index.html",
    "query_string": "",
    "protocol": "HTTP/2.0",
    "referer": "-"
  },
  "user_agent": {
    "UserAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Edg/123.0.0.0",
    "CH_UA": "\"Microsoft Edge\";v=\"123\", \"Not:A-Brand\";v=\"8\", \"Chromium\";v=\"123\"",
    "CH-UA-Mobile": "?0",
    "CH-UA-Bitness": "-",
    "CH-UA-Form-Factors": "-",
    "CH-UA-Full-Version-List": "-",
    "CH-UA-WoW64": "-",
    "CH_Version": "-",
    "CH_Platform": "\"Windows\"",
    "CH_Platform-Version": "-",
    "CH_Arch": "-",
    "CH_Model": "-"
  },
  "ssl": {
    "https": "on",
    "ssl_protocol": "TLSv1.3",
    "ssl_cipher": "TLS_AES_256_GCM_SHA384",
    "quic_version": null
  }
}

Ｎｇｉｎｘ

log_format jsonl escape=json '{"timestamp":"$time_iso8601",'
                             '"elapsed_time":"$request_time",'
                             '"user_name":"$remote_user",'
                             '"status":"$status",'
                             '"response_size":"$body_bytes_sent",'
                             '"network":{'
                             '"server_name":"$server_name",'
                             '"remote_ip":"$remote_addr",'
                             '"remote_port":"$remote_port",'
                             '"local_ip":"$server_addr",'
                             '"local_port":"$server_port",'
                             '"connection_status":"-"},'
                             '"request":{'
                             '"request":"$request",'
                             '"method":"$request_method",'
                             '"url":"$uri",'
                             '"query_string":"$query_string",'
                             '"protocol":"$server_protocol",'
                             '"referer":"$http_referer"},'
                             '"user_agent":{'
                             '"UserAgent":"$http_user_agent",'
                             '"CH_UA":"$http_sec_ch_ua",'
                             '"CH-UA-Mobile":"$http_sec_ch_ua_mobile",'
                             '"CH-UA-Bitness":"$http_sec_ch_ua_bitness",'
                             '"CH-UA-Form-Factors":"$http_sec_ch_ua_form_factors",'
                             '"CH-UA-Full-Version-List":"$http_sec_ch_ua_full_version_list",'
                             '"CH-UA-WoW64":"$http_sec_ch_ua_wow64",'
                             '"CH_Version":"$http_sec_ch_ua_full_version",'
                             '"CH_Platform":"$http_sec_ch_ua_platform",'
                             '"CH_Platform-Version":"$http_sec_ch_ua_platform_version",'
                             '"CH_Arch":"$http_sec_ch_ua_arch",'
                             '"CH_Model":"$http_sec_ch_ua_model"},'
                             '"ssl":{'
                             '"https":"$https",'
                             '"ssl_protocol":"$ssl_protocol",'
                             '"ssl_cipher":"$ssl_cipher",'
                             '"quic_version":null}}';

留意点

ＱＵＩＣ未対応¹¹のため、常に null とするようにしています。
ＮｇｉｎｘではＪＳＯＮフォーマットのための専用エスケープ機能があります。
時刻にはミリ秒は含まれません。含ませることもできません。
タイムゾーンの表記に他のウェブサーバーとは若干の差異があります（+09:00 と +0900）。
remote_port を出力しない（空文字）場合があります。ソースを読むとポート 0 の場合、空文字になります。原理的にはローカルポートでも発生します。

わかりにくいのでＪＳＯＮとして展開すると下記の通りとなります。

{
  "timestamp": "$time_iso8601",
  "elapsed_time": "$request_time",
  "user_name": "$remote_user",
  "status": "$status",
  "response_size": "$body_bytes_sent",
  "network":{
    "server_name": "$server_name",
    "remote_ip": "$remote_addr",
    "remote_port": "$remote_port",
    "local_ip": "$server_addr",
    "local_port": "$server_port",
    "connection_status": "-"
  },
  "request":{
    "request": "$request",
    "method": "$request_method",
    "url": "$uri",
    "query_string": "$query_string",
    "protocol": "$server_protocol",
    "referer": "$http_referer"
  },
  "user_agent": {
    "UserAgent": "$http_user_agent",
    "CH_UA": "$http_sec_ch_ua",
    "CH-UA-Mobile": "$http_sec_ch_ua_mobile",
    "CH-UA-Bitness": "$http_sec_ch_ua_bitness",
    "CH-UA-Form-Factors": "$http_sec_ch_ua_form_factors",
    "CH-UA-Full-Version-List": "$http_sec_ch_ua_full_version_list",
    "CH-UA-WoW64": "$http_sec_ch_ua_wow64",
    "CH_Version": "$http_sec_ch_ua_full_version",
    "CH_Platform": "$http_sec_ch_ua_platform",
    "CH_Platform-Version": "$http_sec_ch_ua_platform_version",
    "CH_Arch": "$http_sec_ch_ua_arch",
    "CH_Model": "$http_sec_ch_ua_model"
  },
  "ssl": {
    "https": "$https",
    "ssl_protocol": "$ssl_protocol",
    "ssl_cipher": "$ssl_cipher",
    "quic_version": null
  }
}

Ｈ２Ｏ

access-log:
    format: '{"timestamp":"%{%FT%T}t.%{msec_frac}t%{%z}t","elapsed_time":"%{duration}x","user_name":"%u","status":"%s","response_size":"%b","network":{"server_name":"%v","remote_ip":"%h","remote_port":"%{remote}p","local_ip":"%A","local_port":"%{local}p","connection_status":"-"},"request":{"request":"%r","method":"%m","url":"%U","query_string":"%q","protocol":"%H","referer":"%{Referer}i"},"user_agent":{"UserAgent":"%{User-Agent}i","CH_UA":"%{Sec-CH-UA}i","CH-UA-Mobile":"%{Sec-CH-UA-Mobile}i","CH-UA-Bitness":"%{Sec-CH-UA-Bitness}i","CH-UA-Form-Factors":"%{Sec-CH-UA-Form-Factors}i","CH-UA-Full-Version-List":"%{Sec-CH-UA-Full-Version-List}i","CH-UA-WoW64":"%{Sec-CH-UA-WoW64}i","CH_Version":"%{Sec-CH-UA-Full-Version}i","CH_Platform":"%{Sec-CH-UA-Platform}i","CH_Platform-Version":"%{Sec-CH-UA-Platform-Version}i","CH_Arch":"%{Sec-CH-UA-Arch}i","CH_Model":"%{Sec-CH-UA-Model}i"},"ssl":{"https":"%{HTTPS}e","ssl_protocol":"%{ssl.protocol-version}x","ssl_cipher":"%{ssl.cipher}x","quic_version":"%{http3.quic-version}x"}}'
    escape: json

留意点

接続ステータスは取得できないため - としています。
他のウェブサーバーで - となる（未設定・空文字）ようなケースでは "-" とならず null になります。
ＪＳＯＮフォーマットのためのエスケープ機能があります。

{
  "timestamp": "%{%FT%T}t.%{msec_frac}t%{%z}t",
  "elapsed_time": "%{duration}x",
  "user_name": "%u",
  "status": "%s",
  "response_size": "%b",
  "network":{
    "server_name": "%v",
    "remote_ip": "%h",
    "remote_port": "%{remote}p",
    "local_ip": "%A",
    "local_port": "%{local}p",
    "connection_status": "-"
  },
  "request": {
    "request": "%r",
    "method": "%m",
    "url": "%U",
    "query_string": "%q",
    "protocol": "%H",
    "referer": "%{Referer}i"
  },
  "user_agent": {
    "UserAgent": "%{User-Agent}i",
    "CH_UA": "%{Sec-CH-UA}i",
    "CH-UA-Mobile": "%{Sec-CH-UA-Mobile}i",
    "CH-UA-Bitness": "%{Sec-CH-UA-Bitness}i",
    "CH-UA-Form-Factors": "%{Sec-CH-UA-Form-Factors}i",
    "CH-UA-Full-Version-List": "%{Sec-CH-UA-Full-Version-List}i",
    "CH-UA-WoW64": "%{Sec-CH-UA-WoW64}i",
    "CH_Version": "%{Sec-CH-UA-Full-Version}i",
    "CH_Platform": "%{Sec-CH-UA-Platform}i",
    "CH_Platform-Version": "%{Sec-CH-UA-Platform-Version}i",
    "CH_Arch": "%{Sec-CH-UA-Arch}i",
    "CH_Model": "%{Sec-CH-UA-Model}i"
  },
  "ssl": {
    "https": "%{HTTPS}e",
    "ssl_protocol": "%{ssl.protocol-version}x",
    "ssl_cipher": "%{ssl.cipher}x",
    "quic_version": "%{http3.quic-version}x"
  }
}

実際のアクセス例としては下記のようになる。

{
  "timestamp": "2024-04-08T09:00:00.000+0900",
  "elapsed_time": "0",
  "user_name": null,
  "status": "200",
  "response_size": "1920",
  "network": {
    "server_name": "example.com",
    "remote_ip": "XXX.XXX.XXX.XXX",
    "remote_port": "XXXXX",
    "local_ip": "XXX.XXX.XXX.XXX",
    "local_port": "443",
    "connection_status": "-"
  },
  "request": {
    "request": "GET / HTTP/2",
    "method": "GET",
    "url": "/",
    "query_string": "",
    "protocol": "HTTP/2",
    "referer": null
  },
  "user_agent": {
    "UserAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Edg/123.0.0.0",
    "CH_UA": "\"Microsoft Edge\";v=\"123\", \"Not:A-Brand\";v=\"8\", \"Chromium\";v=\"123\"",
    "CH-UA-Mobile": "?0",
    "CH-UA-Bitness": null,
    "CH-UA-Form-Factors": null,
    "CH-UA-Full-Version-List": null,
    "CH-UA-WoW64": null,
    "CH_Version": null,
    "CH_Platform": "\"Windows\"",
    "CH_Platform-Version": null,
    "CH_Arch": null,
    "CH_Model": null
  },
  "ssl": {
    "https": "on",
    "ssl_protocol": "TLSv1.3",
    "ssl_cipher": "TLS_AES_256_GCM_SHA384",
    "quic_version": null
  }
}

ＪＳＯＮログの簡易的集計方法

jq コマンドを使用してフィルタリングおよび集計する方法をいくつか紹介します。

期間フィルター

jq 'select("YYYY-MM-DDThh:mm:ss" <= .timestamp                                       )'
jq 'select("YYYY-MM-DDThh:mm:ss" <= .timestamp and .timestamp < "YYYY-MM-DDThh:mm:ss")'
jq 'select(                                        .timestamp < "YYYY-MM-DDThh:mm:ss")'

select() で期間を指定します。開始日時と終了日時を同時に指定することで、特定の範囲に限定されます。
開始日時や終了日時を指定しないことで、特定過去、特定未来として対象にできます。
書き方は色々あると思いますが、自分は 過去 ≦ 今 ≦ 未来 の表現に近い、上記の書き方をするように心がけています。

また日付は YYYY-MM-DDThh:mm:ss と表記しなければならないなど、若干注意が必要です。YYYY-MM-DD ... と指定した場合、YYYY-MM-DD の時点で評価が定まります。
さらに YYYY/MM/DD... という表記もダメです。この辺りは日時型で評価されず、文字列として評価されるためです。

数の集計

いくつか集計関数がありますが、抽出したのち、レコードまとめて…という処理にならないので、他のツールを使用します。

jq '.network.remote_ip' | sort | uniq -c

時刻の解析

jq コマンドのミリ秒の取り扱いが非常によろしく無いです。せっかくＩＳＯ８６０１準拠の日時フォーマットなのに fromdate のような便利な関数が使えません。
このままではエラーになってしまいます。タイムゾーンの扱いもよろしくないです。その辺り、ひと工夫が必要です。
というわけでミリ秒以下は切り捨てましょう。
下記の例では .timestamp を YYYY-MM-DD フォーマットに書き換えます（日別集計したい場合など）。

jq '.timestamp |= ( split(".")[0] | strptime("%FT%T") | strftime("%F") )'

ログの拡張

アクセスしたユーザーの記録といった拡張を行うなら、クッキー等のデータを活用することで可能になります。
が、それぞれ限界があるのでうまく見繕う必要があります。特にクッキーは個別で指定できないケースの方が多そうです。
専用アプリであればヘッダー定義して、送信してしまうのが、どのサーバーでも安心・安全で楽でしょうか。

Ａｐａｃｈｅの場合

"appendix":{
  "環境変数名": "%{環境変数名}e",
  "ヘッダー名": "%{ヘッダー名}i",
  "クッキー名": "%{クッキー名}C"
}

Ｎｇｉｎｘの場合

"appendix":{
  "ヘッダー名": "$http_ヘッダー名",
  "クッキー": "$http_cookie"
}

Ｈ２Ｏの場合

"appendix":{
  "環境変数名": "%{環境変数名}e",
  "ヘッダー名": "%{ヘッダー名}i",
  "クッキー": "%{Cookie}i"
}

ＰＯＳＴリクエストのロギング

ＰＯＳＴされたデータを記録したいケースがあります。各サーバー毎にしやすいこと、しにくいこと、できること、できないことがあります。

Ａｐａｃｈｅの場合

Ｎｇｉｎｘの場合

$request_body（あるいは $request_body_file）という指定でＰＯＳＴした内容をログに残すことができますが、癖があります。
$request_body_file については未調査ですが、$request_body の場合、ログとしては事実上、記録できません。
詳しくは資料を見てもらうとして、
proxy_pass、fastcgi_pass、uwsgi_pass、scgi_pass ディレクティブの使用と、一定のメモリバッファサイズ内で記録することができます。
そのために若干のワークアラウンドが必要になります。
サービスを提供しつつ $request_body も取る、というユースケースであればＮｇｉｎｘはプロキシーサーバーとして運用すべきでしょう。
静的なコンテンツではＰＯＳＴされたデータは不要なので、ほぼプロキシーサーバーユースになるかと思います。
その場合、proxy_pass、fastcgi_pass、uwsgi_pass、scgi_pass ディレクティブを指定しているでしょうから、自動的に機能しているように見えます。
よって単純に記録だけ取りたい場合は、下記のようなテクニックを使用します。

http {
 :
  server {
    listen unix:/run/nginx-status-204.sock;
    return 204 "accepted";
  }
 :
  upstream status204 {
    listen unix:/run/nginx-status-204.sock;
  }
 :
  server {
    listen ...;
 :
    location /log-post-body {
      proxy_pass http://status204;
      break;
    }
 :
  }
}

コツとしては以下の点です。

ＵＮＩＸドメインソケットでダミーのサービスを用意する。これは２０４応答を返すだけの機能を提供する。
- ポート番号を消費しない
- 外部からの通信は行われない
- オーバーヘッドが小さい
アップストリームとしてＵＮＩＸドメインソケットに名前を付けておく（要らないかもしれないけど未確認）。
サービス用サーバー内の一部パスとして proxy_pass を通す。

あとｈｔｔｐ句の中で access_log あると、全てのｓｅｒｖｅｒ句のアクセスログが残るので、accsss_log off; と設定した上で、ｓｅｒｖｅｒ句毎に access_log を定義した方がいいです。

http {
  access_log off;
  server {
    access_log ...;
  }
  server {
    access_log ...;
  }
}

今回特定パス名の…で限定していますが、全てのアクセスで記録取るならフロントエンド側の設定をバックエンド側に持ってきて、フロントエンド側は proxy_pass に専念する必要があります。
また当然ですが、バックエンド側（status204）で $request_body の内容は取得できません。

Ｈ２Ｏの場合

未調査。

よくある質問とその答え

Ｑ．ＮｇｉｎｘにおけるＵＮＩＸソケットドメインでの通信状況を教えてください。

Ａ．下記のようにリモート側は unix: でローカル側はソケットのパス名となる。

  "network": {
    "server_name": "",
    "remote_ip": "unix:",
    "remote_port": "",
    "local_ip": "unix:/backend-to-path",
    "local_port": "",
    "connection_status": "-"
  },

参考文献

コミットＩＤ cd553a2e04790 以降（2.2.6 では一部機能しない） ↩
ＩＰアドレスの逆引きは、速度的ペナルティが大きいので、通常は無効化されている ↩
厳密にはリモートログ名だが、前世紀に使用が終了しているＩＤＥＮＴプロトコル⁸による取得が必要である。それは何？と思ったら、即ち必要では無いこと、に気がつくレベル。 ↩
ＨＴＴＰ認証時にユーザー名として入る。通常は未認証なので - になる。 ↩
Ａｐａｃｈｅの場合： LogFormat '%h %l %u %t \"%r\" %>s %b "%{Referer}i" "%{User-Agent}i"' combined ↩
Ｎｇｉｎｘの場合： log_format combined '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent"'; ↩
Ｈ２Ｏの場合： format: '%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i"' ↩
ＮｇｉｎｘとＨ２Ｏでは、そもそも実装されてない。 ↩
User Agent Client Hints ↩
ＣＧＮ（Carrier Grade Network）の関係でＩＰアドレスだけではアクセス元を特定できず、ポート番号も必要になる ↩
少なくとも ngx_http_ssl_module中に記載が無い ↩