improve LogFilter

This commit is contained in:
wenshao
2012-11-27 12:51:32 +08:00
parent ae3fd5e261
commit 619c007db9
5 changed files with 73 additions and 65 deletions
@@ -291,16 +291,16 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
connectionLog("{conn-" + connection.getId() + "} connected");
}
}
@Override
public Savepoint connection_setSavepoint(FilterChain chain, ConnectionProxy connection) throws SQLException {
Savepoint savepoint = chain.connection_setSavepoint(connection);
if (isConnectionLogEnabled()) {
connectionLog("{conn " + connection.getId() + "} setSavepoint-" + savepoint.getSavepointId());
}
return savepoint;
}
@@ -308,11 +308,11 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
public Savepoint connection_setSavepoint(FilterChain chain, ConnectionProxy connection, String name)
throws SQLException {
Savepoint savepoint = chain.connection_setSavepoint(connection, name);
if (isConnectionLogEnabled()) {
connectionLog("{conn " + connection.getId() + "} setSavepoint-" + name);
}
return savepoint;
}
@@ -324,11 +324,12 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
connectionLog("{conn " + connection.getId() + "} rollback");
}
}
@Override
public void connection_rollback(FilterChain chain, ConnectionProxy connection, Savepoint savePoint) throws SQLException {
public void connection_rollback(FilterChain chain, ConnectionProxy connection, Savepoint savePoint)
throws SQLException {
super.connection_rollback(chain, connection, savePoint);
if (connectionRollbackAfterLogEnable && isConnectionLogEnabled()) {
connectionLog("{conn " + connection.getId() + "} rollback -> " + savePoint.getSavepointId());
}
@@ -371,7 +372,7 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
@Override
protected void statementExecuteBefore(StatementProxy statement, String sql) {
statement.setLastExecuteStartNano();
if (statement instanceof PreparedStatementProxy) {
logParameter((PreparedStatementProxy) statement);
}
@@ -380,14 +381,27 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
@Override
protected void statementExecuteAfter(StatementProxy statement, String sql, boolean firstResult) {
if (statementExecuteAfterLogEnable && isStatementLogEnabled()) {
statement.setLastExecuteTimeNano();
long nanos = statement.getLastExecuteTimeNano();
long millis = nanos / (1000 * 1000);
statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + "} executed. "
+ sql);
+ sql + " (" + millis + " milliseconds)");
}
}
@Override
protected void statementExecuteBatchBefore(StatementProxy statement) {
statement.setLastExecuteStartNano();
}
@Override
protected void statementExecuteBatchAfter(StatementProxy statement, int[] result) {
if (statementExecuteBatchAfterLogEnable && isStatementLogEnabled()) {
statement.setLastExecuteTimeNano();
long nanos = statement.getLastExecuteTimeNano();
long millis = nanos / (1000 * 1000);
String sql;
if (statement instanceof PreparedStatementProxy) {
sql = ((PreparedStatementProxy) statement).getSql();
@@ -396,13 +410,13 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
}
statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement)
+ "} batch executed. " + sql);
+ "} batch executed. " + sql + " (" + millis + " milliseconds)");
}
}
@Override
protected void statementExecuteQueryBefore(StatementProxy statement, String sql) {
statement.setLastExecuteStartNano();
if (statement instanceof PreparedStatementProxy) {
logParameter((PreparedStatementProxy) statement);
}
@@ -411,14 +425,18 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
@Override
protected void statementExecuteQueryAfter(StatementProxy statement, String sql, ResultSetProxy resultSet) {
if (statementExecuteQueryAfterLogEnable && isStatementLogEnabled()) {
statement.setLastExecuteTimeNano();
long nanos = statement.getLastExecuteTimeNano();
long millis = nanos / (1000 * 1000);
statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement) + ", rs-"
+ resultSet.getId() + "} query executed. " + sql);
+ resultSet.getId() + "} query executed. " + sql + " (" + millis + " milliseconds)");
}
}
@Override
protected void statementExecuteUpdateBefore(StatementProxy statement, String sql) {
statement.setLastExecuteStartNano();
if (statement instanceof PreparedStatementProxy) {
logParameter((PreparedStatementProxy) statement);
}
@@ -427,8 +445,12 @@ public abstract class LogFilter extends FilterEventAdapter implements LogFilterM
@Override
protected void statementExecuteUpdateAfter(StatementProxy statement, String sql, int updateCount) {
if (statementExecuteUpdateAfterLogEnable && isStatementLogEnabled()) {
statement.setLastExecuteTimeNano();
long nanos = statement.getLastExecuteTimeNano();
long millis = nanos / (1000 * 1000);
statementLog("{conn-" + statement.getConnectionProxy().getId() + ", " + stmtId(statement)
+ "} update executed. effort " + updateCount + ". " + sql);
+ "} update executed. effort " + updateCount + ". " + sql + " (" + millis + " milliseconds)");
}
}
@@ -376,18 +376,13 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean {
}
private final void internalBeforeStatementExecute(StatementProxy statement, String sql) {
final long startNano = System.nanoTime();
JdbcDataSourceStat dataSourceStat = statement.getConnectionProxy().getDirectDataSource().getDataSourceStat();
dataSourceStat.getStatementStat().beforeExecute();
final JdbcStatementStat.Entry statementStat = getStatementInfo(statement);
final ConnectionProxy connection = statement.getConnectionProxy();
final JdbcConnectionStat.Entry connectionCounter = getConnectionInfo(connection);
statementStat.setLastExecuteStartNano(startNano);
statementStat.setLastExecuteSql(sql);
statement.setLastExecuteStartNano();
connectionCounter.setLastSql(sql);
@@ -426,17 +421,14 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean {
}
StatFilterContext.getInstance().executeBefore(sql, inTransaction);
Profiler.enter(sql, Profiler.PROFILE_TYPE_SQL);
}
private final void internalAfterStatementExecute(StatementProxy statement, boolean firstResult,
int... updateCountArray) {
final JdbcStatementStat.Entry entry = getStatementInfo(statement);
final long nowNano = System.nanoTime();
final long nanos = nowNano - entry.getLastExecuteStartNano();
final long nanos = nowNano - statement.getLastExecuteStartNano();
JdbcDataSourceStat dataSourceStat = statement.getConnectionProxy().getDirectDataSource().getDataSourceStat();
dataSourceStat.getStatementStat().afterExecute(nanos);
@@ -485,11 +477,10 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean {
@Override
protected void statement_executeErrorAfter(StatementProxy statement, String sql, Throwable error) {
JdbcStatementStat.Entry counter = getStatementInfo(statement);
ConnectionProxy connection = statement.getConnectionProxy();
JdbcConnectionStat.Entry connectionCounter = getConnectionInfo(connection);
long nanos = System.nanoTime() - counter.getLastExecuteStartNano();
long nanos = System.nanoTime() - statement.getLastExecuteStartNano();
JdbcDataSourceStat dataSourceStat = statement.getConnectionProxy().getDirectDataSource().getDataSourceStat();
dataSourceStat.getStatementStat().error(error);
@@ -618,17 +609,6 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean {
return counter;
}
public JdbcStatementStat.Entry getStatementInfo(StatementProxy statement) {
JdbcStatementStat.Entry counter = (JdbcStatementStat.Entry) statement.getAttributes().get(ATTR_NAME_STATEMENT_STAT);
if (counter == null) {
statement.getAttributes().put(ATTR_NAME_STATEMENT_STAT, new JdbcStatementStat.Entry());
counter = (JdbcStatementStat.Entry) statement.getAttributes().get(ATTR_NAME_STATEMENT_STAT);
}
return counter;
}
public JdbcSqlStat createSqlStat(StatementProxy statement, String sql) {
DataSourceProxy dataSource = statement.getConnectionProxy().getDirectDataSource();
JdbcDataSourceStat dataSourceStat = dataSource.getDataSourceStat();
@@ -42,8 +42,13 @@ public interface StatementProxy extends Statement, WrapperProxy {
String getLastExecuteSql();
long getLastExecuteStartNano();
void setLastExecuteStartNano(long lastExecuteStartNano);
void setLastExecuteStartNano();
long getLastExecuteTimeNano();
void setLastExecuteTimeNano(long nano);
void setLastExecuteTimeNano();
Map<Integer, JdbcParameter> getParameters();
@@ -39,7 +39,9 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro
private final Statement statement;
protected String lastExecuteSql;
private long lastExecuteStartNano;
private long lastExecuteTimeNano;
protected JdbcSqlStat sqlStat;
protected boolean firstResultSet;
@@ -144,11 +146,11 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro
firstResultSet = false;
lastExecuteType = StatementExecuteType.ExecuteBatch;
int[] updateCounts = createChain().statement_executeBatch(this);
if (updateCounts != null && updateCounts.length == 1) {
updateCount = updateCounts[0];
}
return updateCounts;
}
@@ -264,13 +266,13 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro
return createChain().statement_getResultSetType(this);
}
//bug fixed for oracle
// bug fixed for oracle
@Override
public int getUpdateCount() throws SQLException {
if (updateCount == null) {
updateCount = createChain().statement_getUpdateCount(this);
}
return updateCount;
return updateCount;
}
@Override
@@ -391,6 +393,27 @@ public class StatementProxyImpl extends WrapperProxyImpl implements StatementPro
public void setLastExecuteTimeNano(long lastExecuteTimeNano) {
this.lastExecuteTimeNano = lastExecuteTimeNano;
}
public void setLastExecuteTimeNano() {
if (this.lastExecuteTimeNano <= 0 && this.lastExecuteStartNano > 0) {
this.lastExecuteTimeNano = System.nanoTime() - this.lastExecuteStartNano;
}
}
public long getLastExecuteStartNano() {
return lastExecuteStartNano;
}
public void setLastExecuteStartNano(long lastExecuteStartNano) {
this.lastExecuteStartNano = lastExecuteStartNano;
this.lastExecuteTimeNano = -1L;
}
public void setLastExecuteStartNano() {
if (lastExecuteStartNano <= 0) {
setLastExecuteStartNano(System.nanoTime());
}
}
public StatementExecuteType getLastExecuteType() {
return lastExecuteType;
@@ -202,26 +202,4 @@ public class JdbcStatementStat implements JdbcStatementStatMBean {
public void incrementStatementCloseCounter() {
closeCount.incrementAndGet();
}
public static class Entry {
private long lastExecuteStartNano;
private String lastExecuteSql;
public long getLastExecuteStartNano() {
return lastExecuteStartNano;
}
public void setLastExecuteStartNano(long lastExecuteStartNano) {
this.lastExecuteStartNano = lastExecuteStartNano;
}
public String getLastExecuteSql() {
return lastExecuteSql;
}
public void setLastExecuteSql(String lastExecuteSql) {
this.lastExecuteSql = lastExecuteSql;
}
}
}