fix: add retry logging for BigQueryRetryAlgorithm.java (#1506)

stephaniewang526 · prash-mi · web-flow · commit f5982794fb5f · 2021-08-17T16:06:51.000-04:00
* fix: add retry logging for BigQueryRetryAlgorithm.java

* Added shouldRetry and Error Message to Logging

* Added shouldRetry and Error Message to Logging

* update based on comments - to add in retried method (enclosingMethod)

* set log level to FINEST

Co-authored-by: Prashant Mishra &lt;prash_mi@yahoo.com&gt;
diff --git a/google-cloud-bigquery/src/main/java/com/google/cloud/bigquery/BigQueryRetryAlgorithm.java b/google-cloud-bigquery/src/main/java/com/google/cloud/bigquery/BigQueryRetryAlgorithm.java
@@ -27,7 +27,10 @@
 import com.google.api.gax.retrying.TimedRetryAlgorithmWithContext;
 import java.util.Iterator;
 import java.util.concurrent.CancellationException;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 import java.util.regex.Pattern;
+import org.threeten.bp.Duration;
 
 public class BigQueryRetryAlgorithm<ResponseT> extends RetryAlgorithm<ResponseT> {
   private final BigQueryRetryConfig bigQueryRetryConfig;
@@ -36,6 +39,8 @@ public class BigQueryRetryAlgorithm<ResponseT> extends RetryAlgorithm<ResponseT>
   private final ResultRetryAlgorithmWithContext<ResponseT> resultAlgorithmWithContext;
   private final TimedRetryAlgorithmWithContext timedAlgorithmWithContext;
 
+  private static final Logger LOG = Logger.getLogger(BigQueryRetryAlgorithm.class.getName());
+
   public BigQueryRetryAlgorithm(
       ResultRetryAlgorithm<ResponseT> resultAlgorithm,
       TimedRetryAlgorithm timedAlgorithm,
@@ -55,11 +60,32 @@ public boolean shouldRetry(
       ResponseT previousResponse,
       TimedAttemptSettings nextAttemptSettings)
       throws CancellationException {
+    // Log retry info
+    int attemptCount = nextAttemptSettings == null ? 0 : nextAttemptSettings.getAttemptCount();
+    Duration retryDelay =
+        nextAttemptSettings == null ? Duration.ZERO : nextAttemptSettings.getRetryDelay();
+    String errorMessage = previousThrowable != null ? previousThrowable.getMessage() : "";
+
     // Implementing shouldRetryBasedOnBigQueryRetryConfig so that we can retry exceptions based on
     // the exception messages
-    return (shouldRetryBasedOnResult(context, previousThrowable, previousResponse)
-            || shouldRetryBasedOnBigQueryRetryConfig(previousThrowable, bigQueryRetryConfig))
-        && shouldRetryBasedOnTiming(context, nextAttemptSettings);
+    boolean shouldRetry =
+        (shouldRetryBasedOnResult(context, previousThrowable, previousResponse)
+                || shouldRetryBasedOnBigQueryRetryConfig(previousThrowable, bigQueryRetryConfig))
+            && shouldRetryBasedOnTiming(context, nextAttemptSettings);
+
+    if (LOG.isLoggable(Level.FINEST)) {
+      LOG.log(
+          Level.FINEST,
+          "Retrying with:\n{0}\n{1}\n{2}\n{3}\n{4}",
+          new Object[] {
+            "BigQuery attemptCount: " + attemptCount,
+            "BigQuery delay: " + retryDelay,
+            "BigQuery retriableException: " + previousThrowable,
+            "BigQuery shouldRetry: " + shouldRetry,
+            "BigQuery previousThrowable.getMessage: " + errorMessage
+          });
+    }
+    return shouldRetry;
   }
 
   private boolean shouldRetryBasedOnBigQueryRetryConfig(
diff --git a/google-cloud-bigquery/src/main/java/com/google/cloud/bigquery/BigQueryRetryHelper.java b/google-cloud-bigquery/src/main/java/com/google/cloud/bigquery/BigQueryRetryHelper.java
@@ -16,13 +16,24 @@
 package com.google.cloud.bigquery;
 
 import com.google.api.core.ApiClock;
-import com.google.api.gax.retrying.*;
+import com.google.api.gax.retrying.DirectRetryingExecutor;
+import com.google.api.gax.retrying.ExponentialRetryAlgorithm;
+import com.google.api.gax.retrying.ResultRetryAlgorithm;
+import com.google.api.gax.retrying.RetryAlgorithm;
+import com.google.api.gax.retrying.RetrySettings;
+import com.google.api.gax.retrying.RetryingExecutor;
+import com.google.api.gax.retrying.RetryingFuture;
+import com.google.api.gax.retrying.TimedRetryAlgorithm;
 import com.google.cloud.RetryHelper;
 import java.util.concurrent.Callable;
 import java.util.concurrent.ExecutionException;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 
 public class BigQueryRetryHelper extends RetryHelper {
 
+  private static final Logger LOG = Logger.getLogger(BigQueryRetryHelper.class.getName());
+
   public static <V> V runWithRetries(
       Callable<V> callable,
       RetrySettings retrySettings,
@@ -60,6 +71,16 @@ private static <V> V run(
     // BigQueryRetryAlgorithm retries considering bigQueryRetryConfig
     RetryingExecutor<V> executor = new DirectRetryingExecutor<>(retryAlgorithm);
 
+    // Log retry info
+    if (LOG.isLoggable(Level.FINEST)) {
+      LOG.log(
+          Level.FINEST,
+          "Retrying with:\n{0}",
+          new Object[] {
+            "BigQuery retried method: " + callable.getClass().getEnclosingMethod().getName(),
+          });
+    }
+
     RetryingFuture<V> retryingFuture = executor.createFuture(callable);
     executor.submit(retryingFuture);
     return retryingFuture.get();
