p6spy手順メモとカスタマイズ

JDBCドライバをラップしてSQLログを出力するP6SpyというOSSを試してみました。

作業手順

以下ダウンロードしてspy-install.jarを展開する。 http://sourceforge.net/projects/p6spy/
p6spy.jarとspy.propertiesをクラスパスに置く
spy.propertiesを編集。デフォルトから以下を変更する。



realdriver=org.apache.derby.jdbc.ClientDriver ←P6spyがラップする実体のドライバを指定

appender=com.p6spy.engine.logging.appender.Log4jLogger

dateformat=MM-dd-yy HH:mm:ss:SS

Log4Jの定義はlog4j.xmlに集約



<?xml version="1.0" encoding="Windows-31J" ?>

<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="">http://jakarta.apache.org/log4j/">

    <appender name="stdout" class="org.apache.log4j.ConsoleAppender">

        <layout class="org.apache.log4j.PatternLayout">

            <param name="ConversionPattern" value="%t %5p %d{HH:mm:ss:SSS} %c (%L) %m%n"/>

        </layout>

    </appender>

    <logger name="p6spy">

        <level value="DEBUG"/>

        <appender-ref ref="stdout"/>

    </logger>

    <logger name="sample">

        <level value="DEBUG"/>

        <appender-ref ref="stdout"/>

    </logger>

</log4j:configuration>

iBATISが使用するsqlMapConfig.xmlにP6Spyのドライバを指定



   <dataSource type="POOLED">

    <property name="driver" value="com.p6spy.engine.spy.P6SpyDriver"/>

    <property name="url" value="jdbc:derby://localhost:1527/sampledb"/>

    <property name="username" value="admin"/>

    <property name="password" value="admin"/>

   </dataSource>

ログはこんなふうに出力されます。



main  INFO 16:35:57:800 p6spy (95) 1297409757799|3|0|rollback||

main  INFO 16:35:57:962 p6spy (95) 1297409757962|3|0|statement|insert into

   ACCOUNT

  (

   account_id,

   customer_no,

   email_address,

   password,

   status

  ) VALUES (

   ?,

   ?,

   ?,

   ?,

   ?

  )|insert into

   ACCOUNT

  (

   account_id,

   customer_no,

   email_address,

   password,

   status

  ) VALUES (

   1,

   961,

   'DCQTHZPWQJ',

   'PMNXYVTQQF',

   571

  )

main  INFO 16:35:58:008 p6spy (95) 1297409758008|36|0|statement|select * from ACCOUNT where account_id = ?|select

 * from ACCOUNT where account_id = 1

main  INFO 16:35:58:046 p6spy (95) 1297409758046|-1||resultset|select * from ACCOUNT where account_id = 1|ACCOUNT_

ID = 1, CUSTOMER_NO = 961, EMAIL_ADDRESS = DCQTHZPWQJ, PASSWORD = PMNXYVTQQF, STATUS = 571, account_id = 1, custo

mer_no = 961, email_address = DCQTHZPWQJ, password = PMNXYVTQQF, status = 571

main  INFO 16:35:58:139 p6spy (95) 1297409758139|1|0|statement|update ACCOUNT

    SET customer_no=?,

    email_address=?,

    password=?,

    status=? 

   where account_id = ?|update ACCOUNT

    SET customer_no=1,

    email_address='ADRIZOBOFM',

    password='USVJLXEYIZ',

    status=1 

   where account_id = 1

main  INFO 16:35:58:151 p6spy (95) 1297409758151|1|0|statement|delete from Account where account_id = ?|delete from

 Account where account_id = 1

main  INFO 16:35:58:155 p6spy (95) 1297409758155|1|0|commit||

しかしログの出力フォーマットが常に

current time|execution time|category|statement SQL String|effective SQL string

に固定されるのがいまいちです。主な不満。

現在時刻の定義とかはLog4Jとかぶる。
PreparedStatementと実行時SQLが常にペアで出力される
区切り文字が|なのが分かりづらい。つかログ文言カスタマイズさせれ。
ResultSetが毎回出るのウゼェ。つかexcludecategories指定しても効いてなくね？

そう思ってソースみたところ、最終的にログのフォーマットを決めているのはcom.p6spy.engine.logging.appender.Log4jLoggerだったので、これをカスタマイズしてspy.propertiesの指定で挿し込めば自分好みにできそうです。ということで簡単なの作ってみた。



package jp.gr.java_conf.minokuba.p6spy.engine.logging.appender;
import java.util.ArrayList;

import java.util.List;

import java.util.Properties;
import com.p6spy.engine.common.P6SpyProperties;

import com.p6spy.engine.logging.appender.Log4jLogger;
/**

 * @author minokuba

 */

public class CustomizedLog4jLogger extends Log4jLogger{
    private boolean  initialized = false;
    private List categories = new ArrayList();

    private boolean preparedEnabled = false;

    private boolean sqlEnabled = true;

    private String format = "%ct %c: %e[ms] %s";
    public void intialize(){

        if(!initialized){

            doInitialize();

        }

    }
    protected void doInitialize(){

        P6SpyProperties p6SpyProperties = new P6SpyProperties();

        Properties properties = p6SpyProperties.forceReadProperties();
        String enableCategory = properties.getProperty("CustomizedLog4jLogger.enable.category");

        String enableSqlLevel = properties.getProperty("CustomizedLog4jLogger.enable.sql.level");

        String format = properties.getProperty("CustomizedLog4jLogger.format");
        if(!isNullString(enableCategory)){

            for (String category : enableCategory.trim().split(",")) {

                this.categories.add(category.trim());

            }

        }else{

            categories.add("statement");

            categories.add("resultset");

            categories.add("commit");

            categories.add("rollback");

        }
        if(!isNullString(enableSqlLevel)){

            enableSqlLevel = enableSqlLevel.trim();

            if(enableSqlLevel.equals("all")){

                this.preparedEnabled = true;

                this.sqlEnabled = true;

            }else if(enableSqlLevel.equals("prepare")){

                this.preparedEnabled = true;

                this.sqlEnabled = false;

            }else{

                this.preparedEnabled = false;

                this.sqlEnabled = true;

            }

        }
        if(!isNullString(format)){

            this.format = format;

        }

        initialized = true;

    }
    private boolean isNullString(String string){

        return string == null || string.trim().length() == 0;

    }
    /**

     * ログメッセージのフォーマットを行う（適当

     */

    private String replace(int connectionId, String now, long elapsed, String category, String statement){

        return

            this.format.

                replace("%ct", String.valueOf(category)).

                replace("%c", String.valueOf(connectionId)).

                replace("%e", String.valueOf(elapsed)).

                replace("%n", now).

                replace("%s",statement);

    }
    /* (非 Javadoc)

     */

    public void logSQL(int connectionId, String now, long elapsed, String category, String prepared, String sql) {

        intialize();

        if(categories.contains(category)){

            if(preparedEnabled){

                logText(replace(connectionId,now,elapsed,category,prepared));

            }

            if(sqlEnabled){

                logText(replace(connectionId,now,elapsed,category,sql));

            }

        }

    }

}

使い方はこんなふうにspy.propertiesに定義。



appender=jp.gr.java_conf.minokuba.p6spy.engine.logging.appender.CustomizedLog4jLogger

#出力するカテゴリを複数指定

CustomizedLog4jLogger.enable.category=statement,commit,rollback

#prepareStatmementを出すかどうか。allは全部出す

CustomizedLog4jLogger.enable.sql=sql

#ログフォーマット

CustomizedLog4jLogger.format=[%ct] %c: %e[ms] %s

この設定だとこんな感じにカスタマイズできました。



main  INFO 19:31:22:940 p6spy (95) [statement] 0: 3[ms] insert into

   ACCOUNT

  (

   account_id,

   customer_no,

   email_address,

   password,

   status

  ) VALUES (

   1,

   281,

   'KGAUCILSTE',

   'HAVTPSLQZA',

   793

  )

main  INFO 19:31:22:987 p6spy (95) [statement] 0: 33[ms] select * from ACCOUNT where account_id = 1

main  INFO 19:31:23:132 p6spy (95) [statement] 0: 1[ms] update ACCOUNT

    SET customer_no=1,

    email_address='MPCOAWFGPC',

    password='QHBPHLQYEA',

    status=1 

   where account_id = 1

main  INFO 19:31:23:144 p6spy (95) [statement] 0: 0[ms] delete from Account where account_id = 1

main  INFO 19:31:23:152 p6spy (95) [commit] 0: 4[ms]

ちなみにカテゴリを絞り込むロジック埋め込んだのは、P6spyに不具合があってspy.propertiesに定義したexcludecategoriesを読み込まないからです（ひでぇ…。本当は文字列生成処理もカットしたいから根本解決したほうがいいね）。カテゴリにresultsetを出すと検索結果を表示できるのは便利といえば便利。あとソースコードはzipダウンロードできないのでsvnから落としてくる必要ありますね。