BLOGサブスレッドの日常

2018.11.02

Webアプリで任意の値をアクセスログに記録する

mzsm

このブログでは超おひさしぶりになります。
みずしま a.k.a mzsm(@mzsm_j)です。こんにちは。

サブスレッドは昨日から7年目に突入したそうです。
おめでたい。

ですが今日の記事はそれとは全く関係ないお話。

例えばWebアプリの管理画面で誰かが誤った操作を行ってしまった場合に、「当該操作が行われた時刻はいつなのか」「誰が当該操作を行ったのか」などを確認するためにApacheやnginxなどWebサーバのアクセスログを確認するということがよくあります。

しかし、アクセスログには1件1件のアクセスは記録されていますが、それが誰によるものなのか、あるいはどういう操作を行ったのかというのは、それだけではわかりません。
Webアプリ側で独自にログを残すというのも一つの方法ですが、Webサーバのアクセスログにまとめて記録されている方が都合が良い場合もあります。

というわけで、Webアプリ側が出力した任意の値をWebサーバのアクセスログに記録する方法を考えてみます。

なお今回は、Apacheあるいはnginxがフロントエンドサーバとして存在しており、FastCGI、WSGIもしくはリバースプロキシなどの方法でバックエンドのWebアプリと接続しているというケースを想定しています。
Webアプリの実装の説明には、筆者がよく使用しているPython製Webフレームワーク「Django」を使用していますが、このテクニックはフレームワークや言語に関係なく利用できます。

WebアプリからWebサーバへデータを受け渡す

特別な仕組みを使わず、Web標準に則った方法で考えるならば、レスポンスヘッダを使用するのが最も簡単で素直です。

Djangoでは、レスポンスオブジェクトに対して辞書のような操作でレスポンスヘッダの追加ができます。

def view(request):
    response = HttpResponse()
    response[ヘッダ名] = 値
    return response

ログイン中のユーザー名をヘッダに出力する場合は、こんな感じのミドルウェアを作って適用してやると良いでしょう。

foom django.utils.deprecation import MiddlewareMixin

class UserNameMiddleware(MiddlewareMixin):
    def process_response(self, request, response):
        if request.user and request.user.is_authenticated:
            response['X-Foo-Bar'] = request.user.username
        return response

レスポンスヘッダの内容をアクセスログに出力する

Apacheの場合

Apacheでログフォーマットを変更するには、LogFormatディレクティブでフォーマットを定義し、CustomLog(アクセスログ)またはErrorLog(エラーログ)ディレクティブで使用するフォーマットを指定します。

レスポンスヘッダの内容を出力するには、%{ヘッダ名}oという書式で指定します。
ヘッダ名がX-Foo-Barならば、%{X-Foo-Bar}oとなります。

LogFormat "%{%Y-%m-%d}t\t%{%H:%M:%S}t\t(中略)\t%{Referer}i\t%{X-Foo-Bar}o" oreoreformat
CustomLog logs/access.log oreoreformat

#またはCustomLogで直接フォーマットを指定することもできる
CustomLog logs/access.log "%{%Y-%m-%d}t\t%{%H:%M:%S}t\t(中略)\t%{Referer}i\t%{X-Foo-Bar}o"

nginxの場合

nginxでは、log_formatディレクティブでフォーマットを定義し、access_log(アクセスログ)またはerror_log(エラーログ)ディレクティブで使用するフォーマットを指定します。

レスポンスヘッダの内容を出力するには、$sent_http_に続けて、ログに出力したいヘッダ名を指定します。
このとき、ヘッダ名はハイフンをアンダースコアに置換した上で小文字化する必要があります。
例えばヘッダ名がX-Foo-Barならば、$sent_http_x_foo_barと指定することになります。

なお、よく似た名前で$http_の後にヘッダ名を指定するものもありますが、こちらは ブラウザからWebサーバへのリクエストヘッダ を出力するものなので注意してください。

log_format oreoreformat '$time_iso8601\t(中略)\t$http_referer\t$sent_http_x_foo_bar';
access_log logs/access.log oreoreformar;

出力できた!…けど…

さて、これで必要な情報がアクセスログに記録されるようになりました。

しかし、実はこのままではひとつ問題があります。
それは、アクセスログに書き込んだヘッダの情報がそのままレスポンスとしてクライアントに返されてしまうということです。

ユーザー名程度ならば別に問題ないかもしれませんが、ユーザーにはあまり見せたくない内部的な情報を出力したい場合は困ってしまいます。

というわけで、Webアプリから送られてきたヘッダを消した上でクライアントに返すようにしましょう。

レスポンスヘッダの内容をアクセスログに出力した上で、当該ヘッダを削除する

Apacheの場合

ApacheではHeaderディレクティブにunset ヘッダ名というオプションを渡すことでヘッダを削除できます。

Header unset X-FooBar

しかし、ヘッダを削除すると%{ヘッダ名}oを利用したアクセスログへの出力もできなくなってしまいます。
これでは意味がありません。

そこで利用するのがnoteという機能です。
Headerディレクティブにnote ヘッダ名 ノート名というオプションを渡すことで、ヘッダの内容をノート(メモ)に記録することができます。
いったんノートに記録したら、ヘッダはもう削除してしまって構いません。

Header note X-FooBar hoge
Header unset X-FooBar

ノートの内容をログに出力するには、%{ノート名}nと指定します。

LogFormat "%{%Y-%m-%d}t\t%{%H:%M:%S}t\t(中略)\t%{Referer}i\t%{hoge}n" oreoreformat

nginxの場合

Webアプリ側から送られてきたヘッダを削除する方法は、nginxとWebアプリ間の接続方法によって少し変わります。
それぞれのアプリに合わせて適切なものを選んでください。

proxy_hide_header X-Foo-Bar;  # リバースプロキシの場合
uwsgi_hide_header X-Foo-Bar;  # uWSGIの場合
fastcgi_hide_header X-Foo-Bar;  # FastCGIの場合

nginxにはApacheのnoteに相当するものはありませんが、nginxがクライアントに返すレスポンスヘッダ だけでなく 上位サーバからnginxに送られてきたレスポンスヘッダ もアクセスログに出力できるため、問題ありません。

$sent_http_<ヘッダ名>はnginxがクライアントに返すレスポンスヘッダを出力するものでした。
上位サーバ(つまり今回のケースではWebアプリ)からnginxに送られてきたレスポンスヘッダを出力するには$upstream_http_に続けてヘッダ名を指定します。

log_format oreoreformat '$time_iso8601\t(中略)\t$http_referer\t$upstream_http_x_foo_bar';

これで、Webアプリから送られてきたヘッダの内容をアクセスログに記録した上で、ヘッダを削除してクライアントへ返すことができるようになりました。

この記事を書いた人

mzsm