Apacheのログで、リクエスト時間をマイクロ秒で表示する方法

ApacheのLogFormatで %t を指定すると、リクエストの時間が表示されますよね。

複数のサーバのログを集めて結合すると、時間が秒レベルなのでソートしても微妙に順番が変になったりします。

なので、秒より精度の高い時間を出力しようと思いました。
使っているのが Apache2.2系なこともあり、2.2のカスタムログ書式を眺めても、特にミリ秒とかマイクロ秒で出力できる感じなかったので、調べて見つけたのが

• リクエスト時刻のミリ秒を表示する | うーたまっくす

でした。
なるほどと思い、とりあえず mod_log_config.c がやっていることを見てみようと、なぜか手元には 2.4.3 のソースがあったのでそちらを見てみました。

そしたら、なんかこんなコードが。

        else if (!strncmp(fmt, "usec", 4)) {
            fmt += 4;
            if (!*fmt) {
                fmt_type = TIME_FMT_ABS_USEC;
            }
            else if (!strcmp(fmt, "_frac")) {
                fmt_type = TIME_FMT_ABS_USEC_FRAC;
            }

ん？マイクロ秒レベルで出力できる感じじゃん。
ということで、2.4のドキュメント見てみるも、何も書いてない。
とりあえず、英語版を、ということで見てみると、

the following format tokens are supported:
sec	number of seconds since the Epoch
msec	number of milliseconds since the Epoch
usec	number of microseconds since the Epoch
msec_frac	millisecond fraction
usec_frac	microsecond fraction

ちゃんと書いてあるじゃないですか。
ということで、Apache2.4 以降では LogFormat に

%{usec}t

と書くと、リクエストの時間がエポックからのマイクロ秒でログ出力されます。（スイマセン、知りませんでした。）

が、今使っているのは2.2系。
2.4のmod_log_config.cそのままはさすがにビルドできなかったので、この部分だけ抜き出したmod_log_config.c を作りました。こちら。

ということで、これをhttpdのソースのmodules/loggersにコピーして

$ apxs -c mod_log_config.c
$ su
# apxs -i mod_log_config.la

という感じで apxs でビルド・インストールすれば、2.2でも同じようにマイクロ秒で出力できるようになりました。

これで、少し解析が楽になる。