Resinの機能を利用してSQLログを出力する

このCookBookでは、Resinの設定変更のみでSQLログを出力する方法について説明します。

SQLログを出力すると、以下の情報が確認できます。

  • コネクションプール開始
  • データベースへの接続
  • 発行されたSQL
  • バインド変数
  • トランザクションの開始/終了

設定方法

  1. resin-web.xmlのデータベース接続設定に対して spy タグを追記します。
      <database jndi-name=“jdbc/default">
        <driver>
          <type>org.postgresql.ds.PGConnectionPoolDataSource</type>
          <url>jdbc:postgresql://localhost:5432/iap833</url>
          <user>imart</user>
          <password>imart</password>
          ・・・
        </driver>
        <spy>true</spy> <!-- 追記 --> 
        ・・・・
      </database>
  1. Resinのresin.xmlにLogger設定を追記します。

    【注意】 SQLログは、大量に出力されるため、SQLログ用のログファイルに出力するようにしています。

      <!-- DBログはたくさん出力されるため、別のログファイルに出力 --> 
      <log-handler name="com.caucho.sql" level="all" path="log/db.log"
                     timestamp="[%y-%m-%d %H:%M:%S.%s]"
                     format="   {${thread}} ${log.level}    ${log.name} ${log.message}"/>

      <!-- DBロガー設定(log/db.log のみに出力するようにしておく)-->
      <logger name="com.caucho.sql" level="fine" use-parent-handlers="false"/>


ログ出力イメージ

SQLログを出力する設定を行うと、log/db.logに以下のようなログが出力されます。

// コネクションプール開始
{main} CONFIG com.caucho.sql.DriverConfig   loading driver: org.postgresql.ds.PGConnectionPoolDataSource
{main} CONFIG com.caucho.sql.DBPoolImpl database java:comp/env/jdbc/default starting (URL:jdbc:postgresql://localhost:5432/iap833)
{main} CONFIG com.caucho.sql.DriverConfig   loading driver: org.postgresql.ds.PGConnectionPoolDataSource
{main} CONFIG com.caucho.sql.DBPoolImpl database java:comp/env/jdbc/default2 starting (URL:jdbc:postgresql://localhost:5432/iap833_1)

// データベースへの接続
{resin-57} FINE com.caucho.sql.spy.SpyConnectionPoolDataSource [106ms] jdbc/default.d0:getPooledConnection(imart) -> jdbc/default.d0.0:org.postgresql.ds.PGPooledConnection@79ec0420
{pool-1-thread-1} FINE com.caucho.sql.spy.SpyConnectionPoolDataSource   [37ms] jdbc/default.d0:getPooledConnection(imart) -> jdbc/default.d0.1:org.postgresql.ds.PGPooledConnection@3b0d5fbf

// SQL発行(トランザクションなし)
{resin-57} FINE com.caucho.sql.spy.SpyConnection    jdbc/default.d0.0.1:prepareStatement(SELECT * FROM im_schema_update WHERE module_id = ? AND import_type LIKE ?)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.1:setString(1,itext)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.1:setString(2,SYSTEM%)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [3ms] jdbc/default.d0.0.1:executeQuery(SELECT * FROM im_schema_update WHERE module_id = ? AND import_type LIKE ?)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.1:clearParameters()
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.1:stmt-close()
{resin-57} FINE com.caucho.sql.spy.SpyConnection    jdbc/default.d0.0:clearWarnings()

// SQL発行(トランザクションあり)
{resin-57} FINE com.caucho.sql.spy.SpyConnection.XA jdbc/default.d0.0:setAutoCommit(false)
{resin-57} FINE com.caucho.sql.spy.SpyConnection    jdbc/default.d0.0.305:prepareStatement(SELECT tenant_id FROM im_tenant_info WHERE tenant_id = ?)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.305:setString(1,default2)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.305:executeQuery(SELECT tenant_id FROM im_tenant_info WHERE tenant_id = ?)
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.305:clearParameters()
{resin-57} FINE com.caucho.sql.spy.SpyStatement [0ms] jdbc/default.d0.0.305:stmt-close()
{resin-57} FINE com.caucho.sql.spy.SpyConnection.XA [0ms] jdbc/default.d0.0:commit()
{resin-57} FINE com.caucho.sql.spy.SpyConnection.XA jdbc/default.d0.0:setAutoCommit(true)
{resin-57} FINE com.caucho.sql.spy.SpyConnection    jdbc/default.d0.0:clearWarnings()

【ログの補足】
jdbc/default.d0.0.1 の意味

JNDI名.ドライバ番号.コネクション番号.ステートメント番号