From 34dc7b577dd2476e35901f03e4b642bc4db5fd57 Mon Sep 17 00:00:00 2001 From: wenshao Date: Tue, 25 Dec 2012 01:02:28 +0800 Subject: [PATCH] improve LogFilter --- .../druid/filter/logging/LogFilter.java | 64 +++++++++++-- .../druid/pool/DruidPooledConnection.java | 8 +- .../java/com/alibaba/druid/sql/SQLUtils.java | 15 ++- .../sql/visitor/SQLASTOutputVisitor.java | 91 ++++++++++++++++++- .../alibaba/druid/benckmark/pool/Case1.java | 2 +- .../druid/bvt/filter/log/LogFilterTest3.java | 44 +++++++++ 6 files changed, 208 insertions(+), 16 deletions(-) create mode 100644 src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest3.java 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 df9f175127..043bd006e4 100644 --- a/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java +++ b/src/main/java/com/alibaba/druid/filter/logging/LogFilter.java @@ -19,6 +19,9 @@ import java.sql.ResultSetMetaData; import java.sql.SQLException; import java.sql.Savepoint; import java.sql.Types; +import java.util.ArrayList; +import java.util.List; +import java.util.Map; import com.alibaba.druid.filter.FilterChain; import com.alibaba.druid.filter.FilterEventAdapter; @@ -31,6 +34,7 @@ import com.alibaba.druid.proxy.jdbc.JdbcParameter; import com.alibaba.druid.proxy.jdbc.PreparedStatementProxy; import com.alibaba.druid.proxy.jdbc.ResultSetProxy; import com.alibaba.druid.proxy.jdbc.StatementProxy; +import com.alibaba.druid.sql.SQLUtils; import com.alibaba.druid.util.JdbcUtils; /** @@ -57,6 +61,7 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM private boolean statementExecuteQueryAfterLogEnable = true; private boolean statementExecuteUpdateAfterLogEnable = true; private boolean statementExecuteBatchAfterLogEnable = true; + private boolean statementExecutableSqlLogEnable = false; private boolean statementCloseAfterLogEnable = true; @@ -89,6 +94,12 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM resultSetLogEnabled = false; } } + { + String prop = System.getProperty("druid.log.stmt.executableSql"); + if (prop == "true") { + statementExecutableSqlLogEnable = true; + } + } } @Override @@ -224,6 +235,14 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM this.statementExecuteUpdateAfterLogEnable = afterStatementExecuteUpdateLogEnable; } + public boolean isStatementExecutableSqlLogEnable() { + return statementExecutableSqlLogEnable; + } + + public void setStatementExecutableSqlLogEnable(boolean statementExecutableSqlLogEnable) { + this.statementExecutableSqlLogEnable = statementExecutableSqlLogEnable; + } + public boolean isStatementPrepareCallAfterLogEnabled() { return isStatementLogEnabled() && statementPrepareCallAfterLogEnable; } @@ -392,6 +411,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM @Override protected void statementExecuteAfter(StatementProxy statement, String sql, boolean firstResult) { + logExecutableSql(statement, sql); + if (statementExecuteAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); double nanos = statement.getLastExecuteTimeNano(); @@ -409,18 +430,20 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM @Override protected void statementExecuteBatchAfter(StatementProxy statement, int[] result) { + String sql; + if (statement instanceof PreparedStatementProxy) { + sql = ((PreparedStatementProxy) statement).getSql(); + } else { + sql = statement.getBatchSql(); + } + + logExecutableSql(statement, sql); + if (statementExecuteBatchAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); double nanos = statement.getLastExecuteTimeNano(); double millis = nanos / (1000 * 1000); - String sql; - if (statement instanceof PreparedStatementProxy) { - sql = ((PreparedStatementProxy) statement).getSql(); - } else { - sql = statement.getBatchSql(); - } - statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} batch executed. " + millis + " millis. " + sql); } @@ -436,6 +459,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM @Override protected void statementExecuteQueryAfter(StatementProxy statement, String sql, ResultSetProxy resultSet) { + logExecutableSql(statement, sql); + if (statementExecuteQueryAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); double nanos = statement.getLastExecuteTimeNano(); @@ -456,6 +481,8 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM @Override protected void statementExecuteUpdateAfter(StatementProxy statement, String sql, int updateCount) { + logExecutableSql(statement, sql); + if (statementExecuteUpdateAfterLogEnable && isStatementLogEnabled()) { statement.setLastExecuteTimeNano(); double nanos = statement.getLastExecuteTimeNano(); @@ -466,6 +493,29 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM } } + private void logExecutableSql(StatementProxy statement, String sql) { + if (!isStatementExecutableSqlLogEnable()) { + return; + } + + Map parameterMap = statement.getParameters(); + if (parameterMap == null || parameterMap.size() == 0) { + statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} executed. " + + sql); + return; + } + + List parameters = new ArrayList(parameterMap.size()); + for (JdbcParameter jdbcParam : parameterMap.values()) { + parameters.add(jdbcParam.getValue()); + } + + String dbType = statement.getConnectionProxy().getDirectDataSource().getDbType(); + String formattedSql = SQLUtils.format(sql, dbType, parameters); + statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} executed. " + + formattedSql); + } + @Override public void resultSet_close(FilterChain chain, ResultSetProxy resultSet) throws SQLException { chain.resultSet_close(resultSet); diff --git a/src/main/java/com/alibaba/druid/pool/DruidPooledConnection.java b/src/main/java/com/alibaba/druid/pool/DruidPooledConnection.java index 14426e88cf..94143ba5c3 100644 --- a/src/main/java/com/alibaba/druid/pool/DruidPooledConnection.java +++ b/src/main/java/com/alibaba/druid/pool/DruidPooledConnection.java @@ -137,6 +137,10 @@ public class DruidPooledConnection extends PoolableWrapper implements javax.sql. public void closePoolableStatement(DruidPooledPreparedStatement stmt) throws SQLException { PreparedStatement rawStatement = stmt.getRawPreparedStatement(); + if (holder == null) { + return; + } + if (holder.isPoolPreparedStatements()) { try { rawStatement.clearParameters(); @@ -145,10 +149,6 @@ public class DruidPooledConnection extends PoolableWrapper implements javax.sql. } } - if (holder == null) { - return; - } - stmt.getPreparedStatementHolder().decrementInUseCount(); if (holder.isPoolPreparedStatements()) { holder.getStatementPool().put(stmt.getPreparedStatementHolder()); diff --git a/src/main/java/com/alibaba/druid/sql/SQLUtils.java b/src/main/java/com/alibaba/druid/sql/SQLUtils.java index f7413ba42c..21f156643e 100644 --- a/src/main/java/com/alibaba/druid/sql/SQLUtils.java +++ b/src/main/java/com/alibaba/druid/sql/SQLUtils.java @@ -140,12 +140,16 @@ public class SQLUtils { public static SQLExpr toSQLExpr(String sql) { return toSQLExpr(sql, null); } - + public static String format(String sql, String dbType) { + return format(sql, dbType, null); + } + + public static String format(String sql, String dbType, List parameters) { try { List statementList = toStatementList(sql, dbType); - return toSQLString(statementList, dbType); + return toSQLString(statementList, dbType, parameters); } catch (SQLParseException ex) { LOG.warn("format error", ex); return sql; @@ -156,8 +160,15 @@ public class SQLUtils { } public static String toSQLString(List statementList, String dbType) { + return toSQLString(statementList, dbType, null); + } + + public static String toSQLString(List statementList, String dbType, List parameters) { StringBuilder out = new StringBuilder(); SQLASTOutputVisitor visitor = createFormatOutputVisitor(out, statementList, dbType); + if (parameters != null) { + visitor.setParameters(parameters); + } for (SQLStatement stmt : statementList) { stmt.accept(visitor); diff --git a/src/main/java/com/alibaba/druid/sql/visitor/SQLASTOutputVisitor.java b/src/main/java/com/alibaba/druid/sql/visitor/SQLASTOutputVisitor.java index 78c1ef157a..74551b2cd4 100644 --- a/src/main/java/com/alibaba/druid/sql/visitor/SQLASTOutputVisitor.java +++ b/src/main/java/com/alibaba/druid/sql/visitor/SQLASTOutputVisitor.java @@ -16,7 +16,14 @@ package com.alibaba.druid.sql.visitor; import java.io.IOException; +import java.io.InputStream; +import java.io.Reader; +import java.sql.Blob; +import java.sql.Clob; +import java.sql.NClob; +import java.text.SimpleDateFormat; import java.util.ArrayList; +import java.util.Date; import java.util.List; import com.alibaba.druid.sql.ast.SQLCommentHint; @@ -107,10 +114,24 @@ public class SQLASTOutputVisitor extends SQLASTVisitorAdapter { private int indentCount = 0; private boolean prettyFormat = true; + private List parameters; + public SQLASTOutputVisitor(Appendable appender){ this.appender = appender; } + public List getParameters() { + if (parameters == null) { + parameters = new ArrayList(); + } + + return parameters; + } + + public void setParameters(List parameters) { + this.parameters = parameters; + } + public int getIndentCount() { return indentCount; } @@ -147,6 +168,16 @@ public class SQLASTOutputVisitor extends SQLASTVisitorAdapter { print(Integer.toString(value)); } + public void print(Date date) { + SimpleDateFormat dateFormat; + if (date instanceof java.sql.Timestamp) { + dateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); + } else { + dateFormat = new SimpleDateFormat("yyyy-MM-dd"); + } + print("'" + dateFormat.format(date) + "'"); + } + public void print(long value) { print(Long.toString(value)); } @@ -655,7 +686,63 @@ public class SQLASTOutputVisitor extends SQLASTVisitorAdapter { } public boolean visit(SQLVariantRefExpr x) { - print(x.getName()); + int index = x.getIndex(); + + if (parameters == null || index >= parameters.size()) { + print(x.getName()); + return false; + } + + Object param = parameters.get(index); + + if (param == null) { + print("NULL"); + return false; + } + + if (param instanceof Number // + || param instanceof Boolean) { + print(param.toString()); + return false; + } + + if (param instanceof String) { + SQLCharExpr charExpr = new SQLCharExpr((String) param); + visit(charExpr); + return false; + } + + if (param instanceof Date) { + print((Date) param); + return false; + } + + if (param instanceof InputStream) { + print("'"); + return false; + } + + if (param instanceof Reader) { + print("'"); + return false; + } + + if (param instanceof Blob) { + print("'"); + return false; + } + + if (param instanceof NClob) { + print("'"); + return false; + } + + if (param instanceof Clob) { + print("'"); + return false; + } + + print("'" + param.getClass().getName() + "'"); return false; } @@ -887,7 +974,7 @@ public class SQLASTOutputVisitor extends SQLASTVisitorAdapter { print(x.getOperator().name); SQLExpr expr = x.getExpr(); - + switch (x.getOperator()) { case BINARY: case Prior: diff --git a/src/test/java/com/alibaba/druid/benckmark/pool/Case1.java b/src/test/java/com/alibaba/druid/benckmark/pool/Case1.java index 78e3aa1926..928d9f0993 100644 --- a/src/test/java/com/alibaba/druid/benckmark/pool/Case1.java +++ b/src/test/java/com/alibaba/druid/benckmark/pool/Case1.java @@ -59,7 +59,7 @@ public class Case1 extends TestCase { private String validationQuery = "SELECT 1"; private int threadCount = 5; private int loopCount = 10; - final int LOOP_COUNT = 1000 * 1000 * 1 / threadCount; + final int LOOP_COUNT = 1000 * 1 * 1 / threadCount; private static AtomicLong physicalConnStat = new AtomicLong(); diff --git a/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest3.java b/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest3.java new file mode 100644 index 0000000000..d5d9a80789 --- /dev/null +++ b/src/test/java/com/alibaba/druid/bvt/filter/log/LogFilterTest3.java @@ -0,0 +1,44 @@ +package com.alibaba.druid.bvt.filter.log; + +import java.sql.Connection; +import java.sql.PreparedStatement; +import java.sql.ResultSet; + +import junit.framework.TestCase; + +import com.alibaba.druid.pool.DruidDataSource; +import com.alibaba.druid.util.JdbcUtils; + +public class LogFilterTest3 extends TestCase { + + private DruidDataSource dataSource; + + protected void setUp() throws Exception { + System.setProperty("druid.log.stmt.executableSql", "true"); + dataSource = new DruidDataSource(); + dataSource.setUrl("jdbc:derby:classpath:petstore-db"); + dataSource.setFilters("log4j"); + } + + public void test_select() throws Exception { + Connection conn = dataSource.getConnection(); + + PreparedStatement stmt = conn.prepareStatement("SELECT * FROM ITEM WHERE LISTPRICE > ?"); + stmt.setInt(1, 10); + + for (int i = 0; i < 10; ++i) { + ResultSet rs = stmt.executeQuery(); + rs.close(); + } + + stmt.close(); + + conn.close(); + } + + protected void tearDown() throws Exception { + JdbcUtils.close(dataSource); + + System.clearProperty("druid.log.stmt.executableSql"); + } +}