Apache内部の情報をダンプするモジュール mod_request_dumper

最近は論文を書いてばっかりなので、コーディングを忘れないようにちょっとしたApacheモジュールを作ってました。

まずは機能から

このモジュールの名前は、mod_request_dumperとしました。

mod_request_dumper機能は、Apache内部がリクエストからレスポンスを返すまでに持つrequest_rec構造体（中に含まれるserver_recやconn_recも含む）の中身を、各種フックのタイミングでDumpするモジュールです。Dumpの仕方は、JSON形式に構造体の主要なデータをシリアライズして任意のファイルに出力します。

（追記：2012/05/22）
また、CustomLogのようなパイプログ形式の記述を行うことで、スクリプトに直接JSONデータを渡す事が可能です。

今のところは、フックの箇所は以下の三箇所を選択できるようにしています。（もっと色々な所で出力したいという要望や必要性があれば、どんどん追加していきたいとは思っています）

ap_hook_translate_name

アクセスのあったURIをサーバ内のファイルパスに紐づけるフェイズ

ap_hook_handler

コンテンツの処理を行うフェイズ

ap_hook_log_transaction

コンテンツの処理後にレスポンスを返してアクセスログを出力するフェイズ

なぜこの三箇所にしたかというと、大体この三箇所で主要なApache内部の構造体が変更されていくからです。この三つのフェイズを抑えておくと、Apache内の構造体の情報がどのように変わっていっていくかの流れを理解しやすいと思います。

例えば、ap_hook_translate_nameのフェイズでDumpした場合は、URIにファイルパスを紐づけるフェイズなので、request_recのfilenameメンバはnullだということが分かります。また、ap_hook_handlerのフェイズではfilenameはtranslate_nameのフェイズで決定されているわけですから、きちんと決まった値が入っているはずです。mod_rewriteは、handlerの直前のfixupというフェイズまでの、各種フェイズで色々request_rec内の値を書き換えるためのモジュールと考えると分かりやすいかもしれません。

導入は簡単

導入はいつも通り非常に簡単にしたので、気軽に試してもらえたらうれしいです。導入においては、json-c-0.9をインストールする必要があります。僕はLFSやBLFSが大好きなので、BLFSのjson-cのページを参考にインストールしました。

この方法でインストールした後は、githubのmod_request_dumperページからソースをcloneしてもってきます。

git clone git://github.com/matsumoto-r/mod_request_dumper.git mod_request_dumper

そして、以下のようにコンパイルしてインストールすれば完了です。

make
make install

Apacheの設定

設定は以下のように記述します。httpd.conf内に記述して下さい。

dumpするログのファイル名を指定する場合（デフォルトは/tmp/mod_request_dumper.log）

パイプログ形式で渡せるようにしました（追記：2012/05/22）

DumpRequestLog "ファイル名"
DumpRequestLog "| mongointo.pl"

ap_hook_translate_nameのフェイズでApacheの内部情報を出力させたい場合

DumpTranslateName On

ap_hook_handlerフェイズで出力させたい場合

DumpHandler On

ap_hook_log_transactionフェイズで出力させたい場合

DumpLogTransaction On

いずれの場合も併用可能です。設定後に、Apacheをリスタートします。

Dumpの出力をしてみる

以下のようにJSON形式でApache内部の情報（request_recやserver_recやconn_rec構造体内部の主要のメンバの値）をDumpします。検証環境で適当に出力してみた場合は以下のようになりました。設定をDumpLogTransactionにのみしていた場合です。

{ "filename": "\/var\/www\/html\/favicon.ico", "uri": "\/favicon.ico", "user": "null", "content_type": "text\/html; charset=iso-8859-1", "protocol": "HTTP\/1.1", "vlist_validator": "null", "ap_auth_type": "null", "unparsed_uri": "\/favicon.ico", "canonical_filename": "\/var\/www\/html\/favicon.ico", "path_info": "", "hostname": "exampl.com", "method": "GET", "the_request": "GET \/favicon.ico HTTP\/1.1", "range": "null", "handler": "null", "args": "null", "status_line": "404 Not Found", "content_encoding": "null", "assbackwards": 0, "proxyreq": 0, "header_only": 0, "proto_num": 1001, "status": 404, "method_number": 0, "chunked": 0, "read_body": 0, "read_chunked": 0, "no_cache": 0, "no_local_copy": 0, "used_path_info": 2, "eos_sent": 1, "request_time": -238943458, "connection": { "remote_ip": "192.168.0.10", "remote_host": "null", "remote_logname": "null", "local_ip": "172.16.71.100", "local_host": "null", "keepalives": 0, "data_in_input_filters": 0 }, "server": { "error_fname": "logs\/error_log", "defn_name": "null", "server_scheme": "null", "server_admin": "root@localhost", "path": "null", "server_hostname": "example.com", "loglevel": 4, "is_virtual": 0, "keep_alive_max": 100, "keep_alive": 0, "pathlen": 0, "limit_req_line": 8190, "limit_req_fieldsize": 8190, "limit_req_fields": 100, "process": { "short_name": "httpd", "argc": 1 } }, "time": "Tue May 22 16:27:00 2012", "pid": 30944, "hook": "ap_hook_log_transaction" }

実際の出力は上記のように、出力を1行毎に出力しますが、今回は少し見やすいように整形してみました。すると以下のようになりました。

{
    "ap_auth_type": "null",
    "args": "null",
    "assbackwards": 0,
    "canonical_filename": "/var/www/html/favicon.ico",
    "chunked": 0,
    "connection": {
        "data_in_input_filters": 0,
        "keepalives": 0,
        "local_host": "null",
        "local_ip": "172.16.71.100",
        "remote_host": "null",
        "remote_ip": "192.168.0.10",
        "remote_logname": "null"
    },
    "content_encoding": "null",
    "content_type": "text/html; charset=iso-8859-1",
    "eos_sent": 1,
    "filename": "/var/www/html/favicon.ico",
    "handler": "null",
    "header_only": 0,
    "hook": "ap_hook_log_transaction",
    "hostname": "exampl.com",
    "method": "GET",
    "method_number": 0,
    "no_cache": 0,
    "no_local_copy": 0,
    "path_info": "",
    "pid": 30944,
    "proto_num": 1001,
    "protocol": "HTTP/1.1",
    "proxyreq": 0,
    "range": "null",
    "read_body": 0,
    "read_chunked": 0,
    "request_time": -238943458,
    "server": {
        "defn_name": "null",
        "error_fname": "logs/error_log",
        "is_virtual": 0,
        "keep_alive": 0,
        "keep_alive_max": 100,
        "limit_req_fields": 100,
        "limit_req_fieldsize": 8190,
        "limit_req_line": 8190,
        "loglevel": 4,
        "path": "null",
        "pathlen": 0,
        "process": {
            "argc": 1,
            "short_name": "httpd"
        },
        "server_admin": "root@localhost",
        "server_hostname": "example.com",
        "server_scheme": "null"
    },
    "status": 404,
    "status_line": "404 Not Found",
    "the_request": "GET /favicon.ico HTTP/1.1",
    "time": "Tue May 22 16:27:00 2012",
    "unparsed_uri": "/favicon.ico",
    "uri": "/favicon.ico",
    "used_path_info": 2,
    "user": "null",
    "vlist_validator": "null"
}

どうでしょうか。Apacheを実際にコーディングしたり、Apacheモジュールを作られている方は見慣れたデータだと思います。Apacheにリクエストがあってからrequest_recという構造体が用意され、それが各種フックのフェイズにおいて様々なstateをApacheの設定やモジュールの実装によって書き変わりながら、最終的にrequest_recのデータを元にレスポンスを返す、というのがApacheの基本的な処理の流れです。そのため、各種フックのフェイズで値はどんどん変わっていきます。

request_recを制する者はApacheを制すといっても過言じゃないかもしれません。request_recの中には、server_recとconn_recというとても重要な構造体を持っています。それらも、上記のような出力によって構造体の構成はそのままに、JSONにシリアライズして出力する事ができていますね。

最後に

これが何に使えるのかはあまり考えていませんので、是非とも有用な使い方を教えて頂ければうれしいです！JSONにしているので、このDumpの出力から各種スクリプトに連携させたり、パイプログの設定によって直接mongodb系のツールや自作スクリプトに直接渡すことで、データベースにまるっとほりこんだり連想配列に変換したりして扱う事も非常に簡単になると思います。

Apacheのログ解析以上に、Apacheに対するリクエストからレスポンスまでの情報を、各種フックのフェイズ単位で得る事ができるので、より詳細にWebサーバの解析や傾向調査、またインシデント時のデバッグが可能になるかもしれませんね。

そのた、例えばApacheに手を入れた場合のデバッグや、Apacheモジュールを組み込んだ場合に、適切に構造体の値が変わっているか等を確認するには良いかもしれません。

まずは機能から

導入は簡単

Apacheの設定

Dumpの出力をしてみる

最後に

「Apache内部の情報をダンプするモジュール mod_request_dumper」への2件のフィードバック