From f0fa59e7a3525dd5d665f089a37fba83337c8b78 Mon Sep 17 00:00:00 2001
From: Brett Wooldridge <brett.wooldridge@gmail.com>
Date: Sun, 12 Jan 2014 17:14:40 +0900
Subject: [PATCH] Added debug level pool statistics logging

---
 .../java/com/zaxxer/hikari/HikariPool.java    | 43 +++++++++++++++----
 1 file changed, 34 insertions(+), 9 deletions(-)

diff --git a/core/src/main/java/com/zaxxer/hikari/HikariPool.java b/core/src/main/java/com/zaxxer/hikari/HikariPool.java
index 111abf98..f66bfd45 100644
--- a/core/src/main/java/com/zaxxer/hikari/HikariPool.java
+++ b/core/src/main/java/com/zaxxer/hikari/HikariPool.java
@@ -57,6 +57,7 @@ public final class HikariPool implements HikariPoolMBean
     private final boolean jdbc4ConnectionTest;
     private final boolean isAutoCommit;
     private int transactionIsolation;
+    private boolean debug;
 
     private final Timer houseKeepingTimer;
 
@@ -79,6 +80,7 @@ public final class HikariPool implements HikariPoolMBean
         this.leakDetectionThreshold = configuration.getLeakDetectionThreshold();
         this.isAutoCommit = configuration.isAutoCommit();
         this.transactionIsolation = configuration.getTransactionIsolation();
+        this.debug = LOGGER.isDebugEnabled();
 
         String dsClassName = configuration.getDataSourceClassName();
         try
@@ -154,15 +156,17 @@ public final class HikariPool implements HikariPoolMBean
                     connectionProxy.captureStack(leakDetectionThreshold, houseKeepingTimer);
                 }
 
-                connection.setTransactionIsolation(transactionIsolation);
                 connection.clearWarnings();
 
                 return connection;
 
             } while (timeout > 0);
 
+            logPoolState();
+
         	String msg = String.format("Timeout of %dms encountered waiting for connection.", configuration.getConnectionTimeout());
             LOGGER.error(msg);
+
             throw new SQLException(msg);
         }
         catch (InterruptedException e)
@@ -262,6 +266,8 @@ public final class HikariPool implements HikariPoolMBean
         {
             addConnection();
         }
+
+        logPoolState();
     }
 
     /**
@@ -305,7 +311,7 @@ public final class HikariPool implements HikariPoolMBean
                         }
                         backgroundFillQueued.set(false);
                     }
-    	        }, 50/*ms*/);
+    	        }, 90/*ms*/);
     	    }
     	    break;
     	}
@@ -324,6 +330,11 @@ public final class HikariPool implements HikariPoolMBean
                 Connection connection = dataSource.getConnection();
                 IHikariConnectionProxy proxyConnection = (IHikariConnectionProxy) JavassistProxyFactoryFactory.getProxyFactory().getProxyConnection(this, connection);
 
+                if (transactionIsolation < 0)
+                {
+                    transactionIsolation = connection.getTransactionIsolation();
+                }
+                
                 boolean alive = isConnectionAlive((Connection) proxyConnection, configuration.getConnectionTimeout());
                 if (!alive)
                 {
@@ -331,11 +342,6 @@ public final class HikariPool implements HikariPoolMBean
                     throw new RuntimeException("Connection not alive, retry.");
                 }
 
-                if (transactionIsolation < 0)
-                {
-                    transactionIsolation = connection.getTransactionIsolation();
-                }
-
                 String initSql = configuration.getConnectionInitSql();
                 if (initSql != null && initSql.length() > 0)
                 {
@@ -355,7 +361,14 @@ public final class HikariPool implements HikariPoolMBean
             {
                 if (retries++ > configuration.getAcquireRetries())
                 {
-                    LOGGER.error("Maximum connection creation retries exceeded", e);
+                    if (debug)
+                    {
+                        LOGGER.error("Maximum connection creation retries exceeded", e);
+                    }
+                    else
+                    {
+                        LOGGER.error("Maximum connection creation retries exceeded");
+                    }
                     break;
                 }
 
@@ -408,7 +421,7 @@ public final class HikariPool implements HikariPoolMBean
         }
         catch (SQLException e)
         {
-            LOGGER.error("Exception during keep alive check.  Connection must be dead.");
+            LOGGER.error("Exception during keep alive check.  Connection must be dead.", e);
             return false;
         }
         finally
@@ -445,6 +458,13 @@ public final class HikariPool implements HikariPoolMBean
         }
     }
 
+    private void logPoolState(String... prefix)
+    {
+        int total = totalConnections.get();
+        int idle = idleConnectionCount.get();
+        LOGGER.debug("{}Pool stats (total={}, inUse={}, avail={}", (prefix != null ? prefix : ""), total, total - idle, idle);
+    }
+
     /**
      * The house keeping task to retire idle and maxAge connections.
      */
@@ -452,8 +472,11 @@ public final class HikariPool implements HikariPoolMBean
     {
         public void run()
         {
+            debug = LOGGER.isDebugEnabled();
             houseKeepingTimer.purge();
 
+            logPoolState("Before pool cleanup ");
+
             final long now = System.currentTimeMillis();
             final long idleTimeout = configuration.getIdleTimeout();
             final long maxLifetime = configuration.getMaxLifetime();
@@ -483,6 +506,8 @@ public final class HikariPool implements HikariPoolMBean
             }
 
             addConnections(AddConnectionStrategy.MAINTAIN_MINIMUM);
+
+            logPoolState("After pool cleanup ");
         }
     }