From 28fddfa1d97c0d8b5fb4a81cc7a72648e774b1f8 Mon Sep 17 00:00:00 2001 From: Artur Havliukovskyi Date: Sun, 30 Mar 2025 11:42:05 +0200 Subject: [PATCH] Migrate threshold to use Duration instead of seconds --- .../dsproxy/DataSourceProxyProperties.java | 22 ++++-- .../ProxyDataSourceBuilderConfigurer.java | 54 +++++++------- .../ProxyDataSourceConfigurationTests.java | 72 ++++++++++++++++--- .../sample/SampleController.java | 34 +++++++++ .../src/main/resources/application.yml | 4 +- 5 files changed, 141 insertions(+), 45 deletions(-) diff --git a/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/DataSourceProxyProperties.java b/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/DataSourceProxyProperties.java index 0956e78..91dd713 100644 --- a/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/DataSourceProxyProperties.java +++ b/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/DataSourceProxyProperties.java @@ -20,7 +20,10 @@ import net.ttddyy.dsproxy.listener.logging.CommonsLogLevel; import net.ttddyy.dsproxy.listener.logging.SLF4JLogLevel; import net.ttddyy.dsproxy.support.ProxyDataSourceBuilder; +import org.springframework.boot.convert.DurationUnit; +import java.time.Duration; +import java.time.temporal.ChronoUnit; import java.util.concurrent.TimeUnit; import java.util.logging.Level; @@ -51,7 +54,7 @@ public class DataSourceProxyProperties { /** * Use formatted SQL for logging query. * - * @see ProxyDataSourceBuilder#formatQuery(ProxyDataSourceBuilder.FormatQueryCallback) + * @see ProxyDataSourceBuilder#formatQuery(ProxyDataSourceBuilder.FormatQueryCallback) */ private boolean formatSql = false; @@ -194,9 +197,10 @@ public static class SlowQuery { */ private String logLevel = "WARN"; /** - * Number of seconds to consider query as slow. + * Query duration to consider the query slow and log it. */ - private long threshold = 300; + @DurationUnit(value = ChronoUnit.SECONDS) + private Duration threshold = Duration.ofSeconds(300); public boolean isEnableLogging() { return this.enableLogging; @@ -210,7 +214,15 @@ public String getLogLevel() { return this.logLevel; } + /** + * @deprecated Use {@link #getThresholdDuration()} instead. + */ + @Deprecated(since = "1.11.0", forRemoval = true) public long getThreshold() { + return this.threshold.toSeconds(); + } + + public Duration getThresholdDuration() { return this.threshold; } @@ -226,7 +238,7 @@ public void setLogLevel(String logLevel) { this.logLevel = logLevel; } - public void setThreshold(long threshold) { + public void setThreshold(Duration threshold) { this.threshold = threshold; } } @@ -237,4 +249,4 @@ public enum DataSourceProxyLogging { COMMONS, JUL } -} \ No newline at end of file +} diff --git a/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceBuilderConfigurer.java b/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceBuilderConfigurer.java index 21c299d..2dd4471 100644 --- a/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceBuilderConfigurer.java +++ b/datasource-decorator-spring-boot-autoconfigure/src/main/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceBuilderConfigurer.java @@ -71,43 +71,49 @@ public class ProxyDataSourceBuilderConfigurer { ProxyDataSourceBuilder.FormatQueryCallback formatQueryCallback; public void configure(ProxyDataSourceBuilder proxyDataSourceBuilder, DataSourceProxyProperties datasourceProxy) { + var query = datasourceProxy.getQuery(); + var slowQuery = datasourceProxy.getSlowQuery(); switch (datasourceProxy.getLogging()) { case SLF4J: { - if (datasourceProxy.getQuery().isEnableLogging()) { - proxyDataSourceBuilder.logQueryBySlf4j(toSlf4JLogLevel(datasourceProxy.getQuery().getLogLevel()), datasourceProxy.getQuery().getLoggerName()); + if (query.isEnableLogging()) { + proxyDataSourceBuilder.logQueryBySlf4j(toSlf4JLogLevel(query.getLogLevel()), query.getLoggerName()); } - if (datasourceProxy.getSlowQuery().isEnableLogging()) { - proxyDataSourceBuilder.logSlowQueryBySlf4j(datasourceProxy.getSlowQuery().getThreshold(), TimeUnit.SECONDS, - toSlf4JLogLevel(datasourceProxy.getSlowQuery().getLogLevel()), datasourceProxy.getSlowQuery().getLoggerName()); + if (slowQuery.isEnableLogging()) { + proxyDataSourceBuilder.logSlowQueryBySlf4j( + slowQuery.getThresholdDuration().toMillis(), TimeUnit.MILLISECONDS, + toSlf4JLogLevel(slowQuery.getLogLevel()), slowQuery.getLoggerName()); } break; } case JUL: { - if (datasourceProxy.getQuery().isEnableLogging()) { - proxyDataSourceBuilder.logQueryByJUL(toJULLogLevel(datasourceProxy.getQuery().getLogLevel()), datasourceProxy.getQuery().getLoggerName()); + if (query.isEnableLogging()) { + proxyDataSourceBuilder.logQueryByJUL(toJULLogLevel(query.getLogLevel()), query.getLoggerName()); } - if (datasourceProxy.getSlowQuery().isEnableLogging()) { - proxyDataSourceBuilder.logSlowQueryByJUL(datasourceProxy.getSlowQuery().getThreshold(), TimeUnit.SECONDS, - toJULLogLevel(datasourceProxy.getSlowQuery().getLogLevel()), datasourceProxy.getSlowQuery().getLoggerName()); + if (slowQuery.isEnableLogging()) { + proxyDataSourceBuilder.logSlowQueryByJUL( + slowQuery.getThresholdDuration().toMillis(), TimeUnit.MILLISECONDS, + toJULLogLevel(slowQuery.getLogLevel()), slowQuery.getLoggerName()); } break; } case COMMONS: { - if (datasourceProxy.getQuery().isEnableLogging()) { - proxyDataSourceBuilder.logQueryByCommons(toCommonsLogLevel(datasourceProxy.getQuery().getLogLevel()), datasourceProxy.getQuery().getLoggerName()); + if (query.isEnableLogging()) { + proxyDataSourceBuilder.logQueryByCommons(toCommonsLogLevel(query.getLogLevel()), query.getLoggerName()); } - if (datasourceProxy.getSlowQuery().isEnableLogging()) { - proxyDataSourceBuilder.logSlowQueryByCommons(datasourceProxy.getSlowQuery().getThreshold(), TimeUnit.SECONDS, - toCommonsLogLevel(datasourceProxy.getSlowQuery().getLogLevel()), datasourceProxy.getSlowQuery().getLoggerName()); + if (slowQuery.isEnableLogging()) { + proxyDataSourceBuilder.logSlowQueryByCommons( + slowQuery.getThresholdDuration().toMillis(), TimeUnit.MILLISECONDS, + toCommonsLogLevel(slowQuery.getLogLevel()), slowQuery.getLoggerName()); } break; } case SYSOUT: { - if (datasourceProxy.getQuery().isEnableLogging()) { + if (query.isEnableLogging()) { proxyDataSourceBuilder.logQueryToSysOut(); } - if (datasourceProxy.getSlowQuery().isEnableLogging()) { - proxyDataSourceBuilder.logSlowQueryToSysOut(datasourceProxy.getSlowQuery().getThreshold(), TimeUnit.SECONDS); + if (slowQuery.isEnableLogging()) { + proxyDataSourceBuilder.logSlowQueryToSysOut( + slowQuery.getThresholdDuration().toMillis(), TimeUnit.MILLISECONDS); } break; } @@ -201,14 +207,4 @@ private CommonsLogLevel toCommonsLogLevel(String logLevel) { throw new IllegalArgumentException("Unresolved log level " + logLevel + " for apache commons logger, " + "known levels " + Arrays.toString(CommonsLogLevel.values())); } - - private static boolean classExists(String fullQualifiedClassName) { - - try { - Class.forName(fullQualifiedClassName); - return true; - } catch (ClassNotFoundException e) { - return false; - } - } -} \ No newline at end of file +} diff --git a/datasource-decorator-spring-boot-autoconfigure/src/test/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceConfigurationTests.java b/datasource-decorator-spring-boot-autoconfigure/src/test/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceConfigurationTests.java index ac0e1bb..bcb26d0 100644 --- a/datasource-decorator-spring-boot-autoconfigure/src/test/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceConfigurationTests.java +++ b/datasource-decorator-spring-boot-autoconfigure/src/test/java/com/github/gavlyukovskiy/boot/jdbc/decorator/dsproxy/ProxyDataSourceConfigurationTests.java @@ -47,6 +47,7 @@ import javax.sql.DataSource; import java.util.List; import java.util.concurrent.ThreadLocalRandom; +import java.util.concurrent.TimeUnit; import static org.assertj.core.api.Assertions.assertThat; @@ -68,8 +69,10 @@ void testRegisterLogAndSlowQueryLogByDefaultToSlf4j() { DataSource dataSource = context.getBean(DataSource.class); ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); ChainListener chainListener = proxyDataSource.getProxyConfig().getQueryListener(); - assertThat(chainListener.getListeners()).extracting("class").contains(SLF4JSlowQueryListener.class); - assertThat(chainListener.getListeners()).extracting("class").contains(SLF4JQueryLoggingListener.class); + assertThat(chainListener.getListeners()).hasExactlyElementsOfTypes( + SLF4JQueryLoggingListener.class, + SLF4JSlowQueryListener.class + ); }); } @@ -81,8 +84,10 @@ void testRegisterLogAndSlowQueryLogByUsingSlf4j() { DataSource dataSource = context.getBean(DataSource.class); ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); ChainListener chainListener = proxyDataSource.getProxyConfig().getQueryListener(); - assertThat(chainListener.getListeners()).extracting("class").contains(SLF4JSlowQueryListener.class); - assertThat(chainListener.getListeners()).extracting("class").contains(SLF4JQueryLoggingListener.class); + assertThat(chainListener.getListeners()).hasExactlyElementsOfTypes( + SLF4JQueryLoggingListener.class, + SLF4JSlowQueryListener.class + ); }); } @@ -94,8 +99,10 @@ void testRegisterLogAndSlowQueryLogUsingSystemOut() { DataSource dataSource = context.getBean(DataSource.class); ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); ChainListener chainListener = proxyDataSource.getProxyConfig().getQueryListener(); - assertThat(chainListener.getListeners()).extracting("class").contains(SystemOutSlowQueryListener.class); - assertThat(chainListener.getListeners()).extracting("class").contains(SystemOutQueryLoggingListener.class); + assertThat(chainListener.getListeners()).hasExactlyElementsOfTypes( + SystemOutQueryLoggingListener.class, + SystemOutSlowQueryListener.class + ); }); } @@ -107,8 +114,10 @@ void testRegisterLogAndSlowQueryLogUsingJUL() { DataSource dataSource = context.getBean(DataSource.class); ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); ChainListener chainListener = proxyDataSource.getProxyConfig().getQueryListener(); - assertThat(chainListener.getListeners()).extracting("class").contains(JULSlowQueryListener.class); - assertThat(chainListener.getListeners()).extracting("class").contains(JULQueryLoggingListener.class); + assertThat(chainListener.getListeners()).hasExactlyElementsOfTypes( + JULQueryLoggingListener.class, + JULSlowQueryListener.class + ); }); } @@ -120,11 +129,54 @@ void testRegisterLogAndSlowQueryLogUsingApacheCommons() { DataSource dataSource = context.getBean(DataSource.class); ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); ChainListener chainListener = proxyDataSource.getProxyConfig().getQueryListener(); - assertThat(chainListener.getListeners()).extracting("class").contains(CommonsSlowQueryListener.class); - assertThat(chainListener.getListeners()).extracting("class").contains(CommonsQueryLoggingListener.class); + assertThat(chainListener.getListeners()).hasExactlyElementsOfTypes( + CommonsQueryLoggingListener.class, + CommonsSlowQueryListener.class + ); }); } + @Test + void testSlowQueryWithoutTimeUnit() { + ApplicationContextRunner contextRunner = this.contextRunner.withPropertyValues( + "decorator.datasource.datasource-proxy.slow-query.threshold:50" + ); + + contextRunner.run(context -> { + DataSource dataSource = context.getBean(DataSource.class); + ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); + var slowQueryListener = findListener(proxyDataSource, SLF4JSlowQueryListener.class); + assertThat(slowQueryListener.getThreshold()).isEqualTo(50000); + assertThat(slowQueryListener.getThresholdTimeUnit()).isEqualTo(TimeUnit.MILLISECONDS); + }); + } + + @Test + void testSlowQueryMilliseconds() { + ApplicationContextRunner contextRunner = this.contextRunner.withPropertyValues( + "decorator.datasource.datasource-proxy.slow-query.threshold:50ms" + ); + + contextRunner.run(context -> { + DataSource dataSource = context.getBean(DataSource.class); + ProxyDataSource proxyDataSource = (ProxyDataSource) ((DecoratedDataSource) dataSource).getDecoratedDataSource(); + var slowQueryListener = findListener(proxyDataSource, SLF4JSlowQueryListener.class); + assertThat(slowQueryListener.getThreshold()).isEqualTo(50); + assertThat(slowQueryListener.getThresholdTimeUnit()).isEqualTo(TimeUnit.MILLISECONDS); + }); + } + + private static T findListener(ProxyDataSource proxyDataSource, Class clazz) { + return proxyDataSource.getProxyConfig() + .getQueryListener() + .getListeners() + .stream() + .filter(clazz::isInstance) + .map(clazz::cast) + .findFirst() + .orElseThrow(() -> new IllegalStateException("Listener of type " + clazz.getName() + " not found")); + } + @Test void testCustomParameterAndQueryTransformer() { ApplicationContextRunner contextRunner = this.contextRunner.withUserConfiguration(CustomDataSourceProxyConfiguration.class); diff --git a/samples/datasource-proxy-sample/src/main/java/com/github/gavlyukovskiy/sample/SampleController.java b/samples/datasource-proxy-sample/src/main/java/com/github/gavlyukovskiy/sample/SampleController.java index ab3ff1a..5dc633b 100644 --- a/samples/datasource-proxy-sample/src/main/java/com/github/gavlyukovskiy/sample/SampleController.java +++ b/samples/datasource-proxy-sample/src/main/java/com/github/gavlyukovskiy/sample/SampleController.java @@ -17,13 +17,16 @@ package com.github.gavlyukovskiy.sample; import org.springframework.web.bind.annotation.RequestMapping; +import org.springframework.web.bind.annotation.RequestParam; import org.springframework.web.bind.annotation.RestController; import javax.sql.DataSource; import java.sql.Connection; +import java.sql.PreparedStatement; import java.sql.ResultSet; import java.sql.ResultSetMetaData; +import java.sql.SQLException; import java.sql.Statement; import java.util.ArrayList; import java.util.HashMap; @@ -38,6 +41,25 @@ public class SampleController { public SampleController(DataSource dataSource) { this.dataSource = dataSource; + prepareFunctions(dataSource); + } + + private static void prepareFunctions(DataSource dataSource) { + try ( + Connection connection = dataSource.getConnection(); + PreparedStatement statement = connection.prepareStatement( + """ + CREATE ALIAS sleep AS ' + void sleep(int millis) throws Exception { + Thread.sleep(millis); + } + '; + """) + ) { + statement.execute(); + } catch (SQLException e) { + throw new IllegalStateException(e); + } } @RequestMapping("/commit") @@ -95,4 +117,16 @@ public void error() { catch (Exception ignored) { } } + + @RequestMapping("/sleep") + public void sleep(@RequestParam(defaultValue = "3000") int millis) { + try (Connection connection = dataSource.getConnection(); + PreparedStatement statement = connection.prepareStatement("SELECT SLEEP(?)")) { + statement.setInt(1, millis); + statement.execute(); + } + catch (Exception e) { + throw new IllegalStateException(e); + } + } } diff --git a/samples/datasource-proxy-sample/src/main/resources/application.yml b/samples/datasource-proxy-sample/src/main/resources/application.yml index c562f0e..18b2d9f 100644 --- a/samples/datasource-proxy-sample/src/main/resources/application.yml +++ b/samples/datasource-proxy-sample/src/main/resources/application.yml @@ -24,4 +24,6 @@ decorator: datasource-proxy: format-sql: true query: - log-level: INFO \ No newline at end of file + log-level: INFO + slow-query: + threshold: 100ms