7.1.1.2.2. SQLログの出力

SQLログは、パフォーマンスチューニングに使用するために、SQL文の実行時間やSQL文を出力する。 アプリケーションでは、ログ出力の設定を行うことにより出力する。

7.1.1.2.2.1. SQLログの出力方針

SQLログは、ログのサイズが大きくなりディスクフルになったり、パフォーマンスに影響を与える可能性がある。 そのため、SQLログは開発時の使用を想定し、DEBUGレベル以下で出力する。

SQLログの出力方針
ログレベル ロガー名 出力内容
DEBUG SQL SQL文、実行時間、件数(検索件数や更新件数など)、トランザクションの処理結果(コミット又はロールバック)
TRACE SQL SQLパラメータ(バインド変数の値)

上記出力方針に対するログ出力の設定例を下記に示す。

log.propertiesの設定例
writerNames=appLog

# アプリケーションログの出力先
writer.appLog.className=nablarch.core.log.basic.FileLogWriter
writer.appLog.filePath=/var/log/app/app.log
writer.appLog.encoding=UTF-8
writer.appLog.maxFileSize=10000
writer.appLog.formatter.className=nablarch.core.log.basic.BasicLogFormatter
writer.appLog.formatter.format=$date$ -$logLevel$- $runtimeLoggerName$ [$executionId$] boot_proc = [$bootProcess$] proc_sys = [$processingSystem$] req_id = [$requestId$] usr_id = [$userId$] $message$$information$$stackTrace$

availableLoggersNamesOrder=SQL,ROO

# アプリケーションログの設定
loggers.ROO.nameRegex=.*
loggers.ROO.level=INFO
loggers.ROO.writerNames=appLog

# SQLログの設定
loggers.SQL.nameRegex=SQL
loggers.SQL.level=TRACE
loggers.SQL.writerNames=appLog
app-log.propertiesの設定例
# SqlLogFormatter
#sqlLogFormatter.className=
# SqlPStatement#retrieveのフォーマット
sqlLogFormatter.startRetrieveFormat=$methodName$\
                                      \n\tSQL = [$sql$]\
                                      \n\tstart_position = [$startPosition$] size = [$size$]\
                                      \n\tquery_timeout = [$queryTimeout$] fetch_size = [$fetchSize$]\
                                      \n\tadditional_info:\
                                      \n\t$additionalInfo$
sqlLogFormatter.endRetrieveFormat=$methodName$\
                                    \n\texecute_time(ms) = [$executeTime$] retrieve_time(ms) = [$retrieveTime$] count = [$count$]
# SqlPStatement#executeのフォーマット
sqlLogFormatter.startExecuteFormat=$methodName$\
                                      \n\tSQL = [$sql$]\
                                      \n\tadditional_info:\
                                      \n\t$additionalInfo$
sqlLogFormatter.endExecuteFormat=$methodName$\
                                    \n\texecute_time(ms) = [$executeTime$]
# SqlPStatement#executeQueryのフォーマット
sqlLogFormatter.startExecuteQueryFormat=$methodName$\
                                          \n\tSQL = [$sql$]\
                                          \n\tadditional_info:\
                                          \n\t$additionalInfo$
sqlLogFormatter.endExecuteQueryFormat=$methodName$\
                                        \n\texecute_time(ms) = [$executeTime$]
# SqlPStatement#executeUpdateのフォーマット
sqlLogFormatter.startExecuteUpdateFormat=$methodName$\
                                            \n\tSQL = [$sql$]\
                                            \n\tadditional_info:\
                                            \n\t$additionalInfo$
sqlLogFormatter.endExecuteUpdateFormat=$methodName$\
                                        \n\texecute_time(ms) = [$executeTime$] update_count = [$updateCount$]
# SqlStatement#executeBatchのフォーマット
sqlLogFormatter.startExecuteBatchFormat=$methodName$\
                                          \n\tSQL = [$sql$]\
                                          \n\tadditional_info:\
                                          \n\t$additionalInfo$
sqlLogFormatter.endExecuteBatchFormat=$methodName$\
                                        \n\texecute_time(ms) = [$executeTime$] batch_count = [$updateCount$]

7.1.1.2.2.2. 使用方法

7.1.1.2.2.2.1. SQLログの設定を行う

SQLログの設定は、 各種ログの設定を行う で説明したプロパティファイルに行う。

記述ルール

sqlLogFormatter.className
SqlLogFormatter を実装したクラス。 差し替える場合に指定する。
sqlLogFormatter.startRetrieveFormat

SqlPStatement#retrieve の開始時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
SQL文:$sql$
取得開始位置:$startPosition$
取得最大件数:$size$
タイムアウト時間:$queryTimeout$
フェッチする行数:$fetchSize$
付加情報:$additionalInfo$
デフォルトのフォーマット
$methodName$
    \n\tSQL = [$sql$]
    \n\tstart_position = [$startPosition$] size = [$size$]
    \n\tquery_timeout = [$queryTimeout$] fetch_size = [$fetchSize$]
    \n\tadditional_info:
    \n\t$additionalInfo$
sqlLogFormatter.endRetrieveFormat

SqlPStatement#retrieve の終了時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
実行時間:$executeTime$
データ取得時間:$retrieveTime$
検索件数:$count$
デフォルトのフォーマット
$methodName$
    \n\texecute_time(ms) = [$executeTime$] retrieve_time(ms) = [$retrieveTime$] count = [$count$]
sqlLogFormatter.startExecuteFormat

SqlPStatement#execute の開始時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
SQL文:$sql$
付加情報:$additionalInfo$
デフォルトのフォーマット
$methodName$
    \n\tSQL = [$sql$]
    \n\tadditional_info:
    \n\t$additionalInfo$
sqlLogFormatter.endExecuteFormat

SqlPStatement#execute の終了時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
実行時間:$executeTime$
デフォルトのフォーマット
$methodName$
    \n\texecute_time(ms) = [$executeTime$]
sqlLogFormatter.startExecuteQueryFormat

SqlPStatement#executeQuery の開始時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
SQL文:$sql$
付加情報:$additionalInfo$
デフォルトのフォーマット
$methodName$
    \n\tSQL = [$sql$]
    \n\tadditional_info:
    \n\t$additionalInfo$
sqlLogFormatter.endExecuteQueryFormat

SqlPStatement#executeQuery の終了時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
実行時間:$executeTime$
デフォルトのフォーマット
$methodName$
    \n\texecute_time(ms) = [$executeTime$]
sqlLogFormatter.startExecuteUpdateFormat

SqlPStatement#executeUpdate の開始時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
SQL文:$sql$
付加情報:$additionalInfo$
デフォルトのフォーマット
$methodName$
    \n\tSQL = [$sql$]
    \n\tadditional_info:
    \n\t$additionalInfo$
sqlLogFormatter.endExecuteUpdateFormat

SqlPStatement#executeUpdate の終了時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
実行時間:$executeTime$
更新件数:$updateCount$
デフォルトのフォーマット
$methodName$
    \n\texecute_time(ms) = [$executeTime$] update_count = [$updateCount$]
sqlLogFormatter.startExecuteBatchFormat

SqlStatement#executeBatch の開始時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
SQL文:$sql$
付加情報:$additionalInfo$
デフォルトのフォーマット
$methodName$
    \n\tSQL = [$sql$]
    \n\tadditional_info:
    \n\t$additionalInfo$
sqlLogFormatter.endExecuteBatchFormat

SqlStatement#executeBatch の終了時に使用するフォーマット。

フォーマットに指定可能なプレースホルダ
メソッド名:$methodName$
実行時間:$executeTime$
バッチ件数:$batchCount$
デフォルトのフォーマット
$methodName$
    \n\texecute_time(ms) = [$executeTime$] batch_count = [$updateCount$]
記述例
sqlLogFormatter.className=nablarch.core.db.statement.SqlLogFormatter
sqlLogFormatter.startRetrieveFormat=$methodName$\n\tSQL:$sql$\n\tstart:$startPosition$ size:$size$\n\tadditional_info:\n\t$additionalInfo$
sqlLogFormatter.endRetrieveFormat=$methodName$\n\texe:$executeTime$ms ret:$retrieveTime$ms count:$count$
sqlLogFormatter.startExecuteFormat=$methodName$\n\tSQL:$sql$\n\tadditional_info:\n\t$additionalInfo$
sqlLogFormatter.endExecuteFormat=$methodName$\n\texe:$executeTime$ms
sqlLogFormatter.startExecuteQueryFormat=$methodName$\n\tSQL:$sql$\n\tadditional_info:\n\t$additionalInfo$
sqlLogFormatter.endExecuteQueryFormat=$methodName$\n\texe:$executeTime$ms
sqlLogFormatter.startExecuteUpdateFormat=$methodName$\n\tSQL:$sql$\n\tadditional_info:\n\t$additionalInfo$
sqlLogFormatter.endExecuteUpdateFormat=$methodName$\n\texe:$executeTime$ms count:$updateCount$
sqlLogFormatter.startExecuteBatchFormat=$methodName$\n\tSQL:$sql$\n\tadditional_info:\n\t$additionalInfo$
sqlLogFormatter.endExecuteBatchFormat=$methodName$\n\texe:$executeTime$ms count:$updateCount$