LoginSignup
0
0

ウェブサーバーのJSONログ化のおススメ

Last updated at Posted at 2024-04-08

はじめに

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

検証環境

  • Apache: 2.4.59
  • Nginx: 1.24.0
  • H2O: 2.3.0 ベータ(2021-07-05 以降1

本資料の完成度

  • 自分が運用したことのある主要ウェブサーバーの設定の解説(100%)
  • 簡易な解析方法についての解説(80%程度、まぁまぁ最低限は説明した)
  • アクセスログ解析ツールの代わりとなるツールの案内(0% ※考えてない)
  • UNIXドメインソケット通信におけるログの表示に関する調査(33% ※Nginxしか情報無し、気が向いたら)
  • ログの取得事例(0% 気が向いたら)
  • User Agent Client Hints について(0% これで何が取得できるのか、追加で得るための方法等の追記)
  • POST時のメッセージボディの記録方法(25%、とは言えH2Oは取れなさそう?)

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

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

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

  • リモートホスト(IPアドレスまたは逆引きしている場合は逆引きしたホスト名)2
  • - 固定3
  • リモートユーザー名4
  • リクエストを受け付けた日時
  • リクエストの最初の行
  • 応答ステータス
  • レスポンスのバイト数
  • リファラー
  • ユーザーエージェント

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

提案するアクセスログ

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

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

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

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

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

設定例

Apache

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

留意点

  • QUIC未対応のため、常に null とするようにしています。
  • Apacheのログでは "\" とクォートしてくるため、JSONフォーマットと干渉しません。

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

{
  "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
  }
}

Nginx

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}}';

留意点

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

わかりにくいので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
  }
}

H2O

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 になります。
  • JSONフォーマットのためのエスケープ機能があります。
{
  "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
  }
}

JSONログの簡易的集計方法

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 コマンドのミリ秒の取り扱いが非常によろしく無いです。せっかくISO8601準拠の日時フォーマットなのに fromdate のような便利な関数が使えません。
このままではエラーになってしまいます。タイムゾーンの扱いもよろしくないです。その辺り、ひと工夫が必要です。
というわけでミリ秒以下は切り捨てましょう。
下記の例では .timestampYYYY-MM-DD フォーマットに書き換えます(日別集計したい場合など)。

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

ログの拡張

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

  • Apacheの場合
"appendix":{
  "環境変数名": "%{環境変数名}e",
  "ヘッダー名": "%{ヘッダー名}i",
  "クッキー名": "%{クッキー名}C"
}
  • Nginxの場合
"appendix":{
  "ヘッダー名": "$http_ヘッダー名",
  "クッキー": "$http_cookie"
}
  • H2Oの場合
"appendix":{
  "環境変数名": "%{環境変数名}e",
  "ヘッダー名": "%{ヘッダー名}i",
  "クッキー": "%{Cookie}i"
}

POSTリクエストのロギング

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

Apacheの場合

Nginxの場合

$request_body(あるいは $request_body_file)という指定でPOSTした内容をログに残すことができますが、癖があります。
$request_body_file については未調査ですが、$request_body の場合、ログとしては事実上、記録できません。
詳しくは資料を見てもらうとして、
proxy_passfastcgi_passuwsgi_passscgi_pass ディレクティブの使用と、一定のメモリバッファサイズ内で記録することができます。
そのために若干のワークアラウンドが必要になります。
サービスを提供しつつ $request_body も取る、というユースケースであればNginxはプロキシーサーバーとして運用すべきでしょう。
静的なコンテンツではPOSTされたデータは不要なので、ほぼプロキシーサーバーユースになるかと思います。
その場合、proxy_passfastcgi_passuwsgi_passscgi_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;
    }
 :
  }
}

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

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

あとhttp句の中で access_log あると、全てのserver句のアクセスログが残るので、accsss_log off; と設定した上で、server句毎に access_log を定義した方がいいです。

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

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

H2Oの場合

未調査。

よくある質問とその答え

Q.NginxにおけるUNIXソケットドメインでの通信状況を教えてください。

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

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

参考文献

  1. コミットID cd553a2e04790 以降(2.2.6 では一部機能しない)

  2. IPアドレスの逆引きは、速度的ペナルティが大きいので、通常は無効化されている

  3. 厳密にはリモートログ名だが、前世紀に使用が終了しているIDENTプロトコル8による取得が必要である。それは何?と思ったら、即ち必要では無いこと、に気がつくレベル。

  4. HTTP認証時にユーザー名として入る。通常は未認証なので - になる。

  5. Apacheの場合: LogFormat '%h %l %u %t \"%r\" %>s %b "%{Referer}i" "%{User-Agent}i"' combined

  6. Nginxの場合: log_format combined '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent"';

  7. H2Oの場合: format: '%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i"'

  8. NginxとH2Oでは、そもそも実装されてない。

  9. User Agent Client Hints

  10. CGN(Carrier Grade Network)の関係でIPアドレスだけではアクセス元を特定できず、ポート番号も必要になる

  11. 少なくとも ngx_http_ssl_module中に記載が無い

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
0