Apacheのアクセスログの日本語エスケープが適当な気がする

Apacheのアクセスログを以下のようなLTSVのフォーマットで管理しています。

LogFormat "host:%h\tforwardedfor:%{X-Forwarded-For}i\tident:%l\tuser:%u\ttime:%t\tmethod:%m\tpath:%U\tquery:%q\tstatus:%>s\tsize:%b\treqsize:%I\treqtime_microsec:%D\treferer:%{Referer}i\tua:%{User-Agent}i" combined_ltsv

LTSVはそのままfluentdに渡すことができますし、コマンドで見やすく整形したりしやすいので便利です。

 

出力されるアクセスログは以下の様な感じになります(タブを改行に置換しています)。

host:192.168.1.128
forwardedfor:-
ident:-
user:-
time:[15/Apr/2014:01:23:17 +0900]
method:GET
path:/2014/04/04/hello-world/
query: status:200
size:20965
reqsize:594
reqtime_microsec:227935
referer:-
ua:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.152 Safari/537.36

こうして見ると普通なのですが、path(%U)が日本語になるとおかしな事になります。

host:192.168.1.128
forwardedfor:-
ident:-
user:-
time:[15/Apr/2014:01:44:40 +0900]
method:GET
path:/2014/04/05/\xe6\x97\xa5\xe6\x9c\xac\xe8\xaa\x9e\xe3\x82\xbf\xe3\x82\xa4\xe3\x83\x88\xe3\x83\xab\xe3\x81\xae\xe6\x8a\x95\xe7\xa8\xbf/
query:
status:200
size:20276
reqsize:673
reqtime_microsec:235604
referer:-
ua:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.152 Safari/537.36

日本語が読めなくなってしまいました。文字化けしています。

どうも、以下のように

/2014/04/05/%e6%97%a5%e6%9c%ac%e8%aa%9e%e3%82%bf%e3%82%a4%e3%83%88%e3%83%ab%e3%81%ae%e6%8a%95%e7%a8%bf/

パーセントエンコードされた上で、さらにパーセント記号(%)が\xに置換されているようです。

 

これを過去記事の「(fluentdからElasticSearch+kibana3に転送した文字列が分かち書きされるのを回避する」のようにkibanaで見ようとするとひどいことになります。

escapebake

文字化けしてしまうので、どのページへアクセスがあったのかさっぱりわかりません。。

 

調べてみると、pathのパーセント記号(%)が\xに置換されているのは、脆弱性対応を目的としたもののようでした。

参考URL:ろば電子が詰まっている – [Apache]Apache 2.2.25とRewriteLogのエスケープと日本語 (CVE-2013-1862)

 

しかし、path(%U)はエスケープされるものの、refererはエスケープされていないように見えます。

host:192.168.1.128
forwardedfor:-
ident:-
user:-
time:[15/Apr/2014:02:08:28 +0900]
method:GET
path:/2014/04/05/\xe6\x97\xa5\xe6\x9c\xac\xe8\xaa\x9e\xe3\x82\xbf\xe3\x82\xa4\xe3\x83\x88\xe3\x83\xab\xe3\x81\xaf\xe5\x8c\x96\xe3\x81\x91\xe3\x82\x8b\xe3\x81\x8b\xe3\x82\x82\xe3\x80\x82\xe3\x80\x82\xe3\x80\x82\xef\xbc\x9f/
query:
status:200
size:20732
reqsize:844
reqtime_microsec:259037
referer:http://192.168.1.146/2014/04/05/%e6%97%a5%e6%9c%ac%e8%aa%9e%e3%82%bf%e3%82%a4%e3%83%88%e3%83%ab%e3%81%ae%e6%8a%95%e7%a8%bf/
ua:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.152 Safari/537.36

 

しかも、以下のように

LogFormat "host:%h\tforwardedfor:%{X-Forwarded-For}i\tident:%l\tuser:%u\ttime:%t\treq:%r\tmethod:%m\tpath:%U\tquery:%q\tstatus:%>s\tsize:%b\treqsize:%I\treqtime_microsec:%D\treferer:%{Referer}i\tua:%{User-Agent}i" combined_ltsv

一時的にLogFormatにreq(%r)を追加してアクセスログを見てみると、

host:192.168.1.128
forwardedfor:-
ident:-
user:-
time:[15/Apr/2014:02:25:35 +0900]
req:GET /2014/04/05/%e6%97%a5%e6%9c%ac%e8%aa%9e%e3%82%bf%e3%82%a4%e3%83%88%e3%83%ab%e3%81%ae%e6%8a%95%e7%a8%bf/ HTTP/1.1
method:GET
path:/2014/04/05/\xe6\x97\xa5\xe6\x9c\xac\xe8\xaa\x9e\xe3\x82\xbf\xe3\x82\xa4\xe3\x83\x88\xe3\x83\xab\xe3\x81\xae\xe6\x8a\x95\xe7\xa8\xbf/
query:
status:200
size:20276
reqsize:844
reqtime_microsec:312045
referer:http://192.168.1.146/2014/04/05/%e6%97%a5%e6%9c%ac%e8%aa%9e%e3%82%bf%e3%82%a4%e3%83%88%e3%83%ab%e3%81%af%e5%8c%96%e3%81%91%e3%82%8b%e3%81%8b%e3%82%82%e3%80%82%e3%80%82%e3%80%82%ef%bc%9f/
ua:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.152 Safari/537.36

req(%r)はエスケープされない状態で表示され、path(%U)はエスケープされた状態で表示されます。

http://httpd.apache.org/docs/2.2/ja/logs.htmlを見る限り、

"GET /apache_pb.gif HTTP/1.0" (\"%r\")クライアントからのリクエストが二重引用符の中に示されています。 リクエストには多くの有用な情報があります。まず、この場合クライアントが 使ったメソッドは GET です。次に、クライアントは リソース /apache_pb.gif を要求しました。そして、 クライアントはプロトコル HTTP/1.0 を使用しました。 リクエストの各部分を独立にログ収集することもできます。例えば、 フォーマット文字列 “%m %U%q %H” は メソッド、パス、クエリ文字列、プロトコルをログ収集し、 結局 “%r” とまったく同じ出力になります。

とありますが、同じ出力になってません。。!

どっちつかずな感じですが、これでいいのでしょうか。。