いろいろ試行錯誤したので、できた所までの覚え書き。
環境
- SpringSource Toole Suite ：2.8.1.RELEASE
- JDK：1.6.0_30
実装のベース
Spring Frameworkへのロギングについてはググればいろいろ出てくると思いますが、今回試行錯誤したのはSpring Source公式サンプルの
・Samples | SpringSource.org
http://www.springsource.org/samples
「Spring Framework Samples」のmvc-ajaxプロジェクトへの実装。導入と動かし方等は過去の記事で。
log4j.xmlを操作してみる
まず、サーバを実行すると
このようなログがコンソールへ出力されます。日付が入っていないので、試しに日付が出るようにlog4j.xmlを修正してみたいと思います。
ディレクトリで言うと、｛保存先のディレクトリ｝mvc-ajax\trunk\src\main\resources\log4j.xml
パッケージエクスプローラで言うと、src/main/resourcesに入っています。後は以下のように日付フォーマットを記述して
<!-- Appenders -->
<appender name="console" class="org.apache.log4j.ConsoleAppender">
<param name="Target" value="System.out" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss}%-5p: %c - %m%n" />
</layout>
</appender>
サーバを起動させると、日付が挿入されました。
次にこれをファイルに出力してみます。これもlog4j.xmlへ以下を追加します。
<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
<param name="File" value="D:/logs/mvc-ajax.log" />
<param name="MaxFileSize" value="1024KB" />
<param name="MaxBackupIndex" value="10" />
<param name="Append" value="true" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern"
value="%d{yyyy/MM/dd HH:mm:ss} %p:%r:%c:%m%n" />
</layout>
</appender>
設定の詳細については、log4jのリファレンスにて。。D:/logs/mvc-ajax.logへログファイルが出力される設定です。このままではファイルは出力されないので、同ファイルのRoot Loggerへ１行追加します。
<!-- Root Logger -->
<root>
<priority value="warn" />
<appender-ref ref="console" />
<appender-ref ref="FILE" />
</root>
これでサーバを起動すると、コンソールとファイルへlog4jのログが出力されます。
オリジナルのログを出力する
上記では、デフォルトで出力されるログについてですが、任意の場所で出力できるようJavaコードを修正してみたいと思います。動作を確認しやすいようにAccountController.javaを対象にします。importへorg.apache.log4j.Loggerを記述。インスタンス生成時とGetリクエストが呼ばれたタイミングでログを出力するようにしてみます。
public class AccountController {
private static Logger logger = Logger.getLogger(AccountController.class);
private Map<Long, Account> accounts = new ConcurrentHashMap<Long, Account>();
private Validator validator;
@Autowired
public AccountController(Validator validator) {
logger.info("create instance");
this.validator = validator;
}
@RequestMapping(method=RequestMethod.GET)
public String getCreateForm(Model model) {
logger.info("GET Request");
model.addAttribute(new Account());
return "account/createForm";
}このままでは、エラーは出ませんが埋め込んだロギングを認識しません。log4j.xmlへorg.springframework.samples.mvc.ajax.account配下のクラスでログ出力するように以下の記述を追加します。
<logger name="org.springframework.samples.mvc.ajax.account">
<level value="info" />
</logger>
これでサーバを起動したタイミングで、
2012-01-07 04:05:05 INFO : org.springframework.samples.mvc.ajax.account.AccountController - create instance
という出力や、クリックしたタイミングで、
2012-01-07 04:05:36 INFO : org.springframework.samples.mvc.ajax.account.AccountController - GET Request
のように表示されます。
アスペクト指向（ＡＯＰ）でロギングを自動的に埋め込む
コードをいじらなくても、ＡＯＰでメソッドの最初と終りにログを埋め込める魔法のようなやり方だと思ってましたが、なかなか一筋縄にいかず、とりあえずできた方法を掲載します。このmvc-ajaxというサンプルでなく、単にAOPの実装を動かしてみたい場合は、ググればもっと簡単なやり方があるのでそちらを。。
まず、mvc-ajaxはデフォルトでアスペクト指向を使えないので、mavenへdependencyを追加してやります。
mvc-ajaxのプロジェクト右クリック → Maven → Add Dependencyを選択します。
aspectで検索かけると２件ヒットするので、２件とも追加します。
そして以下の３ファイルをorg.springframework.samples.mvc.ajax.accountへ追加します。
- IHoge.java・・・・・・Hogehoge.javaのインタフェース。ロギングしたいメソッドを記述します
- Hogehoge.java・・・・ロギングされるクラス。
- MethodLogger.java・・Hogehoge.javaへ埋め込むロギング処理
せっかくベースとなるAccoutController.javaがあるのでそちらへロギングを埋め込もうとしましたが、エラーが出て実装できないのでHogehoge.javaへロギングを埋め込み、AccountControllerから呼び出す形でログを出力したいと思います。
IHoge.java
package org.springframework.samples.mvc.ajax.account;
public interface IHoge {
public void testMethod();
}
Hogehoge.java
package org.springframework.samples.mvc.ajax.account;
public class Hogehoge implements IHoge{
public void testMethod() {
System.out.println("hello world!");
}
}
MethodLogger.java
package org.springframework.samples.mvc.ajax.account;
import org.apache.log4j.Logger;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;
@Component
@Aspect
public class MethodLogger {
@Around("execution(* org.springframework.samples.mvc.ajax.account.Hogehoge.*(..))")
public Object timeMethod(ProceedingJoinPoint joinPoint) throws Throwable {
StopWatch stopWatch = new StopWatch();
Logger.getLogger(this.getClass()).info("Method Start");
stopWatch.start();
Object retVal = joinPoint.proceed();
stopWatch.stop();
StringBuffer logMessageStringBuffer = new StringBuffer();
logMessageStringBuffer.append(joinPoint.getTarget().getClass().getName());
logMessageStringBuffer.append(".");
logMessageStringBuffer.append(joinPoint.getSignature().getName());
logMessageStringBuffer.append("(");
logMessageStringBuffer.append(joinPoint.getArgs());
logMessageStringBuffer.append(")");
logMessageStringBuffer.append(" execution time: ");
logMessageStringBuffer.append(stopWatch.getTotalTimeMillis());
logMessageStringBuffer.append(" ms");
logMessageStringBuffer.append(" end");
Logger.getLogger(this.getClass()).info(logMessageStringBuffer.toString());
return retVal;
}
}
この処理の、@Around("execution(* org.springframework.samples.mvc.ajax.account.Hogehoge.*(..))")でロギングを埋め込みたいメソッドを指定しています。今回はワイルドカードを使ってHogehogeクラス全てのメソッドへ適用するようにしています。で、処理開始と処理終了のロギングをObject retVal = joinPoint.proceed();の前後で行っている所がポイントです。この前後にLogger.getLogger(this.getClass()).info("Method Start");のようなメソッドの開始（または終了）だと分かる処理を記述してやります。
これらの処理をbeen定義ファイルで有効にするにはservlet-context.xmlを修正してやります。ちゃんと実装する場合には、このファイルではなく別途been定義ファイルを作成した方が良いような記述を見受けました。以下beansのタグ内とaopタグbeanタグを追加します。
<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:context="http://www.springframework.org/schema/context"
xmlns:mvc="http://www.springframework.org/schema/mvc"
xmlns:aop="http://www.springframework.org/schema/aop"
xsi:schemaLocation="http://www.springframework.org/schema/mvc http://www.springframework.org/schema/mvc/spring-mvc-3.0.xsd
http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.0.xsd
http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.0.xsd">
（中略）
<aop:aspectj-autoproxy />
<bean class="org.springframework.samples.mvc.ajax.account.Hogehoge" />
</beans>
で最後にAccountControllerからメソッド呼び出しの処理を追加します。今回はGetリクエスト処理内へ追加しました。
public class AccountController {
private static Logger logger = Logger.getLogger(AccountController.class);
private Map<Long, Account> accounts = new ConcurrentHashMap<Long, Account>();
private Validator validator;
@Autowired
private IHoge hoge;
@Autowired
public AccountController(Validator validator) {
logger.info("create instance AccountController");
this.validator = validator;
}
@RequestMapping(method=RequestMethod.GET)
public String getCreateForm(Model model) {
logger.info("GET Request AccountController");
this.hoge.testMethod();
model.addAttribute(new Account());
return "account/createForm";
}private IHoge hogeを定義し、このインタフェースへロギング対象ということで@Autowiredを記述。Getリクエストを受けてthis.hoge.testMethod()のメソッドを呼び出しすよう修正しました。
これでサーバを起動し、
クリックすると、メソッド呼び出しで以下のようにログが出力されます。
2012-01-07 04:48:40 INFO : org.springframework.samples.mvc.ajax.account.MethodLogger - Method Start
hello world!
2012-01-07 04:48:40 INFO : org.springframework.samples.mvc.ajax.account.MethodLogger - org.springframework.samples.mvc.ajax.account.Hogehoge.testMethod([Ljava.lang.Object;@4f13f501) execution time: 0 ms end
太字の部分が埋め込まれたロギング出力です。
AccountControllerクラスでHogehogeクラスをnewしてインスタンスを生成した場合だとロギングは埋め込まれません。必ずインタフェースからメソッドを呼び出す必要があります。これがSpring Frameworkの思想との事ですが、自由にロギングを追加／削除できるイメージでしたが、このやり方だとある程度最初からＡＯＰを意識した実装にしておかないといけないですね。。(´ﾍ｀；)
コメント
コメントを投稿