From d16f33d26bb31ed82bac90e1461e4295c29fe876 Mon Sep 17 00:00:00 2001 From: Rob Bygrave Date: Thu, 12 Dec 2013 20:57:50 +1300 Subject: [PATCH] Modified DataSource pool - cleanup of reset and statistics collection --- .../avaje/ebean/config/DataSourceConfig.java | 4 +- .../server/lib/sql/BusyConnectionBuffer.java | 36 +- .../server/lib/sql/DataSourcePool.java | 29 +- .../lib/sql/DataSourcePoolStatistics.java | 97 +++ .../lib/sql/ExtendedPreparedStatement.java | 7 +- .../server/lib/sql/FreeConnectionBuffer.java | 34 + .../server/lib/sql/PooledConnection.java | 791 +++++++++--------- .../server/lib/sql/PooledConnectionQueue.java | 98 ++- .../lib/sql/PooledConnectionStatistics.java | 162 ++++ .../server/lib/sql/PstmtCache.java | 34 +- .../server/lib/sql/TestBusyBuffer.java | 12 + 11 files changed, 852 insertions(+), 452 deletions(-) create mode 100644 src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePoolStatistics.java create mode 100644 src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionStatistics.java diff --git a/src/main/java/com/avaje/ebean/config/DataSourceConfig.java b/src/main/java/com/avaje/ebean/config/DataSourceConfig.java index d6481e28c..9ed13c363 100644 --- a/src/main/java/com/avaje/ebean/config/DataSourceConfig.java +++ b/src/main/java/com/avaje/ebean/config/DataSourceConfig.java @@ -42,14 +42,14 @@ public class DataSourceConfig { private int leakTimeMinutes = 30; - private int maxInactiveTimeSecs = 900; + private int maxInactiveTimeSecs = 720; private int pstmtCacheSize = 20; private int cstmtCacheSize = 20; private int waitTimeoutMillis = 1000; - + private String poolListener; private boolean offline; diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/BusyConnectionBuffer.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/BusyConnectionBuffer.java index dc5a314c2..98b55d682 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/BusyConnectionBuffer.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/BusyConnectionBuffer.java @@ -5,6 +5,11 @@ import java.util.Arrays; import java.util.Collections; import java.util.List; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import com.avaje.ebeaninternal.server.lib.sql.PooledConnectionStatistics.LoadValues; + /** * A buffer especially designed for Busy PooledConnections. *

@@ -21,6 +26,8 @@ import java.util.List; */ class BusyConnectionBuffer { + private static final Logger logger = LoggerFactory.getLogger(BusyConnectionBuffer.class); + private PooledConnection[] slots; private int growBy; @@ -66,8 +73,13 @@ class BusyConnectionBuffer { return size; } - protected boolean isEmpty(){ - return size == 0; + protected boolean isEmpty() { + for (int i = 0; i < slots.length; i++) { + if (slots[i] != null) { + return false; + } + } + return true; } protected int add(PooledConnection pc){ @@ -75,23 +87,37 @@ class BusyConnectionBuffer { // grow the capacity setCapacity(slots.length + growBy); } - ++size; int slot = nextEmptySlot(); pc.setSlotId(slot); slots[slot] = pc; - return size; + return ++size; } protected boolean remove(PooledConnection pc) { - --size; + int slotId = pc.getSlotId(); if (slots[slotId] != pc){ + PooledConnection heldBy = slots[slotId]; + logger.warn("Failed to remove from slot[{}] PooledConnection[{}] - HeldBy[{}]", pc.getSlotId(), pc, heldBy); return false; } slots[slotId] = null; + --size; return true; } + /** + * Collect the load statistics from all the busy connections. + * @param reset + */ + protected void collectStatistics(LoadValues values, boolean reset) { + + for (int i = 0; i < slots.length; i++) { + if (slots[i] != null){ + values.plus(slots[i].getStatistics().getValues(reset)); + } + } + } /** * Get a shallow read only List of the busy connections. diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePool.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePool.java index c54d5582e..3cb861427 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePool.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePool.java @@ -15,11 +15,12 @@ import java.util.Set; import javax.persistence.PersistenceException; import javax.sql.DataSource; -import com.avaje.ebean.config.DataSourceConfig; -import com.avaje.ebeaninternal.api.ClassUtil; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import com.avaje.ebean.config.DataSourceConfig; +import com.avaje.ebeaninternal.api.ClassUtil; + /** * A robust DataSource. *

@@ -73,7 +74,7 @@ public class DataSourcePool implements DataSource { * The sql used to test a connection. */ private final String heartbeatsql; - + private final int heartbeatFreqSecs; /** @@ -573,7 +574,15 @@ public class DataSourcePool implements DataSource { } queue.returnPooledConnection(pooledConnection); } - + + /** + * Collect statistics of a connection that is fully closing + */ + protected void reportClosingConnection(PooledConnection pooledConnection) { + + queue.reportClosingConnection(pooledConnection); + } + /** * Returns information describing connections that are currently being used. */ @@ -834,6 +843,14 @@ public class DataSourcePool implements DataSource { public Status getStatus(boolean reset) { return queue.getStatus(reset); } + + /** + * Return the aggregated load statistics collected on all the connections in the pool. + */ + public DataSourcePoolStatistics getStatistics(boolean reset) { + + return queue.getStatistics(reset); + } /** * Deregister the JDBC driver. @@ -873,8 +890,8 @@ public class DataSourcePool implements DataSource { } public String toString() { - return "min:" + minSize + " max:" + maxSize + " free:" + free + " busy:" + busy + " waiting:" + waiting - + " highWaterMark:" + highWaterMark + " waitCount:" + waitCount + " hitCount:" + hitCount; + return "min[" + minSize + "] max[" + maxSize + "] free[" + free + "] busy[" + busy + "] waiting[" + waiting + + "] highWaterMark[" + highWaterMark + "] waitCount[" + waitCount + "] hitCount[" + hitCount+"]"; } /** diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePoolStatistics.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePoolStatistics.java new file mode 100644 index 000000000..5bdc1c9ad --- /dev/null +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/DataSourcePoolStatistics.java @@ -0,0 +1,97 @@ +package com.avaje.ebeaninternal.server.lib.sql; + +/** + * Represents aggregated statistics collected from the DataSourcePool. + *

+ * The goal is to present insight into the overload load of the DataSourcePool. + * These statistics can be collected and reported regularly to show load over + * time. + *

+ *

+ * Each pooled connection collects statistics. When a pooled connection is fully + * closed it can report it's statistics to the pool to be included as part of + * the collected statistics. + *

+ */ +public class DataSourcePoolStatistics { + + private final long collectionStart; + + private final long count; + + private final long errorCount; + + private final long hwmMicros; + + private final long totalMicros; + + /** + * No statistics collected. + */ + public DataSourcePoolStatistics() { + this.collectionStart = 0; + this.count = 0; + this.errorCount = 0; + this.hwmMicros = 0; + this.totalMicros = 0; + } + + /** + * Construct with statistics collected. + */ + public DataSourcePoolStatistics(long collectionStart, long count, long errorCount, long hwmMicros, long totalMicros) { + this.collectionStart = collectionStart; + this.count = count; + this.errorCount = errorCount; + this.hwmMicros = hwmMicros; + this.totalMicros = totalMicros; + } + + public String toString() { + return "count[" + count + "] errors[" + errorCount + "] totalMicros[" + totalMicros + "] hwmMicros[" + hwmMicros + + "] avgMicros[" + getAvgMicros() + "]"; + } + + /** + * Return the start time this set of statistics was collected from. + */ + public long getCollectionStart() { + return collectionStart; + } + + /** + * Return the total number of 'get connection' requests. + */ + public long getCount() { + return count; + } + + /** + * Return the number of SQLExceptions reported. + */ + public long getErrorCount() { + return errorCount; + } + + /** + * Return the high water mark for the duration a connection was busy/used. + */ + public long getHwmMicros() { + return hwmMicros; + } + + /** + * Return the aggregate time connections were busy/used. + */ + public long getTotalMicros() { + return totalMicros; + } + + /** + * Return the average time connections were busy/used. + */ + public long getAvgMicros() { + return (totalMicros == 0) ? 0 : totalMicros / count; + } + +} diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/ExtendedPreparedStatement.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/ExtendedPreparedStatement.java index 3b3b40344..439b0731f 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/ExtendedPreparedStatement.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/ExtendedPreparedStatement.java @@ -31,18 +31,17 @@ public class ExtendedPreparedStatement extends ExtendedStatement implements Prep /** * The SQL used to create the underlying PreparedStatement. */ - final String sql; + private final String sql; /** * The key used to cache this in the connection. */ - final String cacheKey; + private final String cacheKey; /** * Create a wrapped PreparedStatement that can be cached. */ - public ExtendedPreparedStatement(PooledConnection pooledConnection, PreparedStatement pstmt, - String sql, String cacheKey) { + public ExtendedPreparedStatement(PooledConnection pooledConnection, PreparedStatement pstmt, String sql, String cacheKey) { super(pooledConnection, pstmt); this.sql = sql; this.cacheKey = cacheKey; diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/FreeConnectionBuffer.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/FreeConnectionBuffer.java index 23f160091..813740633 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/FreeConnectionBuffer.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/FreeConnectionBuffer.java @@ -3,6 +3,8 @@ package com.avaje.ebeaninternal.server.lib.sql; import java.util.ArrayList; import java.util.List; +import com.avaje.ebeaninternal.server.lib.sql.PooledConnectionStatistics.LoadValues; + /** * A buffer designed especially to hold free pooled connections. *

@@ -48,11 +50,31 @@ class FreeConnectionBuffer { * Add at connection. */ protected void add(PooledConnection pc) { + if (conns[addIndex] != null) { + throw new RuntimeException("Buffer slot ["+addIndex+"] already full?"); + } conns[addIndex] = pc; addIndex = inc(addIndex); ++size; } + protected void closeAll(boolean logErrors) { + + final PooledConnection[] items = this.conns; + + this.conns = new PooledConnection[items.length]; + this.size = 0; + this.removeIndex = 0; + this.addIndex = 0; + + for (int i = 0; i < items.length; i++) { + PooledConnection c = items[i]; + if (c != null) { + c.closeConnectionFully(logErrors); + } + } + } + /** * Remove a connection at current remove position. */ @@ -79,6 +101,18 @@ class FreeConnectionBuffer { return copy; } + /** + * Collect the load statistics from all the free connections. + */ + protected void collectStatistics(LoadValues values, boolean reset) { + + for (int i = 0; i < conns.length; i++) { + if (conns[i] != null){ + values.plus(conns[i].getStatistics().getValues(reset)); + } + } + } + /** * Set the free list to be the connections in this copy. This is done after * unused connections have been trimmed. diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnection.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnection.java index 5b29b7fb5..d6c3293bc 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnection.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnection.java @@ -34,8 +34,7 @@ import org.slf4j.LoggerFactory; * statement that was executed. Keeps statistics on how long it is in use. *

*/ -public class PooledConnection extends ConnectionDelegator -{ +public class PooledConnection extends ConnectionDelegator { private static final Logger logger = LoggerFactory.getLogger(PooledConnection.class); @@ -45,49 +44,49 @@ public class PooledConnection extends ConnectionDelegator * Set when connection is idle in the pool. In general when in the pool the * connection should not be modified. */ - static final int STATUS_IDLE = 88; + private static final int STATUS_IDLE = 88; /** * Set when connection given to client. */ - static final int STATUS_ACTIVE = 89; + private static final int STATUS_ACTIVE = 89; /** * Set when commit() or rollback() called. */ - static final int STATUS_ENDED = 87; + private static final int STATUS_ENDED = 87; /** * Name used to identify the PooledConnection for logging. */ - final String name; + private final String name; /** * The pool this connection belongs to. */ - final DataSourcePool pool; + private final DataSourcePool pool; /** * The underlying connection. */ - final Connection connection; + private final Connection connection; /** * The time this connection was created. */ - final long creationTime; + private final long creationTime; /** * Cache of the PreparedStatements */ - final PstmtCache pstmtCache; + private final PstmtCache pstmtCache; - final Object pstmtMonitor = new Object(); + private final Object pstmtMonitor = new Object(); /** * The status of the connection. IDLE, ACTIVE or ENDED. */ - int status = STATUS_IDLE; + private int status = STATUS_IDLE; /** * Set this to true if the connection will be busy for a long time. @@ -95,56 +94,53 @@ public class PooledConnection extends ConnectionDelegator * This means it should skip the suspected connection pool leak checking. *

*/ - boolean longRunning; + private boolean longRunning; /** * Flag to indicate that this connection had errors and should be checked to * make sure it is okay. */ - boolean hadErrors; + private boolean hadErrors; /** * The last start time. When the connection was given to a thread. */ - long startUseTime; + private long startUseTime; /** * The last end time of this connection. This is to calculate the usage * time. */ - long lastUseTime; + private long lastUseTime; + + private long exeStartNanos; + + private final PooledConnectionStatistics stats = new PooledConnectionStatistics(); /** * The last statement executed by this connection. */ - String lastStatement; - - /** - * The number of hits against the preparedStatement cache. - */ - int pstmtHitCounter; - - /** - * The number of misses against the preparedStatement cache. - */ - int pstmtMissCounter; + private String lastStatement; /** * The non avaje method that created the connection. */ - String createdByMethod; + private String createdByMethod; /** * Used to find connection pool leaks. */ - StackTraceElement[] stackTrace; + private StackTraceElement[] stackTrace; - int maxStackTrace; + private int maxStackTrace; /** * Slot position in the BusyConnectionBuffer. */ - int slotId; + private int slotId; + + private boolean resetIsolationReadOnlyRequired; + /** * Construct the connection that can refer back to the pool it belongs to. @@ -165,47 +161,47 @@ public class PooledConnection extends ConnectionDelegator this.lastUseTime = creationTime; } - /** - * For testing the pool without real connections. - */ - protected PooledConnection(String name) { - super(null); - this.name = name; - this.pool = null; - this.connection = null; - this.pstmtCache = null; - this.maxStackTrace = 0; - this.creationTime = System.currentTimeMillis(); - this.lastUseTime = creationTime; - } - - /** - * Return the slot position in the busy buffer. - */ - public int getSlotId() { - return slotId; - } + /** + * For testing the pool without real connections. + */ + protected PooledConnection(String name) { + super(null); + this.name = name; + this.pool = null; + this.connection = null; + this.pstmtCache = null; + this.maxStackTrace = 0; + this.creationTime = System.currentTimeMillis(); + this.lastUseTime = creationTime; + } - /** - * Set the slot position in the busy buffer. - */ - public void setSlotId(int slotId) { - this.slotId = slotId; - } + /** + * Return the slot position in the busy buffer. + */ + public int getSlotId() { + return slotId; + } - /** - * Return the DataSourcePool that this connection belongs to. - */ - public DataSourcePool getDataSourcePool() { - return pool; - } + /** + * Set the slot position in the busy buffer. + */ + public void setSlotId(int slotId) { + this.slotId = slotId; + } - /** - * Return the time the connection was created. - */ - public long getCreationTime() { - return creationTime; - } + /** + * Return the DataSourcePool that this connection belongs to. + */ + public DataSourcePool getDataSourcePool() { + return pool; + } + + /** + * Return the time the connection was created. + */ + public long getCreationTime() { + return creationTime; + } /** * Return a string to identify the connection. @@ -214,16 +210,24 @@ public class PooledConnection extends ConnectionDelegator return name; } + public String getNameSlot() { + return name+":"+slotId; + } + public String toString() { - return name; + return getDescription(); } public String getDescription() { - return "name["+name+"] startTime["+getStartUseTime()+"] stmt["+getLastStatement()+"] createdBy["+getCreatedByMethod()+"]"; + return "name["+name+"] slot["+slotId+"] startTime["+getStartUseTime()+"] stmt["+getLastStatement()+"] createdBy["+getCreatedByMethod()+"]"; } - public String getStatistics() { - return "name["+name+"] startTime["+getStartUseTime()+"] pstmtHits["+pstmtHitCounter+"] pstmtMiss["+pstmtMissCounter+"] "+pstmtCache.getDescription(); + public String getPstmtStatistics() { + return "name["+name+"] startTime["+getStartUseTime()+"] "+pstmtCache.getDescription(); + } + + public PooledConnectionStatistics getStatistics() { + return stats; } /** @@ -253,21 +257,25 @@ public class PooledConnection extends ConnectionDelegator */ public void closeConnectionFully(boolean logErrors) { - String msg = "Closing Connection[" + getName() + "]" + " psReuse[" + pstmtHitCounter - + "] psCreate[" + pstmtMissCounter + "] psSize[" + pstmtCache.size() + "]"; - - logger.debug(msg); + if (pool != null) { + // allow collection of load statistics + pool.reportClosingConnection(this); + } + + if (logger.isDebugEnabled()) { + logger.debug("Closing Connection[{}] slot[{}] Stats: {} , PstmtStats: {} ", name, slotId, stats.getValues(false), pstmtCache.getDescription()); + } try { if (connection.isClosed()) { // Typically the JDBC Driver has its own JVM shutdown hook and already // closed the connections in our DataSource pool so making this DEBUG level - logger.debug("Closing Connection[" + getName() + "] that is already closed?"); + logger.debug("Closing Connection[{}] that is already closed?", name); return; } } catch (SQLException ex) { if (logErrors) { - logger.error("Error when fully closing connection [" + getName() + "]", ex); + logger.error("Error checking if connection [" + getNameSlot() + "] is closed", ex); } } @@ -287,8 +295,8 @@ public class PooledConnection extends ConnectionDelegator try { connection.close(); } catch (SQLException ex) { - if (logErrors) { - logger.error("Error when fully closing connection [" + getName() + "]", ex); + if (logErrors || logger.isDebugEnabled()) { + logger.error("Error when fully closing connection [" + getNameSlot() + "]", ex); } } } @@ -337,26 +345,15 @@ public class PooledConnection extends ConnectionDelegator protected void returnPreparedStatement(ExtendedPreparedStatement pstmt) { synchronized (pstmtMonitor) { - ExtendedPreparedStatement alreadyInCache = pstmtCache.get(pstmt.getCacheKey()); + if (!pstmtCache.returnStatement(pstmt)) { + try { + // Already an entry in the cache with the exact same SQL... + pstmt.closeDestroy(); - if (alreadyInCache == null) { - // add the returning prepared statement to the cache. - // Note that the LRUCache will automatically close fully old unused - // PStmts when the cache has hit its maximum size. - pstmtCache.put(pstmt.getCacheKey(), pstmt); - - } else { - try { - // if a entry in the cache exists for the exact same SQL... - // then remove it from the cache and close it fully. - // Only having one PreparedStatement per unique SQL - // statement - pstmt.closeDestroy(); - - } catch (SQLException e) { - logger.error("Error closing Pstmt", e); - } - } + } catch (SQLException e) { + logger.error("Error closing Pstmt", e); + } + } } } @@ -392,12 +389,10 @@ public class PooledConnection extends ConnectionDelegator ExtendedPreparedStatement pstmt = pstmtCache.remove(cacheKey); if (pstmt != null) { - pstmtHitCounter++; return pstmt; } // create a new PreparedStatement - pstmtMissCounter++; PreparedStatement actualPstmt; if (useFlag) { actualPstmt = connection.prepareStatement(sql, flag); @@ -420,7 +415,6 @@ public class PooledConnection extends ConnectionDelegator } try { // no caching when creating PreparedStatements this way - pstmtMissCounter++; lastStatement = sql; return connection.prepareStatement(sql, resultSetType, resultSetConcurreny); } catch (SQLException ex) { @@ -436,6 +430,7 @@ public class PooledConnection extends ConnectionDelegator protected void resetForUse() { this.status = STATUS_ACTIVE; this.startUseTime = System.currentTimeMillis(); + this.exeStartNanos = System.nanoTime(); this.createdByMethod = null; this.lastStatement = null; this.hadErrors = false; @@ -480,6 +475,9 @@ public class PooledConnection extends ConnectionDelegator throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "close()"); } + long durationNanos = System.nanoTime() - exeStartNanos; + stats.add(durationNanos, hadErrors); + if (hadErrors) { if (!pool.validateConnection(this)) { // the connection is BAD, close it and test the pool @@ -530,12 +528,11 @@ public class PooledConnection extends ConnectionDelegator try { if (connection != null && !connection.isClosed()) { // connect leak? - String msg = "Closing Connection[" + getName() + "] on finalize()."; - logger.warn(msg); + logger.warn("Closing Connection[" + getName() + "] on finalize()."); closeConnectionFully(false); } } catch (Exception e) { - logger.error(null, e); + logger.error("Error when finalize is closing a connection? (unexpected)", e); } super.finalize(); } @@ -581,7 +578,6 @@ public class PooledConnection extends ConnectionDelegator } } - boolean resetIsolationReadOnlyRequired = false; /** * Also note the read only status needs to be reset when put back into the @@ -614,327 +610,326 @@ public class PooledConnection extends ConnectionDelegator } } - // - // - // Simple wrapper methods which pass a method call onto the acutal - // connection object. These methods are safe-guarded to prevent use of - // the methods whilst the connection is in the connection pool. - // - // - public void clearWarnings() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "clearWarnings()"); - } - connection.clearWarnings(); - } + // + // + // Simple wrapper methods which pass a method call onto the acutal + // connection object. These methods are safe-guarded to prevent use of + // the methods whilst the connection is in the connection pool. + // + // + public void clearWarnings() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "clearWarnings()"); + } + connection.clearWarnings(); + } - public void commit() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "commit()"); - } - try { - status = STATUS_ENDED; - connection.commit(); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } - - public boolean getAutoCommit() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getAutoCommit()"); - } - return connection.getAutoCommit(); - } + public void commit() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "commit()"); + } + try { + status = STATUS_ENDED; + connection.commit(); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public String getCatalog() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getCatalog()"); - } - return connection.getCatalog(); - } + public boolean getAutoCommit() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getAutoCommit()"); + } + return connection.getAutoCommit(); + } - public DatabaseMetaData getMetaData() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getMetaData()"); - } - return connection.getMetaData(); - } + public String getCatalog() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getCatalog()"); + } + return connection.getCatalog(); + } - public int getTransactionIsolation() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getTransactionIsolation()"); - } - return connection.getTransactionIsolation(); - } + public DatabaseMetaData getMetaData() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getMetaData()"); + } + return connection.getMetaData(); + } - public Map> getTypeMap() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getTypeMap()"); - } - return connection.getTypeMap(); - } + public int getTransactionIsolation() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getTransactionIsolation()"); + } + return connection.getTransactionIsolation(); + } - public SQLWarning getWarnings() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getWarnings()"); - } - return connection.getWarnings(); - } + public Map> getTypeMap() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getTypeMap()"); + } + return connection.getTypeMap(); + } - public boolean isClosed() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "isClosed()"); - } - return connection.isClosed(); - } + public SQLWarning getWarnings() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "getWarnings()"); + } + return connection.getWarnings(); + } - public boolean isReadOnly() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "isReadOnly()"); - } - return connection.isReadOnly(); - } + public boolean isClosed() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "isClosed()"); + } + return connection.isClosed(); + } - public String nativeSQL(String sql) throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "nativeSQL()"); - } - lastStatement = sql; - return connection.nativeSQL(sql); - } + public boolean isReadOnly() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "isReadOnly()"); + } + return connection.isReadOnly(); + } - public CallableStatement prepareCall(String sql) throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareCall()"); - } - lastStatement = sql; - return connection.prepareCall(sql); - } + public String nativeSQL(String sql) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "nativeSQL()"); + } + lastStatement = sql; + return connection.nativeSQL(sql); + } - public CallableStatement prepareCall(String sql, int resultSetType, int resultSetConcurreny) - throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareCall()"); - } - lastStatement = sql; - return connection.prepareCall(sql, resultSetType, resultSetConcurreny); - } + public CallableStatement prepareCall(String sql) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareCall()"); + } + lastStatement = sql; + return connection.prepareCall(sql); + } - public void rollback() throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "rollback()"); - } - try { - status = STATUS_ENDED; - connection.rollback(); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public CallableStatement prepareCall(String sql, int resultSetType, int resultSetConcurreny) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareCall()"); + } + lastStatement = sql; + return connection.prepareCall(sql, resultSetType, resultSetConcurreny); + } - public void setAutoCommit(boolean autoCommit) throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setAutoCommit()"); - } - try { - connection.setAutoCommit(autoCommit); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public void rollback() throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "rollback()"); + } + try { + status = STATUS_ENDED; + connection.rollback(); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public void setCatalog(String catalog) throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setCatalog()"); - } - connection.setCatalog(catalog); - } + public void setAutoCommit(boolean autoCommit) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setAutoCommit()"); + } + try { + connection.setAutoCommit(autoCommit); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public void setTypeMap(Map> map) throws SQLException { - if (status == STATUS_IDLE) { - throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setTypeMap()"); - } - connection.setTypeMap(map); - } + public void setCatalog(String catalog) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setCatalog()"); + } + connection.setCatalog(catalog); + } - public Savepoint setSavepoint() throws SQLException { - try { - return connection.setSavepoint(); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public void setTypeMap(Map> map) throws SQLException { + if (status == STATUS_IDLE) { + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "setTypeMap()"); + } + connection.setTypeMap(map); + } - public Savepoint setSavepoint(String savepointName) throws SQLException { - try { - return connection.setSavepoint(savepointName); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public Savepoint setSavepoint() throws SQLException { + try { + return connection.setSavepoint(); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public void rollback(Savepoint sp) throws SQLException { - try { - connection.rollback(sp); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public Savepoint setSavepoint(String savepointName) throws SQLException { + try { + return connection.setSavepoint(savepointName); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public void releaseSavepoint(Savepoint sp) throws SQLException { - try { - connection.releaseSavepoint(sp); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public void rollback(Savepoint sp) throws SQLException { + try { + connection.rollback(sp); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public void setHoldability(int i) throws SQLException { - try { - connection.setHoldability(i); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public void releaseSavepoint(Savepoint sp) throws SQLException { + try { + connection.releaseSavepoint(sp); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public int getHoldability() throws SQLException { - try { - return connection.getHoldability(); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public void setHoldability(int i) throws SQLException { + try { + connection.setHoldability(i); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public Statement createStatement(int i, int x, int y) throws SQLException { - try { - return connection.createStatement(i, x, y); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public int getHoldability() throws SQLException { + try { + return connection.getHoldability(); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public PreparedStatement prepareStatement(String s, int i, int x, int y) throws SQLException { - try { - return connection.prepareStatement(s, i, x, y); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public Statement createStatement(int i, int x, int y) throws SQLException { + try { + return connection.createStatement(i, x, y); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public PreparedStatement prepareStatement(String s, int[] i) throws SQLException { - try { - return connection.prepareStatement(s, i); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public PreparedStatement prepareStatement(String s, int i, int x, int y) throws SQLException { + try { + return connection.prepareStatement(s, i, x, y); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public PreparedStatement prepareStatement(String s, String[] s2) throws SQLException { - try { - return connection.prepareStatement(s, s2); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public PreparedStatement prepareStatement(String s, int[] i) throws SQLException { + try { + return connection.prepareStatement(s, i); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - public CallableStatement prepareCall(String s, int i, int x, int y) throws SQLException { - try { - return connection.prepareCall(s, i, x, y); - } catch (SQLException ex) { - addError(ex); - throw ex; - } - } + public PreparedStatement prepareStatement(String s, String[] s2) throws SQLException { + try { + return connection.prepareStatement(s, s2); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - /** - * Returns the method that created the connection. - *

- * Used to help finding connection pool leaks. - *

- */ - public String getCreatedByMethod() { - if (createdByMethod != null) { - return createdByMethod; - } - if (stackTrace == null) { - return null; - } + public CallableStatement prepareCall(String s, int i, int x, int y) throws SQLException { + try { + return connection.prepareCall(s, i, x, y); + } catch (SQLException ex) { + addError(ex); + throw ex; + } + } - for (int j = 0; j < stackTrace.length; j++) { - String methodLine = stackTrace[j].toString(); - if (skipElement(methodLine)) { - // ignore these methods... - } else { - createdByMethod = methodLine; - return createdByMethod; - } - } + /** + * Returns the method that created the connection. + *

+ * Used to help finding connection pool leaks. + *

+ */ + public String getCreatedByMethod() { + if (createdByMethod != null) { + return createdByMethod; + } + if (stackTrace == null) { + return null; + } - return null; - } + for (int j = 0; j < stackTrace.length; j++) { + String methodLine = stackTrace[j].toString(); + if (skipElement(methodLine)) { + // ignore these methods... + } else { + createdByMethod = methodLine; + return createdByMethod; + } + } - private boolean skipElement(String methodLine) { - if (methodLine.startsWith("java.lang.")) { - return true; - } else if (methodLine.startsWith("java.util.")) { - return true; - } else if (methodLine.startsWith("com.avaje.ebeaninternal.server.query.CallableQuery.")) { - // creating connection on future... - return true; - } else if (methodLine.startsWith("com.avaje.ebeaninternal.server.query.Callable")) { - // it is a future task being executed... - return false; - } else if (methodLine.startsWith("com.avaje.ebeaninternal")) { - return true; - } else { - return false; - } - } - - /** - * Set the stack trace to help find connection pool leaks. - */ - protected void setStackTrace(StackTraceElement[] stackTrace) { - this.stackTrace = stackTrace; - } + return null; + } - /** - * Return the full stack trace that got the connection from the pool. You - * could use this if getCreatedByMethod() doesn't work for you. - */ - public StackTraceElement[] getStackTrace() { - - if (stackTrace == null){ - return null; - } - - // filter off the top of the stack that we are not interested in - ArrayList filteredList = new ArrayList(); - boolean include = false; - for (int i = 0; i < stackTrace.length; i++) { - if (!include && !skipElement(stackTrace[i].toString())){ - include = true; - } - if (include && filteredList.size() < maxStackTrace){ - filteredList.add(stackTrace[i]); - } - } - return filteredList.toArray(new StackTraceElement[filteredList.size()]); - - } + private boolean skipElement(String methodLine) { + if (methodLine.startsWith("java.lang.")) { + return true; + } else if (methodLine.startsWith("java.util.")) { + return true; + } else if (methodLine.startsWith("com.avaje.ebeaninternal.server.query.CallableQuery.")) { + // creating connection on future... + return true; + } else if (methodLine.startsWith("com.avaje.ebeaninternal.server.query.Callable")) { + // it is a future task being executed... + return false; + } else if (methodLine.startsWith("com.avaje.ebeaninternal")) { + return true; + } else { + return false; + } + } + + /** + * Set the stack trace to help find connection pool leaks. + */ + protected void setStackTrace(StackTraceElement[] stackTrace) { + this.stackTrace = stackTrace; + } + + /** + * Return the full stack trace that got the connection from the pool. You + * could use this if getCreatedByMethod() doesn't work for you. + */ + public StackTraceElement[] getStackTrace() { + + if (stackTrace == null) { + return null; + } + + // filter off the top of the stack that we are not interested in + ArrayList filteredList = new ArrayList(); + boolean include = false; + for (int i = 0; i < stackTrace.length; i++) { + if (!include && !skipElement(stackTrace[i].toString())) { + include = true; + } + if (include && filteredList.size() < maxStackTrace) { + filteredList.add(stackTrace[i]); + } + } + return filteredList.toArray(new StackTraceElement[filteredList.size()]); + + } } diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionQueue.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionQueue.java index b7daa3942..fe5d45c04 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionQueue.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionQueue.java @@ -9,10 +9,12 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.locks.Condition; import java.util.concurrent.locks.ReentrantLock; -import com.avaje.ebeaninternal.server.lib.sql.DataSourcePool.Status; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import com.avaje.ebeaninternal.server.lib.sql.DataSourcePool.Status; +import com.avaje.ebeaninternal.server.lib.sql.PooledConnectionStatistics.LoadValues; + public class PooledConnectionQueue { private static final Logger logger = LoggerFactory.getLogger(PooledConnectionQueue.class); @@ -34,6 +36,16 @@ public class PooledConnectionQueue { */ private final BusyConnectionBuffer busyList; + /** + * Load statistics collected off connections that have closed fully (left the pool). + */ + private final PooledConnectionStatistics collectedStats = new PooledConnectionStatistics(); + + /** + * Currently accumulated load statistics. + */ + private LoadValues accumulatedValues = new LoadValues(); + /** * Main lock guarding all access */ @@ -95,10 +107,10 @@ public class PooledConnectionQueue { this.waitTimeoutMillis = pool.getWaitTimeoutMillis(); this.leakTimeMinutes = pool.getLeakTimeMinutes(); - this.busyList = new BusyConnectionBuffer(50,20); + this.busyList = new BusyConnectionBuffer(maxSize, 20); this.freeList = new FreeConnectionBuffer(maxSize); - - this.lock = new ReentrantLock(true); + + this.lock = new ReentrantLock(false); this.notEmpty = lock.newCondition(); } @@ -116,6 +128,36 @@ public class PooledConnectionQueue { } } + /** + * Collect statistics of a connection that is fully closing + */ + protected void reportClosingConnection(PooledConnection pooledConnection) { + + collectedStats.add(pooledConnection.getStatistics()); + } + + public DataSourcePoolStatistics getStatistics(boolean reset) { + + final ReentrantLock lock = this.lock; + lock.lock(); + try { + + LoadValues aggregate = collectedStats.getValues(reset); + + freeList.collectStatistics(aggregate, reset); + busyList.collectStatistics(aggregate, reset); + + aggregate.plus(accumulatedValues); + + this.accumulatedValues = (reset) ? new LoadValues() : aggregate; + + return new DataSourcePoolStatistics(aggregate.getCollectionStart(), aggregate.getCount(), aggregate.getErrorCount(), aggregate.getHwmMicros(), aggregate.getTotalMicros()); + + } finally { + lock.unlock(); + } + } + public Status getStatus(boolean reset) { final ReentrantLock lock = this.lock; lock.lock(); @@ -203,7 +245,7 @@ public class PooledConnectionQueue { lock.lock(); try { if (!busyList.remove(c)) { - logger.error("Connection [" + c + "] not found in BusyList? "); + logger.error("Connection [{}] not found in BusyList? ", c); } if (c.getCreationTime() <= lastResetTime) { c.closeConnectionFully(false); @@ -261,8 +303,7 @@ public class PooledConnectionQueue { // are other threads already waiting? (they get priority) if (waitingThreads == 0){ - int freeSize = freeList.size(); - if (freeSize > 0){ + if (!freeList.isEmpty()){ // we have a free connection to return return extractFromFreeList(); } @@ -333,13 +374,13 @@ public class PooledConnectionQueue { try { doingShutdown = true; Status status = createStatus(); - logger.debug("DataSourcePool [" + name + "] shutdown: "+status); + DataSourcePoolStatistics statistics = pool.getStatistics(false); + logger.debug("DataSourcePool [" + name + "] shutdown {} - Statistics {}", status, statistics); closeFreeConnections(true); if (!busyList.isEmpty()) { - logger.warn("A potential connection leak was detected. Busy connections: "+ busyList.size()); - + logger.warn("Closing busy connections on shutdown size: "+ busyList.size()); dumpBusyConnectionInformation(); closeBusyConnections(0); } @@ -366,8 +407,7 @@ public class PooledConnectionQueue { closeFreeConnections(false); closeBusyConnections(leakTimeMinutes); - String busyMsg = "Busy Connections:\r\n" + getBusyConnectionInformation(); - logger.info(busyMsg); + logger.info("Busy Connections:\n" + getBusyConnectionInformation()); } finally { lock.unlock(); @@ -434,11 +474,7 @@ public class PooledConnectionQueue { final ReentrantLock lock = this.lock; lock.lock(); try { - while (!freeList.isEmpty()) { - PooledConnection c = freeList.remove(); - logger.debug("PSTMT Statistics: "+c.getStatistics()); - c.closeConnectionFully(logErrors); - } + freeList.closeAll(logErrors); } finally { lock.unlock(); } @@ -465,6 +501,9 @@ public class PooledConnectionQueue { long olderThanTime = System.currentTimeMillis() - (leakTimeMinutes*60000); List copy = busyList.getShallowCopy(); + + logger.debug("Closing busy connections using leakTimeMinutes {}", leakTimeMinutes); + for (int i = 0; i < copy.size(); i++) { PooledConnection pc = copy.get(i); if (pc.isLongRunning() || pc.getLastUsedTime() > olderThanTime) { @@ -472,7 +511,7 @@ public class PooledConnectionQueue { // expected to be longRunning so not closing... } else { busyList.remove(pc); - closeBusyConnection(pc); + closeBusyConnection(pc, leakTimeMinutes); } } @@ -481,26 +520,26 @@ public class PooledConnectionQueue { } } - private void closeBusyConnection(PooledConnection pc) { + private void closeBusyConnection(PooledConnection pc, long leakMinutes) { try { String methodLine = pc.getCreatedByMethod(); Date luDate = new Date(); luDate.setTime(pc.getLastUsedTime()); - String msg = "DataSourcePool closing leaked connection? " + " name[" - + pc.getName() + "] lastUsed[" + luDate + "] createdBy[" + methodLine + String msg = "DataSourcePool closing leaked connection? name[" + + pc.getName() + "] leakMinutes["+leakMinutes+"] lastUsed[" + luDate + "] createdBy[" + methodLine + "] lastStmt[" + pc.getLastStatement() + "]"; logger.warn(msg); logStackElement(pc, "Possible Leaked Connection: "); + System.out.println("CLOSING Possibly leaked connection: "+pc); - System.out.println("CLOSING BUSY CONNECTION ??? "+pc); - pc.close(); + pc.closeConnectionFully(false); - } catch (SQLException ex) { + } catch (Exception ex) { // this should never actually happen - logger.error(null, ex); + logger.error("Error when closing potentially leaked connection "+pc.getDescription(), ex); } } @@ -557,13 +596,14 @@ public class PooledConnectionQueue { lock.lock(); try { - if (toLogger) { - logger.info("Dumping busy connections: (Use datasource.xxx.capturestacktrace=true ... to get stackTraces)"); - } - StringBuilder sb = new StringBuilder(); List copy = busyList.getShallowCopy(); + + if (toLogger) { + logger.info("Dumping [{}] busy connections: (Use datasource.xxx.capturestacktrace=true ... to get stackTraces)", copy.size()); + } + for (int i = 0; i < copy.size(); i++) { PooledConnection pc = copy.get(i); if (toLogger) { diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionStatistics.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionStatistics.java new file mode 100644 index 000000000..6f9eeac53 --- /dev/null +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PooledConnectionStatistics.java @@ -0,0 +1,162 @@ +package com.avaje.ebeaninternal.server.lib.sql; + +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicLong; + +/** + * Collects load statistics for a PooledConnection. + */ +public class PooledConnectionStatistics { + + private final AtomicLong count = new AtomicLong(); + + private final AtomicLong errorCount = new AtomicLong(); + + private final AtomicLong hwmNanos = new AtomicLong(); + + private final AtomicLong totalNanos = new AtomicLong(); + + private final AtomicLong collectionStart; + + public PooledConnectionStatistics() { + this.collectionStart = new AtomicLong(System.currentTimeMillis()); + } + + /** + * Add statistics from another collector. + */ + public void add(PooledConnectionStatistics other) { + + errorCount.addAndGet(other.getErrorCount()); + totalNanos.addAndGet(other.totalNanos.get()); + count.addAndGet(other.getCount()); + + final long otherHwm = other.hwmNanos.get(); + if (otherHwm > hwmNanos.get()) { + hwmNanos.set(otherHwm); + } + } + + /** + * Add some time duration to the statistics. + */ + public void add(long durationNanos, boolean hasError) { + + // This will be done in pretty much single threaded fashion + // as the Connections generally are not shared across threads + + if (hasError) { + errorCount.incrementAndGet(); + } + count.incrementAndGet(); + totalNanos.addAndGet(durationNanos); + if (durationNanos > hwmNanos.get()) { + hwmNanos.set(durationNanos); + } + } + + public String toString() { + return "count["+count+"] errors["+errorCount+"] totalMicros["+getTotalMicros()+"] hwmMicros["+getHwmMicros()+"]"; + } + + public long getCollectionStart() { + return collectionStart.get(); + } + + public long getCount() { + return count.get(); + } + + public long getErrorCount() { + return errorCount.get(); + } + + public long getTotalMicros() { + return TimeUnit.MICROSECONDS.convert(totalNanos.get(), TimeUnit.NANOSECONDS); + } + + public long getHwmMicros() { + return TimeUnit.MICROSECONDS.convert(hwmNanos.get(), TimeUnit.NANOSECONDS); + } + + /** + * Get the current values and reset the statistics if necessary. + */ + public LoadValues getValues(boolean reset) { + LoadValues value = new LoadValues(collectionStart.get(), count.get(), errorCount.get(), getHwmMicros(), getTotalMicros()); + if (reset) { + count.set(0); + errorCount.set(0); + hwmNanos.set(0); + totalNanos.set(0); + collectionStart.set(System.currentTimeMillis()); + } + return value; + } + + /** + * Values representing the load or activity of a PooledConnection. + *

+ * These are aggregated up to get a total for the DataSourcePool. + *

+ */ + public static class LoadValues { + + private long collectionStart; + private long count; + private long errorCount; + private long hwmMicros; + private long totalMicros; + + public LoadValues() { + } + + public LoadValues(long collectionStart, long count, long errorCount, long hwmMicros, long totalMicros) { + this.collectionStart = collectionStart; + this.count = count; + this.errorCount = errorCount; + this.hwmMicros = hwmMicros; + this.totalMicros = totalMicros; + } + + public void plus(LoadValues additional) { + collectionStart = (collectionStart == 0) ? additional.collectionStart : Math.min(collectionStart, additional.collectionStart); + count += additional.count; + errorCount += additional.errorCount; + hwmMicros = Math.max(hwmMicros, additional.hwmMicros); + totalMicros += additional.totalMicros; + } + + public String toString() { + return "count["+count+"] errors["+errorCount+"] totalMicros["+totalMicros+"] hwmMicros["+hwmMicros+"] avgMicros["+getAvgMicros()+"]"; + } + + public long getCollectionStart() { + return collectionStart; + } + + public long getCount() { + return count; + } + + public long getErrorCount() { + return errorCount; + } + + public long getHwmMicros() { + return hwmMicros; + } + + public long getTotalMicros() { + return totalMicros; + } + + public long getAvgMicros() { + return (count == 0) ? 0 : totalMicros/count; + } + } + + + + +} diff --git a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PstmtCache.java b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PstmtCache.java index 065d3c4ce..f28bfe46d 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PstmtCache.java +++ b/src/main/java/com/avaje/ebeaninternal/server/lib/sql/PstmtCache.java @@ -14,37 +14,37 @@ public class PstmtCache extends LinkedHashMap private static final Logger logger = LoggerFactory.getLogger(PstmtCache.class); - static final long serialVersionUID = -3096406924865550697L; + static final long serialVersionUID = -3096406924865550697L; /** * The name of the cache, for tracing purposes. */ - final String cacheName; + protected final String cacheName; /** * The maximum size of the cache. When this is exceeded the oldest entry is removed. */ - final int maxSize; + private final int maxSize; /** * The total number of entries removed from this cache. */ - int removeCounter; + private int removeCounter; /** * The number of get hits. */ - int hitCounter; + private int hitCounter; /** * The number of get() misses. */ - int missCounter; + private int missCounter; /** * The number of puts into this cache. */ - int putCounter; + private int putCounter; public PstmtCache(String cacheName, int maxCacheSize) { @@ -58,7 +58,7 @@ public class PstmtCache extends LinkedHashMap * Return a summary description of this cache. */ public String getDescription() { - return cacheName+" size:"+size()+" max:"+maxSize+" totalHits:"+hitCounter+" hitRatio:"+getHitRatio()+" removes:"+removeCounter; + return "size["+size()+"] max["+maxSize+"] hits["+hitCounter+"] miss["+missCounter+"] hitRatio["+getHitRatio()+"] removes["+removeCounter+"]"; } /** @@ -101,6 +101,24 @@ public class PstmtCache extends LinkedHashMap return putCounter; } + /** + * Try to add the returning statement to the cache. If there is already a + * matching ExtendedPreparedStatement in the cache return false else add + * the statement to the cache and return true. + */ + public boolean returnStatement(ExtendedPreparedStatement pstmt) { + + ExtendedPreparedStatement alreadyInCache = super.get(pstmt.getCacheKey()); + if (alreadyInCache != null) { + return false; + } + // add the returning prepared statement to the cache. + // Note that the LRUCache will automatically close fully old unused + // PStmts when the cache has hit its maximum size. + put(pstmt.getCacheKey(), pstmt); + return true; + } + /** * additionally maintains hit and miss statistics. */ diff --git a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestBusyBuffer.java b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestBusyBuffer.java index d1bd7e870..24fc550d4 100644 --- a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestBusyBuffer.java +++ b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestBusyBuffer.java @@ -44,6 +44,7 @@ public class TestBusyBuffer extends BaseTestCase { } + @Test public void test_rotate() { BusyConnectionBuffer b = new BusyConnectionBuffer(2, 2); @@ -54,13 +55,17 @@ public class TestBusyBuffer extends BaseTestCase { PooledConnection p3 = new PooledConnection("3"); Assert.assertEquals(2, b.getCapacity()); + Assert.assertEquals(0, b.size()); b.add(p0); b.add(p1); + Assert.assertEquals(2, b.size()); Assert.assertEquals(2, b.getCapacity()); b.add(p2); + Assert.assertEquals(3, b.size()); Assert.assertEquals(4, b.getCapacity()); b.add(p3); + Assert.assertEquals(4, b.size()); Assert.assertEquals(4, b.getCapacity()); Assert.assertEquals(0, p0.getSlotId()); @@ -69,13 +74,20 @@ public class TestBusyBuffer extends BaseTestCase { Assert.assertEquals(3, p3.getSlotId()); b.remove(p2); + Assert.assertEquals(3, b.size()); b.remove(p0); + Assert.assertEquals(2, b.size()); b.remove(p3); + Assert.assertEquals(1, b.size()); b.add(p2); + Assert.assertEquals(2, b.size()); Assert.assertEquals(0, p2.getSlotId()); b.remove(p0); + Assert.assertEquals(2, b.size()); b.add(p0); + Assert.assertEquals(3, b.size()); + // p1 is still in it's slot Assert.assertEquals(2, p0.getSlotId());