diff --git a/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java b/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java index 684308423c..14ad2bd491 100644 --- a/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java +++ b/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java @@ -382,8 +382,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM protected void statementExecuteAfter(StatementProxy statement, String sql, boolean firstResult) { if (statementExecuteAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); - long nanos = statement.getLastExecuteTimeNano(); - long millis = nanos / (1000 * 1000); + double nanos = statement.getLastExecuteTimeNano(); + double millis = nanos / (1000 * 1000); statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} executed. " + sql + " (" + millis + " milliseconds)"); @@ -399,8 +399,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM protected void statementExecuteBatchAfter(StatementProxy statement, int[] result) { if (statementExecuteBatchAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); - long nanos = statement.getLastExecuteTimeNano(); - long millis = nanos / (1000 * 1000); + double nanos = statement.getLastExecuteTimeNano(); + double millis = nanos / (1000 * 1000); String sql; if (statement instanceof PreparedStatementProxy) { @@ -426,8 +426,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM protected void statementExecuteQueryAfter(StatementProxy statement, String sql, ResultSetProxy resultSet) { if (statementExecuteQueryAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); - long nanos = statement.getLastExecuteTimeNano(); - long millis = nanos / (1000 * 1000); + double nanos = statement.getLastExecuteTimeNano(); + double millis = nanos / (1000 * 1000); statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + ", rs-" + resultSet.getId() + "} query executed. " + sql + " (" + millis + " milliseconds)"); @@ -446,8 +446,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM protected void statementExecuteUpdateAfter(StatementProxy statement, String sql, int updateCount) { if (statementExecuteUpdateAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); - long nanos = statement.getLastExecuteTimeNano(); - long millis = nanos / (1000 * 1000); + double nanos = statement.getLastExecuteTimeNano(); + double millis = nanos / (1000 * 1000); statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} update executed. effort " + updateCount + ". " + sql + " (" + millis + " milliseconds)"); diff --git a/src/main/java/com/alibaba/druid/proxy/jdbc/StatementProxyImpl.java b/src/main/java/com/alibaba/druid/proxy/jdbc/StatementProxyImpl.java index d18ec0c8e1..d97c2d8aa6 100644 --- a/src/main/java/com/alibaba/druid/proxy/jdbc/StatementProxyImpl.java +++ b/src/main/java/com/alibaba/druid/proxy/jdbc/StatementProxyImpl.java @@ -109,7 +109,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro updateCount = null; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.Execute; - + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + firstResultSet = createChain().statement_execute(this, sql); return firstResultSet; } @@ -119,6 +121,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro updateCount = null; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.Execute; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + firstResultSet = createChain().statement_execute(this, sql, autoGeneratedKeys); return firstResultSet; } @@ -128,6 +133,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro updateCount = null; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.Execute; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + firstResultSet = createChain().statement_execute(this, sql, columnIndexes); return firstResultSet; } @@ -137,6 +145,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro updateCount = null; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.Execute; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + firstResultSet = createChain().statement_execute(this, sql, columnNames); return firstResultSet; } @@ -145,6 +156,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro public int[] executeBatch() throws SQLException { firstResultSet = false; lastExecuteType = StatementExecuteType.ExecuteBatch; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + int[] updateCounts = createChain().statement_executeBatch(this); if (updateCounts != null && updateCounts.length == 1) { @@ -160,6 +174,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro updateCount = null; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.ExecuteQuery; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + return createChain().statement_executeQuery(this, sql); } @@ -168,6 +185,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro firstResultSet = false; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.ExecuteUpdate; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + updateCount = createChain().statement_executeUpdate(this, sql); return updateCount; } @@ -177,6 +197,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro firstResultSet = false; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.ExecuteUpdate; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + updateCount = createChain().statement_executeUpdate(this, sql, autoGeneratedKeys); return updateCount; } @@ -186,6 +209,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro firstResultSet = false; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.ExecuteUpdate; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + updateCount = createChain().statement_executeUpdate(this, sql, columnIndexes); return updateCount; } @@ -195,6 +221,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro firstResultSet = false; lastExecuteSql = sql; lastExecuteType = StatementExecuteType.ExecuteUpdate; + lastExecuteStartNano = -1L; + lastExecuteTimeNano = -1L; + updateCount = createChain().statement_executeUpdate(this, sql, columnNames); return updateCount; } diff --git a/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest.java b/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest.java new file mode 100644 index 0000000000..97b6daed0b --- /dev/null +++ b/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest.java @@ -0,0 +1,40 @@ +package com.alibaba.druid.bvt.filter.log; + +import java.sql.Connection; +import java.sql.ResultSet; +import java.sql.Statement; + +import junit.framework.TestCase; + +import com.alibaba.druid.pool.DruidDataSource; +import com.alibaba.druid.util.JdbcUtils; + +public class LogFilterTest extends TestCase { + + private DruidDataSource dataSource; + + protected void setUp() throws Exception { + dataSource = new DruidDataSource(); + dataSource.setUrl("jdbc:derby:classpath:petstore-db"); + dataSource.setFilters("log4j"); + } + + public void test_select() throws Exception { + Connection conn = dataSource.getConnection(); + + Statement stmt = conn.createStatement(); + + for (int i = 0; i < 10; ++i) { + ResultSet rs = stmt.executeQuery("SELECT * FROM ITEM WHERE LISTPRICE > 10"); + rs.close(); + } + + stmt.close(); + + conn.close(); + } + + protected void tearDown() throws Exception { + JdbcUtils.close(dataSource); + } +}