第13回 Apacheのログを活用しよう

Apacheのログは情報の宝庫だ。サイトの不具合や不審なアクセスを見つけたり、閲覧者の移動経路などからサイトを使いやすくする手掛かりを得ることができる。そのためには、ログの見方やカスタマイズ方法を知る必要がある。

Apacheが残すログ

 Apacheが残すログにはいくつかの種類がある。まずは、どういったログを残すのか、それを知っておくことから始めよう。

 このように、大きく分けて4種類のログを記録できるわけだが、何でもかんでも記録すればいいというものでもない。冒頭にも述べたとおり、ログは活用してこそ意味があるからである。「何かあったときのために」などといって無駄なログを記録しても、ディスク領域を浪費するだけに終わるだろう。それどころか、ディスクアクセスやCPUの負荷を高め、サーバのレスポンスを悪くすることも考えられる。
 ログを残すときは、本当に活用できるかどうかまで含めて検討し、必要最低限の記録を行うように心掛けたい。

エラーログ

エラーログの設定

 エラーログの設定で必要になるディレクティブは、「ErrorLog」と「LogLevel」の2つである。ErrorLogディレクティブはログファイルの位置と名称を指定し、LogLevelディレクティブは記録するログのレベルを指定する。

 表1に、LogLevelディレクティブで指定できるログレベルをまとめておいた。例えば、

LogLevel notice


と指定すると、notice以上のもの(emerg〜notice)が記録されることになる。一般的に、運用状態にあるサーバでは「notice」か「warn」を指定し、テスト状態であれば「info」や「debug」を指定することが多い。

 
レベル
記録される内容
  emerg 動作不能な状況(Emergencyの意)
  alert 修正しなければ(部分的に)動作できない問題
  crit 上記に該当しない動作上の問題(Criticalの意)
  error 存在しないファイルへのアクセスなど各種エラー
  warn 警告(Warningの意)。設定のミスなどが考えられる場合
  notice 起動停止や設定変更された場合など
  info あらゆる情報(プロセスの起動や停止など)
  debug Apache関連のデバッグに必要な情報
  表1 エラーログのレベル


 ErrorLogディレクティブには、ログを指定するディレクトリとファイルの名称を指定する。例えば、

ErrorLog /usr/local/apache/logs/error.log


などのように記述する。あるいは、

ErrorLog syslog


のように、ファイル名の代わりに「syslog」を指定してもよい。この場合、Apache専用のエラーログファイルを作らず、Linuxが標準で持っているsyslogにエラーを記録する。ただし、syslogに記録するよりも管理の利便性から専用のファイルに記録することが多い。

 syslogに記録する場合は、

ErrorLog syslog:facility


のようにすることでsyslogのファシリティを指定することも可能だ。ファシリティの指定がない場合は、local7がデフォルトのファシリティとして採用される。

 httpd.confを変更した場合は、Apacheを再起動しないと設定が有効にならない点に注意すること。それは、ほかの設定についても同様である。

エラーログのチェックポイント

 アクセスの結果、エラーが発生するとエラーログが記録される。例えば、存在しないファイルにアクセスした場合やユーザー認証で不正なパスワードを入力した場合などだ。エラーログを設定したら、わざと間違ったアクセスを試み、どんなログが記録されるのか確認しておくといいだろう。

 ここでは、いくつか例を挙げてログのどこに着目すべきかを紹介しよう。

[crit] [client 192.168.1.11] (13)Permission denied: /usr/local/apache/html/root_own.html pcfg_openfile: unable to check htaccess file, ensure it is readable


 上記のようなログで注目すべきなのは、「Permission denied」の部分である。つまり、ファイルは存在しているがパーミッション(権限)の問題でファイルを読み込めなかったことを意味する。こうした問題はすぐに修正すべきものとして、単なるエラー(error)よりも高レベルのログとして記録される。このようなログを抽出して、問題を早期に修正するようにするべきである。

[alert] [client 192.168.1.11] /home/ichishi/public_html/.htaccess: Multiple <Files> arguments not (yet) supported.
[alert] [client 192.168.1.11] /home/ichishi/public_html/.htaccess: Invalid command 'hogehoge', perhaps mis-spelled or defined by a module not included in the server configuration


 この場合も単なるエラーよりも高レベルのログ(alert)として記録されている。これは、.htaccessの内容に間違いがあることを警告している。Apache自身の動作には問題がないが、このユーザーのファイルに正常にアクセスできなくなる。こうした問題も、発見次第修正しなければならない。

[error] [client 192.168.1.11] File does not exist: /usr/local/apache/html/index.html not_exist


 これは、比較的発生しやすいエラーの1つで、リクエストに対応するファイルがなかったという意味である。このような記録の原因の大半はユーザー側のミスなのだが、リンクのミスという可能性も考えられる。この記録が頻発するようであれば、リンクが間違えていないかなど、検査してみる必要があるだろう。

[error] [client 192.168.1.11] client denied by server configuration: /home/ichishi/public_html/index.html


 これは、「denied」の部分に注目する。つまり、アクセス制限によってアクセスが拒否されたことを意味している。単にパスワードを打ち間違えても記録されるから、目くじらを立てることもないのだが、これがログに頻繁に現れるようなら不正アクセスということも考えられる。

 これらはほんの一例でしかないが、見慣れないエラーでも注意深く英語を解読すればおおよその意味は理解できるはずだ。できればemergなどの例も示したかったが、それらは簡単に発生させられない。もし、error以上のレベルが記録されたら、基本的に対処を要するものだと思った方がよい。

クッキーログ

 まず、クッキーを使ったトラッキングの仕組みを簡単に解説しておこう。クッキーログが有効になっていると、Webサーバはアクセスされた際に自分が発行したクッキーをWebブラウザが持っているかどうかを調べる。Webブラウザが要求されたクッキーを持っていれば、要求にこたえて「クッキー値」と呼ばれる値を返信する。持っていなければ、サーバが新規にクッキーを発行し、Webブラウザに記憶させる。

 このクッキー値をアクセスのたびに要求することで、そのユーザーが過去にアクセスしてきたユーザーか否か、新規でないならだれなのかを識別できる。「識別できる」といっても、あくまでもクッキーの値が同じならば同じユーザーであろうという程度にすぎない。重要なことは、クッキーの値とアクセスしたページ、その時間などを記録しておくことにある。こうした情報が記録されていれば、クッキーの値で特定のユーザーを抽出でき、特定のユーザーの足跡をたどることができるわけだ。

 クッキーログの活用法やより高度な記録の方法については、本稿の意図するところではないから、これ以上詳しくは解説しない。興味があれば、そうした分析の専門企業もあるので調べてみるといいだろう。ここでは、発行したクッキーをWebブラウザから受け取り、足取りを記録する方法を紹介する。

クッキーログの設定

 クッキーログの設定自体は決して難しくない。「CookieTracking」ディレクティブでクッキーを発行する機能を有効にし、「CookieExpires」ディレクティブによってクッキーの有効期限を決める。後は、ユーザーに送られたクッキーをサーバ側に記録するためのログファイルと書式を設定するだけだ。

 CookieTrackingディレクティブの設定は簡単で、

CookieTracking on

のように、指定すべきは「on」(有効)と「off」(無効)だけである。これとペアで用いるのが前述のCookieExpiresディレクティブで、

CookieExpires "2 days"

のように、数字と単位(years、months、weeks、days、hours、minutes、seconds)をダブルクオーテーションで囲んで指定する。このディレクティブで有効期限を指定しなかった場合、クッキーの有効期限はユーザーがWebブラウザを終了させるまでとなる。

 ちなみに、クッキーの発行はバーチャルホストや仮想ディレクトリの単位でも行える。サイト全体ではなく、ある一部分だけ追跡したい場合、こうした細かい単位での設定が有効になるだろう。その場合は、バーチャルホストや仮想ディレクトリのディレクティブ「<Directory>〜</Directory>」の中で、「CookieTracking on」を指定すればよい。

ログを使った追跡

 Webブラウザに記憶させたクッキーを取得してファイルに記録する設定は、実のところアクセスログと共通の方法を用いる。正確には、「カスタムログ」と呼ばれる方法によって実現する。カスタムログとは、ログに記録する書式を設定し、その書式をどのファイルに出力するかを指定する方法を指す。

 カスタムログの書式やファイルの設定については次に譲るとして、ここではクッキーに的を絞って紹介する。リスト1およびリスト2は、実際にクッキーを使ってログを出力した例である。見てのとおり、ログを出力する方法は2つある。

10.3.83.17.54311013115202845
リスト1 %{cookie}nとした場合。IPアドレスの後ろがクッキー値

Apache=10.3.83.17.54311013115202845
リスト2 %{cookie}iとした場合。IPアドレスの後ろがクッキー値

 いずれにしても、書式として%{cookie}とすることに変わりはなく、その後に続く文字によって出力が変化する。また、見てのとおりクッキーだけを記録しても何の役にも立たない。「%{cookie}」で記録されるのは、クッキーを返してきたクライアントのIPアドレスとそのクッキー値だけだからだ。実際には、さらに書式を追加して必要な情報を得られるようにしなければならない。

 書式の設定は、必要とする情報の種類によるので一概にはいえないが、2つほど具体例を紹介しよう。

%{cookie}i %{Referer}i -> %U

とした場合のログがリスト3だ。

Apache=10.3.83.17.54311013115202845 http://10.3.83.17/
-> /manual/index.html.ja.jis
Apache=10.3.83.17.54311013115202845 http://10.3.83.17/
-> /manual/index.html.ja.jis
Apache=10.3.83.17.54311013115202845 http://10.3.83.17/manual/index.html
-> /manual/images/apache_header.gif
Apache=10.3.83.17.54311013115202845 http://10.3.83.17/manual/index.html -> /manual/images/pixel.gif
Apache=10.3.83.17.54311013115202845 http://10.3.83.17/manual/index.html -> /manual/images/index.gif
リスト3 これでユーザーの移動経路が分かる

 前述の%{cookie}iに、アクセスしたファイル「%U」とその前にアクセスしていたファイル「%{Referer}i」を付加している。「->」はログを見やすくするためのもので、特別な意味があるわけではない。

 さらに、時間「%t」を加えて、

%{cookie}i %t %{Referer}i -> %U

とすると、リスト4のようなログになる。

Apache=10.3.83.17.54311013115202845 [08/Feb/2002:06:16:59 +0900] http://10.3.83.17/ -> /manual/index.html.ja.jis
Apache=10.3.83.17.54311013115202845 [08/Feb/2002:06:17:57 +0900] http://10.3.83.17/manual/index.html -> /manual/invoking.html.en
Apache=10.3.83.17.54311013115202845 [08/Feb/2002:06:17:57 +0900] http://10.3.83.17/manual/invoking.html -> /manual/images/sub.gif
Apache=10.3.83.17.54311013115202845 [08/Feb/2002:06:18:15 +0900] http://10.3.83.17/manual/invoking.html -> /manual/windows.html
リスト4 時間情報も付加した場合。これで時系列の分析もできる

 このように、クッキー値とともに付加情報を記録することで、特定のユーザー(Webブラウザ)がどのようにサイト内を移動したのかを追跡できる。

 皆さんも、実際にいろいろ設定を変えてみて、どのようなログが記録されるのか試してみるといいだろう。そのとき重宝するのが「tail」コマンドだ。このコマンドは、もともとファイルの末尾20行程度を見るために用いられるのだが、「-f」オプションを与えるとファイルに書き込まれる内容をリアルタイムに監視できる。例えば、

tail -f /usr/local/apache/logs/cookie_log

とするとcookie_logに書き込まれる内容を監視し、書き込まれた内容を画面に表示してくれる。

 httpd.confの設定を変えたら、エディタを終了せずに保存し、別のウィンドウを使ってApacheをgracefulで再起動する。そして、もう1つのウィンドウでログを監視しながらWebブラウザでいろいろアクセスしてみると、リアルタイムに書き込まれる内容が分かるというわけだ。古くからUNIXやLinuxに触れている方にとっては当たり前の手法かもしれないが、もしご存じでなかったなら一度試してみていただきたい。応用すれば、いろいろな場面で役に立つだろう。

アクセスログ

 クッキー値などが記録できることは理解していただけたと思うが、その設定方法についてはいま一つピンとこないことだろう。ここまでで紹介したのは、エラーログの記録先を決める「ErrorLog」とレベルを決める「LogLevel」、CGIエラーログの記録先を決める「ScriptLog」。そして、クッキーによる追跡を有効にする「CookieTracking」とクッキーの有効期限を設定する「CookieExpires」だった。

 ここから紹介するのは、クッキー値や時間といったさまざまな情報について、どのように記録するかの設定だ。それには、ログの書式を設定し、その書式で記録するログファイルを設定する。それぞれ、「LogFormat」ディレクティブと「CustomLog」ディレクティブで実現する。

アクセスログの設定

 LogFormatとCustomLogディレクティブは、いずれも簡単に設定できる。

 LogFormatディレクティブは、記録する書式と、その書式の名前を設定する。例えば、

LogFormat "%t" time

とすれば、書式の名前が「time」で、記録するのはアクセス時刻「%t」となる。

 続いて、CustomLogディレクティブを使ってこの書式のログを記録するファイルを指定する。

CustomLog /usr/local/apache/logs/time_log time

とすれば、書式名「time」のログを「time_log」というファイル名で記録すると設定したことになる。このようにすることで、自分の使いやすい書式のログをいくつでも記録できるわけだ。

 設定自体は簡単なのだが、書式に指定できる内容が分からなければ話にならない。これについては、まず表2を参照していただこう。Apacheがサポートするログの書式パラメータである。

 
パラメータ
内容
  %b そのリクエストで行われたデータの転送量(bytes)
  %f リクエストされた仮想ディレクトリ+ファイル名
  %{Foobar}e 環境変数(Foobarで指定したもの)の内容
  %h リクエストしたコンピュータの名称またはIPアドレス
  %a リクエストしたコンピュータのIPアドレス
  %{Foobar}i リクエストヘッダ(Foobarで指定したもの)の内容
  %l リモートログ名(identdをクライアントがサポートしているとき)
  %{Foobar}n ほかのモジュールからのノート(Foobarで指定したもの)の内容
  %{Foobar}o レスポンスヘッダ(Foobarで指定したもの)の内容
  %p リクエストを受けたポートの番号
  %P リクエストを受けたApacheのプロセス番号(PID)
  %r リクエストの最初の行
  %s リクエストに対するHTTPのステータスコード(表3参照)
  %t リクエストされた時間(形式例:[08/Feb/2002:04:50:13 +0900])
  %{format}t リクエストされた時間(formatで指定した形式で記録)
  %T リクエストの処理に要した時間(秒)
  %u クライアント側のユーザー名
  %U リクエストされたURLパス
  %v サーバがリクエストを処理する正統なServerName
  %V UseCanonicalNameの設定によるサーバ名
  表2 ログ書式パラメータ。「Foobar」の部分は適宜置き換えること

 これらの書式パラメータを組み合わせ、ダブルクオーテーションで囲んで指定すれば、望みどおりの書式でログを記録できる。とはいえ、表2に示されたもののうち、どれを記録するのが有益かは分かりづらい。それどころか、「Foobar」のように表現したものは、そこに「Referer」や「Cookie」などの名称を指定しなくては使えない。

 これでは、HTTPの仕様に詳しくなければどうしていいものやら困り果ててしまうだろう。ありがたいことに、必要そうな書式はあらかじめApacheの開発者側で設定してくれているのだ。これらはhttpd.confの中に用意されているから、探せばすぐに見つかるだろう。念のためにリスト5にも示しておいた。

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
LogFormat "%h %l %u %t \"%r\" %>s %b" common
LogFormat "%{Referer}i -> %U" referer
LogFormat "%{User-agent}i" agent
リスト5 標準で用意されている書式設定(httpd.confより)

 「\」は「"」をログに記録するためのエスケープ文字。また、「%>s」のように「>」を間に入れると、内部的にリダイレクトされても最終的な結果を出力する指定になる。

 デフォルトのアクセスログ(/usr/local/apache/logs/access_log)では、リスト5の「common」を採用している。commonによって記録されたログの例がリスト6(一部分を抜粋)だ。このログでも、アクセス時間とアクセス先、どこからのアクセスかといったことは理解できる。

10.3.83.17 - - [08/Feb/2002:05:52:37 +0900] "GET / HTTP/1.1" 304 -
10.3.83.17 - - [08/Feb/2002:05:53:22 +0900] "GET /manual/index.html HTTP/1.1" 200 5746
10.3.83.17 - - [08/Feb/2002:05:53:22 +0900] "GET /manual/images/apache_header.gif HTTP/1.1" 200 4084
10.3.83.17 - - [08/Feb/2002:05:53:22 +0900] "GET /manual/images/pixel.gif HTTP/1.1" 200 61
10.3.83.17 - - [08/Feb/2002:05:53:22 +0900] "GET /manual/images/index.gif HTTP/1.1" 200 1540
10.3.83.17 - - [08/Feb/2002:05:57:01 +0900] "GET /manual/index.html HTTP/1.1" 304 -
リスト6 commonのログ出力の一部

 それでも足りないなら「combined」を選択してもよい。combinedは、commonで定義された情報に加えて1つ前にアクセスしていた場所(Referer)とクライアントが使っているWebブラウザ(Agent)も記録する。

 必要であればこれ以上の情報を得ることもできるのだが、ログとしての必要性を考えると、これ以上のカスタマイズが必要なのはまれであろう。情報量を増やすためのカスタマイズよりも、ログの見やすさを追求したり、本当に必要なものだけに絞る方が有益だと思う。リスト5にも示したとおり、「->」を入れると情報を理解しやすくなる。

アクセスログの条件設定

 ログの出力設定についてはほぼマスターしたことになるのだが、もう1つだけマスターしていただきたいことがある。記録するログに条件を付けて、限られたアクセスだけを出力する方法である。これには、CustomLogディレクティブに第3の引数として環境変数とその値を指定する。これを使うと、ある特定の種類のファイル(PDFなど)へのアクセスだけを記録したり、不正と思われる種類のリクエストだけを別なログに記録できるようになる。例えば、

CustomLog /usr/local/apache/logs/pdf_log common env=pdf-files

と指定した場合を考えてみよう。これは、pdf_logというファイルに書式commonで記録するが、記録するのは環境変数「pdf-files」が設定されている場合だけ、という意味になる。では、「環境変数pdf-filesが設定されている場合」とはどういう意味だろうか?

 これには「mod_setenvif」というモジュールが関係し、「SetEnvIf」ディレクティブを使う必要がある。mod_setenvifはApacheに標準で組み込まれるモジュールだから、基本的にはすでに用意されているはずである。このモジュールは、リクエストを条件に従って判定し、条件に一致すると環境変数を設定する役割を果たす。例えば、

SetEnvIf Request_URI \.pdf$ pdf-files

と指定すると、リクエストのURIに拡張子pdfが含まれている場合に環境変数pdf-filesを設定する。これを指定することで、PDFへのアクセス時にはpdf-filesという環境変数が設定されることになり、PDFへのアクセスだけを記録するログが実現できるというわけである。

 この手法はこれ以外にも当然応用可能で、クラッカーが不正アクセス目的で指定するURIを抽出することなども考えられる。また、SetEnvIfはURIだけでなくMethod(POSTかGET)やIPアドレスを判定することもできるから、POSTとGETで区別したり社内・社外のアクセスを区別することもできるだろう。

 社内と社外を区別するなら、

CustomLog /usr/local/apache/logs/internal_log common env=internal

として社内のアクセスを記録する。逆に、社外を記録するなら、

CustomLog /usr/local/apache/logs/outer_log common env!=internal

のように「!=」を使って、「それ以外」(この場合はinternal以外)と指定すると便利だ。

次回はログの分析や管理

 「たかがログ」といっても、その設定の応用は奥が深い。本当は、ログの分析やローテーションについても紹介したかったのだが、筆者の悪癖が出て書き切れなくなってしまった。次回はログ管理の続きとして、出力されたアクセスログの分析やログのローテーション管理について紹介しようと思う。

Appendix

 
コード
内容
  100番台は情報
  100 Continue
  101 Switching Protocols
  200番台は成功
  200 OK
  201 Created
  202 Accepted
  203 Non-Authoritative Information
  204 No Content
  205 Reset Content
  206 Partial Content
  300番台は転送
  300 Multiple Choices
  301 Moved Permanently
  302 Moved Temporarily
  303 See Other
  304 Not Modified
  305 Use Proxy
  400番台はエラー(アクセスする側の問題)
  400 Bad Request
  401 Unauthorized
  402 Payment Required
  403 Forbidden
  404 Not Found
  405 Method Not Allowed
  406 Not Acceptable
  407 Proxy Authentication Required
  408 Request Time-out
  409 Conflict
  410 Gone
  411 Length Required
  412 Precondition Failed
  413 Request Entity Too Large
  414 Request-URI Too Large
  415 Unsupported Media Type
  500番台はエラー(アクセスされる側の問題)
  500 Internal Server Error
  501 Not Implemented
  502 Bad Gateway
  503 Service Unavailable
  504 Gateway Time-out
  505 HTTP Version not supported
  表3 ステータスコード

WWWサーバーのHTTP ログファイルの読み方