From 7a7af668f36d969ff86f2aedf778e788f6c4114c Mon Sep 17 00:00:00 2001 From: wenshao Date: Mon, 1 Oct 2012 16:58:07 +0800 Subject: [PATCH 1/2] optimized DruidDataSource.getStatData lock --- .../druid/pool/DruidAbstractDataSource.java | 20 +++---- .../alibaba/druid/pool/DruidDataSource.java | 59 ++++++++++++++----- 2 files changed, 53 insertions(+), 26 deletions(-) diff --git a/src/main/java/com/alibaba/druid/pool/DruidAbstractDataSource.java b/src/main/java/com/alibaba/druid/pool/DruidAbstractDataSource.java index a570ecea29..f64ffb8f60 100644 --- a/src/main/java/com/alibaba/druid/pool/DruidAbstractDataSource.java +++ b/src/main/java/com/alibaba/druid/pool/DruidAbstractDataSource.java @@ -138,7 +138,7 @@ public abstract class DruidAbstractDataSource extends WrapperAdapter implements protected volatile int queryTimeout; protected volatile int transactionQueryTimeout; - protected long createErrorCount; + protected AtomicLong createErrorCount = new AtomicLong(); protected long createTimespan; @@ -205,11 +205,11 @@ public abstract class DruidAbstractDataSource extends WrapperAdapter implements private final AtomicLong executeCount = new AtomicLong(); - protected Throwable createError; - protected Throwable lastError; - protected long lastErrorTimeMillis; - protected Throwable lastCreateError; - protected long lastCreateErrorTimeMillis; + protected volatile Throwable createError; + protected volatile Throwable lastError; + protected volatile long lastErrorTimeMillis; + protected volatile Throwable lastCreateError; + protected volatile long lastCreateErrorTimeMillis; protected boolean isOracle = false; @@ -839,7 +839,7 @@ public abstract class DruidAbstractDataSource extends WrapperAdapter implements } public long getCreateErrorCount() { - return createErrorCount; + return createErrorCount.get(); } public int getMaxActive() { @@ -1269,19 +1269,19 @@ public abstract class DruidAbstractDataSource extends WrapperAdapter implements validateConnection(conn); createError = null; } catch (SQLException ex) { - createErrorCount++; + createErrorCount.incrementAndGet(); createError = ex; lastCreateError = ex; lastCreateErrorTimeMillis = System.currentTimeMillis(); throw ex; } catch (RuntimeException ex) { - createErrorCount++; + createErrorCount.incrementAndGet(); createError = ex; lastCreateError = ex; lastCreateErrorTimeMillis = System.currentTimeMillis(); throw ex; } catch (Error ex) { - createErrorCount++; + createErrorCount.incrementAndGet(); throw ex; } finally { long nano = System.nanoTime() - startNano; diff --git a/src/main/java/com/alibaba/druid/pool/DruidDataSource.java b/src/main/java/com/alibaba/druid/pool/DruidDataSource.java index 8de4dcb948..ab8d6ae606 100644 --- a/src/main/java/com/alibaba/druid/pool/DruidDataSource.java +++ b/src/main/java/com/alibaba/druid/pool/DruidDataSource.java @@ -127,9 +127,9 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat public DruidDataSource(){ this(true); } - + public DruidDataSource(boolean fairLock){ - super (fairLock); + super(fairLock); } public String getInitStackTrace() { @@ -663,7 +663,7 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat * @param realConnection * @throws SQLException */ - private void discardConnection(Connection realConnection) throws SQLException { + private void discardConnection(Connection realConnection) { JdbcUtils.close(realConnection); lock.lock(); @@ -789,10 +789,11 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat } } - try { - final boolean isAutoCommit = holder.isUnderlyingAutoCommit(); - final boolean isReadOnly = holder.isUnderlyingReadOnly(); + final boolean isAutoCommit = holder.isUnderlyingAutoCommit(); + final boolean isReadOnly = holder.isUnderlyingReadOnly(); + final boolean testOnReturn = this.isTestOnReturn(); + try { // check need to rollback? if ((!isAutoCommit) && (!isReadOnly)) { pooledConnection.rollback(); @@ -801,7 +802,7 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat // reset holder, restore default settings, clear warnings holder.reset(); - if (isTestOnReturn()) { + if (testOnReturn) { boolean validate = testConnectionInternal(physicalConnection); if (!validate) { JdbcUtils.close(physicalConnection); @@ -1188,7 +1189,7 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat LOG.error("create connection holder error", ex); break; } - + lock.lock(); try { connections[poolingCount++] = holder; @@ -1725,6 +1726,32 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat } public Map getStatData() { + final int activeCount; + final int activePeak; + final Date activePeakTime; + + final int poolingCount; + final int poolingPeak; + final Date poolingPeakTime; + + final long connectCount; + final long closeCount; + + lock.lock(); + try { + poolingCount = this.poolingCount; + poolingPeak = this.poolingPeak; + poolingPeakTime = this.getPoolingPeakTime(); + + activeCount = this.activeCount; + activePeak = this.activePeak; + activePeakTime = this.getActivePeakTime(); + + connectCount = this.connectCount; + closeCount = this.closeCount; + } finally { + lock.unlock(); + } Map dataMap = new LinkedHashMap(); dataMap.put("Identity", System.identityHashCode(this)); @@ -1740,13 +1767,13 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat dataMap.put("NotEmptyWaitCount", this.getNotEmptyWaitCount()); dataMap.put("NotEmptyWaitMillis", this.getNotEmptyWaitMillis()); - dataMap.put("PoolingCount", this.getPoolingCount()); - dataMap.put("PoolingPeak", this.getPoolingPeak()); - dataMap.put("PoolingPeakTime", this.getPoolingPeakTime() == null ? null : this.getPoolingPeakTime().toString()); + dataMap.put("PoolingCount", poolingCount); + dataMap.put("PoolingPeak", poolingPeak); + dataMap.put("PoolingPeakTime", poolingPeakTime); - dataMap.put("ActiveCount", this.getActiveCount()); - dataMap.put("ActivePeak", this.getActivePeak()); - dataMap.put("ActivePeakTime", this.getActivePeakTime() == null ? null : this.getActivePeakTime().toString()); + dataMap.put("ActiveCount", activeCount); + dataMap.put("ActivePeak", activePeak); + dataMap.put("ActivePeakTime", activePeakTime); dataMap.put("InitialSize", this.getInitialSize()); dataMap.put("MinIdle", this.getMinIdle()); @@ -1766,8 +1793,8 @@ public class DruidDataSource extends DruidAbstractDataSource implements DruidDat dataMap.put("DefaultReadOnly", this.isDefaultAutoCommit()); dataMap.put("DefaultTransactionIsolation", this.getDefaultTransactionIsolation()); - dataMap.put("LogicConnectCount", this.getConnectCount()); - dataMap.put("LogicCloseCount", this.getCloseCount()); + dataMap.put("LogicConnectCount", connectCount); + dataMap.put("LogicCloseCount", closeCount); dataMap.put("LogicConnectErrorCount", this.getConnectErrorCount()); dataMap.put("PhysicalConnectCount", this.getCreateCount()); From e1823c2f2cd566b4bf9dc4ef7e4bd9bd5df3a30d Mon Sep 17 00:00:00 2001 From: wenshao Date: Sun, 7 Oct 2012 17:51:11 +0800 Subject: [PATCH 2/2] profile support --- .../alibaba/druid/filter/stat/StatFilter.java | 28 ++++--- .../druid/support/http/WebStatFilter.java | 38 +++++++++ .../druid/support/http/stat/WebURIStat.java | 25 ++++-- .../druid/support/profile/ProfileEntry.java | 62 ++++++++------- .../support/profile/ProfileEntryKey.java | 65 ++++++++++++++++ .../support/profile/ProfileEntryReqStat.java | 24 ++++++ .../support/profile/ProfileEntryStat.java | 33 ++++++++ .../druid/support/profile/ProfileStat.java | 55 +++++++++++++ .../druid/support/profile/Profiler.java | 78 +++++++++++-------- .../spring/stat/DruidStatInterceptor.java | 2 + .../support/spring/stat/SpringMethodStat.java | 22 ++++-- .../bvt/support/profile/ProfilerTest.java | 65 ++++++++++++++++ 12 files changed, 415 insertions(+), 82 deletions(-) create mode 100644 src/main/java/com/alibaba/druid/support/profile/ProfileEntryKey.java create mode 100644 src/main/java/com/alibaba/druid/support/profile/ProfileEntryReqStat.java create mode 100644 src/main/java/com/alibaba/druid/support/profile/ProfileEntryStat.java create mode 100644 src/main/java/com/alibaba/druid/support/profile/ProfileStat.java create mode 100644 src/test/java/com/alibaba/druid/bvt/support/profile/ProfilerTest.java diff --git a/src/main/java/com/alibaba/druid/filter/stat/StatFilter.java b/src/main/java/com/alibaba/druid/filter/stat/StatFilter.java index 29d7c87c76..002a7dd462 100644 --- a/src/main/java/com/alibaba/druid/filter/stat/StatFilter.java +++ b/src/main/java/com/alibaba/druid/filter/stat/StatFilter.java @@ -50,6 +50,7 @@ import com.alibaba.druid.stat.JdbcStatementStat; import com.alibaba.druid.support.json.JSONWriter; import com.alibaba.druid.support.logging.Log; import com.alibaba.druid.support.logging.LogFactory; +import com.alibaba.druid.support.profile.Profiler; /** * @author wenshao @@ -425,6 +426,8 @@ 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, @@ -433,10 +436,10 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { final JdbcStatementStat.Entry entry = getStatementInfo(statement); final long nowNano = System.nanoTime(); - final long nanoSpan = nowNano - entry.getLastExecuteStartNano(); + final long nanos = nowNano - entry.getLastExecuteStartNano(); JdbcDataSourceStat dataSourceStat = statement.getConnectionProxy().getDirectDataSource().getDataSourceStat(); - dataSourceStat.getStatementStat().afterExecute(nanoSpan); + dataSourceStat.getStatementStat().afterExecute(nanos); final JdbcSqlStat sqlStat = statement.getSqlStat(); @@ -444,8 +447,8 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { sqlStat.incrementExecuteSuccessCount(); sqlStat.decrementRunningCount(); - sqlStat.addExecuteTime(statement.getLastExecuteType(), firstResult, nanoSpan); - statement.setLastExecuteTimeNano(nanoSpan); + sqlStat.addExecuteTime(statement.getLastExecuteType(), firstResult, nanos); + statement.setLastExecuteTimeNano(nanos); if ((!statement.isFirstResultSet()) && statement.getLastExecuteType() == StatementExecuteType.Execute) { try { int updateCount = statement.getUpdateCount(); @@ -461,7 +464,7 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { } } - long millis = nanoSpan / (1000 * 1000); + long millis = nanos / (1000 * 1000); if (millis >= slowSqlMillis) { String slowParameters = buildSlowParameters(statement); sqlStat.setLastSlowParameters(slowParameters); @@ -474,7 +477,9 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { } String sql = statement.getLastExecuteSql(); - StatFilterContext.getInstance().executeAfter(sql, nanoSpan, null); + StatFilterContext.getInstance().executeAfter(sql, nanos, null); + + Profiler.release(nanos); } @Override @@ -484,11 +489,11 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { ConnectionProxy connection = statement.getConnectionProxy(); JdbcConnectionStat.Entry connectionCounter = getConnectionInfo(connection); - long nanoSpan = System.nanoTime() - counter.getLastExecuteStartNano(); + long nanos = System.nanoTime() - counter.getLastExecuteStartNano(); JdbcDataSourceStat dataSourceStat = statement.getConnectionProxy().getDirectDataSource().getDataSourceStat(); dataSourceStat.getStatementStat().error(error); - dataSourceStat.getStatementStat().afterExecute(nanoSpan); + dataSourceStat.getStatementStat().afterExecute(nanos); connectionCounter.error(error); @@ -497,11 +502,12 @@ public class StatFilter extends FilterEventAdapter implements StatFilterMBean { if (sqlStat != null) { sqlStat.error(error); - sqlStat.addExecuteTime(statement.getLastExecuteType(), statement.isFirstResultSet(), nanoSpan); - statement.setLastExecuteTimeNano(nanoSpan); + sqlStat.addExecuteTime(statement.getLastExecuteType(), statement.isFirstResultSet(), nanos); + statement.setLastExecuteTimeNano(nanos); } - StatFilterContext.getInstance().executeAfter(sql, nanoSpan, error); + StatFilterContext.getInstance().executeAfter(sql, nanos, error); + Profiler.release(nanos); } private String buildSlowParameters(StatementProxy statement) { diff --git a/src/main/java/com/alibaba/druid/support/http/WebStatFilter.java b/src/main/java/com/alibaba/druid/support/http/WebStatFilter.java index 33d23f83e8..baf8b465f6 100644 --- a/src/main/java/com/alibaba/druid/support/http/WebStatFilter.java +++ b/src/main/java/com/alibaba/druid/support/http/WebStatFilter.java @@ -18,6 +18,7 @@ package com.alibaba.druid.support.http; import java.io.IOException; import java.util.Arrays; import java.util.HashSet; +import java.util.Map; import java.util.Set; import javax.servlet.Filter; @@ -41,6 +42,9 @@ import com.alibaba.druid.support.http.stat.WebSessionStat; import com.alibaba.druid.support.http.stat.WebURIStat; import com.alibaba.druid.support.logging.Log; import com.alibaba.druid.support.logging.LogFactory; +import com.alibaba.druid.support.profile.ProfileEntryKey; +import com.alibaba.druid.support.profile.ProfileEntryReqStat; +import com.alibaba.druid.support.profile.Profiler; import com.alibaba.druid.util.DruidWebUtils; import com.alibaba.druid.util.PatternMatcher; import com.alibaba.druid.util.ServletPathMatcher; @@ -55,6 +59,7 @@ public class WebStatFilter implements Filter { private final static Log LOG = LogFactory.getLog(WebStatFilter.class); + public final static String PARAM_NAME_PORFILE_ENABLE = "profileEnable"; public final static String PARAM_NAME_SESSION_STAT_ENABLE = "sessionStatEnable"; public final static String PARAM_NAME_SESSION_STAT_MAX_COUNT = "sessionStatMaxCount"; public static final String PARAM_NAME_EXCLUSIONS = "exclusions"; @@ -75,6 +80,7 @@ public class WebStatFilter implements Filter { private boolean sessionStatEnable = true; private int sessionStatMaxCount = DEFAULT_MAX_STAT_SESSION_COUNT; private boolean createSession = false; + private boolean profileEnable = false; private String contextPath; @@ -114,6 +120,10 @@ public class WebStatFilter implements Filter { } } + if (isProfileEnable()) { + Profiler.initLocal(); + } + // 第一次访问时，uriStat这里为null，是为了防止404攻击。 if (uriStat != null) { uriStat.beforeInvoke(); @@ -177,6 +187,12 @@ public class WebStatFilter implements Filter { } WebRequestStat.set(null); + + if (isProfileEnable()) { + Map requestStatsMap = Profiler.getStatsMap(); + uriStat.getProfiletat().record(requestStatsMap); + Profiler.removeLocal(); + } } } @@ -339,6 +355,20 @@ public class WebStatFilter implements Filter { } } } + + { + String param = config.getInitParameter(PARAM_NAME_PORFILE_ENABLE); + if (param != null && param.trim().length() != 0) { + param = param.trim(); + if ("true".equals(param)) { + this.profileEnable = true; + } else if ("false".equals(param)) { + this.profileEnable = false; + } else { + LOG.error("WebStatFilter Parameter '" + PARAM_NAME_PORFILE_ENABLE + "' config error"); + } + } + } { String param = config.getInitParameter(PARAM_NAME_SESSION_STAT_MAX_COUNT); if (param != null && param.trim().length() != 0) { @@ -376,6 +406,14 @@ public class WebStatFilter implements Filter { this.sessionStatEnable = sessionStatEnable; } + public boolean isProfileEnable() { + return profileEnable; + } + + public void setProfileEnable(boolean profileEnable) { + this.profileEnable = profileEnable; + } + public WebAppStat getWebAppStat() { return webAppStat; } diff --git a/src/main/java/com/alibaba/druid/support/http/stat/WebURIStat.java b/src/main/java/com/alibaba/druid/support/http/stat/WebURIStat.java index a5da059f04..fffd2fa481 100644 --- a/src/main/java/com/alibaba/druid/support/http/stat/WebURIStat.java +++ b/src/main/java/com/alibaba/druid/support/http/stat/WebURIStat.java @@ -21,6 +21,9 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; +import com.alibaba.druid.support.profile.ProfileStat; +import com.alibaba.druid.support.profile.Profiler; + public class WebURIStat { private final String uri; @@ -54,6 +57,8 @@ public class WebURIStat { private volatile long lastAccessTimeMillis = -1L; + private ProfileStat profiletat = new ProfileStat(); + private final static ThreadLocal currentLocal = new ThreadLocal(); public WebURIStat(String uri){ @@ -93,6 +98,8 @@ public class WebURIStat { if (requestStat != null) { this.setLastAccessTimeMillis(requestStat.getStartMillis()); } + + Profiler.enter(uri, Profiler.PROFILE_TYPE_WEB); } public void afterInvoke(Throwable error, long nanos) { @@ -154,16 +161,18 @@ public class WebURIStat { this.jdbcExecuteErrorCount.addAndGet(localStat.getJdbcExecuteErrorCount()); this.jdbcExecuteTimeNano.addAndGet(localStat.getJdbcExecuteTimeNano()); - + this.addJdbcPoolConnectionOpenCount(localStat.getJdbcPoolConnectionOpenCount()); this.addJdbcPoolConnectionCloseCount(localStat.getJdbcPoolConnectionCloseCount()); - + this.addJdbcResultSetOpenCount(localStat.getJdbcResultSetOpenCount()); this.addJdbcResultSetCloseCount(localStat.getJdbcResultSetCloseCount()); } } currentLocal.set(null); + + Profiler.release(nanos); } public int getRunningCount() { @@ -301,7 +310,7 @@ public class WebURIStat { public long getJdbcResultSetOpenCount() { return jdbcResultSetOpenCount.get(); } - + public void addJdbcResultSetOpenCount(long delta) { jdbcResultSetOpenCount.addAndGet(delta); } @@ -309,11 +318,15 @@ public class WebURIStat { public long getJdbcResultSetCloseCount() { return jdbcResultSetCloseCount.get(); } - + public void addJdbcResultSetCloseCount(long delta) { jdbcResultSetCloseCount.addAndGet(delta); } + public ProfileStat getProfiletat() { + return profiletat; + } + public Map getStatData() { Map data = new LinkedHashMap(); @@ -341,10 +354,12 @@ public class WebURIStat { data.put("JdbcPoolConnectionOpenCount", this.getJdbcPoolConnectionOpenCount()); data.put("JdbcPoolConnectionCloseCount", this.getJdbcPoolConnectionCloseCount()); - + data.put("JdbcResultSetOpenCount", this.getJdbcResultSetOpenCount()); data.put("JdbcResultSetCloseCount", this.getJdbcResultSetCloseCount()); + data.put("Profiles", this.getProfiletat().getStatData()); + return data; } } diff --git a/src/main/java/com/alibaba/druid/support/profile/ProfileEntry.java b/src/main/java/com/alibaba/druid/support/profile/ProfileEntry.java index 2e370d2e73..0eb3c83297 100644 --- a/src/main/java/com/alibaba/druid/support/profile/ProfileEntry.java +++ b/src/main/java/com/alibaba/druid/support/profile/ProfileEntry.java @@ -2,41 +2,51 @@ package com.alibaba.druid.support.profile; public class ProfileEntry { - private final Key key; - private final String type; + private final ProfileEntry parent; + private final ProfileEntryKey key; - public ProfileEntry(Key key, String type){ - super(); + private int executeCount = 0; + private long executeTimeNanos = 0; + + public ProfileEntry(ProfileEntry parent, ProfileEntryKey key){ + this.parent = parent; this.key = key; - this.type = type; } - public Key getKey() { + public ProfileEntry getParent() { + return parent; + } + + public ProfileEntryKey getKey() { return key; } + public String getParentName() { + return key.getParentName(); + } + + public String getName() { + return key.getName(); + } + public String getType() { - return type; + return key.getType(); } - public static class Key { - - private String parent; - private String name; - - public Key(String parentName, String name){ - super(); - this.parent = parentName; - this.name = name; - } - - public String getParent() { - return parent; - } - - public String getName() { - return name; - } - + public int getExecuteCount() { + return executeCount; } + + public void incrementExecuteCount() { + this.executeCount++; + } + + public long getExecuteTimeNanos() { + return executeTimeNanos; + } + + public void addExecuteTimeNanos(long nanos) { + this.executeTimeNanos += nanos; + } + } diff --git a/src/main/java/com/alibaba/druid/support/profile/ProfileEntryKey.java b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryKey.java new file mode 100644 index 0000000000..e8469acd13 --- /dev/null +++ b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryKey.java @@ -0,0 +1,65 @@ +package com.alibaba.druid.support.profile; + +public class ProfileEntryKey { + + private final String parentName; + private final String name; + private final String type; + + public ProfileEntryKey(String parentName, String name, String type){ + this.parentName = parentName; + this.name = name; + this.type = type; + } + + public String getParentName() { + return parentName; + } + + public String getName() { + return name; + } + + public String getType() { + return type; + } + + @Override + public int hashCode() { + final int prime = 31; + int result = 1; + result = prime * result + ((name == null) ? 0 : name.hashCode()); + result = prime * result + ((parentName == null) ? 0 : parentName.hashCode()); + return result; + } + + @Override + public boolean equals(Object obj) { + if (this == obj) { + return true; + } + if (obj == null) { + return false; + } + if (getClass() != obj.getClass()) { + return false; + } + ProfileEntryKey other = (ProfileEntryKey) obj; + if (name == null) { + if (other.name != null) { + return false; + } + } else if (!name.equals(other.name)) { + return false; + } + if (parentName == null) { + if (other.parentName != null) { + return false; + } + } else if (!parentName.equals(other.parentName)) { + return false; + } + return true; + } + +} diff --git a/src/main/java/com/alibaba/druid/support/profile/ProfileEntryReqStat.java b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryReqStat.java new file mode 100644 index 0000000000..cd711dbaae --- /dev/null +++ b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryReqStat.java @@ -0,0 +1,24 @@ +package com.alibaba.druid.support.profile; + +public class ProfileEntryReqStat { + + private long executeCount; + private long executeTimeNanos; + + public long getExecuteCount() { + return executeCount; + } + + public void incrementExecuteCount() { + this.executeCount++; + } + + public long getExecuteTimeNanos() { + return executeTimeNanos; + } + + public void addExecuteTimeNanos(long nanos) { + this.executeTimeNanos += nanos; + } + +} diff --git a/src/main/java/com/alibaba/druid/support/profile/ProfileEntryStat.java b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryStat.java new file mode 100644 index 0000000000..657132ddd7 --- /dev/null +++ b/src/main/java/com/alibaba/druid/support/profile/ProfileEntryStat.java @@ -0,0 +1,33 @@ +package com.alibaba.druid.support.profile; + +import java.util.concurrent.atomic.AtomicLongFieldUpdater; + +public class ProfileEntryStat { + + private volatile long executeCount = 0; + private volatile long executeTimeNanos = 0; + + private static final AtomicLongFieldUpdater executeCountUpdater; + private static final AtomicLongFieldUpdater executeTimeNanosUpdater; + + static { + executeCountUpdater = AtomicLongFieldUpdater.newUpdater(ProfileEntryStat.class, "executeCount"); + executeTimeNanosUpdater = AtomicLongFieldUpdater.newUpdater(ProfileEntryStat.class, "executeTimeNanos"); + } + + public long getExecuteCount() { + return executeCount; + } + + public void addExecuteCount(long delta) { + executeCountUpdater.addAndGet(this, delta); + } + + public long getExecuteTimeNanos() { + return executeTimeNanos; + } + + public void addExecuteTimeNanos(long delta) { + executeTimeNanosUpdater.addAndGet(this, delta); + } +} diff --git a/src/main/java/com/alibaba/druid/support/profile/ProfileStat.java b/src/main/java/com/alibaba/druid/support/profile/ProfileStat.java new file mode 100644 index 0000000000..c9a3de9b49 --- /dev/null +++ b/src/main/java/com/alibaba/druid/support/profile/ProfileStat.java @@ -0,0 +1,55 @@ +package com.alibaba.druid.support.profile; + +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; + +public class ProfileStat { + + private ConcurrentHashMap entries = new ConcurrentHashMap(); + + public ConcurrentHashMap getEntries() { + return entries; + } + + public void record(Map requestStatsMap) { + if (requestStatsMap == null) { + return; + } + + for (Map.Entry entry : requestStatsMap.entrySet()) { + ProfileEntryKey entryKey = entry.getKey(); + ProfileEntryReqStat reqEntryStat = entry.getValue(); + + ProfileEntryStat entryStat = entries.get(entryKey); + if (entryStat == null) { + entries.putIfAbsent(entryKey, new ProfileEntryStat()); + entryStat = entries.get(entryKey); + } + + entryStat.addExecuteCount(reqEntryStat.getExecuteCount()); + entryStat.addExecuteTimeNanos(reqEntryStat.getExecuteTimeNanos()); + } + } + + public Map, Map> getStatData() { + Map, Map> data = new LinkedHashMap, Map>(); + + for (Map.Entry entry : entries.entrySet()) { + Map key = new LinkedHashMap(); + Map value = new LinkedHashMap(); + + key.put("Parent", entry.getKey().getParentName()); + key.put("Name", entry.getKey().getName()); + key.put("Type", entry.getKey().getType()); + + value.put("ExecuteCount", entry.getValue().getExecuteCount()); + value.put("ExecuteTimeNanos", entry.getValue().getExecuteTimeNanos()); + + data.put(key, value); + } + + return data; + } + +} diff --git a/src/main/java/com/alibaba/druid/support/profile/Profiler.java b/src/main/java/com/alibaba/druid/support/profile/Profiler.java index 178fd7667e..37d2089e6f 100644 --- a/src/main/java/com/alibaba/druid/support/profile/Profiler.java +++ b/src/main/java/com/alibaba/druid/support/profile/Profiler.java @@ -3,49 +3,34 @@ package com.alibaba.druid.support.profile; import java.util.HashMap; import java.util.Map; -import com.alibaba.druid.support.profile.ProfileEntry.Key; - public class Profiler { - public static ThreadLocal enableLocal = new ThreadLocal(); + public static final String PROFILE_TYPE_WEB = "WEB"; + public static final String PROFILE_TYPE_SPRING = "SPRING"; + public static final String PROFILE_TYPE_SQL = "SQL"; - private static ThreadLocal> entriesLocal = new ThreadLocal>(); + private static ThreadLocal> statsMapLocal = new ThreadLocal>(); - private final static ThreadLocal currentLocal = new ThreadLocal(); - - public static void setThreadLocalEnable() { - enableLocal.set(true); - } - - public static void setThreadLocalDisable() { - enableLocal.remove(); - } + private final static ThreadLocal currentLocal = new ThreadLocal(); public static boolean isEnable() { - return Boolean.TRUE == enableLocal.get(); + return statsMapLocal != null; } - public static void enter(String name, String type, long startNano) { + public static void enter(String name, String type) { + if (!isEnable()) { + return; + } + ProfileEntry parent = currentLocal.get(); String parentName = null; if (parent != null) { - parentName = parent.getKey().getName(); + parentName = parent.getName(); } - - ProfileEntry.Key key = new ProfileEntry.Key(parentName, name); - - Map entries = entriesLocal.get(); - if (entries == null) { - entries = new HashMap(); - entriesLocal.set(entries); - } - - ProfileEntry entry = entries.get(key); - if (entry == null) { - entry = new ProfileEntry(key, type); - entries.put(key, entry); - } - + + ProfileEntryKey key = new ProfileEntryKey(parentName, name, type); + ProfileEntry entry = new ProfileEntry(parent, key); + currentLocal.set(entry); } @@ -53,7 +38,36 @@ public class Profiler { return currentLocal.get(); } - public static void release(long nanoSpan) { + public static void release(long nanos) { + ProfileEntry current = currentLocal.get(); + currentLocal.set(current.getParent()); + ProfileEntryReqStat stat = null; + Map statsMap = statsMapLocal.get(); + if (statsMap == null) { + return; + } + + stat = statsMap.get(current.getKey()); + + if (stat == null) { + stat = new ProfileEntryReqStat(); + statsMap.put(current.getKey(), stat); + } + + stat.incrementExecuteCount(); + stat.addExecuteTimeNanos(nanos); + } + + public static Map getStatsMap() { + return statsMapLocal.get(); + } + + public static void initLocal() { + statsMapLocal.set(new HashMap()); + } + + public static void removeLocal() { + statsMapLocal.remove(); } } diff --git a/src/main/java/com/alibaba/druid/support/spring/stat/DruidStatInterceptor.java b/src/main/java/com/alibaba/druid/support/spring/stat/DruidStatInterceptor.java index dd27071eaf..ed46fa6b83 100644 --- a/src/main/java/com/alibaba/druid/support/spring/stat/DruidStatInterceptor.java +++ b/src/main/java/com/alibaba/druid/support/spring/stat/DruidStatInterceptor.java @@ -30,6 +30,8 @@ import com.alibaba.druid.support.logging.LogFactory; public class DruidStatInterceptor implements MethodInterceptor, InitializingBean, DisposableBean { + public static final String PROP_NAME_PORFILE = "druid.profile"; + private final static Log LOG = LogFactory.getLog(DruidStatInterceptor.class); private static SpringStat springStat = new SpringStat(); diff --git a/src/main/java/com/alibaba/druid/support/spring/stat/SpringMethodStat.java b/src/main/java/com/alibaba/druid/support/spring/stat/SpringMethodStat.java index 6327c665ed..cc9b259103 100644 --- a/src/main/java/com/alibaba/druid/support/spring/stat/SpringMethodStat.java +++ b/src/main/java/com/alibaba/druid/support/spring/stat/SpringMethodStat.java @@ -21,6 +21,8 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; +import com.alibaba.druid.support.profile.Profiler; + public class SpringMethodStat { private final static ThreadLocal currentLocal = new ThreadLocal(); @@ -72,7 +74,7 @@ public class SpringMethodStat { jdbcPoolConnectionOpenCount.set(0); jdbcPoolConnectionCloseCount.set(0); - + jdbcResultSetOpenCount.set(0); jdbcResultSetCloseCount.set(0); @@ -111,6 +113,8 @@ public class SpringMethodStat { } executeCount.incrementAndGet(); + + Profiler.enter(methodInfo.getSignature(), Profiler.PROFILE_TYPE_SPRING); } public void afterInvoke(Throwable error, long nanos) { @@ -122,6 +126,8 @@ public class SpringMethodStat { lastError = error; lastErrorTimeMillis = System.currentTimeMillis(); } + + Profiler.release(nanos); } public Throwable getLastError() { @@ -263,15 +269,15 @@ public class SpringMethodStat { public void incrementJdbcPoolConnectionCloseCount() { jdbcPoolConnectionCloseCount.incrementAndGet(); } - + public long getJdbcResultSetOpenCount() { return jdbcResultSetOpenCount.get(); } - + public void addJdbcResultSetOpenCount(long delta) { jdbcResultSetOpenCount.addAndGet(delta); } - + public void incrementJdbcResultSetOpenCount() { jdbcResultSetOpenCount.incrementAndGet(); } @@ -279,11 +285,11 @@ public class SpringMethodStat { public long getJdbcResultSetCloseCount() { return jdbcResultSetCloseCount.get(); } - + public void addJdbcResultSetCloseCount(long delta) { jdbcResultSetCloseCount.addAndGet(delta); } - + public void incrementJdbcResultSetCloseCount() { jdbcResultSetCloseCount.incrementAndGet(); } @@ -305,10 +311,10 @@ public class SpringMethodStat { data.put("JdbcPoolConnectionOpenCount", this.getJdbcPoolConnectionOpenCount()); data.put("JdbcPoolConnectionCloseCount", this.getJdbcPoolConnectionCloseCount()); - + data.put("JdbcResultSetOpenCount", this.getJdbcResultSetOpenCount()); data.put("JdbcResultSetCloseCount", this.getJdbcResultSetCloseCount()); - + data.put("JdbcExecuteCount", this.getJdbcExecuteCount()); data.put("JdbcExecuteErrorCount", this.getJdbcExecuteErrorCount()); data.put("JdbcExecuteTimeMillis", this.getJdbcExecuteTimeMillis()); diff --git a/src/test/java/com/alibaba/druid/bvt/support/profile/ProfilerTest.java b/src/test/java/com/alibaba/druid/bvt/support/profile/ProfilerTest.java new file mode 100644 index 0000000000..8af2c8c619 --- /dev/null +++ b/src/test/java/com/alibaba/druid/bvt/support/profile/ProfilerTest.java @@ -0,0 +1,65 @@ +package com.alibaba.druid.bvt.support.profile; + +import junit.framework.Assert; +import junit.framework.TestCase; + +import com.alibaba.druid.support.profile.ProfileEntryKey; +import com.alibaba.druid.support.profile.ProfileEntryReqStat; +import com.alibaba.druid.support.profile.Profiler; + +public class ProfilerTest extends TestCase { + + public void test_profile() throws Exception { + for (int i = 0; i < 10; ++i) { + req(); + } + } + + private void req() { + Profiler.initLocal(); + + Profiler.enter("/", Profiler.PROFILE_TYPE_WEB); + + for (int i = 0; i < 100; ++i) { + execA(); + } + + Assert.assertEquals(2, Profiler.getStatsMap().size()); + + { + ProfileEntryReqStat stat = Profiler.getStatsMap().get(new ProfileEntryKey("/", "com.xxx.a(int)", + Profiler.PROFILE_TYPE_SPRING)); + Assert.assertEquals(100, stat.getExecuteCount()); + Assert.assertEquals(100, stat.getExecuteTimeNanos()); + } + + { + ProfileEntryReqStat stat = Profiler.getStatsMap().get(new ProfileEntryKey("com.xxx.a(int)", + "com.xxx.b(int)", + Profiler.PROFILE_TYPE_SPRING)); + Assert.assertEquals(1000 * 100, stat.getExecuteCount()); + Assert.assertEquals(1000 * 100, stat.getExecuteTimeNanos()); + } + + Profiler.release(1); + + Assert.assertEquals(3, Profiler.getStatsMap().size()); + + Profiler.removeLocal(); + } + + private void execA() { + Profiler.enter("com.xxx.a(int)", Profiler.PROFILE_TYPE_SPRING); + + for (int i = 0; i < 1000; ++i) { + execB(); + } + + Profiler.release(1); + } + + private void execB() { + Profiler.enter("com.xxx.b(int)", Profiler.PROFILE_TYPE_SPRING); + Profiler.release(1); + } +}