Log4j のNDC（ネスト化診断コンテキスト）を使用します。
Web アプリケーションのような複数のクライアントが同時にアクセスするシステムにおいて、特定のクライアントの操作を追跡したい場合があると思います。
単純にログ出力メッセージにクライアントを特定する情報を加えるという方法でも追跡は可能ですが、ログ出力毎にコードを記述しなければなりませんし、クライアントを特定する情報の出力の制御ができません。
Log4j ではこれを実現するための NDC という仕組みが用意されています。以下ではクライアントを識別する情報を"診断コンテキスト"と呼びます。
まず以下のサーブレット・フィルタを作成し、サーブレットへのリクエストに対してこのフィルタを通過させるよう、web.xml で設定します。
public final class NDCFilter implements Filter {
private static final Logger logger = Logger.getLogger(NDCFilter.class);
private FilterConfig filterConfig = null;
public void destroy() {
this.filterConfig = null;
}
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
if (filterConfig == null) {
return;
}
if (request instanceof HttpServletRequest) {
HttpServletRequest req = (HttpServletRequest) request;
NDC.push(req.getSession().getId());
try {
chain.doFilter(request, response);
} finally {
NDC.remove();
}
}
}
public void init(FilterConfig filterConfig) throws ServletException {
this.filterConfig = filterConfig;
}
}
doFilter() メソッドでは org.apache.log4j.NDC#push() メソッドを呼び出し、診断コンテキストとしてセッション ID を追加しています。こうすることによって、これ以降のログ出力でセッション ID の出力が可能になります（実際に出力するには NDC 出力用の変換パターン記号を指定する必要があります）。
そして、chain.doFilter() を try でくくり、finally 節で NDC.remove() を呼び出して追加した診断コンテキストを削除します。これら NDC クラスのメソッドが、カレントスレッドに対する操作であることには注意して下さい。例えばスレッドAが NDC#push() メソッドを呼び出し、スレッドBが NDC#remove() を呼び出しても、スレッドAにはスレッドBによる診断コンテキスト削除の影響は何もありません。逆に操作がスレッド単位であるからこそ、クライアント毎に操作を追跡することができるということですね。
NDC#remove() はスレッドが終了する前に必ず呼び出す必要があります。NDC#push() によって NDC クラスがカレントスレッドの参照を保持することになるのですが、このリンクを削除するためです。もしNDC#remove() を呼び出さずにスレッドが終了すると、NDC クラスに保持されたスレッドが GC の対象にならず、OutOfMemory を引き起こす可能性があります。
ただ、 Tomcat を始めとして、ほとんどのサーブレット・コンテナではスレッド・プールの仕組みを持っているため、スレッドは終了することなく再びプールに戻されます。そのような場合は、NDC#clear() メソッドを呼び出したほうがよいかもしれません。NDC#clear() ではNDCクラスからスレッドの参照を削除しないため、低コストで動作します。ただ、上の例では念のため NDC#remove() を finally 節で呼び出すようにしています。
フィルタを実装したら、診断コンテキストを出力する変換パターン記号をレイアウトに加えます。
<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
<param name="File" value="C:/Myfolder/java/eclipse2.1.2/workspace/Log4jTest/log/example.log" />
<param name="Append" value="true" />
<param name="MaxFileSize" value="1MB"/>
<param name="MaxBackupIndex" value="10"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%x %t %-5p %c{2} - %m%n"/>
</layout>
</appender>
'%x'が診断コンテキストの変換パターン文字です。これを加えることによって、フィルタで設定したセッション ID が出力されます。Logger クラスのメソッドによるログ出力コードは変更不要です。診断コンテキストを削除したければ、フィルタを削除し、設定ファイルから変換パターン文字を削除すれば良いです。
実際の出力は以下のようになりました。
ADDF701FCB19B48C1939DCBB06FCB14D Thread-5 DEBUG web.LoggingServlet - DEBUG message ADDF701FCB19B48C1939DCBB06FCB14D Thread-5 INFO web.LoggingServlet - INFO 日本語テスト 〜① ADDF701FCB19B48C1939DCBB06FCB14D Thread-5 WARN web.LoggingServlet - WARN message
この例では現在時刻を出力していませんが、診断コンテキストでログをフィルタし、時刻でソートすれば時系列でクライアントの操作をトレースできます。