Jacob special logging

java/jdbc/pom.xml

@@ -18,6 +18,11 @@
       <groupId>com.google.protobuf</groupId>
       <artifactId>protobuf-java</artifactId>
     </dependency>
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-api</artifactId>
+      <version>1.7.22</version>
+    </dependency>
 
     <dependency>
       <groupId>io.vitess</groupId>

java/jdbc/src/main/java/io/vitess/jdbc/VitessPreparedStatement.java

@@ -24,6 +24,9 @@
 import io.vitess.util.Constants;
 import io.vitess.util.StringUtils;
 
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
 import java.io.InputStream;
 import java.io.Reader;
 import java.math.BigDecimal;
@@ -66,7 +69,7 @@
  * calling any of the above method.
  */
 public class VitessPreparedStatement extends VitessStatement implements PreparedStatement {
-
+  private static final Logger LOG = LoggerFactory.getLogger(VitessPreparedStatement.class);
   /* Get actual class name to be printed on */
   private final String sql;
   private final Map<String, Object> bindVariables;
@@ -117,9 +120,14 @@ public ResultSet executeQuery() throws SQLException {
       if (vitessConnection.isSimpleExecute() && this.fetchSize == 0) {
         checkAndBeginTransaction();
         Context context = this.vitessConnection.createContext(this.queryTimeoutInMillis);
+        long start = System.currentTimeMillis();
         cursor = vtGateConn
             .execute(context, this.sql, this.bindVariables, vitessConnection.getVtSession())
             .checkedGet();
+        long duration = System.currentTimeMillis() - start;
+        if (duration > 15) {
+          LOG.info("Query {} took {} ms with bindings {}", this.sql, duration, this.bindVariables);
+        }
       } else {
         Context context = this.vitessConnection.createContext(this.queryTimeoutInMillis);
         cursor = vtGateConn

java/jdbc/src/main/java/io/vitess/jdbc/VitessVTGateManager.java

@@ -35,9 +35,11 @@
 import java.lang.reflect.InvocationTargetException;
 import java.sql.SQLException;
 import java.util.ArrayList;
+import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
 import java.util.Random;
+import java.util.Set;
 import java.util.Timer;
 import java.util.TimerTask;
 import java.util.concurrent.ConcurrentHashMap;
@@ -91,7 +93,8 @@ public VTGateConnections(final VitessConnection connection) {
                 new TimerTask() {
                   @Override
                   public void run() {
-                    refreshUpdatedSSLConnections(hostInfo, connection);
+                    refreshUpdatedSSLConnections(hostInfo,
+                        connection);
                   }
                 },
                 TimeUnit.SECONDS.toMillis(connection.getRefreshSeconds()),
@@ -141,21 +144,25 @@ private static void updateVtGateConnHashMap(String identifier, VitessJDBCUrl.Hos
 
   private static void refreshUpdatedSSLConnections(VitessJDBCUrl.HostInfo hostInfo,
       VitessConnection connection) {
+    Set<VTGateConnection> closedConnections = new HashSet<>();
     synchronized (VitessVTGateManager.class) {
-      int updatedCount = 0;
       for (Map.Entry<String, VTGateConnection> entry : vtGateConnHashMap.entrySet()) {
         if (entry.getValue() instanceof RefreshableVTGateConnection) {
           RefreshableVTGateConnection existing = (RefreshableVTGateConnection) entry.getValue();
           if (existing.checkKeystoreUpdates()) {
-            updatedCount++;
             VTGateConnection old = vtGateConnHashMap
                 .replace(entry.getKey(), getVtGateConn(hostInfo, connection));
-            closeRefreshedConnection(old);
+            closedConnections.add(old);
           }
         }
       }
-      if (updatedCount > 0) {
-        logger.info("refreshed " + updatedCount + " vtgate connections due to keystore update");
+    }
+
+    if (closedConnections.size() > 0) {
+      logger.info(
+          "refreshed " + closedConnections.size() + " vtgate connections due to keystore update");
+      for (VTGateConnection closedConnection : closedConnections) {
+        closeRefreshedConnection(closedConnection);
       }
     }
   }
@@ -216,13 +223,11 @@ private static VTGateConnection getVtGateConn(VitessJDBCUrl.HostInfo hostInfo,
           .trustStorePath(trustStorePath).trustStorePassword(trustStorePassword)
           .trustAlias(trustAlias);
 
-      return new RefreshableVTGateConnection(
-          new GrpcClientFactory(channelProvider, errorHandler)
-              .createTls(context, hostInfo.toString(), tlsOptions), keyStorePath, trustStorePath);
+      return new RefreshableVTGateConnection(new GrpcClientFactory(channelProvider, errorHandler)
+          .createTls(context, hostInfo.toString(), tlsOptions), keyStorePath, trustStorePath);
     } else {
-      return new VTGateConnection(
-          new GrpcClientFactory(channelProvider, errorHandler)
-              .create(context, hostInfo.toString()));
+      return new VTGateConnection(new GrpcClientFactory(channelProvider, errorHandler)
+          .create(context, hostInfo.toString()));
     }
   }
 
@@ -235,8 +240,7 @@ private static RetryingInterceptorConfig getRetryingInterceptorConfig(VitessConn
         conn.getGrpcRetryMaxBackoffMillis(), conn.getGrpcRetryBackoffMultiplier());
   }
 
-  private static ErrorHandler getErrorHandlerFromProperties(
-      VitessConnection connection) {
+  private static ErrorHandler getErrorHandlerFromProperties(VitessConnection connection) {
     // Skip reflection in default case
     if (Strings.isNullOrEmpty(connection.getErrorHandlerClass())) {
       return new DefaultErrorHandler();