Add retries logging

Author: Johan Walles

src/main/java/redis/clients/jedis/BinaryJedis.java

@@ -189,6 +189,11 @@ public BinaryJedis(final JedisSocketFactory jedisSocketFactory) {
     client = new Client(jedisSocketFactory);
   }
 
+  @Override
+  public String toString() {
+    return "BinaryJedis{" + client + '}';
+  }
+
   private void initializeClientFromURI(URI uri) {
     initializeClientFromURI(uri, null, null, null);
   }

src/main/java/redis/clients/jedis/Connection.java

@@ -57,6 +57,11 @@ public Connection(final JedisSocketFactory jedisSocketFactory) {
     this.jedisSocketFactory = jedisSocketFactory;
   }
 
+  @Override
+  public String toString() {
+    return "Connection{" + jedisSocketFactory + "}";
+  }
+
   public Socket getSocket() {
     return socket;
   }

src/main/java/redis/clients/jedis/DefaultJedisSocketFactory.java

@@ -121,4 +121,9 @@ public int getSoTimeout() {
   public void setSoTimeout(int soTimeout) {
     this.soTimeout = soTimeout;
   }
+
+  @Override
+  public String toString() {
+    return "DefaultJedisSocketFactory{" + host + ":" + +port + "}";
+  }
 }

src/main/java/redis/clients/jedis/JedisClusterCommand.java

@@ -4,6 +4,8 @@
 import java.time.Instant;
 import java.util.concurrent.TimeUnit;
 import java.util.function.Supplier;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import redis.clients.jedis.exceptions.JedisAskDataException;
 import redis.clients.jedis.exceptions.JedisClusterMaxAttemptsException;
 import redis.clients.jedis.exceptions.JedisClusterOperationException;
@@ -24,6 +26,8 @@ public abstract class JedisClusterCommand<T> {
    */
   private static final Duration DEFAULT_TIMEOUT = Duration.ofSeconds(20);
 
+  private static final Logger LOG = LoggerFactory.getLogger(JedisClusterCommand.class);
+
   private final JedisClusterConnectionHandler connectionHandler;
   private final int maxAttempts;
   private final Duration timeout;
@@ -143,10 +147,15 @@ private T runWithRetries(final int slot) {
           redirectionSupplier = null;
         }
 
-        return execute(connection);
+        final T result = execute(connection);
+        if (currentAttempt > 0) {
+          LOG.info("Success after {} attempts", currentAttempt + 1);
+        }
+        return result;
       } catch (JedisNoReachableClusterNodeException e) {
         throw e;
       } catch (JedisConnectionException e) {
+        LOG.warn("Failed connecting to Redis: {}", connection, e);
         // "- 1" because we just did one, but the currentAttempt counter hasn't increased yet
         int attemptsLeft = maxAttempts - currentAttempt - 1;
         connectionSupplier = handleConnectionProblem(connection, slot, attemptsLeft, deadline);
@@ -155,13 +164,16 @@ private T runWithRetries(final int slot) {
       } finally {
         releaseConnection(connection);
       }
+
+      LOG.info("{} retries left...", maxAttempts - currentAttempt - 1);
     }
 
     throw new JedisClusterMaxAttemptsException("No more cluster attempts left.");
   }
 
   protected void sleep(long sleepMillis) {
     try {
+      LOG.info("Backing off, sleeping {}ms before trying again...", sleepMillis);
       TimeUnit.MILLISECONDS.sleep(sleepMillis);
     } catch (InterruptedException e) {
       throw new RuntimeException(e);
@@ -171,7 +183,11 @@ protected void sleep(long sleepMillis) {
   private Supplier<Jedis> handleConnectionProblem(Jedis failedConnection, final int slot, int attemptsLeft,
       Instant doneDeadline) {
     if (!shouldBackOff(attemptsLeft)) {
-      return () -> connectionHandler.getConnectionFromSlot(slot);
+      return () -> {
+        Jedis connection = connectionHandler.getConnectionFromSlot(slot);
+        LOG.info("Retrying with {}", connection);
+        return connection;
+      };
     }
 
     // Must release current connection before renewing the slot cache below. If we fail to do this,
@@ -188,11 +204,16 @@ private Supplier<Jedis> handleConnectionProblem(Jedis failedConnection, final in
     return () -> {
       sleep(getBackoffSleepMillis(attemptsLeft, doneDeadline));
       // Get a random connection, it will redirect us if it's not the right one
-      return connectionHandler.getConnection();
+      LOG.info("Retrying with a random node...");
+      Jedis connection = connectionHandler.getConnection();
+      LOG.info("Retrying with random pick: {}", connection);
+      return connection;
     };
   }
 
   private Supplier<Jedis> handleRedirection(Jedis connection, final JedisRedirectionException jre) {
+    LOG.debug("Redirected by server to {}", jre.getTargetNode());
+
     // if MOVED redirection occurred,
     if (jre instanceof JedisMovedDataException) {
       // it rebuilds cluster's slot cache recommended by Redis cluster specification
@@ -204,6 +225,7 @@ private Supplier<Jedis> handleRedirection(Jedis connection, final JedisRedirecti
 
     return () -> {
       Jedis redirectedConnection = connectionHandler.getConnectionFromNode(jre.getTargetNode());
+      LOG.info("Retrying with redirection target {}", connection);
       if (jre instanceof JedisAskDataException) {
         // TODO: Pipeline asking with the original command to make it faster....
         redirectedConnection.asking();