2012年5月2日水曜日

seasar2 AOP

seasar2を使った、簡単なAOPのサンプルです。
seasar2に用意されているorg.seasar.framework.aop.interceptors.TraceInterceptorをアドバイス(インターセプタ)としてそのまま利用しています。
org.seasar.framework.aop.interceptors.TraceInterceptorは、ポイントカットとなるメソッドの前後にメソッド名や引数、戻り値をコンソールに出力してくれるアドバイス(インターセプタ)です。

今回のサンプルでは、log4jは使用していません。
log4jのjarは、クラスパスに置いていないので、 自動でjava.util.logging.Loggerが使用されます。

org.seasar.framework.aop.interceptors.TraceInterceptorはデバッグレベルでログを出力します。
java.util.logging.LoggerのログレベルはFINEにしておいてください。
参考URL:http://www.alles.or.jp/~torutk/oojava/maneuver/2001/logging/logging.html

(1)パッケージ構成




(2)ソース
Driver.java package org.yama.study.aop.pk1;

import org.seasar.framework.container.S2Container;
import org.seasar.framework.container.factory.SingletonS2ContainerFactory;

public class Driver {
    public static void main(String[] args) {
        SingletonS2ContainerFactory.init();
        S2Container container = SingletonS2ContainerFactory.getContainer();
        ClassAImpl ca = (ClassAImpl) container.getComponent("classA");
        ca.methodA();
        ca.methodB();
    }
}

ClassAImpl.java package org.yama.study.aop.pk1;

public class ClassAImpl {
    public void methodA() {
        System.out.println("Hello Aop from methodA!");
    }
    public void methodB() {
        System.out.println("Hello Aop from methodB!");
    }
}

app.dicon <?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE components PUBLIC "-//SEASAR//DTD S2Container 2.4//EN"
"http://www.seasar.org/dtd/components24.dtd">
<components>
    <component name="traceInterceptor"
     class="org.seasar.framework.aop.interceptors.TraceInterceptor" />

    <component name="classA" class="org.yama.study.aop.pk1.ClassAImpl">
      <aspect>traceInterceptor</aspect>
    </component>
</components>

main()を実行すると以下の実行結果が得られます。
実行結果 (以下の出力以外に、seasar2本体のログが出力される場合もありますがテーマに関係ないので削除しました。)

普通: BEGIN org.yama.study.aop.pk1.ClassAImpl#methodA()
Hello Aop from methodA!
5 02, 2012 3:11:35 午後 org.seasar.framework.log.Logger debug
普通: END org.yama.study.aop.pk1.ClassAImpl#methodA() : null
5 02, 2012 3:11:35 午後 org.seasar.framework.log.Logger debug
普通: BEGIN org.yama.study.aop.pk1.ClassAImpl#methodB()
Hello Aop from methodB!
5 02, 2012 3:11:35 午後 org.seasar.framework.log.Logger debug
普通: END org.yama.study.aop.pk1.ClassAImpl#methodB() : null

メソッドの前後にログが出力されています。

続いてapp.diconを以下のように変更してみます。
app.dicon(修正後) <?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE components PUBLIC "-//SEASAR//DTD S2Container 2.4//EN"
"http://www.seasar.org/dtd/components24.dtd">
<components>
    <component name="traceInterceptor"
     class="org.seasar.framework.aop.interceptors.TraceInterceptor" />

    <component name="classA" class="org.yama.study.aop.pk1.ClassAImpl">
    <aspect pointcut="methodA">traceInterceptor</aspect>
    </component>
</components>

「<aspect pointcut="methodA">traceInterceptor</aspect>」の部分を修正しています。

すると、methodAの前後にだけアドバイスが織り込まれている(ウィービングされている)ことがわかります。

実行結果 (以下の出力以外に、seasar2本体のログが出力される場合もありますがテーマに関係ないので削除しました。)

5 02, 2012 3:42:14 午後 org.seasar.framework.log.Logger debug
普通: BEGIN org.yama.study.aop.pk1.ClassAImpl#methodA()
Hello Aop from methodA!
5 02, 2012 3:42:14 午後 org.seasar.framework.log.Logger debug
普通: END org.yama.study.aop.pk1.ClassAImpl#methodA() : null
Hello Aop from methodB!


Java Logging API ハマリポイント

Java Logging APIを使用して、はまった箇所の備忘録

Java Logging APIの基本的な使い方は、他のページを参照
http://www.alles.or.jp/~torutk/oojava/maneuver/2001/logging/logging.html
http://struts.wasureppoi.com/util/04_javalog.html


ロギングの簡単な操作を覚えるために簡単なサンプルを作成した。
Driver.java package org.yama.study;

import java.util.logging.Logger;

public class Driver {
    private final Logger logger = Logger
            .getLogger("driver");

    public static void main(String[] args) {
        Driver dv = new Driver();
        dv.prccess();
    }

    private void prccess() {
        logger.finest("finest");
        logger.fine("fine");
        logger.config("config");
        logger.info("info");
        logger.warning("warning");
        logger.severe("severe");
    }
}

設定ファイル※1の内容(デフォルトのままいじらず)
logging.properties ############################################################
#   Default Logging Configuration File
#
# You can use a different file by specifying a filename
# with the java.util.logging.config.file system property.
# For example java -Djava.util.logging.config.file=myfile
############################################################

############################################################
#   Global properties
############################################################

# "handlers" specifies a comma separated list of log Handler
# classes.  These handlers will be installed during VM startup.
# Note that these classes must be on the system classpath.
# By default we only configure a ConsoleHandler, which will only
# show messages at the INFO and above levels.
handlers= java.util.logging.ConsoleHandler

# To also add the FileHandler, use the following line instead.
#handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler

# Default global logging level.
# This specifies which kinds of events are logged across
# all loggers.  For any given facility this global level
# can be overriden by a facility specific level
# Note that the ConsoleHandler also has a separate level
# setting to limit messages printed to the console.
.level= INFO

############################################################
# Handler specific properties.
# Describes specific configuration info for Handlers.
############################################################

# default file output is in user's home directory.
java.util.logging.FileHandler.pattern = %h/java%u.log
java.util.logging.FileHandler.limit = 50000
java.util.logging.FileHandler.count = 1
java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter

# Limit the message that are printed on the console to INFO and above.
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

# Example to customize the SimpleFormatter output format
# to print one-line log message like this:
#     <level>: <log message> [<date/time>]
#
# java.util.logging.SimpleFormatter.format=%4$s: %5$s [%1$tc]%n

############################################################
# Facility specific properties.
# Provides extra control for each logger.
############################################################

# For example, set the com.xyz.foo logger to only log SEVERE
# messages:
com.xyz.foo.level = SEVERE


出力結果
出力結果 5 02, 2012 12:24:51 午後 org.yama.study.Driver prccess
情報: info
5 02, 2012 12:24:51 午後 org.yama.study.Driver prccess
警告: warning
5 02, 2012 12:24:51 午後 org.yama.study.Driver prccess
重大: severe

さて、ログレベルを変えてやってみるかと、設定ファイルを変更した。
logging.properties(抜粋) #java.util.logging.ConsoleHandler.level = INFO コメントアウト
java.util.logging.ConsoleHandler.level = FINEST

が、これでは、出力結果が変わらない!?


調査した結果、こっち↓も変えないといけなかった。
logging.properties(抜粋) #.level= INFO コメントアウト
.level= FINEST

無事に出力できました。
出力結果 5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess最も詳細: finest5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess普通: fine5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess構成: config5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess情報: info5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess警告: warning5 02, 2012 12:31:17 午後 org.yama.study.Driver prccess重大: severe

結局、グローバルログレベルでログ出力を制限し、さらにコンソールハンドラレベルでそれ以上に絞りたいのであれば絞ることができる。
したがって、コンソールハンドラレベルにおいて、グローバルログレベル以上のログを出力しようとしても無理なことが判明した。
(設定ファイル※1のコメントに「グローバルログレベルのほかに、コンソールハンドラでもレベルを設定できるから注意しろよ!」と英語で書いてあった。)


※1 JDKインストールディレクトリ以下の「~\lib\logging.properties」もしくは、JREインストールディレクトリ以下の「~\lib\logging.properties」。
このファイルは、すべてのアプリに対して影響するので、普通は編集しません。正しくは、アプリ固有の設定ファイルを準備し、そのファイルを参照しにいくようVMの起動パラメータを指定する必要があります。