読者です 読者をやめる 読者になる 読者になる

Challenge Java EE !

Java EEを中心に趣味や仕事における開発メモを書いています。

EclipseLinkのログ出力でギブアップしたこと…

ロギング EclipseLink JPA EJB

なんか初めて諦めてしまったことな気がします…(-_-;

EclipseLinkのログ出力でやりたかったこと

去年のエントリ「EclipseLinkのログをSLF4J&Logbackにて出力したい」で、JPQLのクエリからEclipseLinkで生成された実クエリをログ出力できることを確認しました。

これ以降の作業を棚上げしていたのですが、実際にやりたいこととしては以下のようなログ出力を出力することでした。


2013-01-29 17:11:29.296,INFO,search,kikutaro777,**画面のID**,10.xx.xx.xx,商談検索を実行
2013-01-29 17:11:30.174,DEBUG,logic,kikutaro777,**画面のID**,10.xx.xx.xx,実行検索クエリ -> 'SELECT t0.OPPORTUNITYNAME, ...
bind => [kikutaro777] '

画面ログと内部ロジックのログは分けるとか、そういうレベルの議論もありますが…。

ログ自体はSLF4JとLogbackの組合せで使っていて、EclipseLinkでそのログに上記のようなフォーマットで出したいというものです。

ASP.NETだと多分簡単に上記のようなログを出せるのですが、Java EEだとちょっと悩んでしまったり…。

結論から書くと、ちょっと時間的にもギブアップをして(一応、色々調べてみたのですが…)、クエリ部分は以下のようなログとなりそうです。


2013-01-29 17:11:29.296,INFO,search,kikutaro777,**画面のID**,10.xx.xx.xx,商談検索を実行
2013-01-29 17:11:30.174,DEBUG,,,,,実行検索クエリ -> 'SELECT t0.OPPORTUNITYNAME, ...
bind => [kikutaro777] '

要はビューサイド、Beanサイドから得る情報は出さない、というノリ…。
まあ、クエリまでログ出すのは、基本的に障害分析とか性能分析のためなので…。

なんだか自分のコーディング力がない気がプンプンしますが、とりあえず、やってみたことだけまとめます。

イメージ

すさまじくざっくりしたショボンな絵ですが…自分はこんな感じでJava EE6内部のイメージをしています。

f:id:kikutaro777:20130129194531p:plain

例えば「商談情報を検索する」みたいなもので、画面で検索ボタン押して、その画面のBackingBeanがEJBのDB検索処理ロジックを呼び出して…みたいな。EJBはステートレスセッションなのでプール上にインスタンスがいて…みたいな。

試した実装

SLF4J経由のLogbackでロギングしてますが、Logbackは以下のような感じで設定しています。

logback.xml
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <File>/CpqPrototypeLog/logFile.log</File>
        
    <!-- logファイルを区切る設定 -->
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        ...
    </rollingPolicy>
        
    <!-- 出力内容設定 -->
    <encoder>
        <charset>UTF-8</charset>
        <!-- 日付,出力レベル,処理区分,ログイン者ID,画面ID,クライアントIP,内容 -->
        <Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS},%-5level,%marker,%X{LOGIN_USER_ID},%X{SCREEN_ID},%X{CLIENT_IP_ADDR},%msg %n</Pattern>
    </encoder>
</appender>

で、EclipseLinkのドキュメントを色々みていくと、CustomLoggerを使って出すのが良い…のかなと(^^;

EclipseLinkのCustomLoggerドキュメント

上記ドキュメントを参考に色々試していたのですが、頭がこんがらがったのでクラス図書きました。

f:id:kikutaro777:20130129194925p:plain

Custom Logger

ほぼサンプルイコールですが、以下のような感じで。Logクラスは内部でSLF4Jでロギングする処理を持つクラスです。
本当はここで、ログイン者情報とか画面IDとかをBackingBeanから取る、あるいはその逆などをしたいのですが、なんともかんとも。

package jp.co.hoge.hogehoge.log;

import org.eclipse.persistence.logging.AbstractSessionLog;
import org.eclipse.persistence.logging.SessionLog;
import org.eclipse.persistence.logging.SessionLogEntry;

public class CustomSessionLog extends AbstractSessionLog implements SessionLog{
    
    //private static Logger logger = LoggerFactory.getLogger("jp.co.hoge.hogehoge.log.CustomSessionLog");
    
    @Override
    public void log(SessionLogEntry sle) {
        Log.info("ログメッセージ:" + sle.getMessage());
    }
}
SessionCustomizerとかSessionEventAdapterとか

SessionCustomizerが入ると以下のような形になるっぽいです。
f:id:kikutaro777:20130129195030p:plain
Adapterとかも触ってみて、なんかできないかなと模索したり。。。

package jp.co.hoge.hogehoge.log;

import org.eclipse.persistence.config.SessionCustomizer;
import org.eclipse.persistence.logging.SessionLog;
import org.eclipse.persistence.sessions.Session;

public class CustomSessionCustomizer implements SessionCustomizer{

    @Override
    public void customize(Session sn) throws Exception {
        SessionLog customLogger = new CustomSessionLog();
        sn.setSessionLog(customLogger);

        sn.getEventManager().addListener(new LogSessionEventAdapter());
    }
}
package jp.co.hoge.hogehoge.log;

import org.eclipse.persistence.sessions.Session;
import org.eclipse.persistence.sessions.SessionEvent;
import org.eclipse.persistence.sessions.SessionEventAdapter;

public class LogSessionEventAdapter extends SessionEventAdapter{
    
    @Override
    public void preExecuteQuery(SessionEvent event) {
        System.out.println("クエリ実行の前に走るイベントです");
    }
}

なんというか、何をしてもBackingBeanと縁が遠すぎてどうしたものかと。
たとえばASP.NETだと、上図のような境界が明確にはないため、なんでもかんでもできるのですが、Java EEって境界がしっかり分かれていて、CDIで注入は簡単ですが、上記のような既存ログの仕組みにどうやってログイン者情報のインスタンスとか伝播(あるいは逆から取得)させていくんだろ…とか悩んでしまったり。

ちなみに

persistence.xmlにあるproperty属性でeclipselink.logging.parametersがあるよという情報を頂き、調べたのですが、これはJPQLのバインド変数を出力するスイッチで使う、と理解しました。あってる…かな(^^;

たぶん

なんか自分の理解がおかしかったり、EclipseLink内のSession辺りがちゃんと理解できていないのが間違いなく今回の問題・原因なんですが、これ以上時間をかけるのは厳しいため諦めました(-_-;
今までで一番悩んだかもしれません。

EclipseLinkのログ周辺情報はすごく少ない感じを受けて、ちょっと不安にもなったり…。
がんばろー。

追記
記事の投稿後、interceptorでloggerを実装して、リフレクションでbeanの情報を取得して…って流れでどうでしょう、とコメント頂きました。またトライして結果が出たら追加、あるいは別記事にしたいと思います(^^)コメントありがとございました!

にほんブログ村 IT技術ブログへ
にほんブログ村
にほんブログ村 IT技術ブログ Javaへ
にほんブログ村