Fix idle timeout tests, sleep too tight to idle threshold. (+1 squashed commit)

Squashed commits:
[4844f9e1] Fix idle timeout tests, sleep too tight to idle threshold. (+8 squashed commits)
Squashed commits:
[e0ec6b7f] Fix idle timeout tests, sleep too tight to idle threshold.
[c40a690d] Fix idle timeout tests, sleep too tight to idle threshold.
[7a0a1560] Synchronize idleTimeout manipulation methods
[bab9f648] Fix idle timeout tests, sleep too tight to idle threshold.
[4ee5259b] Add missing ) character in message
[e9d49fc2] Enable debug logging for tests.
[89c1ab45] Fix idle timeout tests, sleep too tight to idle threshold.
[aa06bb85] Simplify pool entry last-accessed time handling.

src/main/java/com/zaxxer/hikari/pool/HikariPool.java

@@ -173,7 +173,7 @@ public final class HikariPool extends PoolBase implements HikariPoolMXBean, IBag
             }
             else {
                metricsTracker.recordBorrowStats(poolEntry, startTime);
-               return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry), now);
+               return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry));
             }
          } while (timeout > 0L);
 
@@ -518,7 +518,7 @@ public final class HikariPool extends PoolBase implements HikariPoolMXBean, IBag
          addConnectionExecutor.submit(isAfterAdd ? postFillPoolEntryCreator : poolEntryCreator);
       }
       else if (isAfterAdd) {
-         logger.debug("{} - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth={}.", poolName, queueDepth);
+         logger.debug("{} - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth={}).", poolName, queueDepth);
       }
    }
 

src/main/java/com/zaxxer/hikari/pool/PoolEntry.java

@@ -27,6 +27,7 @@ import java.util.concurrent.ScheduledFuture;
 import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
 
 import static com.zaxxer.hikari.util.ClockSource.*;
+import static com.zaxxer.hikari.util.ClockSource.currentTime;
 
 /**
  * Entry used in the ConcurrentBag to track Connection instances.
@@ -72,13 +73,11 @@ final class PoolEntry implements IConcurrentBagEntry
 
    /**
     * Release this entry back to the pool.
-    *
-    * @param lastAccessed last access time-stamp
     */
-   void recycle(final long lastAccessed)
+   void recycle()
    {
       if (connection != null) {
-         this.lastAccessed = lastAccessed;
+         this.lastAccessed = currentTime();
          hikariPool.recycle(this);
       }
    }
@@ -97,9 +96,9 @@ final class PoolEntry implements IConcurrentBagEntry
       this.keepalive = keepalive;
    }
 
-   Connection createProxyConnection(final ProxyLeakTask leakTask, final long now)
+   Connection createProxyConnection(final ProxyLeakTask leakTask)
    {
-      return ProxyFactory.getProxyConnection(this, connection, openStatements, leakTask, now, isReadOnly, isAutoCommit);
+      return ProxyFactory.getProxyConnection(this, connection, openStatements, leakTask, isReadOnly, isAutoCommit);
    }
 
    void resetConnectionState(final ProxyConnection proxyConnection, final int dirtyBits) throws SQLException

src/main/java/com/zaxxer/hikari/pool/ProxyConnection.java

@@ -28,14 +28,12 @@ import java.util.Set;
 import java.util.concurrent.Executor;
 
 import static com.zaxxer.hikari.SQLExceptionOverride.Override.DO_NOT_EVICT;
-import static com.zaxxer.hikari.util.ClockSource.currentTime;
 
 /**
  * This is the proxy class for java.sql.Connection.
  *
  * @author Brett Wooldridge
  */
-@SuppressWarnings("ClassEscapesDefinedScope")
 public abstract class ProxyConnection implements Connection
 {
    static final int DIRTY_BIT_READONLY   = 0b000001;
@@ -57,7 +55,6 @@ public abstract class ProxyConnection implements Connection
    private final FastList<Statement> openStatements;
 
    private int dirtyBits;
-   private long lastAccess;
    private boolean isCommitStateDirty;
 
    private boolean isReadOnly;
@@ -89,14 +86,12 @@ public abstract class ProxyConnection implements Connection
                              final Connection connection,
                              final FastList<Statement> openStatements,
                              final ProxyLeakTask leakTask,
-                             final long now,
                              final boolean isReadOnly,
                              final boolean isAutoCommit) {
       this.poolEntry = poolEntry;
       this.delegate = connection;
       this.openStatements = openStatements;
       this.leakTask = leakTask;
-      this.lastAccess = now;
       this.isReadOnly = isReadOnly;
       this.isAutoCommit = isAutoCommit;
    }
@@ -196,10 +191,7 @@ public abstract class ProxyConnection implements Connection
 
    final void markCommitStateDirty()
    {
-      if (isAutoCommit) {
-         lastAccess = currentTime();
-      }
-      else {
+      if (!isAutoCommit) {
          isCommitStateDirty = true;
       }
    }
@@ -255,13 +247,11 @@ public abstract class ProxyConnection implements Connection
          try {
             if (isCommitStateDirty && !isAutoCommit) {
                delegate.rollback();
-               lastAccess = currentTime();
                LOGGER.debug("{} - Executed rollback on connection {} due to dirty commit state on close().", poolEntry.getPoolName(), delegate);
             }
 
             if (dirtyBits != 0) {
                poolEntry.resetConnectionState(this, dirtyBits);
-               lastAccess = currentTime();
             }
 
             delegate.clearWarnings();
@@ -274,7 +264,7 @@ public abstract class ProxyConnection implements Connection
          }
          finally {
             delegate = ClosedConnection.CLOSED_CONNECTION;
-            poolEntry.recycle(lastAccess);
+            poolEntry.recycle();
          }
       }
    }
@@ -386,7 +376,6 @@ public abstract class ProxyConnection implements Connection
    {
       delegate.commit();
       isCommitStateDirty = false;
-      lastAccess = currentTime();
    }
 
    /** {@inheritDoc} */
@@ -395,7 +384,6 @@ public abstract class ProxyConnection implements Connection
    {
       delegate.rollback();
       isCommitStateDirty = false;
-      lastAccess = currentTime();
    }
 
    /** {@inheritDoc} */
@@ -404,7 +392,6 @@ public abstract class ProxyConnection implements Connection
    {
       delegate.rollback(savepoint);
       isCommitStateDirty = false;
-      lastAccess = currentTime();
    }
 
    /** {@inheritDoc} */

src/main/java/com/zaxxer/hikari/pool/ProxyFactory.java

@@ -39,12 +39,11 @@ public final class ProxyFactory
     * @param connection the raw database Connection
     * @param openStatements a reusable list to track open Statement instances
     * @param leakTask the ProxyLeakTask for this connection
-    * @param now the current timestamp
     * @param isReadOnly the default readOnly state of the connection
     * @param isAutoCommit the default autoCommit state of the connection
     * @return a proxy that wraps the specified {@link Connection}
     */
-   static ProxyConnection getProxyConnection(final PoolEntry poolEntry, final Connection connection, final FastList<Statement> openStatements, final ProxyLeakTask leakTask, final long now, final boolean isReadOnly, final boolean isAutoCommit)
+   static ProxyConnection getProxyConnection(final PoolEntry poolEntry, final Connection connection, final FastList<Statement> openStatements, final ProxyLeakTask leakTask, final boolean isReadOnly, final boolean isAutoCommit)
    {
       // Body is replaced (injected) by JavassistProxyFactory
       throw new IllegalStateException("You need to run the CLI build and you need target/classes in your classpath to run.");

src/test/java/com/zaxxer/hikari/db/BasicPoolTest.java

@@ -77,14 +77,14 @@ public class BasicPoolTest
       System.setProperty("com.zaxxer.hikari.housekeeping.periodMs", "1000");
 
       try (HikariDataSource ds = new HikariDataSource(config)) {
+         getUnsealedConfig(ds).setIdleTimeout(3000);
+
          System.clearProperty("com.zaxxer.hikari.housekeeping.periodMs");
 
          SECONDS.sleep(1);
 
          HikariPool pool = getPool(ds);
 
-         getUnsealedConfig(ds).setIdleTimeout(3000);
-
          assertEquals("Total connections not as expected", 5, pool.getTotalConnections());
          assertEquals("Idle connections not as expected", 5, pool.getIdleConnections());
 
@@ -99,7 +99,7 @@ public class BasicPoolTest
 
          assertEquals("Idle connections not as expected", 6, pool.getIdleConnections());
 
-         SECONDS.sleep(2);
+         MILLISECONDS.sleep(3000);
 
          assertEquals("Third total connections not as expected", 5, pool.getTotalConnections());
          assertEquals("Third idle connections not as expected", 5, pool.getIdleConnections());

src/test/java/com/zaxxer/hikari/pool/TestJavassistCodegen.java

@@ -48,7 +48,6 @@ public class TestJavassistCodegen {
             connection,
             fastList,
             null /*leakTask*/,
-            0L /*now*/,
             Boolean.FALSE /*isReadOnly*/,
             Boolean.FALSE /*isAutoCommit*/);
       Assert.assertNotNull(proxyConnection);

src/test/java/com/zaxxer/hikari/pool/TestMBean.java

@@ -66,10 +66,10 @@ public class TestMBean
 
       try (HikariDataSource ds = new HikariDataSource(config)) {
 
-         getUnsealedConfig(ds).setIdleTimeout(3000);
-
          TimeUnit.SECONDS.sleep(1);
 
+         getUnsealedConfig(ds).setIdleTimeout(3000);
+
          MBeanServer mBeanServer = ManagementFactory.getPlatformMBeanServer();
          ObjectName poolName = new ObjectName("com.zaxxer.hikari:type=Pool (testMBeanReporting)");
          HikariPoolMXBean hikariPoolMXBean = JMX.newMXBeanProxy(mBeanServer, poolName, HikariPoolMXBean.class);
@@ -86,12 +86,11 @@ public class TestMBean
             assertEquals(4, hikariPoolMXBean.getTotalConnections());
          }
 
-         TimeUnit.SECONDS.sleep(2);
+         TimeUnit.SECONDS.sleep(3);
 
          assertEquals(0, hikariPoolMXBean.getActiveConnections());
          assertEquals(3, hikariPoolMXBean.getIdleConnections());
          assertEquals(3, hikariPoolMXBean.getTotalConnections());
-
       }
       finally {
          System.clearProperty("com.zaxxer.hikari.housekeeping.periodMs");

src/test/resources/log4j2-test.xml

@@ -6,7 +6,7 @@
     </Console>
   </appenders>
   <Loggers>
-    <Root level="info">
+    <Root level="debug">
       <AppenderRef ref="Console" />
     </Root>
   </Loggers>