diff --git a/pom.xml b/pom.xml index 03033ccac..5ad4142d6 100644 --- a/pom.xml +++ b/pom.xml @@ -129,7 +129,7 @@ mysql mysql-connector-java - 5.1.15 + 5.1.27 test @@ -140,6 +140,13 @@ test + + org.mockito + mockito-core + 1.9.5 + test + + ch.qos.logback logback-classic diff --git a/src/main/java/com/avaje/ebean/config/DataSourceConfig.java b/src/main/java/com/avaje/ebean/config/DataSourceConfig.java index d6481e28c..5e55e4065 100644 --- a/src/main/java/com/avaje/ebean/config/DataSourceConfig.java +++ b/src/main/java/com/avaje/ebean/config/DataSourceConfig.java @@ -36,25 +36,31 @@ public class DataSourceConfig { private int heartbeatFreqSecs = 30; + private int heartbeatTimeoutSeconds = 3; + private boolean captureStackTrace; private int maxStackTraceSize = 5; private int leakTimeMinutes = 30; - private int maxInactiveTimeSecs = 900; + private int maxInactiveTimeSecs = 720; + + private int maxAgeMinutes = 0; + + private int trimPoolFreqSecs = 59; private int pstmtCacheSize = 20; private int cstmtCacheSize = 20; private int waitTimeoutMillis = 1000; - + private String poolListener; private boolean offline; - - Map customProperties; + + protected Map customProperties; /** * Return the connection URL. @@ -194,6 +200,20 @@ public class DataSourceConfig { public void setHeartbeatFreqSecs(int heartbeatFreqSecs) { this.heartbeatFreqSecs = heartbeatFreqSecs; } + + /** + * Return the heart beat timeout in seconds. + */ + public int getHeartbeatTimeoutSeconds() { + return heartbeatTimeoutSeconds; + } + + /** + * Set the heart beat timeout in seconds. + */ + public void setHeartbeatTimeoutSeconds(int heartbeatTimeoutSeconds) { + this.heartbeatTimeoutSeconds = heartbeatTimeoutSeconds; + } /** * Return true if a stack trace should be captured when obtaining a connection @@ -309,6 +329,23 @@ public class DataSourceConfig { return maxInactiveTimeSecs; } + /** + * Return the maximum age a connection is allowed to be before it is closed. + *

+ * This can be used to close really old connections. + *

+ */ + public int getMaxAgeMinutes() { + return maxAgeMinutes; + } + + /** + * Set the maximum age a connection can be in minutes. + */ + public void setMaxAgeMinutes(int maxAgeMinutes) { + this.maxAgeMinutes = maxAgeMinutes; + } + /** * Set the time in seconds a connection can be idle after which it can be * trimmed from the pool. @@ -321,6 +358,25 @@ public class DataSourceConfig { this.maxInactiveTimeSecs = maxInactiveTimeSecs; } + + /** + * Return the minimum time gap between pool trim checks. + *

+ * This defaults to 59 seconds meaning that the pool trim check will run every + * minute assuming the heart beat check runs every 30 seconds. + *

+ */ + public int getTrimPoolFreqSecs() { + return trimPoolFreqSecs; + } + + /** + * Set the minimum trim gap between pool trim checks. + */ + public void setTrimPoolFreqSecs(int trimPoolFreqSecs) { + this.trimPoolFreqSecs = trimPoolFreqSecs; + } + /** * Return the pool listener. */ @@ -359,7 +415,7 @@ public class DataSourceConfig { public void setOffline(boolean offline) { this.offline = offline; } - + /** * Return a map of custom properties for the jdbc driver connection. */ @@ -388,18 +444,18 @@ public class DataSourceConfig { this.username = properties.get(prefix + "username", null); this.password = properties.get(prefix + "password", null); - String v; + String dbDriver = properties.get(prefix + "databaseDriver", null); + this.driver = properties.get(prefix + "driver", dbDriver); - v = properties.get(prefix + "databaseDriver", null); - this.driver = properties.get(prefix + "driver", v); - - v = properties.get(prefix + "databaseUrl", null); - this.url = properties.get(prefix + "url", v); + String dbUrl = properties.get(prefix + "databaseUrl", null); + this.url = properties.get(prefix + "url", dbUrl); this.captureStackTrace = properties.getBoolean(prefix + "captureStackTrace", false); this.maxStackTraceSize = properties.getInt(prefix + "maxStackTraceSize", 5); this.leakTimeMinutes = properties.getInt(prefix + "leakTimeMinutes", 30); - this.maxInactiveTimeSecs = properties.getInt(prefix + "maxInactiveTimeSecs", 900); + this.maxInactiveTimeSecs = properties.getInt(prefix + "maxInactiveTimeSecs", 720); + this.trimPoolFreqSecs = properties.getInt(prefix + "trimPoolFreqSecs", 59); + this.maxAgeMinutes = properties.getInt(prefix + "maxAgeMinutes", 0); this.minConnections = properties.getInt(prefix + "minConnections", 0); this.maxConnections = properties.getInt(prefix + "maxConnections", 20); @@ -409,6 +465,7 @@ public class DataSourceConfig { this.waitTimeoutMillis = properties.getInt(prefix + "waitTimeout", 1000); this.heartbeatSql = properties.get(prefix + "heartbeatSql", null); + this.heartbeatTimeoutSeconds = properties.getInt(prefix + "heartbeatTimeoutSeconds", 3); this.poolListener = properties.get(prefix + "poolListener", null); this.offline = properties.getBoolean(prefix + "offline", false); diff --git a/src/main/java/com/avaje/ebeaninternal/server/core/DefaultServerFactory.java b/src/main/java/com/avaje/ebeaninternal/server/core/DefaultServerFactory.java index 2bf4dc6fe..99dcb029f 100644 --- a/src/main/java/com/avaje/ebeaninternal/server/core/DefaultServerFactory.java +++ b/src/main/java/com/avaje/ebeaninternal/server/core/DefaultServerFactory.java @@ -353,6 +353,11 @@ public class DefaultServerFactory implements BootupEbeanManager { if (sequenceFormat != null) { nc.setSequenceFormat(sequenceFormat); } + + String schema = config.getProperty("namingConvention.schema"); + if (schema != null) { + nc.setSchema(schema); + } } } @@ -410,32 +415,10 @@ public class DefaultServerFactory implements BootupEbeanManager { return null; } - if (dsConfig.getHeartbeatSql() == null) { - // use default heartbeatSql from the DatabasePlatform - String heartbeatSql = getHeartbeatSql(dsConfig.getDriver()); - dsConfig.setHeartbeatSql(heartbeatSql); - } - DataSourceAlert notify = new SimpleDataSourceAlert(); return new DataSourcePool(notify, config.getName(), dsConfig); } - /** - * Return a heartbeatSql depending on the jdbc driver name. - */ - private String getHeartbeatSql(String driver) { - if (driver != null) { - String d = driver.toLowerCase(); - if (d.contains("oracle")) { - return "select 'x' from dual"; - } - if (d.contains(".h2.") || d.contains(".mysql.") || d.contains("postgre")) { - return "select 1"; - } - } - return null; - } - /** * Check the autoCommit and Transaction Isolation levels of the DataSource. *

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..98b50346b 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 @@ -1,9 +1,11 @@ package com.avaje.ebeaninternal.server.lib.sql; -import java.util.ArrayList; 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 +23,8 @@ import java.util.List; */ class BusyConnectionBuffer { + private static final Logger logger = LoggerFactory.getLogger(BusyConnectionBuffer.class); + private PooledConnection[] slots; private int growBy; @@ -46,7 +50,7 @@ class BusyConnectionBuffer { /** * We can only grow (not shrink) the capacity. */ - private void setCapacity(int newCapacity) { + protected void setCapacity(int newCapacity) { if (newCapacity > slots.length){ PooledConnection[] current = this.slots; this.slots = new PooledConnection[newCapacity]; @@ -66,8 +70,8 @@ class BusyConnectionBuffer { return size; } - protected boolean isEmpty(){ - return size == 0; + protected boolean isEmpty() { + return size == 0; } protected int add(PooledConnection pc){ @@ -75,41 +79,103 @@ 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. - *

- * Note that the {@link #remove(PooledConnection)} MUST be used to remove PooledConnections. - *

- * @return + * Close connections that should be considered leaked. */ - protected List getShallowCopy() { - ArrayList tmp = new ArrayList(); - for (int i = 0; i < slots.length; i++) { - if (slots[i] != null){ - tmp.add(slots[i]); + protected void closeBusyConnections(long leakTimeMinutes) { + + long olderThanTime = System.currentTimeMillis() - (leakTimeMinutes*60000); + + logger.debug("Closing busy connections using leakTimeMinutes {}", leakTimeMinutes); + + for (int i = 0; i < slots.length; i++) { + if (slots[i] != null){ + //tmp.add(slots[i]); + PooledConnection pc = slots[i]; + if (pc.isLongRunning() || pc.getLastUsedTime() > olderThanTime) { + // PooledConnection has been used recently or + // expected to be longRunning so not closing... + } else { + slots[i] = null; + --size; + closeBusyConnection(pc); } } - return Collections.unmodifiableList(tmp); + } } + private void closeBusyConnection(PooledConnection pc) { + try { + + logger.warn("DataSourcePool closing busy connection? "+pc.getFullDescription()); + System.out.println("CLOSING busy connection: "+pc.getFullDescription()); + + pc.closeConnectionFully(false); + + } catch (Exception ex) { + // this should never actually happen + logger.error("Error when closing potentially leaked connection "+pc.getDescription(), ex); + } + } + + /** + * Returns information describing connections that are currently being used. + */ + protected String getBusyConnectionInformation(boolean toLogger) { + + if (toLogger) { + logger.info("Dumping [{}] busy connections: (Use datasource.xxx.capturestacktrace=true ... to get stackTraces)", size()); + } + + StringBuilder sb = new StringBuilder(); + + for (int i = 0; i < slots.length; i++) { + if (slots[i] != null){ + PooledConnection pc = slots[i]; + if (toLogger) { + logger.info("Busy Connection - {}", pc.getFullDescription()); + } else { + sb.append(pc.getFullDescription()).append("\r\n"); + } + } + } + + return sb.toString(); + } + + /** * Return the position of the next empty slot. */ 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..de80b9c7b 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,8 +74,13 @@ public class DataSourcePool implements DataSource { * The sql used to test a connection. */ private final String heartbeatsql; - + private final int heartbeatFreqSecs; + + private final int heartbeatTimeoutSeconds; + + + private final long trimPoolFreqMillis; /** * The transaction isolation level as per java.sql.Connection. @@ -86,6 +92,17 @@ public class DataSourcePool implements DataSource { */ private final boolean autoCommit; + /** + * Max idle time in millis. + */ + private final int maxInactiveMillis; + + /** + * Max age a connection is allowed in millis. + * A value of 0 means no limit (no trimming based on max age). + */ + private final long maxAgeMillis; + /** * Flag set to true to capture stackTraces (can be expensive). */ @@ -135,17 +152,12 @@ public class DataSourcePool implements DataSource { /** * The time a thread will wait for a connection to become available. */ - private int waitTimeoutMillis; + private final int waitTimeoutMillis; /** * The size of the preparedStatement cache; */ private int pstmtCacheSize; - - /** - * By default trim connections that are inactive for longer than this time. - */ - private int maxInactiveTimeSecs; private final PooledConnectionQueue queue; @@ -166,8 +178,9 @@ public class DataSourcePool implements DataSource { this.autoCommit = false; this.transactionIsolation = params.getIsolationLevel(); - - this.maxInactiveTimeSecs = params.getMaxInactiveTimeSecs(); + + this.maxInactiveMillis = 1000 * params.getMaxInactiveTimeSecs(); + this.maxAgeMillis = 60000 * params.getMaxAgeMinutes(); this.leakTimeMinutes = params.getLeakTimeMinutes(); this.captureStackTrace = params.isCaptureStackTrace(); this.maxStackTraceSize = params.getMaxStackTraceSize(); @@ -180,6 +193,8 @@ public class DataSourcePool implements DataSource { this.waitTimeoutMillis = params.getWaitTimeoutMillis(); this.heartbeatsql = params.getHeartbeatSql(); this.heartbeatFreqSecs = params.getHeartbeatFreqSecs(); + this.heartbeatTimeoutSeconds = params.getHeartbeatTimeoutSeconds(); + this.trimPoolFreqMillis = 1000 * params.getTrimPoolFreqSecs(); queue = new PooledConnectionQueue(this); @@ -317,12 +332,11 @@ public class DataSourcePool implements DataSource { private void notifyDataSourceIsDown(SQLException ex) { if (!dataSourceDownAlertSent) { - logger.error("FATAL: DataSourcePool [" + name + "] is down!!!", ex); + logger.error("FATAL: DataSourcePool [" + name + "] is down or has network error!!!", ex); if (notify != null) { notify.dataSourceDown(name); } dataSourceDownAlertSent = true; - } if (dataSourceUp) { reset(); @@ -366,6 +380,20 @@ public class DataSourcePool implements DataSource { return heartbeatRunnable; } + /** + * Trim connections (in the free list) based on idle time and maximum age. + */ + private void trimIdleConnections() { + if (System.currentTimeMillis() > (lastTrimTime + trimPoolFreqMillis)) { + try { + queue.trim(maxInactiveMillis, maxAgeMillis); + lastTrimTime = System.currentTimeMillis(); + } catch (Exception e) { + logger.error("Error trying to trim idle connections", e); + } + } + } + /** * Check the dataSource is up. Trim connections. *

@@ -374,17 +402,19 @@ public class DataSourcePool implements DataSource { *

*/ public void checkDataSource() { + + // first trim idle connections + trimIdleConnections(); + Connection conn = null; try { // Get a connection from the pool and test it conn = getConnection(); - testConnection(conn); - - notifyDataSourceIsUp(); - - if (System.currentTimeMillis() > (lastTrimTime + (maxInactiveTimeSecs * 1000))) { - queue.trim(maxInactiveTimeSecs); - lastTrimTime = System.currentTimeMillis(); + if (testConnection(conn)) { + notifyDataSourceIsUp(); + + } else { + notifyDataSourceIsDown(null); } } catch (SQLException ex) { @@ -487,33 +517,38 @@ public class DataSourcePool implements DataSource { return waitTimeoutMillis; } - /** - * Set the time after which inactive connections are trimmed. - */ - public void setMaxInactiveTimeSecs(int maxInactiveTimeSecs) { - this.maxInactiveTimeSecs = maxInactiveTimeSecs; - } - /** * Return the time after which inactive connections are trimmed. */ - public int getMaxInactiveTimeSecs() { - return maxInactiveTimeSecs; + public int getMaxInactiveMillis() { + return maxInactiveMillis; + } + + /** + * Return the maximum age a connection is allowed to be before it is trimmed + * out of the pool. This value can be 0 which means there is no maximum age. + */ + public long getMaxAgeMillis() { + return maxAgeMillis; } - private void testConnection(Connection conn) throws SQLException { + private boolean testConnection(Connection conn) throws SQLException { if (heartbeatsql == null) { - return; + return conn.isValid(heartbeatTimeoutSeconds); } Statement stmt = null; ResultSet rset = null; try { - // It should only error IF the DataSource is down ? (or a network - // issue?) + // It should only error IF the DataSource is down or a network issue stmt = conn.createStatement(); + if (heartbeatTimeoutSeconds > 0) { + stmt.setQueryTimeout(heartbeatTimeoutSeconds); + } rset = stmt.executeQuery(heartbeatsql); conn.commit(); + + return true; } finally { try { @@ -539,13 +574,7 @@ public class DataSourcePool implements DataSource { */ protected boolean validateConnection(PooledConnection conn) { try { - if (heartbeatsql == null) { - logger.debug("Can not test connection as heartbeatsql is not set"); - return false; - } - - testConnection(conn); - return true; + return testConnection(conn); } catch (Exception e) { logger.warn("heartbeatsql test failed on connection[" + conn.getName() + "]"); @@ -573,7 +602,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. */ @@ -635,7 +672,6 @@ public class DataSourcePool implements DataSource { notifyDataSourceIsDown(ex); throw ex; } - } /** @@ -834,6 +870,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 +917,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..8fede2fc2 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 @@ -1,138 +1,106 @@ package com.avaje.ebeaninternal.server.lib.sql; import java.util.ArrayList; +import java.util.Iterator; +import java.util.LinkedList; import java.util.List; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import com.avaje.ebeaninternal.server.lib.sql.PooledConnectionStatistics.LoadValues; + /** * A buffer designed especially to hold free pooled connections. *

- * It is circular in nature. - *

- *

* All thread safety controlled externally (by PooledConnectionQueue). *

- * - * @author rbygrave - * */ class FreeConnectionBuffer { - private PooledConnection[] conns; + private static final Logger logger = LoggerFactory.getLogger(FreeConnectionBuffer.class); + + /** + * Buffer oriented for add and remove. + */ + private final LinkedList freeBuffer = new LinkedList(); - private int removeIndex; + protected FreeConnectionBuffer() { + } - private int addIndex; + protected int size() { + return freeBuffer.size(); + } - /** - * The current number of connections in the buffer - */ - private int size; + protected boolean isEmpty() { + return freeBuffer.isEmpty(); + } + + /** + * Add connection to the free list. + */ + protected void add(PooledConnection pc) { + freeBuffer.addLast(pc); + } + + /** + * Remove a connection from the free list. + */ + protected PooledConnection remove() { + return freeBuffer.removeFirst(); + } + + /** + * Close all connections in this buffer. + */ + protected void closeAll(boolean logErrors) { + + // create a temporary list + List tempList = new ArrayList(freeBuffer.size()); - protected FreeConnectionBuffer(int capacity) { - this.conns = new PooledConnection[capacity]; + // add all the connections into it + for (PooledConnection c : freeBuffer) { + tempList.add(c); } - protected int getCapacity() { - return conns.length; - } + // clear the buffer (in case it takes some time to close these connections). + freeBuffer.clear(); - protected int size() { - return size; + logger.debug("... closing all {} connections from the free list with logErrors: {}", tempList.size(), logErrors); + for (int i = 0; i < tempList.size(); i++) { + PooledConnection pooledConnection = tempList.get(i); + logger.debug("... closing {} of {} connections from the free list", i, tempList.size()); + pooledConnection.closeConnectionFully(logErrors); } - - protected boolean isEmpty() { - return size == 0; - } - - /** - * Add at connection. - */ - protected void add(PooledConnection pc) { - conns[addIndex] = pc; - addIndex = inc(addIndex); - ++size; + } + + /** + * Trim any inactive connections that have not been used since usedSince. + */ + protected int trim(long usedSince, long createdSince) { + + int trimCount = 0; + + Iterator iterator = freeBuffer.iterator(); + while (iterator.hasNext()) { + PooledConnection pooledConnection = iterator.next(); + if (pooledConnection.shouldTrim(usedSince, createdSince)) { + iterator.remove(); + pooledConnection.closeConnectionFully(true); + trimCount++; + } } - /** - * Remove a connection at current remove position. - */ - protected PooledConnection remove() { - final PooledConnection[] items = this.conns; - PooledConnection pc = items[removeIndex]; - items[removeIndex] = null; - removeIndex = inc(removeIndex); - --size; - return pc; - } - - /** - * Return a shallow copy of the free connections. - */ - protected List getShallowCopy() { - - List copy = new ArrayList(conns.length); - for (int i = 0; i < conns.length; i++) { - if (conns[i] != null){ - copy.add(conns[i]); - } - } - return copy; - } - - /** - * Set the free list to be the connections in this copy. This is done after - * unused connections have been trimmed. - *

- * Not a particularly performant approach but this should not be called very - * often - *

- */ - protected void setShallowCopy(List copy) { - - // reset to empty state - this.removeIndex = 0; - this.addIndex = 0; - this.size = 0; + return trimCount; + } - // null all the current connections - for (int i = 0; i < conns.length; i++) { - conns[i] = null; - } + /** + * Collect the load statistics from all the free connections. + */ + protected void collectStatistics(LoadValues values, boolean reset) { - // add connections from the copy - for (int i = 0; i < copy.size(); i++) { - add(copy.get(i)); - } + for (PooledConnection c : freeBuffer) { + values.plus(c.getStatistics().getValues(reset)); } - - /** - * Increase the capacity of the buffer. This is a relatively expensive - * operation but should occur very infrequently. - */ - protected void setCapacity(int newCapacity) { - if (newCapacity > conns.length){ - - List copy = getShallowCopy(); - - // reset to empty state - this.removeIndex = 0; - this.addIndex = 0; - this.size = 0; - - this.conns = new PooledConnection[newCapacity]; - - // add the connections back from the copy - for (int i = 0; i < copy.size(); i++) { - add(copy.get(i)); - } - } - } - - /** - * Circularly increment i. - */ - private final int inc(int i) { - return (++i == conns.length)? 0 : i; - } - + } } 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..cd6ade3e0 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 @@ -9,13 +9,14 @@ import java.sql.SQLWarning; import java.sql.Savepoint; import java.sql.Statement; import java.util.ArrayList; -import java.util.Iterator; +import java.util.Arrays; import java.util.Map; -import com.avaje.ebeaninternal.jdbc.ConnectionDelegator; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import com.avaje.ebeaninternal.jdbc.ConnectionDelegator; + /** * Is a connection that belongs to a DataSourcePool. * @@ -34,117 +35,136 @@ 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); - private static String IDLE_CONNECTION_ACCESSED_ERROR = "Pooled Connection has been accessed whilst idle in the pool, via method: "; + private static final String IDLE_CONNECTION_ACCESSED_ERROR = "Pooled Connection has been accessed whilst idle in the pool, via method: "; + /** + * Marker for when connection is closed due to exceeding the max allowed age. + */ + private static final String REASON_MAXAGE = "maxAge"; + + /** + * Marker for when connection is closed due to exceeding the max inactive time. + */ + private static final String REASON_IDLE = "idleTime"; + + /** + * Marker for when the connection is closed due to a reset. + */ + private static final String REASON_RESET = "reset"; + /** * 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(); + /** + * Helper for statistics collection. + */ + private final PooledConnectionStatistics stats = new PooledConnectionStatistics(); + /** * The status of the connection. IDLE, ACTIVE or ENDED. */ - int status = STATUS_IDLE; + private int status = STATUS_IDLE; + /** + * The reason for a connection closing. + */ + private String closeReason; + /** * Set this to true if the connection will be busy for a long time. *

* 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; + /** * 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 +185,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 +234,32 @@ public class PooledConnection extends ConnectionDelegator return name; } + public String getNameSlot() { + return name+":"+slotId; + } + public String toString() { - return name; + return getDescription(); + } + + public long getBusySeconds() { + return (System.currentTimeMillis() - startUseTime)/1000; } public String getDescription() { - return "name["+name+"] startTime["+getStartUseTime()+"] stmt["+getLastStatement()+"] createdBy["+getCreatedByMethod()+"]"; + return "name["+name+"] slot["+slotId+"] startTime["+getStartUseTime()+"] busySeconds["+getBusySeconds()+"] createdBy["+getCreatedByMethod()+"] stmt["+getLastStatement()+"]"; } - - public String getStatistics() { - return "name["+name+"] startTime["+getStartUseTime()+"] pstmtHits["+pstmtHitCounter+"] pstmtMiss["+pstmtMissCounter+"] "+pstmtCache.getDescription(); + + public String getFullDescription() { + return "name["+name+"] slot["+slotId+"] startTime["+getStartUseTime()+"] busySeconds["+getBusySeconds()+"] stackTrace["+getStackTraceAsString()+"] stmt["+getLastStatement()+"]"; + } + + public String getPstmtStatistics() { + return "name["+name+"] startTime["+getStartUseTime()+"] "+pstmtCache.getDescription(); + } + + public PooledConnectionStatistics getStatistics() { + return stats; } /** @@ -253,30 +289,32 @@ 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[{}] reason[{}] stats: {} , pstmtStats: {} ", name, slotId, closeReason, 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); } } try { - Iterator psi = pstmtCache.values().iterator(); - while (psi.hasNext()) { - ExtendedPreparedStatement ps = (ExtendedPreparedStatement) psi.next(); - ps.closeDestroy(); - } + for (ExtendedPreparedStatement ps : pstmtCache.values()) { + ps.closeDestroy(); + } } catch (SQLException ex) { if (logErrors) { @@ -287,8 +325,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); } } } @@ -317,8 +355,7 @@ public class PooledConnection extends ConnectionDelegator } } - public Statement createStatement(int resultSetType, int resultSetConcurreny) - throws SQLException { + public Statement createStatement(int resultSetType, int resultSetConcurreny) throws SQLException { if (status == STATUS_IDLE) { throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "createStatement()"); } @@ -337,26 +374,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); + } + } } } @@ -381,8 +407,7 @@ public class PooledConnection extends ConnectionDelegator private PreparedStatement prepareStatement(String sql, boolean useFlag, int flag, String cacheKey) throws SQLException { if (status == STATUS_IDLE) { - String m = IDLE_CONNECTION_ACCESSED_ERROR + "prepareStatement()"; - throw new SQLException(m); + throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareStatement()"); } try { synchronized (pstmtMonitor) { @@ -392,12 +417,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); @@ -413,14 +436,13 @@ public class PooledConnection extends ConnectionDelegator } } - public PreparedStatement prepareStatement(String sql, int resultSetType, int resultSetConcurreny) - throws SQLException { + public PreparedStatement prepareStatement(String sql, int resultSetType, int resultSetConcurreny) throws SQLException { + if (status == STATUS_IDLE) { throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "prepareStatement()"); } try { // no caching when creating PreparedStatements this way - pstmtMissCounter++; lastStatement = sql; return connection.prepareStatement(sql, resultSetType, resultSetConcurreny); } catch (SQLException ex) { @@ -436,6 +458,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 +503,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 @@ -510,6 +536,7 @@ public class PooledConnection extends ConnectionDelegator } catch (Exception ex) { // the connection is BAD, close it and test the pool + logger.warn("Error when trying to return connection to pool, closing fully.", ex); closeConnectionFully(false); pool.checkDataSource(); } @@ -530,16 +557,54 @@ 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 on finalize() - {}", getFullDescription()); closeConnectionFully(false); } } catch (Exception e) { - logger.error(null, e); + logger.error("Error when finalize is closing a connection? (unexpected)", e); } super.finalize(); } + /** + * Return true if the connection is too old. + */ + public boolean exceedsMaxAge(long maxAgeMillis) { + if (maxAgeMillis > 0 && (creationTime < (System.currentTimeMillis() - maxAgeMillis))){ + this.closeReason = REASON_MAXAGE; + return true; + } + return false; + } + + public boolean shouldTrimOnReturn(long lastResetTime, long maxAgeMillis) { + if (creationTime <= lastResetTime) { + this.closeReason = REASON_RESET; + return true; + } + if (exceedsMaxAge(maxAgeMillis)) { + return true; + } + return false; + } + + /** + * Return true if the connection has been idle for too long or is too old. + */ + public boolean shouldTrim(long usedSince, long createdSince) { + if (lastUseTime < usedSince) { + // been idle for too long so trim it + this.closeReason = REASON_IDLE; + return true; + } + if (createdSince > 0 && createdSince > creationTime) { + // exceeds max age so trim it + this.closeReason = REASON_MAXAGE; + return true; + } + return false; + } + /** * Return the time the connection was passed to the client code. *

@@ -581,7 +646,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 +678,337 @@ 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 stackTrace as a String for logging purposes. + */ + public String getStackTraceAsString() { + StackTraceElement[] stackTrace = getStackTrace(); + if (stackTrace == null){ + return ""; + } + return Arrays.toString(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..e355394d1 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 @@ -1,18 +1,16 @@ package com.avaje.ebeaninternal.server.lib.sql; import java.sql.SQLException; -import java.util.Arrays; -import java.util.Date; -import java.util.Iterator; -import java.util.List; 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 +32,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 */ @@ -46,10 +54,12 @@ public class PooledConnectionQueue { private int connectionId; - private long waitTimeoutMillis; - - private long leakTimeMinutes; + private final long waitTimeoutMillis; + private final long leakTimeMinutes; + + private final long maxAgeMillis; + private int warningSize; private int maxSize; @@ -94,11 +104,12 @@ public class PooledConnectionQueue { this.warningSize = pool.getWarningSize(); this.waitTimeoutMillis = pool.getWaitTimeoutMillis(); this.leakTimeMinutes = pool.getLeakTimeMinutes(); - - this.busyList = new BusyConnectionBuffer(50,20); - this.freeList = new FreeConnectionBuffer(maxSize); - - this.lock = new ReentrantLock(true); + this.maxAgeMillis = pool.getMaxAgeMillis(); + + this.busyList = new BusyConnectionBuffer(maxSize, 20); + this.freeList = new FreeConnectionBuffer(); + + this.lock = new ReentrantLock(false); this.notEmpty = lock.newCondition(); } @@ -116,6 +127,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(); @@ -152,7 +193,7 @@ public class PooledConnectionQueue { if (maxSize < this.minSize){ throw new IllegalArgumentException("maxSize "+maxSize+" < minSize "+this.minSize); } - freeList.setCapacity(maxSize); + this.busyList.setCapacity(maxSize); this.maxSize = maxSize; } finally { lock.unlock(); @@ -203,10 +244,11 @@ 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) { + if (c.shouldTrimOnReturn(lastResetTime, maxAgeMillis)) { c.closeConnectionFully(false); + } else { freeList.add(c); notEmpty.signal(); @@ -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(); } @@ -272,9 +313,9 @@ public class PooledConnectionQueue { PooledConnection c = pool.createConnectionForQueue(connectionId++); int busySize = registerBusyConnection(c); - String msg = "DataSourcePool [" + name + "] grow; id["+c.getName()+"] busy["+busySize+"] max["+maxSize+"]"; - logger.debug(msg); - + if (logger.isDebugEnabled()) { + logger.debug("DataSourcePool [{}] grow; id[{}] busy[{}] max[{}]", name, c.getName(), busySize, maxSize); + } checkForWarningSize(); return c; } @@ -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 [{}] shutdown {} - Statistics {}", name, 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); } @@ -360,27 +401,30 @@ public class PooledConnectionQueue { lock.lock(); try { Status status = createStatus(); - logger.info("Reseting DataSourcePool [" + name + "] "+status); + logger.info("Reseting DataSourcePool [{}] {}", name, status); lastResetTime = System.currentTimeMillis(); closeFreeConnections(false); closeBusyConnections(leakTimeMinutes); - String busyMsg = "Busy Connections:\r\n" + getBusyConnectionInformation(); - logger.info(busyMsg); + logger.info("Busy Connections:\n" + getBusyConnectionInformation()); } finally { lock.unlock(); } } - public void trim(int maxInactiveTimeSecs) throws SQLException { + public void trim(long maxInactiveMillis, long maxAgeMillis) { final ReentrantLock lock = this.lock; lock.lock(); try { - trimInactiveConnections(maxInactiveTimeSecs); - ensureMinimumConnections(); - + if (trimInactiveConnections(maxInactiveMillis, maxAgeMillis) > 0) { + try { + ensureMinimumConnections(); + } catch (SQLException e) { + logger.error("Error trying to ensure minimum connections", e); + } + } } finally { lock.unlock(); } @@ -389,40 +433,14 @@ public class PooledConnectionQueue { /** * Trim connections that have been not used for some time. */ - private int trimInactiveConnections(int maxInactiveTimeSecs) { - - int maxTrim = freeList.size() - minSize; - if (maxTrim <= 0) { - return 0; - } - - int trimedCount = 0; - long usedSince = System.currentTimeMillis() - (maxInactiveTimeSecs * 1000); - - // get a shallow copy to manipulate - List freeListCopy = freeList.getShallowCopy(); - - Iterator it = freeListCopy.iterator(); - while (it.hasNext()) { - PooledConnection pc = it.next(); - if (pc.getLastUsedTime() < usedSince) { - // trim this connection as it hasn't been used in a while - trimedCount++; - it.remove(); - pc.closeConnectionFully(true); - if (trimedCount >= maxTrim) { - break; - } - } - } - - if (trimedCount > 0) { + private int trimInactiveConnections(long maxInactiveMillis, long maxAgeMillis) { - // rebuild the free list from the trimmed copy - freeList.setShallowCopy(freeListCopy); - - String msg = "DataSourcePool [" + name + "] trimmed [" + trimedCount + "] inactive connections. New size[" + totalConnections() + "]"; - logger.debug(msg); + long usedSince = System.currentTimeMillis() - maxInactiveMillis; + long createdSince = (maxAgeMillis == 0) ? 0 : System.currentTimeMillis() - maxAgeMillis; + + int trimedCount = freeList.trim(usedSince, createdSince); + if (trimedCount > 0) { + logger.debug("DataSourcePool [{}] trimmed [{}] inactive connections. New size[{}]", name, trimedCount, totalConnections()); } return trimedCount; } @@ -434,11 +452,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(); } @@ -461,62 +475,12 @@ public class PooledConnectionQueue { final ReentrantLock lock = this.lock; lock.lock(); try { - - long olderThanTime = System.currentTimeMillis() - (leakTimeMinutes*60000); - - List copy = busyList.getShallowCopy(); - for (int i = 0; i < copy.size(); i++) { - PooledConnection pc = copy.get(i); - if (pc.isLongRunning() || pc.getLastUsedTime() > olderThanTime) { - // PooledConnection has been used recently or - // expected to be longRunning so not closing... - } else { - busyList.remove(pc); - closeBusyConnection(pc); - } - } - + busyList.closeBusyConnections(leakTimeMinutes); } finally { lock.unlock(); } } - - private void closeBusyConnection(PooledConnection pc) { - 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 - + "] lastStmt[" + pc.getLastStatement() + "]"; - - logger.warn(msg); - logStackElement(pc, "Possible Leaked Connection: "); - - System.out.println("CLOSING BUSY CONNECTION ??? "+pc); - pc.close(); - - } catch (SQLException ex) { - // this should never actually happen - logger.error(null, ex); - } - } - private void logStackElement(PooledConnection pc, String prefix) { - StackTraceElement[] stackTrace = pc.getStackTrace(); - if (stackTrace != null){ - String s = Arrays.toString(stackTrace); - String msg = prefix+" name["+pc.getName()+"] stackTrace: "+s; - logger.warn(msg); - // also send to syserr ... as the loggers get turned - // off early in JVM shutdown - System.err.println(msg); - } - } - - /** * As the pool grows it gets closer to the maxConnections limit. We can send * an Alert (or warning) as we get close to this limit and hence an @@ -557,26 +521,8 @@ 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(); - for (int i = 0; i < copy.size(); i++) { - PooledConnection pc = copy.get(i); - if (toLogger) { - logger.info(pc.getDescription()); - logStackElement(pc, "Busy Connection: "); - - } else { - sb.append(pc.getDescription()).append("\r\n"); - } - } - - return sb.toString(); - + return busyList.getBusyConnectionInformation(toLogger); + } finally { lock.unlock(); } 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()); diff --git a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMax.java b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMax.java index cd3ee4b7f..c392515a9 100644 --- a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMax.java +++ b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMax.java @@ -1,8 +1,9 @@ package com.avaje.ebeaninternal.server.lib.sql; import java.sql.Connection; +import java.sql.PreparedStatement; +import java.sql.ResultSet; -import org.junit.Assert; import org.junit.Test; import com.avaje.ebean.BaseTestCase; @@ -15,44 +16,50 @@ public class TestDataSourceMax extends BaseTestCase { @Test public void test() { - boolean runThisManuallyNow = true; + boolean skipThisTest = true; - if (!runThisManuallyNow) { + if (skipThisTest) { return; } - - String name = "h2"; + + String name = "mysql"; DataSourceConfig dsConfig = new DataSourceConfig(); dsConfig.loadSettings(name); - dsConfig.setMinConnections(3); - dsConfig.setMaxConnections(3); + dsConfig.setMinConnections(2); + dsConfig.setMaxConnections(25); dsConfig.setWaitTimeoutMillis(30000); + dsConfig.setCaptureStackTrace(true); DataSourcePool pool = new DataSourcePool(null, name, dsConfig); - Assert.assertEquals(3, pool.getMaxSize()); - - DefaultBackgroundExecutor bg = new DefaultBackgroundExecutor(10, 2, 180, 30, "testDs"); + + //pool.checkDataSource(); + +// if (true) { +// pool.shutdown(false); +// return; +// } + + DefaultBackgroundExecutor bg = new DefaultBackgroundExecutor(1, 2, 180, 30, "testDs"); try { for (int i = 0; i < 12; i++) { // Thread.sleep(10*i); - bg.execute(new ConnRunner(pool, 100)); + bg.execute(new ConnRunner(pool, 4000, i)); } System.out.println("main thread sleep ... " + pool.getStatus(false)); - Thread.sleep(1000); + Thread.sleep(10000); + pool.getStatistics(true); + + Thread.sleep(30000); + Status status = pool.getStatus(false); System.out.println(status); - // this dumpOrder was for 3 vectors used in PooledConnectionQueue - // that logged the order of wait, notify and obtain events - // I have remove that code. - - // String s = pool.dumpOrder(); - // System.err.println(s); + pool.shutdown(false); } catch (Exception e) { e.printStackTrace(); @@ -64,21 +71,65 @@ public class TestDataSourceMax extends BaseTestCase { final DataSourcePool pool; final long sleepMillis; + final int position; - ConnRunner(DataSourcePool pool, long sleepMillis) { + ConnRunner(DataSourcePool pool, long sleepMillis, int position) { this.pool = pool; this.sleepMillis = sleepMillis; + this.position = position; } - public void run() { + private void waitSomeTime(long count) { try { - Connection connection = pool.getConnection(); - Thread.sleep(sleepMillis); - connection.close(); - } catch (Exception e) { - e.printStackTrace(); + System.out.println(position+" sleep " + sleepMillis+" count:"+count); + Thread.sleep(sleepMillis); + System.out.println(position+" sleep done"); + } catch (InterruptedException e){ + throw new RuntimeException(e); } } + + public void run() { + Connection connection = null; + PreparedStatement pstmt = null; + ResultSet rset = null; + long count = -1; + try { + connection = pool.getConnection(); + pstmt = connection.prepareStatement("select count(*) from o_customer"); + rset = pstmt.executeQuery(); + + while (rset.next()) { + // do nothing actually + count = rset.getLong(1); + } + } catch (Exception ex) { + ex.printStackTrace(); + } finally { + if (rset != null) { + try { + rset.close(); + } catch (Exception e) { + e.printStackTrace(); + } + if (pstmt != null) { + try { + pstmt.close(); + } catch (Exception e) { + e.printStackTrace(); + } + } + if (connection != null) { + try { + connection.close(); + } catch (Exception e) { + e.printStackTrace(); + } + } + } + waitSomeTime(count); + } + } } } diff --git a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMaxWithEntity.java b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMaxWithEntity.java new file mode 100644 index 000000000..b4d136a7c --- /dev/null +++ b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestDataSourceMaxWithEntity.java @@ -0,0 +1,70 @@ +package com.avaje.ebeaninternal.server.lib.sql; + +import org.junit.Test; + +import com.avaje.ebean.BaseTestCase; +import com.avaje.ebean.Ebean; +import com.avaje.ebean.EbeanServer; +import com.avaje.ebeaninternal.server.core.DefaultBackgroundExecutor; +import com.avaje.tests.model.basic.Customer; + +public class TestDataSourceMaxWithEntity extends BaseTestCase { + + @Test + public void test() { + + boolean skipThisTest = true; + + if (skipThisTest) { + return; + } + + EbeanServer server = Ebean.getServer(null); + + + DefaultBackgroundExecutor bg = new DefaultBackgroundExecutor(1, 2, 180, 30, "testDs"); + + try { + for (int i = 0; i < 12; i++) { + // Thread.sleep(10*i); + bg.execute(new ConnRunner(server, 4000, i)); + } + + System.out.println("main thread sleep ... "); + + + Thread.sleep(30000); + + server.shutdown(true, false); + + } catch (Exception e) { + e.printStackTrace(); + } + + } + + private static class ConnRunner implements Runnable { + + final EbeanServer server; + final long sleepMillis; + final int position; + + ConnRunner(EbeanServer server, long sleepMillis, int position) { + this.server = server; + this.sleepMillis = sleepMillis; + this.position = position; + } + + public void run() { + + server.find(Customer.class).findRowCount(); + try { + System.out.println(position+" sleep " + sleepMillis); + Thread.sleep(sleepMillis); + System.out.println(position+" sleep done"); + } catch (InterruptedException e) { + e.printStackTrace(); + } + } + } +} diff --git a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBuffer.java b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBuffer.java index de3a451b1..85e0f1a4e 100644 --- a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBuffer.java +++ b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBuffer.java @@ -10,14 +10,13 @@ public class TestFreeBuffer extends BaseTestCase { @Test public void test() { - FreeConnectionBuffer b = new FreeConnectionBuffer(3); + FreeConnectionBuffer b = new FreeConnectionBuffer(); PooledConnection p0 = new PooledConnection("0"); PooledConnection p1 = new PooledConnection("1"); PooledConnection p2 = new PooledConnection("2"); // PooledConnection p3 = new PooledConnection("3"); - Assert.assertEquals(3, b.getCapacity()); Assert.assertEquals(0, b.size()); Assert.assertEquals(true, b.isEmpty()); diff --git a/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBufferTrim.java b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBufferTrim.java new file mode 100644 index 000000000..a7a4052c2 --- /dev/null +++ b/src/test/java/com/avaje/ebeaninternal/server/lib/sql/TestFreeBufferTrim.java @@ -0,0 +1,40 @@ +package com.avaje.ebeaninternal.server.lib.sql; + +import org.junit.Assert; +import org.junit.Test; +import org.mockito.Mockito; + +import com.avaje.ebean.BaseTestCase; + +public class TestFreeBufferTrim extends BaseTestCase { + + @Test + public void testWithTime() { + + FreeConnectionBuffer b = new FreeConnectionBuffer(); + Assert.assertEquals(0, b.size()); + + PooledConnection p0 = Mockito.mock(PooledConnection.class); + Mockito.when(p0.shouldTrim(1500, 0)).thenReturn(true); + + PooledConnection p1 = Mockito.mock(PooledConnection.class); + Mockito.when(p1.shouldTrim(1500, 0)).thenReturn(true); + + PooledConnection p2 = Mockito.mock(PooledConnection.class); + Mockito.when(p2.shouldTrim(1500, 0)).thenReturn(false); + + b.add(p0); + b.add(p1); + b.add(p2); + + Assert.assertEquals(3, b.size()); + + int trimCount = b.trim(1500, 0); + + Assert.assertEquals(1, b.size()); + Assert.assertEquals(2, trimCount); + } + + + +} diff --git a/src/test/resources/ebean.properties b/src/test/resources/ebean.properties index b86889338..0af68ce63 100644 --- a/src/test/resources/ebean.properties +++ b/src/test/resources/ebean.properties @@ -24,8 +24,8 @@ ebean.autofetch.profiling.base=10 ebean.autofetch.traceUsageCollection=false -ebean.ddl.generate=true -ebean.ddl.run=true +#ebean.ddl.generate=true +#ebean.ddl.run=true ebean.debug.sql=true @@ -74,13 +74,14 @@ ebean.cacheWarmingDelay=-1 #ebean.namingConvention=com.avaje.ebean.config.UnderscoreNamingConvention #ebean.namingConvention.sequenceFormat={table}_{column}_seq +#ebean.namingConvention.schema=banan #ebean.databaseSequenceBatchSize=1 ## ------------------------------------------------------------- ## DataSources (If using default Ebean DataSourceFactory) ## ------------------------------------------------------------- -datasource.default=h2 +datasource.default=mysql datasource.h2.username=sa datasource.h2.password= @@ -115,7 +116,7 @@ datasource.mysql.username=test datasource.mysql.password=test datasource.mysql.databaseUrl=jdbc:mysql://127.0.0.1:3306/test datasource.mysql.databaseDriver=com.mysql.jdbc.Driver -datasource.mysql.minConnections=1 +datasource.mysql.minConnections=2 datasource.mysql.maxConnections=25 #datasource.mysql.heartbeatsql=select count(*) from dual datasource.mysql.isolationlevel=read_committed