apache 2.4.17以降でmod_http2有効にすると、送信バイト数が正しく記録されない?

HTTP/2 対応させてから 10 日ほど経過したわけですが…。

続いては HTTP/2 対応。これは、SSLが有効であることと、Apache HTTP Server の 2.4.17 がインストールされているのが前提です。

[From 自分んとこのWebサイトを常時SSL対応にして HTTP/2 にも対応させてみた - Soukaku's HENA-CHOKO Blog]

特に大きな問題もないなぁ~、と思っていたのだけど、ログを流し見していて気になる点、発見。
HTTPステータスコードに続けて、本来であればレスポンスとして送信したデータのバイト数が記録されるはずが、 "0" になっている。

203.0.113.60 - - [24/Dec/2015:00:39:58 +0900] "GET /~soukaku/images/eyecatch0002.jpg HTTP/2" 200 0 "https://www.downtown.jp/~soukaku/archives/2014/0217_004838.html" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_2) AppleWebKit/601.3.9 (KHTML, like Gecko) Version/9.0.2 Safari/601.3.9"

HTTP/1.1 であれば、下のログのように送信バイト数には "0" 以外の数値が入っている。

198.51.100.20  - [24/Dec/2015:10:28:42 +0900] "GET /~soukaku/images/eyecatch0002.jpg HTTP/1.1" 200 44068 "https://www.downtown.jp/~soukaku/archives/2015/0711_171147.html" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/600.8.9 (KHTML, like Gecko) Version/8.0.8 Safari/600.8.9"

Web サーバとしてのサービス自身が止まっているわけではないし、HTTP/2 自体のアクセス比率もそう高くはないので、困った状況になっているわけではないけど、HTTP/2 でなければ "0" とはなっていないのだから、やはり動作としておかしい。
#awststs のようなアクセス統計ツールでの集計結果が正確なものでなくなる、という点では困るな…。

ドキュメント自体をチェックしてみると、

httpd 2.0 では 1.3 とは異なり、%b と %B フォーマット文字列はクライアントに送信されたバイト数そのものではなく、 HTTP レスポンスのバイト数です (これらは異なるもので、たとえば、 コネクションが途中で破棄された場合や、SSL 使用時に一致しません) 。 mod_logio で提供されている %O フォーマット文字列で、ネットワーク経由で実際に転送されたバイト数を 記録できます。

[From mod_log_config - Apache HTTP サーバ バージョン 2.4]

となっており、確かに実際の設定ファイルでも LogFormat ディレクティブの送信バイト数の位置には "%O" が指定されている。

root@vps2:~# grep ^LogFormat /etc/apache2/apache2.conf
LogFormat "%v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" vhost_combined
LogFormat "%h %l %u %t \"%r\" %>s %B \"%{Referer}i\" \"%{User-Agent}i\"" combined
LogFormat "%h %l %u %t \"%r\" %>s %O" common
LogFormat "%{Referer}i -> %U" referer
LogFormat "%{User-agent}i" agent

"%O" を使うためには、mod_logio が必要だけど、これはすでに組込みモジュールとしてコンパイルてパッケージングされているので、有効になっている。(現に、 HTTP/2 でなければ、"%O" となっていても送信バイト数は、ちゃんと記録されているのだから。)

root@vps2:~# apache2ctl -l
Compiled in modules:
core.c
mod_so.c
mod_watchdog.c
http_core.c
mod_log_config.c
mod_logio.c
mod_version.c
mod_unixd.c

となると、やはり HTTP/2 でのアクセスが有った場合の処理の何処かがおかしいんだろうな、と。考えられるのは、ログとして書き込む際の処理か、送信バイト数をカウントする処理のいずれかになりそうですが…。

改めて、 mod_http2 有効化以降のログもチェックし直してみたところ、有効化の直後から送信バイト数が "0" でロギングされてて、途中 2.4.17 → 2.4.18 のアップデートがあったにもかかわらず、"0" のままという状況が継続していた模様。

ということで、バグレポートしてみたのだけど、fix されるといいな…。

トラックバック(1)

以前書いていた HTTP/2 が有効な apache2 2.4.18 で、相手に送信したコンテンツの送信バイト数がうまく記録されなかった件、 改めて、 m... 続きを読む

コメントする