diff --git a/src/main/java/jp/co/future/uroborosql/SqlAgentImpl.java b/src/main/java/jp/co/future/uroborosql/SqlAgentImpl.java index 3d7e79ed..2c753921 100644 --- a/src/main/java/jp/co/future/uroborosql/SqlAgentImpl.java +++ b/src/main/java/jp/co/future/uroborosql/SqlAgentImpl.java @@ -36,10 +36,6 @@ import java.util.stream.Stream; import java.util.stream.StreamSupport; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -import org.slf4j.MDC; - import jp.co.future.uroborosql.client.SqlParamUtils; import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.connection.ConnectionContext; @@ -84,6 +80,11 @@ import jp.co.future.uroborosql.fluent.SqlEntityUpdate; import jp.co.future.uroborosql.fluent.SqlQuery; import jp.co.future.uroborosql.fluent.SqlUpdate; +import jp.co.future.uroborosql.log.support.CoverageLoggingSupport; +import jp.co.future.uroborosql.log.support.PerformanceLoggingSupport; +import jp.co.future.uroborosql.log.support.ReplLoggingSupport; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; +import jp.co.future.uroborosql.log.support.SqlLoggingSupport; import jp.co.future.uroborosql.mapping.EntityHandler; import jp.co.future.uroborosql.mapping.MappingColumn; import jp.co.future.uroborosql.mapping.MappingUtils; @@ -101,25 +102,8 @@ * * @author H.Sugimoto */ -public class SqlAgentImpl implements SqlAgent { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - - /** SQLロガー */ - private static final Logger SQL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql"); - - /** SQLカバレッジ用ロガー */ - private static final Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); - - /** パフォーマンスロガー */ - private static final Logger PERFORMANCE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.performance"); - - /** REPLロガー */ - private static final Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); - - /** ログ出力を抑止するためのMDCキー */ - private static final String SUPPRESS_PARAMETER_LOG_OUTPUT = "SuppressParameterLogOutput"; - +public class SqlAgentImpl implements SqlAgent, ServiceLoggingSupport, PerformanceLoggingSupport, SqlLoggingSupport, + CoverageLoggingSupport, ReplLoggingSupport { /** ExecutionContext属性キー:リトライカウント */ private static final String CTX_ATTR_KEY_RETRY_COUNT = "__retryCount"; @@ -176,14 +160,17 @@ public class SqlAgentImpl implements SqlAgent { // クラス名が指定されている場合はそのクラス名を指定 var sqlCoverageClassName = System.getProperty(KEY_SQL_COVERAGE); if (sqlCoverageClassName == null) { - COVERAGE_LOG.info("system property - uroborosql.sql.coverage not set. sql coverage turned off."); + COVERAGE_LOG.atInfo() + .log("system property - uroborosql.sql.coverage not set. sql coverage turned off."); } else if (Boolean.FALSE.toString().equalsIgnoreCase(sqlCoverageClassName)) { sqlCoverageClassName = null; - COVERAGE_LOG.info("system property - uroborosql.sql.coverage is set to false. sql coverage turned off."); + COVERAGE_LOG.atInfo() + .log("system property - uroborosql.sql.coverage is set to false. sql coverage turned off."); } else if (Boolean.TRUE.toString().equalsIgnoreCase(sqlCoverageClassName)) { // trueの場合は、デフォルト値を設定 sqlCoverageClassName = "jp.co.future.uroborosql.coverage.CoberturaCoverageHandler"; - COVERAGE_LOG.info("system property - uroborosql.sql.coverage is set to true. sql coverage turned on."); + COVERAGE_LOG.atInfo() + .log("system property - uroborosql.sql.coverage is set to true. sql coverage turned on."); } CoverageHandler handler = null; @@ -191,12 +178,18 @@ public class SqlAgentImpl implements SqlAgent { try { handler = (CoverageHandler) Class.forName(sqlCoverageClassName, true, Thread.currentThread().getContextClassLoader()).getConstructor().newInstance(); - COVERAGE_LOG.info("CoverageHandler : {}", sqlCoverageClassName); + COVERAGE_LOG.atInfo() + .setMessage("CoverageHandler : {}") + .addArgument(sqlCoverageClassName) + .log(); } catch (Exception ex) { - COVERAGE_LOG.warn("Failed to instantiate CoverageHandler class. Class:{}, Cause:{}", - sqlCoverageClassName, - ex.getMessage()); - COVERAGE_LOG.info("Turn off sql coverage due to failure to instantiate CoverageHandler class."); + COVERAGE_LOG.atWarn() + .setMessage("Failed to instantiate CoverageHandler class. Class:{}, Cause:{}") + .addArgument(sqlCoverageClassName) + .addArgument(ex.getMessage()) + .log(); + COVERAGE_LOG.atInfo() + .log("Turn off sql coverage due to failure to instantiate CoverageHandler class."); } } @@ -267,6 +260,7 @@ public void close() { if (COVERAGE_HANDLER_REF.get() != null) { COVERAGE_HANDLER_REF.get().onSqlAgentClose(); } + releaseLogging(); } /** @@ -1349,9 +1343,6 @@ private int[] doBatchUpdate(final EntityHandler handler, */ @Override public ResultSet query(final ExecutionContext executionContext) throws SQLException { - // パラメータログを出力する - MDC.put(SUPPRESS_PARAMETER_LOG_OUTPUT, Boolean.FALSE.toString()); - if (SqlKind.NONE.equals(executionContext.getSqlKind())) { executionContext.setSqlKind(SqlKind.SELECT); } @@ -1367,26 +1358,22 @@ public ResultSet query(final ExecutionContext executionContext) throws SQLExcept // REPLで実行するための文字列をREPLログに出力する outputReplLog(executionContext); - Instant startTime = null; - if (LOG.isDebugEnabled()) { - LOG.debug("Execute query sql. sqlName: {}", executionContext.getSqlName()); - } - if (PERFORMANCE_LOG.isInfoEnabled()) { - startTime = Instant.now(getSqlConfig().getClock()); - } + debugWith(LOG) + .setMessage("Execute query sql. sqlName: {}") + .addArgument(executionContext.getSqlName()) + .log(); + var startTime = PERFORMANCE_LOG.isInfoEnabled() ? Instant.now(getSqlConfig().getClock()) : null; try { // デフォルト最大リトライ回数を取得し、個別指定（ExecutionContextの値）があれば上書き - var maxRetryCount = getMaxRetryCount(); - if (executionContext.getMaxRetryCount() >= 0) { - maxRetryCount = executionContext.getMaxRetryCount(); - } + var maxRetryCount = executionContext.getMaxRetryCount() >= 0 + ? executionContext.getMaxRetryCount() + : getMaxRetryCount(); // デフォルトリトライ待機時間を取得し、個別指定（ExecutionContextの値）があれば上書き - var retryWaitTime = getRetryWaitTime(); - if (executionContext.getRetryWaitTime() > 0) { - retryWaitTime = executionContext.getRetryWaitTime(); - } + var retryWaitTime = executionContext.getRetryWaitTime() > 0 + ? executionContext.getRetryWaitTime() + : getRetryWaitTime(); var loopCount = 0; var dialect = getDialect(); ResultSet rs = null; @@ -1416,11 +1403,11 @@ public ResultSet query(final ExecutionContext executionContext) throws SQLExcept var pessimisticLockingErrorCodes = dialect.getPessimisticLockingErrorCodes(); if (maxRetryCount > loopCount && (getSqlRetryCodes().contains(errorCode) || getSqlRetryCodes().contains(sqlState))) { - if (LOG.isDebugEnabled()) { - LOG.debug(String.format( - "Caught the error code to be retried.(%d times). Retry after %,3d ms.", - loopCount + 1, retryWaitTime)); - } + debugWith(LOG) + .setMessage("Caught the error code to be retried.({} times). Retry after {} ms.") + .addArgument(loopCount + 1) + .addArgument(() -> String.format("%,3d", retryWaitTime)) + .log(); if (retryWaitTime > 0) { try { Thread.sleep(retryWaitTime); @@ -1455,13 +1442,12 @@ public ResultSet query(final ExecutionContext executionContext) throws SQLExcept return null; } finally { // 後処理 - if (PERFORMANCE_LOG.isInfoEnabled() && startTime != null) { - PERFORMANCE_LOG.info("SQL execution time [{}({})] : [{}]", - generateSqlName(executionContext), - executionContext.getSqlKind(), - formatElapsedTime(startTime, Instant.now(getSqlConfig().getClock()))); - } - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); + infoWith(PERFORMANCE_LOG) + .setMessage("SQL execution time [{}({})] : [{}]") + .addArgument(() -> generateSqlName(executionContext)) + .addArgument(executionContext.getSqlKind()) + .addArgument(() -> formatElapsedTime(startTime, Instant.now(getSqlConfig().getClock()))) + .log(); } } @@ -1505,9 +1491,6 @@ public List> query(final ExecutionContext executionContext, */ @Override public int update(final ExecutionContext executionContext) throws SQLException { - // パラメータログを出力する - MDC.put(SUPPRESS_PARAMETER_LOG_OUTPUT, Boolean.FALSE.toString()); - if (SqlKind.NONE.equals(executionContext.getSqlKind())) { executionContext.setSqlKind(SqlKind.UPDATE); } @@ -1517,10 +1500,8 @@ public int update(final ExecutionContext executionContext) throws SQLException { // 更新移譲処理の指定がある場合は移譲処理を実行し結果を返却 if (executionContext.getUpdateDelegate() != null) { - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); - if (LOG.isInfoEnabled()) { - LOG.info("Performs update delegate of update process."); - } + infoWith(LOG) + .log("Performs update delegate of update process."); return executionContext.getUpdateDelegate().apply(executionContext); } @@ -1534,25 +1515,24 @@ public int update(final ExecutionContext executionContext) throws SQLException { // REPLで実行するための文字列をREPLログに出力する outputReplLog(executionContext); - if (LOG.isDebugEnabled()) { - LOG.debug("Execute update sql. sqlName: {}", executionContext.getSqlName()); - } + debugWith(LOG) + .setMessage("Execute update sql. sqlName: {}") + .addArgument(executionContext.getSqlName()) + .log(); if (PERFORMANCE_LOG.isInfoEnabled()) { startTime = Instant.now(getSqlConfig().getClock()); } // デフォルト最大リトライ回数を取得し、個別指定（ExecutionContextの値）があれば上書き - var maxRetryCount = getMaxRetryCount(); - if (executionContext.getMaxRetryCount() >= 0) { - maxRetryCount = executionContext.getMaxRetryCount(); - } + var maxRetryCount = executionContext.getMaxRetryCount() >= 0 + ? executionContext.getMaxRetryCount() + : getMaxRetryCount(); // デフォルトリトライ待機時間を取得し、個別指定（ExecutionContextの値）があれば上書き - var retryWaitTime = getRetryWaitTime(); - if (executionContext.getRetryWaitTime() > 0) { - retryWaitTime = executionContext.getRetryWaitTime(); - } + var retryWaitTime = executionContext.getRetryWaitTime() > 0 + ? executionContext.getRetryWaitTime() + : getRetryWaitTime(); var loopCount = 0; do { try { @@ -1593,11 +1573,11 @@ public int update(final ExecutionContext executionContext) throws SQLException { var errorCode = String.valueOf(ex.getErrorCode()); var sqlState = ex.getSQLState(); if (getSqlRetryCodes().contains(errorCode) || getSqlRetryCodes().contains(sqlState)) { - if (LOG.isDebugEnabled()) { - LOG.debug(String.format( - "Caught the error code to be retried.(%d times). Retry after %,3d ms.", - loopCount + 1, retryWaitTime)); - } + debugWith(LOG) + .setMessage("Caught the error code to be retried.({} times). Retry after {} ms.") + .addArgument(loopCount + 1) + .addArgument(() -> String.format("%,3d", retryWaitTime)) + .log(); if (retryWaitTime > 0) { try { Thread.sleep(retryWaitTime); @@ -1623,13 +1603,14 @@ public int update(final ExecutionContext executionContext) throws SQLException { handleException(executionContext, ex); return 0; } finally { - if (PERFORMANCE_LOG.isInfoEnabled() && startTime != null) { - PERFORMANCE_LOG.info("SQL execution time [{}({})] : [{}]", - generateSqlName(executionContext), - executionContext.getSqlKind(), - formatElapsedTime(startTime, Instant.now(getSqlConfig().getClock()))); - } - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); + // 後処理 + var curStartTime = startTime; + infoWith(PERFORMANCE_LOG) + .setMessage("SQL execution time [{}({})] : [{}]") + .addArgument(() -> generateSqlName(executionContext)) + .addArgument(executionContext.getSqlKind()) + .addArgument(() -> formatElapsedTime(curStartTime, Instant.now(getSqlConfig().getClock()))) + .log(); } } @@ -1639,7 +1620,7 @@ public int update(final ExecutionContext executionContext) throws SQLException { @Override public int[] batch(final ExecutionContext executionContext) throws SQLException { // バッチ処理の場合大量のログが出力されるため、パラメータログの出力を抑止する - MDC.put(SUPPRESS_PARAMETER_LOG_OUTPUT, Boolean.TRUE.toString()); + suppressParameterLogging(); if (SqlKind.NONE.equals(executionContext.getSqlKind())) { executionContext.setSqlKind(SqlKind.BATCH_INSERT); @@ -1650,10 +1631,9 @@ public int[] batch(final ExecutionContext executionContext) throws SQLException // 更新移譲処理の指定がある場合は移譲処理を実行し結果を返却 if (executionContext.getUpdateDelegate() != null) { - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); - if (LOG.isInfoEnabled()) { - LOG.info("Performs update delegate of batch process."); - } + releaseParameterLogging(); + infoWith(LOG) + .log("Performs update delegate of batch process."); return new int[] { executionContext.getUpdateDelegate().apply(executionContext) }; } @@ -1664,24 +1644,23 @@ public int[] batch(final ExecutionContext executionContext) throws SQLException // INパラメータ設定 executionContext.bindBatchParams(stmt); - if (LOG.isDebugEnabled()) { - LOG.debug("Execute batch sql. sqlName: {}", executionContext.getSqlName()); - } + debugWith(LOG) + .setMessage("Execute batch sql. sqlName: {}") + .addArgument(executionContext.getSqlName()) + .log(); if (PERFORMANCE_LOG.isInfoEnabled()) { startTime = Instant.now(getSqlConfig().getClock()); } // デフォルト最大リトライ回数を取得し、個別指定（ExecutionContextの値）があれば上書き - var maxRetryCount = getMaxRetryCount(); - if (executionContext.getMaxRetryCount() >= 0) { - maxRetryCount = executionContext.getMaxRetryCount(); - } + var maxRetryCount = executionContext.getMaxRetryCount() >= 0 + ? executionContext.getMaxRetryCount() + : getMaxRetryCount(); // デフォルトリトライ待機時間を取得し、個別指定（ExecutionContextの値）があれば上書き - var retryWaitTime = getRetryWaitTime(); - if (executionContext.getRetryWaitTime() > 0) { - retryWaitTime = executionContext.getRetryWaitTime(); - } + var retryWaitTime = executionContext.getRetryWaitTime() > 0 + ? executionContext.getRetryWaitTime() + : getRetryWaitTime(); var loopCount = 0; do { try { @@ -1720,11 +1699,11 @@ public int[] batch(final ExecutionContext executionContext) throws SQLException var errorCode = String.valueOf(ex.getErrorCode()); var sqlState = ex.getSQLState(); if (getSqlRetryCodes().contains(errorCode) || getSqlRetryCodes().contains(sqlState)) { - if (LOG.isDebugEnabled()) { - LOG.debug(String.format( - "Caught the error code to be retried.(%d times). Retry after %,3d ms.", - loopCount + 1, retryWaitTime)); - } + debugWith(LOG) + .setMessage("Caught the error code to be retried.({} times). Retry after {} ms.") + .addArgument(loopCount + 1) + .addArgument(() -> String.format("%,3d", retryWaitTime)) + .log(); if (retryWaitTime > 0) { try { Thread.sleep(retryWaitTime); @@ -1752,13 +1731,14 @@ public int[] batch(final ExecutionContext executionContext) throws SQLException return null; } finally { // 後処理 - if (PERFORMANCE_LOG.isInfoEnabled() && startTime != null) { - PERFORMANCE_LOG.info("SQL execution time [{}({})] : [{}]", - generateSqlName(executionContext), - executionContext.getSqlKind(), - formatElapsedTime(startTime, Instant.now(getSqlConfig().getClock()))); - } - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); + var curStartTime = startTime; + infoWith(PERFORMANCE_LOG) + .setMessage("SQL execution time [{}({})] : [{}]") + .addArgument(() -> generateSqlName(executionContext)) + .addArgument(executionContext.getSqlKind()) + .addArgument(() -> formatElapsedTime(curStartTime, Instant.now(getSqlConfig().getClock()))) + .log(); + releaseParameterLogging(); } } @@ -1769,9 +1749,6 @@ public int[] batch(final ExecutionContext executionContext) throws SQLException */ @Override public Map procedure(final ExecutionContext executionContext) throws SQLException { - // パラメータログを出力する - MDC.put(SUPPRESS_PARAMETER_LOG_OUTPUT, Boolean.FALSE.toString()); - // procedureやfunctionの場合、SQL文法エラーになるためバインドパラメータコメントを出力しない executionContext.contextAttrs().put(CTX_ATTR_KEY_OUTPUT_BIND_COMMENT, false); @@ -1789,24 +1766,24 @@ public Map procedure(final ExecutionContext executionContext) th // パラメータ設定 executionContext.bindParams(callableStatement); - if (LOG.isDebugEnabled()) { - LOG.debug("Execute stored procedure. sqlName: {}", executionContext.getSqlName()); - } + debugWith(LOG) + .setMessage("Execute stored procedure. sqlName: {}") + .addArgument(executionContext.getSqlName()) + .log(); if (PERFORMANCE_LOG.isInfoEnabled()) { startTime = Instant.now(getSqlConfig().getClock()); } // デフォルト最大リトライ回数を取得し、個別指定（ExecutionContextの値）があれば上書き - var maxRetryCount = getMaxRetryCount(); - if (executionContext.getMaxRetryCount() >= 0) { - maxRetryCount = executionContext.getMaxRetryCount(); - } + var maxRetryCount = executionContext.getMaxRetryCount() >= 0 + ? executionContext.getMaxRetryCount() + : getMaxRetryCount(); // デフォルトリトライ待機時間を取得し、個別指定（ExecutionContextの値）があれば上書き - var retryWaitTime = getRetryWaitTime(); - if (executionContext.getRetryWaitTime() > 0) { - retryWaitTime = executionContext.getRetryWaitTime(); - } + var retryWaitTime = executionContext.getRetryWaitTime() > 0 + ? executionContext.getRetryWaitTime() + : getRetryWaitTime(); + var loopCount = 0; do { try { @@ -1833,11 +1810,11 @@ public Map procedure(final ExecutionContext executionContext) th var errorCode = String.valueOf(ex.getErrorCode()); var sqlState = ex.getSQLState(); if (getSqlRetryCodes().contains(errorCode) || getSqlRetryCodes().contains(sqlState)) { - if (LOG.isDebugEnabled()) { - LOG.debug(String.format( - "Caught the error code to be retried.(%d times). Retry after %,3d ms.", - loopCount + 1, retryWaitTime)); - } + debugWith(LOG) + .setMessage("Caught the error code to be retried.({} times). Retry after {} ms.") + .addArgument(loopCount + 1) + .addArgument(() -> String.format("%,3d", retryWaitTime)) + .log(); if (retryWaitTime > 0) { try { Thread.sleep(retryWaitTime); @@ -1863,13 +1840,14 @@ public Map procedure(final ExecutionContext executionContext) th } catch (SQLException ex) { handleException(executionContext, ex); } finally { - if (PERFORMANCE_LOG.isInfoEnabled() && startTime != null) { - PERFORMANCE_LOG.info("Stored procedure execution time [{}({})] : [{}]", - generateSqlName(executionContext), - executionContext.getSqlKind(), - formatElapsedTime(startTime, Instant.now(getSqlConfig().getClock()))); - } - MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); + // 後処理 + var curStartTime = startTime; + infoWith(PERFORMANCE_LOG) + .setMessage("Stored procedure execution time [{}({})] : [{}]") + .addArgument(() -> generateSqlName(executionContext)) + .addArgument(executionContext.getSqlKind()) + .addArgument(() -> formatElapsedTime(curStartTime, Instant.now(getSqlConfig().getClock()))) + .log(); } return null; } @@ -1904,9 +1882,15 @@ private void transformContext(final ExecutionContext executionContext) { if (SQL_LOG.isInfoEnabled() && sqlName != null) { if (executionContext.getSqlKind().isEntityType()) { - SQL_LOG.info("EntityClass : {}", sqlName); + infoWith(SQL_LOG) + .setMessage("EntityClass : {}") + .addArgument(sqlName) + .log(); } else if (getSqlResourceManager().existSql(sqlName)) { - SQL_LOG.info("SQLPath : {}", getSqlResourceManager().getSqlPath(sqlName)); + infoWith(SQL_LOG) + .setMessage("SQLPath : {}") + .addArgument(() -> getSqlResourceManager().getSqlPath(sqlName)) + .log(); } } @@ -1930,9 +1914,12 @@ && getSqlConfig().getEventListenerHolder().hasBeforeParseSqlListener()) { .forEach(listener -> listener.accept(eventObj)); } - if (SQL_LOG.isDebugEnabled()) { - SQL_LOG.debug("Template SQL[{}{}{}]", System.lineSeparator(), originalSql, System.lineSeparator()); - } + debugWith(SQL_LOG) + .setMessage("Template SQL[{}{}{}]") + .addArgument(System.lineSeparator()) + .addArgument(originalSql) + .addArgument(System.lineSeparator()) + .log(); if (ObjectUtils.isEmpty(executionContext.getExecutableSql())) { // SQLパーサーによるパース処理 @@ -1947,18 +1934,21 @@ && getSqlConfig().getEventListenerHolder().hasBeforeParseSqlListener()) { // SQLカバレッジ用のログを出力する var coverageData = new CoverageData(sqlName, originalSql, contextTransformer.getPassedRoute()); - if (COVERAGE_LOG.isDebugEnabled()) { - COVERAGE_LOG.debug("coverage data: {}", coverageData); - } + debugWith(COVERAGE_LOG) + .setMessage("coverage data: {}") + .addArgument(coverageData) + .log(); COVERAGE_HANDLER_REF.get().accept(coverageData); } } - if (SQL_LOG.isInfoEnabled()) { - SQL_LOG.info("Executed SQL[{}{}{}]", System.lineSeparator(), executionContext.getExecutableSql(), - System.lineSeparator()); - } + infoWith(SQL_LOG) + .setMessage("Executed SQL[{}{}{}]") + .addArgument(System.lineSeparator()) + .addArgument(executionContext.getExecutableSql()) + .addArgument(System.lineSeparator()) + .log(); } /** 時間計測用のログに出力するSQL名を生成する. @@ -1988,21 +1978,27 @@ private void handleException(final ExecutionContext executionContext, final SQLE cause = cause.getNextException(); } - if (outputExceptionLog && LOG.isErrorEnabled()) { - var builder = new StringBuilder(); - builder.append(System.lineSeparator()).append("Exception occurred in SQL execution.") - .append(System.lineSeparator()); - builder.append("Executed SQL[").append(executionContext.getExecutableSql()).append("]") - .append(System.lineSeparator()); - if (executionContext instanceof ExecutionContextImpl) { - var bindParameters = ((ExecutionContextImpl) executionContext).getBindParameters(); - for (var i = 0; i < bindParameters.length; i++) { - var parameter = bindParameters[i]; - builder.append("Bind Parameter.[INDEX[").append(i + 1).append("], ").append(parameter.toString()) - .append("]").append(System.lineSeparator()); - } - } - LOG.error(builder.toString(), cause); + if (outputExceptionLog) { + errorWith(LOG) + .setMessage(() -> { + var builder = new StringBuilder(); + builder.append(System.lineSeparator()).append("Exception occurred in SQL execution.") + .append(System.lineSeparator()); + builder.append("Executed SQL[").append(executionContext.getExecutableSql()).append("]") + .append(System.lineSeparator()); + if (executionContext instanceof ExecutionContextImpl) { + var bindParameters = ((ExecutionContextImpl) executionContext).getBindParameters(); + for (var i = 0; i < bindParameters.length; i++) { + var parameter = bindParameters[i]; + builder.append("Bind Parameter.[INDEX[").append(i + 1).append("], ") + .append(parameter.toString()) + .append("]").append(System.lineSeparator()); + } + } + return builder.toString(); + }) + .setCause(cause) + .log(); } throw cause; @@ -2014,8 +2010,7 @@ private void handleException(final ExecutionContext executionContext, final SQLE * @param executionContext executionContext */ private void outputReplLog(final ExecutionContext executionContext) { - if (!(REPL_LOG.isInfoEnabled() && - executionContext.getSqlName() != null && + if (!(REPL_LOG.isInfoEnabled() && executionContext.getSqlName() != null && (SqlKind.SELECT.equals(executionContext.getSqlKind()) || SqlKind.UPDATE.equals(executionContext.getSqlKind())))) { // REPLログ出力対象でない場合は何もしない @@ -2040,7 +2035,10 @@ private void outputReplLog(final ExecutionContext executionContext) { builder.append(" "); builder.append(SqlParamUtils.formatPrams(params)); } - REPL_LOG.info("REPL command: {}", builder.toString()); + infoWith(REPL_LOG) + .setMessage("REPL command: {}") + .addArgument(builder.toString()) + .log(); } /** @@ -2893,7 +2891,7 @@ private void applyProperties(final PreparedStatement preparedStatement) throws S * @return フォーマットした経過時間 */ private static String formatElapsedTime(final Instant start, final Instant end) { - return ELAPSED_TIME_FORMAT.format(LocalTime.MIDNIGHT.plus(Duration.between(start, end))); + return ELAPSED_TIME_FORMAT.format(LocalTime.MIDNIGHT.plus(Duration.between(start != null ? start : end, end))); } /** @@ -2903,7 +2901,8 @@ private static String formatElapsedTime(final Instant start, final Instant end) * * @param ResultSetの1行を変換した型 */ - private static final class ResultSetSpliterator extends Spliterators.AbstractSpliterator { + private static final class ResultSetSpliterator extends Spliterators.AbstractSpliterator + implements ServiceLoggingSupport { private final ResultSetConverter converter; private final ResultSet rs; private boolean finished = false; @@ -2932,7 +2931,10 @@ public boolean tryAdvance(final Consumer action) { rs.close(); } } catch (SQLException ex2) { - LOG.error(ex2.getMessage(), ex2); + errorWith(LOG) + .setMessage(ex2.getMessage()) + .setCause(ex2) + .log(); } throw ex; } catch (SQLException ex) { @@ -2941,7 +2943,10 @@ public boolean tryAdvance(final Consumer action) { rs.close(); } } catch (SQLException ex2) { - LOG.error(ex2.getMessage(), ex2); + errorWith(LOG) + .setMessage(ex2.getMessage()) + .setCause(ex2) + .log(); } throw new UroborosqlSQLException(ex); } diff --git a/src/main/java/jp/co/future/uroborosql/SqlEntityQueryImpl.java b/src/main/java/jp/co/future/uroborosql/SqlEntityQueryImpl.java index b3ea55ca..3637de98 100644 --- a/src/main/java/jp/co/future/uroborosql/SqlEntityQueryImpl.java +++ b/src/main/java/jp/co/future/uroborosql/SqlEntityQueryImpl.java @@ -14,9 +14,6 @@ import java.util.stream.Collectors; import java.util.stream.Stream; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.context.ExecutionContext; import jp.co.future.uroborosql.dialect.Dialect; import jp.co.future.uroborosql.enums.ForUpdateType; @@ -26,6 +23,7 @@ import jp.co.future.uroborosql.exception.EntitySqlRuntimeException; import jp.co.future.uroborosql.exception.UroborosqlRuntimeException; import jp.co.future.uroborosql.fluent.SqlEntityQuery; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; import jp.co.future.uroborosql.mapping.EntityHandler; import jp.co.future.uroborosql.mapping.MappingUtils; import jp.co.future.uroborosql.mapping.TableMetadata; @@ -38,10 +36,8 @@ * @param Entity型 * @author ota */ -final class SqlEntityQueryImpl extends AbstractExtractionCondition> implements SqlEntityQuery { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - +final class SqlEntityQueryImpl extends AbstractExtractionCondition> + implements SqlEntityQuery, ServiceLoggingSupport { private final EntityHandler entityHandler; private final Class entityType; private final List sortOrders; @@ -585,9 +581,8 @@ public SqlEntityQuery forUpdateNoWait() { return this; } else if (!agent().getSqlConfig().getSqlAgentProvider().isStrictForUpdateType() && dialect.supportsForUpdate()) { - if (LOG.isWarnEnabled()) { - LOG.warn("'FOR UPDATE NOWAIT' is not supported. Set 'FOR UPDATE' instead."); - } + warnWith(LOG) + .log("'FOR UPDATE NOWAIT' is not supported. Set 'FOR UPDATE' instead."); this.forUpdateType = ForUpdateType.NORMAL; return this; } else { @@ -606,9 +601,8 @@ public SqlEntityQuery forUpdateWait() { return forUpdateWait(agent().getSqlConfig().getSqlAgentProvider().getDefaultForUpdateWaitSeconds()); } else if (!agent().getSqlConfig().getSqlAgentProvider().isStrictForUpdateType() && dialect.supportsForUpdate()) { - if (LOG.isWarnEnabled()) { - LOG.warn("'FOR UPDATE WAIT' is not supported. Set 'FOR UPDATE' instead."); - } + warnWith(LOG) + .log("'FOR UPDATE WAIT' is not supported. Set 'FOR UPDATE' instead."); this.forUpdateType = ForUpdateType.NORMAL; return this; } else { @@ -629,9 +623,8 @@ public SqlEntityQuery forUpdateWait(final int waitSeconds) { return this; } else if (!agent().getSqlConfig().getSqlAgentProvider().isStrictForUpdateType() && dialect.supportsForUpdate()) { - if (LOG.isWarnEnabled()) { - LOG.warn("'FOR UPDATE WAIT' is not supported. Set 'FOR UPDATE' instead."); - } + warnWith(LOG) + .log("'FOR UPDATE WAIT' is not supported. Set 'FOR UPDATE' instead."); this.forUpdateType = ForUpdateType.NORMAL; return this; } else { @@ -649,9 +642,8 @@ public SqlEntityQuery hint(final String hint) { if (dialect.supportsOptimizerHints()) { this.optimizerHints.add(hint); } else { - if (LOG.isWarnEnabled()) { - LOG.warn("Optimizer Hints is not supported."); - } + warnWith(LOG) + .log("Optimizer Hints is not supported."); } return this; } diff --git a/src/main/java/jp/co/future/uroborosql/UroboroSQL.java b/src/main/java/jp/co/future/uroborosql/UroboroSQL.java index 86ab9be1..7b184927 100644 --- a/src/main/java/jp/co/future/uroborosql/UroboroSQL.java +++ b/src/main/java/jp/co/future/uroborosql/UroboroSQL.java @@ -13,9 +13,6 @@ import javax.sql.DataSource; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.connection.ConnectionContext; import jp.co.future.uroborosql.connection.ConnectionContextBuilder; @@ -31,6 +28,8 @@ import jp.co.future.uroborosql.event.EventListenerHolder; import jp.co.future.uroborosql.expr.ExpressionParser; import jp.co.future.uroborosql.expr.ExpressionParserFactory; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; +import jp.co.future.uroborosql.log.support.SettingLoggingSupport; import jp.co.future.uroborosql.mapping.DefaultEntityHandler; import jp.co.future.uroborosql.mapping.EntityHandler; import jp.co.future.uroborosql.store.SqlResourceManager; @@ -42,10 +41,7 @@ * @author H.Sugimoto * @since v0.4.0 */ -public final class UroboroSQL { - /** 設定ロガー */ - private static final Logger SETTING_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.setting"); - +public final class UroboroSQL implements ServiceLoggingSupport, SettingLoggingSupport { private UroboroSQL() { } @@ -238,7 +234,7 @@ public SqlConfig build() { } - public static final class InternalConfig implements SqlConfig { + public static final class InternalConfig implements SqlConfig, SettingLoggingSupport { /** * コネクション提供クラス. */ @@ -300,15 +296,15 @@ public static final class InternalConfig implements SqlConfig { this.entityHandler = new DefaultEntityHandler(); if (clock == null) { this.clock = Clock.systemDefaultZone(); - if (SETTING_LOG.isWarnEnabled()) { - SETTING_LOG.warn("SqlConfig - Clock was not set. Set SystemClock."); - } + warnWith(SETTING_LOG) + .log("SqlConfig - Clock was not set. Set SystemClock."); } else { this.clock = clock; } - if (SETTING_LOG.isInfoEnabled()) { - SETTING_LOG.info("SqlConfig - Clock : {} has been selected.", this.clock.toString()); - } + infoWith(SETTING_LOG) + .setMessage("SqlConfig - Clock : {} has been selected.") + .addArgument(this.clock) + .log(); if (dialect == null) { this.dialect = StreamSupport.stream(ServiceLoader.load(Dialect.class).spliterator(), false) @@ -318,10 +314,10 @@ public static final class InternalConfig implements SqlConfig { } else { this.dialect = dialect; } - if (SETTING_LOG.isInfoEnabled()) { - SETTING_LOG.info("SqlConfig - Dialect : {} has been selected.", - this.dialect.getClass().getSimpleName()); - } + infoWith(SETTING_LOG) + .setMessage("SqlConfig - Dialect : {} has been selected.") + .addArgument(() -> this.dialect.getClass().getSimpleName()) + .log(); if (expressionParser == null) { var expressionParserFactory = StreamSupport @@ -333,10 +329,10 @@ public static final class InternalConfig implements SqlConfig { } else { this.expressionParser = expressionParser; } - if (SETTING_LOG.isInfoEnabled()) { - SETTING_LOG.info("SqlConfig - ExpressionParser : {} has been selected.", - this.expressionParser.getClass().getSimpleName()); - } + infoWith(SETTING_LOG) + .setMessage("SqlConfig - ExpressionParser : {} has been selected.") + .addArgument(() -> this.expressionParser.getClass().getSimpleName()) + .log(); this.sqlResourceManager.setDialect(this.dialect); this.executionContextProvider.setSqlConfig(this); diff --git a/src/main/java/jp/co/future/uroborosql/client/SqlREPL.java b/src/main/java/jp/co/future/uroborosql/client/SqlREPL.java index 26dce413..046f8988 100644 --- a/src/main/java/jp/co/future/uroborosql/client/SqlREPL.java +++ b/src/main/java/jp/co/future/uroborosql/client/SqlREPL.java @@ -49,6 +49,7 @@ import jp.co.future.uroborosql.client.completer.TableNameCompleter; import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.event.subscriber.DumpResultEventSubscriber; +import jp.co.future.uroborosql.log.support.ReplLoggingSupport; import jp.co.future.uroborosql.store.SqlResourceManagerImpl; import jp.co.future.uroborosql.utils.ObjectUtils; @@ -59,10 +60,7 @@ * * @author H.Sugimoto */ -public class SqlREPL { - /** REPLロガー */ - private static final org.slf4j.Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); - +public class SqlREPL implements ReplLoggingSupport { /** プロパティ上のクラスパスに指定された環境変数を置換するための正規表現 */ private static final Pattern SYSPROP_PAT = Pattern.compile("\\$\\{(.+?)\\}"); /** プロパティパス */ @@ -201,7 +199,10 @@ private void initialize(final Terminal terminal) throws Exception { urls.add(Paths.get(sb.toString()).toUri().toURL()); } catch (Exception ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } }); additionalClassLoader = new URLClassLoader(urls.toArray(new URL[urls.size()]), currentClassLoader); @@ -213,7 +214,10 @@ private void initialize(final Terminal terminal) throws Exception { try { DriverManager.registerDriver(new DriverShim(driver)); } catch (Exception ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } }); @@ -307,7 +311,10 @@ private void listen(final Terminal terminal) throws IOException { } catch (UserInterruptException | EndOfFileException ex) { break; } catch (Exception ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } } diff --git a/src/main/java/jp/co/future/uroborosql/client/command/DescCommand.java b/src/main/java/jp/co/future/uroborosql/client/command/DescCommand.java index ef467736..8649fa0a 100644 --- a/src/main/java/jp/co/future/uroborosql/client/command/DescCommand.java +++ b/src/main/java/jp/co/future/uroborosql/client/command/DescCommand.java @@ -17,8 +17,6 @@ import org.jline.reader.LineReader; import org.jline.terminal.Terminal; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.client.completer.TableNameCompleter; import jp.co.future.uroborosql.config.SqlConfig; @@ -30,9 +28,6 @@ * @author H.Sugimoto */ public class DescCommand extends ReplCommand { - /** REPLロガー */ - private static final Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); - /** DESCで表示する項目 */ private static final String[] DESC_COLUMN_LABELS = { "TABLE_NAME", "COLUMN_NAME", "TYPE_NAME", "COLUMN_SIZE", "DECIMAL_DIGITS", "IS_NULLABLE", "COLUMN_DEF", "REMARKS" }; @@ -130,7 +125,10 @@ public boolean execute(final LineReader reader, final String[] parts, final SqlC } writer.println(); } catch (SQLException ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } writer.flush(); diff --git a/src/main/java/jp/co/future/uroborosql/client/command/GenerateCommand.java b/src/main/java/jp/co/future/uroborosql/client/command/GenerateCommand.java index 1994052c..4c1cf4cf 100644 --- a/src/main/java/jp/co/future/uroborosql/client/command/GenerateCommand.java +++ b/src/main/java/jp/co/future/uroborosql/client/command/GenerateCommand.java @@ -11,8 +11,6 @@ import org.jline.reader.LineReader; import org.jline.terminal.Terminal; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.client.completer.SqlKeywordCompleter; import jp.co.future.uroborosql.client.completer.SqlKeywordCompleter.SqlKeyword; @@ -27,9 +25,6 @@ * @author H.Sugimoto */ public class GenerateCommand extends ReplCommand { - /** REPLロガー */ - private static final Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); - /** * Constructor */ @@ -79,7 +74,10 @@ public boolean execute(final LineReader reader, final String[] parts, final SqlC }).orElseGet(() -> sqlConfig.getEntityHandler().createSelectContext(agent, metadata, null, true)); writer.println(ctx.getSql()); } catch (SQLException ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } writer.flush(); diff --git a/src/main/java/jp/co/future/uroborosql/client/command/ReplCommand.java b/src/main/java/jp/co/future/uroborosql/client/command/ReplCommand.java index 04752039..983a2bf1 100644 --- a/src/main/java/jp/co/future/uroborosql/client/command/ReplCommand.java +++ b/src/main/java/jp/co/future/uroborosql/client/command/ReplCommand.java @@ -19,13 +19,14 @@ import jp.co.future.uroborosql.client.SqlREPL; import jp.co.future.uroborosql.config.SqlConfig; +import jp.co.future.uroborosql.log.support.ReplLoggingSupport; /** * REPLで実行するコマンドの抽象親クラス * * @author H.Sugimoto */ -public abstract class ReplCommand { +public abstract class ReplCommand implements ReplLoggingSupport { /** 利用する入力補完の並び */ private final List> completers; /** HELPコマンドで非表示 */ diff --git a/src/main/java/jp/co/future/uroborosql/client/completer/TableNameCompleter.java b/src/main/java/jp/co/future/uroborosql/client/completer/TableNameCompleter.java index f170ecad..d7c6c2c9 100644 --- a/src/main/java/jp/co/future/uroborosql/client/completer/TableNameCompleter.java +++ b/src/main/java/jp/co/future/uroborosql/client/completer/TableNameCompleter.java @@ -12,11 +12,10 @@ import org.jline.reader.Candidate; import org.jline.reader.LineReader; import org.jline.reader.ParsedLine; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.client.command.ReplCommand; import jp.co.future.uroborosql.connection.ConnectionSupplier; +import jp.co.future.uroborosql.log.support.ReplLoggingSupport; /** * テーブル名を補完するCompleter @@ -24,9 +23,7 @@ * @author H.Sugimoto * */ -public class TableNameCompleter extends AbstractCompleter { - /** REPLロガー */ - private static final Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); +public class TableNameCompleter extends AbstractCompleter implements ReplLoggingSupport { /** Connectionサプライヤ. */ private final ConnectionSupplier connectionSupplier; @@ -91,7 +88,10 @@ public void complete(final LineReader reader, final ParsedLine line, final List< } } } catch (SQLException ex) { - REPL_LOG.error(ex.getMessage(), ex); + errorWith(REPL_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); return; } } diff --git a/src/main/java/jp/co/future/uroborosql/context/ExecutionContextImpl.java b/src/main/java/jp/co/future/uroborosql/context/ExecutionContextImpl.java index 5eeab3da..241c4d46 100644 --- a/src/main/java/jp/co/future/uroborosql/context/ExecutionContextImpl.java +++ b/src/main/java/jp/co/future/uroborosql/context/ExecutionContextImpl.java @@ -28,9 +28,6 @@ import java.util.function.Supplier; import java.util.regex.Pattern; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.config.SqlConfigAware; import jp.co.future.uroborosql.enums.SqlKind; @@ -38,6 +35,7 @@ import jp.co.future.uroborosql.event.BeforeParseSqlEvent; import jp.co.future.uroborosql.event.BeforeSetParameterEvent; import jp.co.future.uroborosql.exception.ParameterNotFoundRuntimeException; +import jp.co.future.uroborosql.log.support.SqlLoggingSupport; import jp.co.future.uroborosql.parameter.InOutParameter; import jp.co.future.uroborosql.parameter.OutParameter; import jp.co.future.uroborosql.parameter.Parameter; @@ -53,7 +51,7 @@ * * @author H.Sugimoto */ -public class ExecutionContextImpl implements ExecutionContext, SqlConfigAware { +public class ExecutionContextImpl implements ExecutionContext, SqlConfigAware, SqlLoggingSupport { /** * @see #getParameterNames() */ @@ -86,9 +84,6 @@ public boolean contains(final Object o) { /** 不要な空白、改行を除去するための正規表現 */ private static final Pattern CLEAR_BLANK_PATTERN = Pattern.compile("(?m)^\\s*(\\r\\n|\\r|\\n)"); - /** SQLロガー */ - private static final Logger SQL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql"); - /** SqlConfig. */ private SqlConfig sqlConfig; @@ -892,8 +887,11 @@ public ExecutionContext bindBatchParams(final PreparedStatement preparedStatemen bindParams(preparedStatement); preparedStatement.addBatch(); } - if (SQL_LOG.isDebugEnabled()) { - SQL_LOG.debug("{} items Added for batch process.", batchParameters.size()); + if (!isSuppressLogging()) { + debugWith(SQL_LOG) + .setMessage("{} items Added for batch process.") + .addArgument(batchParameters.size()) + .log(); } return this; } @@ -925,9 +923,10 @@ public Map getOutParams(final CallableStatement callableStatemen parameterIndex++; } - if (SQL_LOG.isDebugEnabled()) { - SQL_LOG.debug("Stored procedure out parameter[{}]", out); - } + debugWith(SQL_LOG) + .setMessage("Stored procedure out parameter[{}]") + .addArgument(out) + .log(); return out; } diff --git a/src/main/java/jp/co/future/uroborosql/context/ExecutionContextProviderImpl.java b/src/main/java/jp/co/future/uroborosql/context/ExecutionContextProviderImpl.java index ce20b014..4347551d 100644 --- a/src/main/java/jp/co/future/uroborosql/context/ExecutionContextProviderImpl.java +++ b/src/main/java/jp/co/future/uroborosql/context/ExecutionContextProviderImpl.java @@ -32,11 +32,10 @@ import java.util.jar.JarFile; import java.util.stream.Collectors; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.event.AfterInitializeExecutionContextEvent; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; +import jp.co.future.uroborosql.log.support.SettingLoggingSupport; import jp.co.future.uroborosql.parameter.Parameter; import jp.co.future.uroborosql.parameter.mapper.BindParameterMapper; import jp.co.future.uroborosql.parameter.mapper.BindParameterMapperManager; @@ -48,13 +47,8 @@ * * @author H.Sugimoto */ -public class ExecutionContextProviderImpl implements ExecutionContextProvider { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - - /** 設定ロガー */ - private static final Logger SETTING_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.setting"); - +public class ExecutionContextProviderImpl + implements ExecutionContextProvider, ServiceLoggingSupport, SettingLoggingSupport { /** 定数パラメータプレフィックス */ private String constParamPrefix = "CLS_"; @@ -160,17 +154,17 @@ protected void makeConstParamMap(final Map paramMap, var newValue = new Parameter(fieldName, field.get(null)); var prevValue = paramMap.put(fieldName, newValue); if (prevValue != null) { - if (SETTING_LOG.isWarnEnabled()) { - SETTING_LOG.warn("Duplicate constant name. Constant name:{}, old value:{} destroy.", - fieldName, - prevValue.getValue()); - } - } - if (SETTING_LOG.isInfoEnabled()) { - SETTING_LOG.info("Constant [name:{}, value:{}] added to parameter.", - fieldName, - newValue.getValue()); + warnWith(SETTING_LOG) + .setMessage("Duplicate constant name. Constant name:{}, old value:{} destroy.") + .addArgument(fieldName) + .addArgument(prevValue.getValue()) + .log(); } + infoWith(SETTING_LOG) + .setMessage("Constant [name:{}, value:{}] added to parameter.") + .addArgument(fieldName) + .addArgument(newValue.getValue()) + .log(); } } } @@ -184,7 +178,10 @@ protected void makeConstParamMap(final Map paramMap, } } } catch (IllegalArgumentException | IllegalAccessException | SecurityException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } @@ -209,17 +206,17 @@ protected void makeEnumConstParamMap(final Map paramMap, var newValue = new Parameter(fieldName, value); var prevValue = paramMap.put(fieldName, newValue); if (prevValue != null) { - if (SETTING_LOG.isWarnEnabled()) { - SETTING_LOG.warn("Duplicate Enum name. Enum name:{}, old value:{} destroy.", - fieldName, - prevValue.getValue()); - } - } - if (SETTING_LOG.isInfoEnabled()) { - SETTING_LOG.info("Enum [name:{}, value:{}] added to parameter.", - fieldName, - newValue.getValue()); + warnWith(SETTING_LOG) + .setMessage("Duplicate Enum name. Enum name:{}, old value:{} destroy.") + .addArgument(fieldName) + .addArgument(prevValue.getValue()) + .log(); } + infoWith(SETTING_LOG) + .setMessage("Enum [name:{}, value:{}] added to parameter.") + .addArgument(fieldName) + .addArgument(newValue.getValue()) + .log(); } } @@ -331,7 +328,10 @@ public ExecutionContextProvider removeBindParamMapper(final BindParameterMapper< var targetClass = Class.forName(className, true, Thread.currentThread().getContextClassLoader()); makeConstParamMap(paramMap, targetClass); } catch (ClassNotFoundException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } } @@ -362,14 +362,17 @@ public ExecutionContextProvider removeBindParamMapper(final BindParameterMapper< * @return クラスリスト */ @SuppressWarnings({ "unchecked", "rawtypes" }) - private static Set>> listUpEnumClasses(final String packageName) { + private Set>> listUpEnumClasses(final String packageName) { var resourceName = packageName.replace('.', '/'); var classLoader = Thread.currentThread().getContextClassLoader(); List roots; try { roots = Collections.list(classLoader.getResources(resourceName)); } catch (IOException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); return Set.of(); } @@ -379,14 +382,20 @@ private static Set>> listUpEnumClasses(final String pack try { classes.addAll(findEnumClassesWithFile(packageName, Paths.get(root.toURI()))); } catch (URISyntaxException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } if ("jar".equalsIgnoreCase(root.getProtocol())) { try (var jarFile = ((JarURLConnection) root.openConnection()).getJarFile()) { classes.addAll(findEnumClassesWithJar(packageName, jarFile)); } catch (IOException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } } @@ -403,7 +412,7 @@ private static Set>> listUpEnumClasses(final String pack * @throws ClassNotFoundException エラー * @throws IOException */ - private static Set> findEnumClassesWithFile(final String packageName, final Path dir) { + private Set> findEnumClassesWithFile(final String packageName, final Path dir) { var prefix = packageName + "."; try (var stream = Files.walk(dir)) { return stream.filter(entry -> entry.getFileName().toString().endsWith(".class")) @@ -416,7 +425,10 @@ private static Set> findEnumClassesWithFile(final String packageName, f .filter(Objects::nonNull) .collect(Collectors.toSet()); } catch (IOException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); return Set.of(); } } @@ -430,7 +442,7 @@ private static Set> findEnumClassesWithFile(final String packageName, f * @throws ClassNotFoundException エラー * @throws IOException */ - private static Collection> findEnumClassesWithJar(final String packageName, + private Collection> findEnumClassesWithJar(final String packageName, final JarFile jarFile) { var resourceName = packageName.replace('.', '/'); return Collections.list(jarFile.entries()).stream() @@ -449,14 +461,17 @@ private static Collection> findEnumClassesWithJar(final Strin * @param className クラス名 * @return ロードしたEnumクラス */ - private static Optional> loadEnum(final String className) { + private Optional> loadEnum(final String className) { try { var type = Class.forName(className, true, Thread.currentThread().getContextClassLoader()); if (type.isEnum()) { return Optional.of(type); } } catch (ClassNotFoundException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } return Optional.empty(); } diff --git a/src/main/java/jp/co/future/uroborosql/coverage/CoberturaCoverageHandler.java b/src/main/java/jp/co/future/uroborosql/coverage/CoberturaCoverageHandler.java index d2e14c65..5ccabbce 100644 --- a/src/main/java/jp/co/future/uroborosql/coverage/CoberturaCoverageHandler.java +++ b/src/main/java/jp/co/future/uroborosql/coverage/CoberturaCoverageHandler.java @@ -30,12 +30,11 @@ import javax.xml.transform.dom.DOMSource; import javax.xml.transform.stream.StreamResult; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import org.w3c.dom.Document; import org.w3c.dom.Element; import jp.co.future.uroborosql.SqlAgent; +import jp.co.future.uroborosql.log.support.CoverageLoggingSupport; import jp.co.future.uroborosql.utils.ObjectUtils; /** @@ -51,10 +50,7 @@ * * @author ota */ -public class CoberturaCoverageHandler implements CoverageHandler { - /** カバレッジロガー. */ - private static final Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); - +public class CoberturaCoverageHandler implements CoverageHandler, CoverageLoggingSupport { /** * カバレッジ数値 line branch セット */ @@ -258,7 +254,10 @@ public synchronized void accept(final CoverageData coverageData) { sqlCoverage = new SqlCoverage(coverageData.getSqlName(), coverageData.getSql(), coverageData.getMd5(), sourcesDirPath, map.size()); } catch (IOException ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); return; } map.put(coverageData.getMd5(), sqlCoverage); @@ -273,7 +272,10 @@ public synchronized void onSqlAgentClose() { try { write(); } catch (Exception ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } @@ -283,7 +285,10 @@ private void init() { try { write(); } catch (Exception ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } })); } diff --git a/src/main/java/jp/co/future/uroborosql/coverage/CoverageData.java b/src/main/java/jp/co/future/uroborosql/coverage/CoverageData.java index 05d56a3a..cc75969d 100644 --- a/src/main/java/jp/co/future/uroborosql/coverage/CoverageData.java +++ b/src/main/java/jp/co/future/uroborosql/coverage/CoverageData.java @@ -8,18 +8,14 @@ import java.security.MessageDigest; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; +import jp.co.future.uroborosql.log.support.CoverageLoggingSupport; /** * カバレッジログ出力用データクラス * * @author ota */ -public class CoverageData { - /** カバレッジロガー. */ - private static final Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); - +public class CoverageData implements CoverageLoggingSupport { /** SQL名. */ private final String sqlName; @@ -66,7 +62,10 @@ private String makeMd5(final String original) { } return builder.toString(); } catch (Exception ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } return ""; } diff --git a/src/main/java/jp/co/future/uroborosql/coverage/reports/html/HtmlReportCoverageHandler.java b/src/main/java/jp/co/future/uroborosql/coverage/reports/html/HtmlReportCoverageHandler.java index 805942a0..a1851ae7 100644 --- a/src/main/java/jp/co/future/uroborosql/coverage/reports/html/HtmlReportCoverageHandler.java +++ b/src/main/java/jp/co/future/uroborosql/coverage/reports/html/HtmlReportCoverageHandler.java @@ -22,12 +22,10 @@ import java.util.stream.Collectors; import java.util.stream.Stream; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.SqlAgent; import jp.co.future.uroborosql.coverage.CoverageData; import jp.co.future.uroborosql.coverage.CoverageHandler; +import jp.co.future.uroborosql.log.support.CoverageLoggingSupport; import jp.co.future.uroborosql.utils.ObjectUtils; /** @@ -41,10 +39,7 @@ * * @author ota */ -public class HtmlReportCoverageHandler implements CoverageHandler { - /** カバレッジロガー. */ - private static final Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); - +public class HtmlReportCoverageHandler implements CoverageHandler, CoverageLoggingSupport { /** カバレッジ情報. */ private final Map> coverages = new ConcurrentHashMap<>(); @@ -115,7 +110,10 @@ private void writeHtml() { Files.copy(src, Paths.get(this.reportDirPath + "/" + filename), StandardCopyOption.REPLACE_EXISTING); } catch (IOException ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } }); // write report @@ -132,7 +130,10 @@ private void writeHtml() { writeSuffix(writer); } } catch (IOException ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } diff --git a/src/main/java/jp/co/future/uroborosql/coverage/reports/html/SqlCoverageReport.java b/src/main/java/jp/co/future/uroborosql/coverage/reports/html/SqlCoverageReport.java index f9d6c5a4..ef2cae28 100644 --- a/src/main/java/jp/co/future/uroborosql/coverage/reports/html/SqlCoverageReport.java +++ b/src/main/java/jp/co/future/uroborosql/coverage/reports/html/SqlCoverageReport.java @@ -23,20 +23,15 @@ import java.util.stream.Collectors; import java.util.stream.IntStream; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.coverage.CoverageHandler; import jp.co.future.uroborosql.coverage.LineRange; import jp.co.future.uroborosql.coverage.PassedRoute; import jp.co.future.uroborosql.coverage.Range; import jp.co.future.uroborosql.coverage.Ranges; +import jp.co.future.uroborosql.log.support.CoverageLoggingSupport; import jp.co.future.uroborosql.utils.ObjectUtils; -class SqlCoverageReport { - /** カバレッジロガー. */ - private static final Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); - +class SqlCoverageReport implements CoverageLoggingSupport { private final String name; private final String sql; private final Path path; @@ -129,7 +124,10 @@ void writeHtml() { writeSuffix(writer); } } catch (IOException ex) { - COVERAGE_LOG.error(ex.getMessage(), ex); + errorWith(COVERAGE_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } updated = false; } diff --git a/src/main/java/jp/co/future/uroborosql/event/subscriber/AbstractSecretColumnEventSubscriber.java b/src/main/java/jp/co/future/uroborosql/event/subscriber/AbstractSecretColumnEventSubscriber.java index 1bbe31cb..449764ef 100644 --- a/src/main/java/jp/co/future/uroborosql/event/subscriber/AbstractSecretColumnEventSubscriber.java +++ b/src/main/java/jp/co/future/uroborosql/event/subscriber/AbstractSecretColumnEventSubscriber.java @@ -27,10 +27,11 @@ import javax.crypto.spec.IvParameterSpec; import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.event.AfterSqlQueryEvent; import jp.co.future.uroborosql.event.BeforeSetParameterEvent; +import jp.co.future.uroborosql.log.support.EventLoggingSupport; +import jp.co.future.uroborosql.log.support.SettingLoggingSupport; import jp.co.future.uroborosql.parameter.Parameter; import jp.co.future.uroborosql.utils.CaseFormat; import jp.co.future.uroborosql.utils.ObjectUtils; @@ -45,12 +46,10 @@ * @since v1.0.0 * */ -public abstract class AbstractSecretColumnEventSubscriber extends EventSubscriber { +public abstract class AbstractSecretColumnEventSubscriber extends EventSubscriber + implements EventLoggingSupport, SettingLoggingSupport { /** イベントロガー */ - private static final Logger EVENT_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.event.secretcolumn"); - - /** 設定ロガー */ - private static final Logger SETTING_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.setting"); + private static final Logger EVENT_LOG = EventLoggingSupport.getEventLogger("secretcolumn"); /** 暗号キー */ private SecretKey secretKey = null; @@ -115,28 +114,41 @@ public void initialize() { KeyStore store; try { if (ObjectUtils.isBlank(getKeyStoreFilePath())) { - SETTING_LOG.error("Invalid KeyStore file path. Path:{}", getKeyStoreFilePath()); + errorWith(SETTING_LOG) + .setMessage("Invalid KeyStore file path. Path:{}") + .addArgument(getKeyStoreFilePath()) + .log(); setSkip(true); return; } var storeFile = toPath(getKeyStoreFilePath()); if (!Files.exists(storeFile)) { - SETTING_LOG.error("Not found KeyStore file path. Path:{}", getKeyStoreFilePath()); + errorWith(SETTING_LOG) + .setMessage("Not found KeyStore file path. Path:{}") + .addArgument(getKeyStoreFilePath()) + .log(); setSkip(true); return; } if (Files.isDirectory(storeFile)) { - SETTING_LOG.error("Invalid KeyStore file path. Path:{}", getKeyStoreFilePath()); + errorWith(SETTING_LOG) + .setMessage("Invalid KeyStore file path. Path:{}") + .addArgument(getKeyStoreFilePath()) + .log(); setSkip(true); return; } if (ObjectUtils.isBlank(getStorePassword())) { - SETTING_LOG.error("Invalid password for access KeyStore."); + errorWith(SETTING_LOG) + .setMessage("Invalid password for access KeyStore.") + .log(); setSkip(true); return; } if (ObjectUtils.isBlank(getAlias())) { - SETTING_LOG.error("No alias for access KeyStore."); + errorWith(SETTING_LOG) + .setMessage("No alias for access KeyStore.") + .log(); setSkip(true); return; } @@ -158,7 +170,10 @@ public void initialize() { encryptCipher.init(Cipher.ENCRYPT_MODE, secretKey); useIV = encryptCipher.getIV() != null; } catch (Exception ex) { - SETTING_LOG.error("Failed to acquire secret key.", ex); + errorWith(SETTING_LOG) + .setMessage("Failed to acquire secret key.") + .setCause(ex) + .log(); setSkip(true); } @@ -194,14 +209,16 @@ void beforeSetParameter(final BeforeSetParameterEvent evt) { new Parameter(key, encrypt(encryptCipher, secretKey, objStr))); } } catch (Exception ex) { - if (EVENT_LOG.isWarnEnabled()) { - EVENT_LOG.warn("Encrypt Exception key:{}", key); - } + warnWith(EVENT_LOG) + .setMessage("Encrypt Exception key:{}") + .addArgument(key) + .log(); } } } } } + } void afterSqlQuery(final AfterSqlQueryEvent evt) { @@ -214,7 +231,10 @@ void afterSqlQuery(final AfterSqlQueryEvent evt) { evt.setResultSet(new SecretResultSet(evt.getResultSet(), this.createDecryptor(), getCryptColumnNames(), getCharset())); } catch (Exception ex) { - EVENT_LOG.error("Failed to create SecretResultSet.", ex); + errorWith(EVENT_LOG) + .setMessage("Failed to create SecretResultSet.") + .setCause(ex) + .log(); } } @@ -371,9 +391,12 @@ public T setCharset(final String charset) { this.charset = Charset.forName(charset); } catch (UnsupportedCharsetException ex) { this.charset = StandardCharsets.UTF_8; - SETTING_LOG.error( - "The specified character set could not be converted to {}. Set the default character set({}).", - charset, this.charset); + errorWith(SETTING_LOG) + .setMessage( + "The specified character set could not be converted to {}. Set the default character set({}).") + .addArgument(charset) + .addArgument(this.charset) + .log(); } return (T) this; } diff --git a/src/main/java/jp/co/future/uroborosql/event/subscriber/AuditLogEventSubscriber.java b/src/main/java/jp/co/future/uroborosql/event/subscriber/AuditLogEventSubscriber.java index c1c4d2b4..ddb1fdb6 100644 --- a/src/main/java/jp/co/future/uroborosql/event/subscriber/AuditLogEventSubscriber.java +++ b/src/main/java/jp/co/future/uroborosql/event/subscriber/AuditLogEventSubscriber.java @@ -10,12 +10,12 @@ import java.sql.SQLException; import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.context.ExecutionContext; import jp.co.future.uroborosql.event.AfterSqlBatchEvent; import jp.co.future.uroborosql.event.AfterSqlQueryEvent; import jp.co.future.uroborosql.event.AfterSqlUpdateEvent; +import jp.co.future.uroborosql.log.support.EventLoggingSupport; /** * 監査用ログを出力するイベントサブスクライバ @@ -24,9 +24,9 @@ * @since v1.0.0 * */ -public class AuditLogEventSubscriber extends EventSubscriber { +public class AuditLogEventSubscriber extends EventSubscriber implements EventLoggingSupport { /** イベントロガー */ - private static final Logger EVENT_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.event.auditlog"); + private static final Logger EVENT_LOG = EventLoggingSupport.getEventLogger("auditlog"); /** 機能名取得用のパラメータキー名 */ private String funcIdKey = "_funcId"; @@ -76,77 +76,54 @@ void afterSqlQuery(final AfterSqlQueryEvent evt) { // ここでの例外は実処理に影響を及ぼさないよう握りつぶす } - var userName = getParam(evt.getExecutionContext(), userNameKey); - if (userName == null) { - // ユーザ名が設定されていない時 - userName = DEFAULT_USER_NAME; - } - - var funcId = getParam(evt.getExecutionContext(), funcIdKey); - if (funcId == null) { - // 機能IDが設定されていない時 - funcId = DEFAULT_FUNC_ID; - } - - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("AuditData: {}", new AuditData(userName, - funcId, - evt.getExecutionContext().getSqlId(), - evt.getExecutionContext().getSqlName(), - evt.getExecutionContext().getExecutableSql(), - rowCount)); - } + var userName = getParam(evt.getExecutionContext(), userNameKey, DEFAULT_USER_NAME); + var funcId = getParam(evt.getExecutionContext(), funcIdKey, DEFAULT_FUNC_ID); + var reportRowCount = rowCount; + debugWith(EVENT_LOG) + .setMessage("AuditData: {}") + .addArgument(() -> new AuditData(userName, + funcId, + evt.getExecutionContext().getSqlId(), + evt.getExecutionContext().getSqlName(), + evt.getExecutionContext().getExecutableSql(), + reportRowCount)) + .log(); } void afterSqlUpdate(final AfterSqlUpdateEvent evt) { - var userName = getParam(evt.getExecutionContext(), userNameKey); - if (userName == null) { - // ユーザ名が設定されていない時 - userName = DEFAULT_USER_NAME; - } - - var funcId = getParam(evt.getExecutionContext(), funcIdKey); - if (funcId == null) { - // 機能IDが設定されていない時 - funcId = DEFAULT_FUNC_ID; - } - - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("AuditData: {}", new AuditData(userName, - funcId, - evt.getExecutionContext().getSqlId(), - evt.getExecutionContext().getSqlName(), - evt.getExecutionContext().getExecutableSql(), - evt.getCount())); - } + var userName = getParam(evt.getExecutionContext(), userNameKey, DEFAULT_USER_NAME); + var funcId = getParam(evt.getExecutionContext(), funcIdKey, DEFAULT_FUNC_ID); + debugWith(EVENT_LOG) + .setMessage("AuditData: {}") + .addArgument(() -> new AuditData(userName, + funcId, + evt.getExecutionContext().getSqlId(), + evt.getExecutionContext().getSqlName(), + evt.getExecutionContext().getExecutableSql(), + evt.getCount())) + .log(); } void afterSqlBatch(final AfterSqlBatchEvent evt) { - var userName = getParam(evt.getExecutionContext(), userNameKey); - if (userName == null) { - // ユーザ名が設定されていない時 - userName = DEFAULT_USER_NAME; - } - - var funcId = getParam(evt.getExecutionContext(), funcIdKey); - if (funcId == null) { - // 機能IDが設定されていない時 - funcId = DEFAULT_FUNC_ID; - } - var rowCount = -1; - if (EVENT_LOG.isDebugEnabled()) { - try { - rowCount = evt.getPreparedStatement().getUpdateCount(); - } catch (SQLException ex) { - // ここでの例外は実処理に影響を及ぼさないよう握りつぶす - } - EVENT_LOG.debug("AuditData: {}", new AuditData(userName, - funcId, - evt.getExecutionContext().getSqlId(), - evt.getExecutionContext().getSqlName(), - evt.getExecutionContext().getExecutableSql(), - rowCount)); - } + var userName = getParam(evt.getExecutionContext(), userNameKey, DEFAULT_USER_NAME); + var funcId = getParam(evt.getExecutionContext(), funcIdKey, DEFAULT_FUNC_ID); + debugWith(EVENT_LOG) + .setMessage("AuditData: {}") + .addArgument(() -> { + var rowCount = -1; + try { + rowCount = evt.getPreparedStatement().getUpdateCount(); + } catch (SQLException ex) { + // ここでの例外は実処理に影響を及ぼさないよう握りつぶす + } + return new AuditData(userName, + funcId, + evt.getExecutionContext().getSqlId(), + evt.getExecutionContext().getSqlName(), + evt.getExecutionContext().getExecutableSql(), + rowCount); + }) + .log(); } /** @@ -176,12 +153,13 @@ public AuditLogEventSubscriber setUserNameKey(final String userNameKey) { * * @param ctx ExecutionContext * @param key パラメータのキー + * @param nullDefault パラメータ値が取得できなかった時のデフォルト値 * @return パラメータの値。キーに対するパラメータが存在しない場合はnull. */ - private String getParam(final ExecutionContext ctx, final String key) { + private String getParam(final ExecutionContext ctx, final String key, final String nullDefault) { var param = ctx.getParam(key); if (param == null) { - return null; + return nullDefault; } else { return String.valueOf(param.getValue()); } diff --git a/src/main/java/jp/co/future/uroborosql/event/subscriber/DebugEventSubscriber.java b/src/main/java/jp/co/future/uroborosql/event/subscriber/DebugEventSubscriber.java index 741b5854..8634d014 100644 --- a/src/main/java/jp/co/future/uroborosql/event/subscriber/DebugEventSubscriber.java +++ b/src/main/java/jp/co/future/uroborosql/event/subscriber/DebugEventSubscriber.java @@ -9,7 +9,6 @@ import java.sql.SQLException; import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.event.AfterBeginTransactionEvent; import jp.co.future.uroborosql.event.AfterGetOutParameterEvent; @@ -18,6 +17,7 @@ import jp.co.future.uroborosql.event.AfterSqlUpdateEvent; import jp.co.future.uroborosql.event.BeforeEndTransactionEvent; import jp.co.future.uroborosql.event.BeforeSetParameterEvent; +import jp.co.future.uroborosql.log.support.EventLoggingSupport; /** * デバッグログを出力するEventSubscriber @@ -25,9 +25,9 @@ * @author H.Sugimoto * @since v1.0.0 */ -public class DebugEventSubscriber extends EventSubscriber { +public class DebugEventSubscriber extends EventSubscriber implements EventLoggingSupport { /** ロガー */ - private static final Logger EVENT_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.event.debug"); + private static final Logger EVENT_LOG = EventLoggingSupport.getEventLogger("debug"); @Override public void initialize() { @@ -41,77 +41,91 @@ public void initialize() { } void afterBeginTransaction(final AfterBeginTransactionEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - try { - EVENT_LOG.debug("Begin Transaction - connection:{}, requiredNew:{}, transactionLevel:{}, occurredOn:{}", - evt.getTransactionContext().getConnection(), - evt.isRequiredNew(), - evt.getTransactionLevel(), - evt.occurredOn()); - } catch (SQLException ex) { - EVENT_LOG.error(ex.getMessage(), ex); - } + try { + debugWith(EVENT_LOG) + .setMessage("Begin Transaction - connection:{}, requiredNew:{}, transactionLevel:{}, occurredOn:{}") + .addArgument(evt.getTransactionContext().getConnection()) + .addArgument(evt.isRequiredNew()) + .addArgument(evt.getTransactionLevel()) + .addArgument(evt.occurredOn()) + .log(); + } catch (SQLException ex) { + errorWith(EVENT_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } void beforeEndTransaction(final BeforeEndTransactionEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - try { - EVENT_LOG.debug( - "End Transaction - connection:{}, requiredNew:{}, transactionLevel:{}, result:{}, occurredOn:{}", - evt.getTransactionContext().getConnection(), - evt.isRequiredNew(), - evt.getTransactionLevel(), - evt.getResult(), - evt.occurredOn()); - } catch (SQLException ex) { - EVENT_LOG.error(ex.getMessage(), ex); - } + try { + debugWith(EVENT_LOG) + .setMessage( + "End Transaction - connection:{}, requiredNew:{}, transactionLevel:{}, result:{}, occurredOn:{}") + .addArgument(evt.getTransactionContext().getConnection()) + .addArgument(evt.isRequiredNew()) + .addArgument(evt.getTransactionLevel()) + .addArgument(evt.getResult()) + .addArgument(evt.occurredOn()) + .log(); + } catch (SQLException ex) { + errorWith(EVENT_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } void beforeSetParameter(final BeforeSetParameterEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("Before Set Parameter - Parameter:{}", evt.getParameter()); - } + debugWith(EVENT_LOG) + .setMessage("Before Set Parameter - Parameter:{}") + .addArgument(evt.getParameter()) + .log(); } void afterGetOutParameter(final AfterGetOutParameterEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("After Get OutParameter - key:{}, value:{}. parameterIndex:{}", - evt.getKey(), evt.getValue(), evt.getParameterIndex()); - } + debugWith(EVENT_LOG) + .setMessage("After Get OutParameter - key:{}, value:{}. parameterIndex:{}") + .addArgument(evt.getKey()) + .addArgument(evt.getValue()) + .addArgument(evt.getParameterIndex()) + .log(); } void afterSqlQuery(final AfterSqlQueryEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("Execute Query - sqlName:{} executed.", evt.getExecutionContext().getSqlName()); - EVENT_LOG.trace("Execute Query sql:{}", evt.getPreparedStatement()); - } + debugWith(EVENT_LOG) + .setMessage("Execute Query - sqlName:{} executed.") + .addArgument(evt.getExecutionContext().getSqlName()) + .log(); + traceWith(EVENT_LOG) + .setMessage("Execute Query sql:{}") + .addArgument(evt.getPreparedStatement()) + .log(); } void afterSqlUpdate(final AfterSqlUpdateEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("Execute Update - sqlName:{} executed. Count:{} items.", - evt.getExecutionContext().getSqlName(), evt.getCount()); - } + debugWith(EVENT_LOG) + .setMessage("Execute Update - sqlName:{} executed. Count:{} items.") + .addArgument(evt.getExecutionContext().getSqlName()) + .addArgument(evt.getCount()) + .log(); } void afterSqlBatch(final AfterSqlBatchEvent evt) { - if (EVENT_LOG.isDebugEnabled()) { - var counts = evt.getCounts(); - try { - counts = new int[] { evt.getPreparedStatement().getUpdateCount() }; - } catch (SQLException ex) { - EVENT_LOG.error(ex.getMessage(), ex); - } - - var builder = new StringBuilder(); - for (int val : counts) { - builder.append(val).append(", "); - } - EVENT_LOG.debug("Execute Update - sqlName:{} executed. Results:{}", - evt.getExecutionContext().getSqlName(), counts); - } + debugWith(EVENT_LOG) + .setMessage("Execute Update - sqlName:{} executed. Results:{}") + .addArgument(evt.getExecutionContext().getSqlName()) + .addArgument(() -> { + try { + return new int[] { evt.getPreparedStatement().getUpdateCount() }; + } catch (SQLException ex) { + errorWith(EVENT_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); + return evt.getCounts(); + } + }) + .log(); } } \ No newline at end of file diff --git a/src/main/java/jp/co/future/uroborosql/event/subscriber/DumpResultEventSubscriber.java b/src/main/java/jp/co/future/uroborosql/event/subscriber/DumpResultEventSubscriber.java index 8d723e49..84abd4c9 100644 --- a/src/main/java/jp/co/future/uroborosql/event/subscriber/DumpResultEventSubscriber.java +++ b/src/main/java/jp/co/future/uroborosql/event/subscriber/DumpResultEventSubscriber.java @@ -20,9 +20,9 @@ import java.util.Map; import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.event.AfterSqlQueryEvent; +import jp.co.future.uroborosql.log.support.EventLoggingSupport; import jp.co.future.uroborosql.utils.ObjectUtils; /** @@ -36,9 +36,12 @@ * @since v1.0.0 * */ -public class DumpResultEventSubscriber extends EventSubscriber { +public class DumpResultEventSubscriber extends EventSubscriber implements EventLoggingSupport { + /** 改行文字 */ + private static final String LINE_SEPARATOR = System.lineSeparator(); + /** ロガー */ - private static final Logger EVENT_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.event.dumpresult"); + private static final Logger EVENT_LOG = EventLoggingSupport.getEventLogger("dumpresult"); /** 文字数計算用のエンコーディング */ private static final String ENCODING_SHIFT_JIS = "Shift-JIS"; @@ -57,16 +60,16 @@ public void initialize() { void afterSqlQuery(final AfterSqlQueryEvent evt) { try { if (evt.getResultSet().getType() == ResultSet.TYPE_FORWARD_ONLY) { - if (EVENT_LOG.isWarnEnabled()) { - EVENT_LOG.warn( - "ResultSet type is TYPE_FORWARD_ONLY. DumpResultEventSubscriber use ResultSet#beforeFirst(). Please Set TYPE_SCROLL_INSENSITIVE or TYPE_SCROLL_SENSITIVE."); - } - } - if (EVENT_LOG.isDebugEnabled()) { - EVENT_LOG.debug("{}", displayResult(evt.getResultSet())); + warnWith(EVENT_LOG) + .log("ResultSet type is TYPE_FORWARD_ONLY. DumpResultEventSubscriber use ResultSet#beforeFirst(). Please Set TYPE_SCROLL_INSENSITIVE or TYPE_SCROLL_SENSITIVE."); } + debugWith(EVENT_LOG) + .log(() -> displayResult(evt.getResultSet()).toString()); } catch (SQLException ex) { - EVENT_LOG.warn(ex.getMessage(), ex); + warnWith(EVENT_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } @@ -103,17 +106,17 @@ private StringBuilder displayResult(final ResultSet rs) { rows.add(data); } - var builder = new StringBuilder(System.lineSeparator()); + var builder = new StringBuilder(LINE_SEPARATOR); // ヘッダ部出力 builder.append("+"); for (var key : keys) { builder.append(ObjectUtils.repeat('-', maxLengthList.get(key))).append("+"); } - builder.append(System.lineSeparator()).append("|"); + builder.append(LINE_SEPARATOR).append("|"); for (var key : keys) { builder.append(fillHeader(key, maxLengthList.get(key))).append("|"); } - builder.append(System.lineSeparator()).append("+"); + builder.append(LINE_SEPARATOR).append("+"); for (var key : keys) { builder.append(ObjectUtils.repeat('-', maxLengthList.get(key))).append("+"); } @@ -121,7 +124,7 @@ private StringBuilder displayResult(final ResultSet rs) { // データ部出力 if (rows.isEmpty()) { - builder.append(System.lineSeparator()).append("|"); + builder.append(LINE_SEPARATOR).append("|"); var len = 1; for (var key : keys) { len = len + maxLengthList.get(key) + 1; @@ -134,14 +137,14 @@ private StringBuilder displayResult(final ResultSet rs) { } } else { for (var row : rows) { - builder.append(System.lineSeparator()).append("|"); + builder.append(LINE_SEPARATOR).append("|"); for (var key : keys) { builder.append(fillData(row.get(key), maxLengthList.get(key))).append("|"); } } } - builder.append(System.lineSeparator()).append("+"); + builder.append(LINE_SEPARATOR).append("+"); for (var key : keys) { builder.append(ObjectUtils.repeat('-', maxLengthList.get(key))).append("+"); } @@ -153,7 +156,10 @@ private StringBuilder displayResult(final ResultSet rs) { return builder; } catch (Exception ex) { - EVENT_LOG.error(ex.getMessage(), ex); + errorWith(EVENT_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } return null; } diff --git a/src/main/java/jp/co/future/uroborosql/expr/AbstractExpressionParser.java b/src/main/java/jp/co/future/uroborosql/expr/AbstractExpressionParser.java index 8797886c..6e57d9fa 100644 --- a/src/main/java/jp/co/future/uroborosql/expr/AbstractExpressionParser.java +++ b/src/main/java/jp/co/future/uroborosql/expr/AbstractExpressionParser.java @@ -7,13 +7,14 @@ package jp.co.future.uroborosql.expr; import jp.co.future.uroborosql.config.SqlConfig; +import jp.co.future.uroborosql.log.support.ParserLoggingSupport; /** * 評価式パーサの共通親クラス * * @author H.Sugimoto */ -public abstract class AbstractExpressionParser implements ExpressionParser { +public abstract class AbstractExpressionParser implements ExpressionParser, ParserLoggingSupport { /** SqlConfig */ private SqlConfig sqlConfig; diff --git a/src/main/java/jp/co/future/uroborosql/expr/ognl/OgnlExpressionParser.java b/src/main/java/jp/co/future/uroborosql/expr/ognl/OgnlExpressionParser.java index 6eb630ff..787eca07 100644 --- a/src/main/java/jp/co/future/uroborosql/expr/ognl/OgnlExpressionParser.java +++ b/src/main/java/jp/co/future/uroborosql/expr/ognl/OgnlExpressionParser.java @@ -10,12 +10,10 @@ import java.util.Objects; import java.util.Set; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.exception.ExpressionRuntimeException; import jp.co.future.uroborosql.expr.AbstractExpressionParser; import jp.co.future.uroborosql.expr.Expression; +import jp.co.future.uroborosql.log.support.ParserLoggingSupport; import jp.co.future.uroborosql.parser.TransformContext; import jp.co.future.uroborosql.utils.SqlFunction; import ognl.ASTProperty; @@ -30,9 +28,6 @@ * @author H.Sugimoto */ public class OgnlExpressionParser extends AbstractExpressionParser { - /** パーサーロガー */ - private static final Logger PARSER_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.parser"); - /** * コンストラクタ */ @@ -70,7 +65,7 @@ public Expression parse(final String expression) { * * @author H.Sugimoto */ - private static class OgnlExpression implements Expression { + private static class OgnlExpression implements Expression, ParserLoggingSupport { private final Object expression; /** @@ -118,7 +113,10 @@ public StringBuilder dumpNode(final Object context) { .append("],"); } catch (OgnlException ex) { // ダンプ処理でシステムが止まっては困るのでログ出力して握りつぶす - PARSER_LOG.warn(ex.getMessage(), ex); + warnWith(PARSER_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } } diff --git a/src/main/java/jp/co/future/uroborosql/expr/spel/SpelExpressionParser.java b/src/main/java/jp/co/future/uroborosql/expr/spel/SpelExpressionParser.java index 0908b0c9..3b47489d 100644 --- a/src/main/java/jp/co/future/uroborosql/expr/spel/SpelExpressionParser.java +++ b/src/main/java/jp/co/future/uroborosql/expr/spel/SpelExpressionParser.java @@ -10,8 +10,6 @@ import java.util.Objects; import java.util.Set; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import org.springframework.expression.EvaluationException; import org.springframework.expression.spel.ExpressionState; import org.springframework.expression.spel.SpelNode; @@ -30,9 +28,6 @@ * @author H.Sugimoto */ public class SpelExpressionParser extends AbstractExpressionParser { - /** パーサーロガー */ - private static final Logger PARSER_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.parser"); - /** 評価式のパーサー */ private static final org.springframework.expression.ExpressionParser parser = new org.springframework.expression.spel.standard.SpelExpressionParser(); @@ -140,7 +135,10 @@ public StringBuilder dumpNode(final Object context) { .append("],"); } catch (EvaluationException ex) { // ダンプ処理でシステムが止まっては困るのでログ出力して握りつぶす - PARSER_LOG.warn(ex.getMessage(), ex); + warnWith(PARSER_LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); } } } diff --git a/src/main/java/jp/co/future/uroborosql/log/support/CoverageLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/CoverageLoggingSupport.java new file mode 100644 index 00000000..b83f286f --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/CoverageLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface CoverageLoggingSupport extends LoggerBase { + /** SQLカバレッジ用ロガー */ + Logger COVERAGE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.coverage"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/EventLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/EventLoggingSupport.java new file mode 100644 index 00000000..f9d28b86 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/EventLoggingSupport.java @@ -0,0 +1,16 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface EventLoggingSupport extends LoggerBase { + static Logger getEventLogger(final String eventName) { + return LoggerFactory.getLogger("jp.co.future.uroborosql.event." + eventName); + } +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/LoggerBase.java b/src/main/java/jp/co/future/uroborosql/log/support/LoggerBase.java new file mode 100644 index 00000000..1c220ab1 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/LoggerBase.java @@ -0,0 +1,132 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.MDC; +import org.slf4j.spi.LoggingEventBuilder; +import org.slf4j.spi.NOPLoggingEventBuilder; + +/** + * ログ出力する際の共通親インタフェース + */ +public interface LoggerBase { + /** すべてのログ出力を抑止するためのMDCキー */ + String SUPPRESS_LOG_OUTPUT = "UroboroSQL_SuppressLogOutput"; + + /** パラメータログ出力を抑止するためのMDCキー */ + String SUPPRESS_PARAMETER_LOG_OUTPUT = "UroboroSQL_SuppressParameterLogOutput"; + + /** + * Uroborosqlが出力するログを抑止する. + */ + default void suppressLogging() { + MDC.put(SUPPRESS_LOG_OUTPUT, SUPPRESS_LOG_OUTPUT); + } + + /** + * Uroborosqlが出力するログが抑止されているかを返す. + * @return ログが抑止されている場合true + */ + default boolean isSuppressLogging() { + return MDC.get(SUPPRESS_LOG_OUTPUT) != null; + } + + /** + * Uroborosqlが出力するログが抑止されている場合、抑止を終了する. + */ + default void releaseLogging() { + MDC.remove(SUPPRESS_LOG_OUTPUT); + } + + /** + * Uroborosqlが出力するパラメータログを抑止する. + */ + default void suppressParameterLogging() { + MDC.put(SUPPRESS_PARAMETER_LOG_OUTPUT, SUPPRESS_PARAMETER_LOG_OUTPUT); + } + + /** + * Uroborosqlが出力するパラメータログが抑止されているかを返す. + * @return パラメータログが抑止されている場合true + */ + default boolean isSuppressParameterLogging() { + return MDC.get(SUPPRESS_PARAMETER_LOG_OUTPUT) != null; + } + + /** + * Uroborosqlが出力するパラメータログが抑止されている場合、抑止を終了する. + */ + default void releaseParameterLogging() { + MDC.remove(SUPPRESS_PARAMETER_LOG_OUTPUT); + } + + /** + * ERRORレベルの fluent-logging エントリーポイント. ログ抑止されている場合は出力しない. + * @param logger ログ出力するためのロガー + * @return ERRORレベルに適したLoggingEventBuilderインスタンス + */ + default LoggingEventBuilder errorWith(final Logger logger) { + if (!isSuppressLogging()) { + return logger.atError(); + } else { + return NOPLoggingEventBuilder.singleton(); + } + } + + /** + * WARNレベルの fluent-logging エントリーポイント. ログ抑止されている場合は出力しない. + * @param logger ログ出力するためのロガー + * @return WARNレベルに適したLoggingEventBuilderインスタンス + */ + default LoggingEventBuilder warnWith(final Logger logger) { + if (!isSuppressLogging()) { + return logger.atWarn(); + } else { + return NOPLoggingEventBuilder.singleton(); + } + } + + /** + * INFOレベルの fluent-logging エントリーポイント. ログ抑止されている場合は出力しない. + * @param logger ログ出力するためのロガー + * @return INFOレベルに適したLoggingEventBuilderインスタンス + */ + default LoggingEventBuilder infoWith(final Logger logger) { + if (!isSuppressLogging()) { + return logger.atInfo(); + } else { + return NOPLoggingEventBuilder.singleton(); + } + } + + /** + * DEBUGレベルの fluent-logging エントリーポイント. ログ抑止されている場合は出力しない. + * @param logger ログ出力するためのロガー + * @return DEBUGレベルに適したLoggingEventBuilderインスタンス + */ + default LoggingEventBuilder debugWith(final Logger logger) { + if (!isSuppressLogging()) { + return logger.atDebug(); + } else { + return NOPLoggingEventBuilder.singleton(); + } + } + + /** + * TRACEレベルの fluent-logging エントリーポイント. ログ抑止されている場合は出力しない. + * @param logger ログ出力するためのロガー + * @return TRACEレベルに適したLoggingEventBuilderインスタンス + */ + default LoggingEventBuilder traceWith(final Logger logger) { + if (!isSuppressLogging()) { + return logger.atTrace(); + } else { + return NOPLoggingEventBuilder.singleton(); + } + } +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/ParserLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/ParserLoggingSupport.java new file mode 100644 index 00000000..06a25777 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/ParserLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface ParserLoggingSupport extends LoggerBase { + /** パーサーロガー */ + Logger PARSER_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.parser"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/PerformanceLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/PerformanceLoggingSupport.java new file mode 100644 index 00000000..bb73b1d1 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/PerformanceLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface PerformanceLoggingSupport extends LoggerBase { + /** パフォーマンスロガー */ + Logger PERFORMANCE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.performance"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/ReplLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/ReplLoggingSupport.java new file mode 100644 index 00000000..cc28da67 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/ReplLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface ReplLoggingSupport extends LoggerBase { + /** REPLロガー */ + Logger REPL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.repl"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/ServiceLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/ServiceLoggingSupport.java new file mode 100644 index 00000000..4c53bb17 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/ServiceLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface ServiceLoggingSupport extends LoggerBase { + /** ロガー */ + Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log.support"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/SettingLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/SettingLoggingSupport.java new file mode 100644 index 00000000..4942701d --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/SettingLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface SettingLoggingSupport extends LoggerBase { + /** 設定ロガー */ + Logger SETTING_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.setting"); +} diff --git a/src/main/java/jp/co/future/uroborosql/log/support/SqlLoggingSupport.java b/src/main/java/jp/co/future/uroborosql/log/support/SqlLoggingSupport.java new file mode 100644 index 00000000..82171674 --- /dev/null +++ b/src/main/java/jp/co/future/uroborosql/log/support/SqlLoggingSupport.java @@ -0,0 +1,15 @@ +/** + * Copyright (c) 2017-present, Future Corporation + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +package jp.co.future.uroborosql.log.support; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public interface SqlLoggingSupport extends LoggerBase { + /** SQLロガー */ + Logger SQL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql"); +} diff --git a/src/main/java/jp/co/future/uroborosql/node/AbstractNode.java b/src/main/java/jp/co/future/uroborosql/node/AbstractNode.java index d9ae0b97..35ec04e3 100644 --- a/src/main/java/jp/co/future/uroborosql/node/AbstractNode.java +++ b/src/main/java/jp/co/future/uroborosql/node/AbstractNode.java @@ -10,13 +10,14 @@ import java.util.List; import jp.co.future.uroborosql.coverage.PassedRoute; +import jp.co.future.uroborosql.log.support.ParserLoggingSupport; /** * SQLノードの抽象親クラス * * @author H.Sugimoto */ -public abstract class AbstractNode implements Node { +public abstract class AbstractNode implements Node, ParserLoggingSupport { /** 子ノード */ private final List children = new ArrayList<>(); diff --git a/src/main/java/jp/co/future/uroborosql/node/IfNode.java b/src/main/java/jp/co/future/uroborosql/node/IfNode.java index 3c17c592..a27fb54e 100644 --- a/src/main/java/jp/co/future/uroborosql/node/IfNode.java +++ b/src/main/java/jp/co/future/uroborosql/node/IfNode.java @@ -6,9 +6,6 @@ */ package jp.co.future.uroborosql.node; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.coverage.PassedRoute; import jp.co.future.uroborosql.exception.IllegalBoolExpressionRuntimeException; import jp.co.future.uroborosql.expr.ExpressionParser; @@ -20,9 +17,6 @@ * @author H.Sugimoto */ public class IfNode extends BranchNode { - /** パーサーロガー */ - private static final Logger PARSER_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql.parser"); - private final ExpressionParser expressionParser; /** 評価式 */ private final String expression; @@ -103,9 +97,15 @@ public void accept(final TransformContext transformContext) { || Boolean.FALSE.toString().equalsIgnoreCase(expression)) { // 単純なBoolean評価の場合はログを出力しない } else { - var builder = expr.dumpNode(transformContext); - PARSER_LOG.info("Evaluation Expression:[{}], Result:[{}], Parameter:[{}]", expression, resultValue, - builder.length() == 0 ? "" : builder.substring(0, builder.length() - 1)); + infoWith(PARSER_LOG) + .setMessage("Evaluation Expression:[{}], Result:[{}], Parameter:[{}]") + .addArgument(expression) + .addArgument(resultValue) + .addArgument(() -> { + var builder = expr.dumpNode(transformContext); + return builder.length() == 0 ? "" : builder.substring(0, builder.length() - 1); + }) + .log(); } } passState(resultValue); diff --git a/src/main/java/jp/co/future/uroborosql/parameter/Parameter.java b/src/main/java/jp/co/future/uroborosql/parameter/Parameter.java index 18b74736..354298e8 100644 --- a/src/main/java/jp/co/future/uroborosql/parameter/Parameter.java +++ b/src/main/java/jp/co/future/uroborosql/parameter/Parameter.java @@ -13,10 +13,8 @@ import java.util.Map; import java.util.Objects; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -import org.slf4j.MDC; - +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; +import jp.co.future.uroborosql.log.support.SqlLoggingSupport; import jp.co.future.uroborosql.parameter.mapper.BindParameterMapperManager; import jp.co.future.uroborosql.utils.ObjectUtils; @@ -26,13 +24,7 @@ * * @author H.Sugimoto */ -public class Parameter { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - - /** SQLロガー */ - private static final Logger SQL_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.sql"); - +public class Parameter implements ServiceLoggingSupport, SqlLoggingSupport { /** 未設定のSQLType */ protected static final SQLType SQL_TYPE_NOT_SET = null; @@ -101,10 +93,10 @@ public Parameter createSubParameter(final String propertyName) { if (value instanceof Map) { subValue = ((Map) value).get(propertyName); if (subValue == null) { - if (LOG.isWarnEnabled()) { - LOG.warn("Set subparameter value to NULL because property can not be accessed.[{}]", - subParameterName); - } + warnWith(LOG) + .setMessage("Set subparameter value to NULL because property can not be accessed.[{}]") + .addArgument(subParameterName) + .log(); } } else { try { @@ -120,21 +112,24 @@ public Parameter createSubParameter(final String propertyName) { .getMethod(prefix + ObjectUtils.capitalize(propertyName)); subValue = method.invoke(value); } catch (Exception ex2) { - if (LOG.isWarnEnabled()) { - LOG.warn("Set subparameter value to NULL because property can not be accessed.[{}]", - subParameterName, ex2); - } + warnWith(LOG) + .setMessage("Set subparameter value to NULL because property can not be accessed.[{}]") + .addArgument(subParameterName) + .setCause(ex2) + .log(); } } catch (Exception ex) { - if (LOG.isWarnEnabled()) { - LOG.warn("Set subparameter value to NULL because property can not be accessed.[{}]", - subParameterName, ex); - } + warnWith(LOG) + .setMessage("Set subparameter value to NULL because property can not be accessed.[{}]") + .addArgument(subParameterName) + .setCause(ex) + .log(); } } } return new Parameter(subParameterName, subValue); + } /** @@ -186,8 +181,12 @@ protected int setInParameter(final PreparedStatement preparedStatement, final in * @param index パラメータインデックス */ protected void parameterLog(final int index) { - if (SQL_LOG.isInfoEnabled() && Boolean.FALSE.toString().equals(MDC.get("SuppressParameterLogOutput"))) { - SQL_LOG.info("Set the parameter.[INDEX[{}], {}]", index, this); + if (SQL_LOG.isInfoEnabled() && !isSuppressParameterLogging()) { + infoWith(SQL_LOG) + .setMessage("Set the parameter.[INDEX[{}], {}]") + .addArgument(index) + .addArgument(this) + .log(); } } diff --git a/src/main/java/jp/co/future/uroborosql/store/SqlResourceManager.java b/src/main/java/jp/co/future/uroborosql/store/SqlResourceManager.java index 6d12b430..e83896fd 100644 --- a/src/main/java/jp/co/future/uroborosql/store/SqlResourceManager.java +++ b/src/main/java/jp/co/future/uroborosql/store/SqlResourceManager.java @@ -10,13 +10,14 @@ import java.util.List; import jp.co.future.uroborosql.dialect.Dialect; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; /** * SQLリソース管理インターフェース * * @author H.Sugimoto */ -public interface SqlResourceManager { +public interface SqlResourceManager extends ServiceLoggingSupport { /** * 初期化
diff --git a/src/main/java/jp/co/future/uroborosql/store/SqlResourceManagerImpl.java b/src/main/java/jp/co/future/uroborosql/store/SqlResourceManagerImpl.java index 0a1bf012..ef52b99a 100644 --- a/src/main/java/jp/co/future/uroborosql/store/SqlResourceManagerImpl.java +++ b/src/main/java/jp/co/future/uroborosql/store/SqlResourceManagerImpl.java @@ -42,11 +42,9 @@ import java.util.stream.Collectors; import java.util.stream.StreamSupport; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.dialect.Dialect; import jp.co.future.uroborosql.exception.UroborosqlRuntimeException; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; import jp.co.future.uroborosql.utils.ObjectUtils; /** @@ -55,9 +53,6 @@ * @author H.Sugimoto */ public class SqlResourceManagerImpl implements SqlResourceManager { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - /** zip, jar内のファイルのscheme */ private static final String SCHEME_JAR = "jar"; /** ファイルシステム上のファイルのscheme */ @@ -234,7 +229,10 @@ public void initialize() { try { watcher = FileSystems.getDefault().newWatchService(); } catch (IOException ex) { - LOG.error("Can't start watcher service.", ex); + errorWith(LOG) + .setMessage("Can't start watcher service.") + .setCause(ex) + .log(); return; } } @@ -277,12 +275,14 @@ private void watchPath() { try { key = watcher.take(); } catch (InterruptedException ex) { - if (LOG.isDebugEnabled()) { - LOG.debug("WatchService caught InterruptedException."); - } + debugWith(LOG) + .log("WatchService caught InterruptedException."); break; } catch (Throwable ex) { - LOG.error("Unexpected exception occurred.", ex); + errorWith(LOG) + .setMessage("Unexpected exception occurred.") + .setCause(ex) + .log(); break; } @@ -299,9 +299,11 @@ private void watchPath() { var dir = watchDirs.get(key); var path = dir.resolve(evt.context()); - if (LOG.isDebugEnabled()) { - LOG.debug("file changed.({}). path={}", kind.name(), path); - } + debugWith(LOG) + .setMessage("file changed.({}). path={}") + .addArgument(kind.name()) + .addArgument(path) + .log(); var isSqlFile = path.toString().endsWith(fileExtension); if (Files.isDirectory(path) || !isSqlFile) { // ENTRY_DELETEの時はFiles.isDirectory()がfalseになるので拡張子での判定も行う @@ -412,14 +414,19 @@ protected void generateSqlInfos() { } else if (SCHEME_JAR.equalsIgnoreCase(scheme)) { traverseJar(url, loadPathSlash); } else { - if (LOG.isWarnEnabled()) { - LOG.warn("Unsupported scheme. scheme : {}, url : {}", scheme, url); - } + warnWith(LOG) + .setMessage("Unsupported scheme. scheme : {}, url : {}") + .addArgument(scheme) + .addArgument(url) + .log(); } } } } catch (IOException | URISyntaxException ex) { - LOG.error("Can't load sql files.", ex); + errorWith(LOG) + .setMessage("Can't load sql files.") + .setCause(ex) + .log(); } } @@ -532,9 +539,12 @@ private boolean validPath(final Path path) { * @param remove 削除指定。trueの場合、指定のPathを除外する。falseの場合は格納する */ private void traverseFile(final Path path, final boolean watch, final boolean remove) { - if (LOG.isTraceEnabled()) { - LOG.trace("traverseFile start. path : {}, watch : {}, remove : {}.", path, watch, remove); - } + traceWith(LOG) + .setMessage("traverseFile start. path : {}, watch : {}, remove : {}.") + .addArgument(path) + .addArgument(watch) + .addArgument(remove) + .log(); if (Files.notExists(path)) { return; } @@ -567,9 +577,11 @@ private void traverseFile(final Path path, final boolean watch, final boolean re */ @SuppressWarnings("resource") private void traverseJar(final URL url, final String loadPath) { - if (LOG.isTraceEnabled()) { - LOG.trace("traverseJar start. url : {}, loadPath : {}.", url, loadPath); - } + traceWith(LOG) + .setMessage("traverseJar start. url : {}, loadPath : {}.") + .addArgument(url) + .addArgument(loadPath) + .log(); FileSystem fs = null; try { var uri = url.toURI(); @@ -610,7 +622,7 @@ private void traverseJar(final URL url, final String loadPath) { /** * SQLファイルの情報を保持するオブジェクト */ - public static class SqlInfo { + public static class SqlInfo implements ServiceLoggingSupport { /** キーとなるsqlName */ private final String sqlName; /** 対象のDialect */ @@ -638,10 +650,13 @@ public static class SqlInfo { final List loadPaths, final Dialect dialect, final Charset charset) { - if (LOG.isTraceEnabled()) { - LOG.trace("SqlInfo - sqlName : {}, path : {}, dialect : {}, charset : {}.", - sqlName, path, dialect, charset); - } + traceWith(LOG) + .setMessage("SqlInfo - sqlName : {}, path : {}, dialect : {}, charset : {}.") + .addArgument(sqlName) + .addArgument(path) + .addArgument(dialect) + .addArgument(charset) + .log(); this.sqlName = sqlName; this.dialect = dialect; this.charset = charset; @@ -656,14 +671,16 @@ public static class SqlInfo { * @param path 対象のPath * @return 最終更新日時 */ - private static FileTime getLastModifiedTime(final Path path) { + private FileTime getLastModifiedTime(final Path path) { if (SCHEME_FILE.equalsIgnoreCase(path.toUri().getScheme())) { try { return Files.getLastModifiedTime(path); } catch (IOException ex) { - if (LOG.isWarnEnabled()) { - LOG.warn("Can't get lastModifiedTime. path:{}", path, ex); - } + warnWith(LOG) + .setMessage("Can't get lastModifiedTime. path:{}") + .addArgument(path) + .setCause(ex) + .log(); } } return FileTime.fromMillis(0L); @@ -722,9 +739,10 @@ private String getSqlBody() { try { var body = new String(Files.readAllBytes(path), charset); sqlBody = formatSqlBody(body); - if (LOG.isDebugEnabled()) { - LOG.debug("Loaded SQL template.[{}]", path); - } + debugWith(LOG) + .setMessage("Loaded SQL template.[{}]") + .addArgument(path) + .log(); } catch (IOException ex) { throw new UroborosqlRuntimeException("Failed to load SQL template[" + path.toAbsolutePath().toString() + "].", ex); @@ -745,9 +763,10 @@ private String getSqlBody() { var body = reader.lines() .collect(Collectors.joining(System.lineSeparator())); sqlBody = formatSqlBody(body); - if (LOG.isDebugEnabled()) { - LOG.debug("Loaded SQL template.[{}]", path); - } + debugWith(LOG) + .setMessage("Loaded SQL template.[{}]") + .addArgument(path) + .log(); } } catch (IOException ex) { throw new UroborosqlRuntimeException("Failed to load SQL template[" @@ -878,17 +897,22 @@ private SqlInfo computePath(final Path newPath, final boolean remove) { var currentTimeStamp = getLastModifiedTime(currentPath); if (!oldPath.equals(currentPath)) { replaceFlag = true; - if (LOG.isDebugEnabled()) { - LOG.debug("sql file switched. sqlName={}, oldPath={}, newPath={}, lastModified={}", sqlName, - oldPath, currentPath, currentTimeStamp.toString()); - } + debugWith(LOG) + .setMessage("sql file switched. sqlName={}, oldPath={}, newPath={}, lastModified={}") + .addArgument(sqlName) + .addArgument(oldPath) + .addArgument(currentPath) + .addArgument(currentTimeStamp) + .log(); } else { if (!this.lastModified.equals(currentTimeStamp)) { replaceFlag = true; - if (LOG.isDebugEnabled()) { - LOG.debug("sql file changed. sqlName={}, path={}, lastModified={}", sqlName, currentPath, - currentTimeStamp.toString()); - } + debugWith(LOG) + .setMessage("sql file changed. sqlName={}, path={}, lastModified={}") + .addArgument(sqlName) + .addArgument(currentPath) + .addArgument(currentTimeStamp) + .log(); } } diff --git a/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionContext.java b/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionContext.java index 8cb2db6a..8573ac08 100644 --- a/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionContext.java +++ b/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionContext.java @@ -17,9 +17,6 @@ import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentMap; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.connection.ConnectionContext; import jp.co.future.uroborosql.context.ExecutionContext; @@ -38,9 +35,6 @@ * @author ota */ class LocalTransactionContext implements TransactionContext { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - /** セーブポイント名リスト */ private final List savepointNames = new ArrayList<>(); @@ -366,9 +360,8 @@ public void close() { if (connection != null && !connection.isClosed()) { connection.close(); } else { - if (LOG.isWarnEnabled()) { - LOG.warn("Connection close was skipped because the connection was already closed."); - } + warnWith(LOG) + .log("Connection close was skipped because the connection was already closed."); } } catch (SQLException ex) { throw new UroborosqlSQLException(ex); diff --git a/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionManager.java b/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionManager.java index a6e168b2..f3a9c8c8 100644 --- a/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionManager.java +++ b/src/main/java/jp/co/future/uroborosql/tx/LocalTransactionManager.java @@ -16,9 +16,6 @@ import java.util.concurrent.ConcurrentLinkedDeque; import java.util.function.Supplier; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.connection.ConnectionContext; import jp.co.future.uroborosql.context.ExecutionContext; @@ -33,9 +30,6 @@ * @author ota */ public class LocalTransactionManager implements TransactionManager { - /** ロガー */ - private static final Logger LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.log"); - /** SQL設定クラス */ private final SqlConfig sqlConfig; @@ -189,7 +183,10 @@ public Connection getConnection() { try { return currentTxContext(true).orElseThrow().getConnection(); } catch (SQLException ex) { - LOG.error(ex.getMessage(), ex); + errorWith(LOG) + .setMessage(ex.getMessage()) + .setCause(ex) + .log(); return null; } } diff --git a/src/main/java/jp/co/future/uroborosql/tx/TransactionContext.java b/src/main/java/jp/co/future/uroborosql/tx/TransactionContext.java index 2c3ae83e..777b0bc4 100644 --- a/src/main/java/jp/co/future/uroborosql/tx/TransactionContext.java +++ b/src/main/java/jp/co/future/uroborosql/tx/TransactionContext.java @@ -15,8 +15,9 @@ import jp.co.future.uroborosql.config.SqlConfig; import jp.co.future.uroborosql.connection.ConnectionContext; import jp.co.future.uroborosql.context.ExecutionContext; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; -public interface TransactionContext extends AutoCloseable { +public interface TransactionContext extends AutoCloseable, ServiceLoggingSupport { /** * SqlConfigの取得. diff --git a/src/main/java/jp/co/future/uroborosql/tx/TransactionManager.java b/src/main/java/jp/co/future/uroborosql/tx/TransactionManager.java index 5888c9e9..54172343 100644 --- a/src/main/java/jp/co/future/uroborosql/tx/TransactionManager.java +++ b/src/main/java/jp/co/future/uroborosql/tx/TransactionManager.java @@ -10,13 +10,14 @@ import java.util.function.Supplier; import jp.co.future.uroborosql.connection.ConnectionManager; +import jp.co.future.uroborosql.log.support.ServiceLoggingSupport; /** * トランザクションマネージャ * * @author ota */ -public interface TransactionManager extends ConnectionManager { +public interface TransactionManager extends ConnectionManager, ServiceLoggingSupport { /** * トランザクションを実行します。 diff --git a/src/test/java/jp/co/future/uroborosql/SqlQueryTest.java b/src/test/java/jp/co/future/uroborosql/SqlQueryTest.java index d02253ed..4ff14697 100644 --- a/src/test/java/jp/co/future/uroborosql/SqlQueryTest.java +++ b/src/test/java/jp/co/future/uroborosql/SqlQueryTest.java @@ -17,6 +17,7 @@ import java.sql.Blob; import java.sql.Clob; import java.sql.NClob; +import java.sql.SQLException; import java.sql.Time; import java.sql.Timestamp; import java.time.DayOfWeek; @@ -94,6 +95,49 @@ void testQuery() throws Exception { assertFalse(rs.next(), "結果が複数件です。"); } + /** + * クエリ実行処理のテストケース。（ログ抑止 + */ + @Test + void testQueryWithSuppressLog() throws Exception { + // 事前条件 + cleanInsert(Paths.get("src/test/resources/data/setup", "testExecuteQuery.ltsv")); + + agent.required(() -> { + agent.suppressLogging(); + try (var rs = agent.query("example/select_product") + .param("product_id", List.of(new BigDecimal("0"), new BigDecimal("2"))) + .resultSet()) { + assertNotNull(rs, "ResultSetが取得できませんでした。"); + assertTrue(rs.next(), "結果が0件です。"); + assertEquals("0", rs.getString("PRODUCT_ID")); + assertEquals("商品名0", rs.getString("PRODUCT_NAME")); + assertEquals("ショウヒンメイゼロ", rs.getString("PRODUCT_KANA_NAME")); + assertEquals("1234567890123", rs.getString("JAN_CODE")); + assertEquals("0番目の商品", rs.getString("PRODUCT_DESCRIPTION")); + assertFalse(rs.next(), "結果が複数件です。"); + } catch (SQLException ex) { + fail(ex); + } + + agent.releaseLogging(); + try (var rs = agent.query("example/select_product") + .param("product_id", List.of(new BigDecimal("0"), new BigDecimal("2"))) + .resultSet()) { + assertNotNull(rs, "ResultSetが取得できませんでした。"); + assertTrue(rs.next(), "結果が0件です。"); + assertEquals("0", rs.getString("PRODUCT_ID")); + assertEquals("商品名0", rs.getString("PRODUCT_NAME")); + assertEquals("ショウヒンメイゼロ", rs.getString("PRODUCT_KANA_NAME")); + assertEquals("1234567890123", rs.getString("JAN_CODE")); + assertEquals("0番目の商品", rs.getString("PRODUCT_DESCRIPTION")); + assertFalse(rs.next(), "結果が複数件です。"); + } catch (SQLException ex) { + fail(ex); + } + }); + } + /** * クエリ実行処理のテストケース。 */ diff --git a/src/test/java/jp/co/future/uroborosql/expr/AbstractExpressionParserTest.java b/src/test/java/jp/co/future/uroborosql/expr/AbstractExpressionParserTest.java index 143112e1..087bf26a 100644 --- a/src/test/java/jp/co/future/uroborosql/expr/AbstractExpressionParserTest.java +++ b/src/test/java/jp/co/future/uroborosql/expr/AbstractExpressionParserTest.java @@ -17,8 +17,6 @@ import org.hamcrest.Matchers; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import jp.co.future.uroborosql.UroboroSQL; import jp.co.future.uroborosql.config.SqlConfig; @@ -26,6 +24,7 @@ import jp.co.future.uroborosql.context.ExecutionContextProviderImpl; import jp.co.future.uroborosql.context.test.TestEnum1; import jp.co.future.uroborosql.dialect.Dialect; +import jp.co.future.uroborosql.log.support.PerformanceLoggingSupport; import jp.co.future.uroborosql.parser.SqlParser; import jp.co.future.uroborosql.parser.SqlParserImpl; @@ -34,10 +33,7 @@ * * @author H.Sugimoto */ -public abstract class AbstractExpressionParserTest { - /** ロガー */ - protected static final Logger PERFORMANCE_LOG = LoggerFactory.getLogger("jp.co.future.uroborosql.performance"); - +public abstract class AbstractExpressionParserTest implements PerformanceLoggingSupport { protected SqlConfig sqlConfig; protected ExecutionContext ctx; protected static final DateTimeFormatter formatter = DateTimeFormatter.ofPattern("HH:mm:ss.SSSSSS"); @@ -201,7 +197,10 @@ void testCollectParams() { @Test void testPerformance() { if (PERFORMANCE_LOG.isDebugEnabled()) { - PERFORMANCE_LOG.debug("\r\n{}", getPerformanceHeader()); + debugWith(PERFORMANCE_LOG) + .setMessage("\r\n{}") + .addArgument(this::getPerformanceHeader) + .log(); var parser = getExpressionParser(); parser.setSqlConfig(sqlConfig); assertThat(parser.getSqlConfig(), is(sqlConfig)); @@ -214,8 +213,12 @@ void testPerformance() { var expr = parser.parse("param" + j + " == null"); expr.getValue(context); } - PERFORMANCE_LOG.debug("No{}:{}", i, - formatter.format(LocalTime.MIDNIGHT.plus(Duration.between(start, Instant.now())))); + debugWith(PERFORMANCE_LOG) + .setMessage("No{}:{}") + .addArgument(i) + .addArgument( + () -> formatter.format(LocalTime.MIDNIGHT.plus(Duration.between(start, Instant.now())))) + .log(); } } }