fix: Lazy refresh should refresh tokens 4 minutes before expiration. (#2063)

Refresh tokens and certificates 4 minutes before they expire to avoid creating race condition that would allow the connector to create an ephemeral certificate with an expired auth token.

Now, IAM auth tokens are now refreshed 4 minutes before they token expire. Also, the Lazy Refresh Strategy will refresh the client certificate 4 minutes before the expiration of the certificate and the IAM auth token.

This should mitigate some of the strange certificate expiration errors commonly found in Cloud Run, see: #2059

Author: hessjcg

core/src/main/java/com/google/cloud/sql/core/DefaultAccessTokenSupplier.java

@@ -16,6 +16,8 @@
 
 package com.google.cloud.sql.core;
 
+import static com.google.cloud.sql.core.RefreshCalculator.DEFAULT_REFRESH_BUFFER;
+
 import com.google.auth.oauth2.AccessToken;
 import com.google.auth.oauth2.GoogleCredentials;
 import com.google.cloud.sql.AuthType;
@@ -76,12 +78,12 @@ public Optional<AccessToken> get() throws IOException {
             () -> {
               final GoogleCredentials credentials = credentialFactory.getCredentials();
               try {
-                credentials.refreshIfExpired();
+                refreshIfRequired(credentials);
               } catch (IllegalStateException e) {
                 throw new IllegalStateException("Error refreshing credentials " + credentials, e);
               }
-              if (credentials.getAccessToken() == null
-                  || "".equals(credentials.getAccessToken().getTokenValue())) {
+
+              if (isAccessTokenEmpty(credentials)) {
 
                 String errorMessage = "Access Token has length of zero";
                 logger.debug(errorMessage);
@@ -97,19 +99,17 @@ public Optional<AccessToken> get() throws IOException {
               // For some implementations of GoogleCredentials, particularly
               // ImpersonatedCredentials, down-scoped credentials are not
               // initialized with a token and need to be explicitly refreshed.
-              if (downscoped.getAccessToken() == null
-                  || "".equals(downscoped.getAccessToken().getTokenValue())) {
+              if (isAccessTokenEmpty(downscoped)) {
                 try {
-                  downscoped.refreshIfExpired();
+                  downscoped.refresh();
                 } catch (Exception e) {
                   throw new IllegalStateException(
                       "Error refreshing downscoped credentials " + credentials, e);
                 }
 
                 // After attempting to refresh once, if the downscoped credentials do not have
                 // an access token after attempting to refresh, then throw an IllegalStateException
-                if (downscoped.getAccessToken() == null
-                    || "".equals(downscoped.getAccessToken().getTokenValue())) {
+                if (isAccessTokenEmpty(downscoped)) {
                   String errorMessage = "Downscoped access token has length of zero";
                   logger.debug(errorMessage);
 
@@ -135,6 +135,28 @@ public Optional<AccessToken> get() throws IOException {
     }
   }
 
+  private static boolean isAccessTokenEmpty(GoogleCredentials credentials) {
+    return credentials.getAccessToken() == null
+        || "".equals(credentials.getAccessToken().getTokenValue());
+  }
+
+  private void refreshIfRequired(GoogleCredentials credentials) throws IOException {
+    // if the token does not exist, or if the token expires in less than 4 minutes, refresh it.
+    if (credentials.getAccessToken() == null) {
+      logger.debug("Current IAM AuthN Token is not set. Refreshing the token.");
+      credentials.refresh();
+    } else if (credentials.getAccessToken().getExpirationTime() != null
+        && credentials
+            .getAccessToken()
+            .getExpirationTime()
+            .toInstant()
+            .minus(DEFAULT_REFRESH_BUFFER)
+            .isBefore(Instant.now())) {
+      logger.debug("Current IAM AuthN Token expires in less than 4 minutes. Refreshing the token.");
+      credentials.refresh();
+    }
+  }
+
   private void validateAccessTokenExpiration(AccessToken accessToken) {
     Date expirationTimeDate = accessToken.getExpirationTime();
 

core/src/main/java/com/google/cloud/sql/core/DefaultConnectionInfoRepository.java

@@ -46,6 +46,7 @@
 import java.security.cert.X509Certificate;
 import java.time.Instant;
 import java.util.Arrays;
+import java.util.Base64;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
@@ -196,7 +197,15 @@ private static ConnectionInfo createConnectionInfo(
               .orElse(x509Certificate.getNotAfter().toInstant());
     }
 
-    logger.debug(String.format("[%s] INSTANCE DATA DONE", instanceName));
+    logger.debug(
+        "[{}] INSTANCE DATA DONE - Ephemeral cert id: {} cert expiration: {} token expiration: {}",
+        instanceName,
+        Base64.getEncoder().encodeToString(((X509Certificate) ephemeralCertificate).getSignature()),
+        token
+            .map(tok -> tok.getExpirationTime())
+            .filter(time -> time != null)
+            .map(time -> time.toInstant().toString())
+            .orElse("(none)"));
 
     return new ConnectionInfo(metadata, sslContext, expiration);
   }

core/src/main/java/com/google/cloud/sql/core/LazyRefreshConnectionInfoCache.java

@@ -16,6 +16,8 @@
 
 package com.google.cloud.sql.core;
 
+import static com.google.cloud.sql.core.RefreshCalculator.DEFAULT_REFRESH_BUFFER;
+
 import com.google.cloud.sql.CredentialFactory;
 import java.security.KeyPair;
 
@@ -54,7 +56,8 @@ public LazyRefreshConnectionInfoCache(
             config.getCloudSqlInstance(),
             () ->
                 connectionInfoRepository.getConnectionInfoSync(
-                    instanceName, accessTokenSupplier, config.getAuthType(), keyPair));
+                    instanceName, accessTokenSupplier, config.getAuthType(), keyPair),
+            DEFAULT_REFRESH_BUFFER);
   }
 
   @Override

core/src/main/java/com/google/cloud/sql/core/LazyRefreshStrategy.java

@@ -17,6 +17,7 @@
 package com.google.cloud.sql.core;
 
 import com.google.errorprone.annotations.concurrent.GuardedBy;
+import java.time.Duration;
 import java.time.Instant;
 import java.util.function.Supplier;
 import org.slf4j.Logger;
@@ -28,6 +29,7 @@ public class LazyRefreshStrategy implements RefreshStrategy {
 
   private final String name;
   private final Supplier<ConnectionInfo> refreshOperation;
+  private final Duration refreshBuffer;
 
   private final Object connectionInfoGuard = new Object();
 
@@ -38,9 +40,11 @@ public class LazyRefreshStrategy implements RefreshStrategy {
   private boolean closed;
 
   /** Creates a new LazyRefreshStrategy instance. */
-  public LazyRefreshStrategy(String name, Supplier<ConnectionInfo> refreshOperation) {
+  public LazyRefreshStrategy(
+      String name, Supplier<ConnectionInfo> refreshOperation, Duration refreshDuration) {
     this.name = name;
     this.refreshOperation = refreshOperation;
+    this.refreshBuffer = refreshDuration;
   }
 
   @Override
@@ -59,7 +63,7 @@ public ConnectionInfo getConnectionInfo(long timeoutMs) {
                 name));
         fetchConnectionInfo();
       }
-      if (Instant.now().isAfter(connectionInfo.getExpiration())) {
+      if (Instant.now().isAfter(connectionInfo.getExpiration().minus(refreshBuffer))) {
         logger.debug(
             String.format(
                 "[%s] Lazy Refresh Operation: Client certificate has expired. Starting next "

core/src/main/java/com/google/cloud/sql/core/RefreshCalculator.java

@@ -28,7 +28,7 @@ class RefreshCalculator {
   // defaultRefreshBuffer is the minimum amount of time for which a
   // certificate must be valid to ensure the next refresh attempt has adequate
   // time to complete.
-  private static final Duration DEFAULT_REFRESH_BUFFER = Duration.ofMinutes(4);
+  static final Duration DEFAULT_REFRESH_BUFFER = Duration.ofMinutes(4);
 
   long calculateSecondsUntilNextRefresh(Instant now, Instant expiration) {
     Duration timeUntilExp = Duration.between(now, expiration);

core/src/test/java/com/google/cloud/sql/core/LazyRefreshStrategyTest.java

@@ -19,6 +19,7 @@
 import static com.google.common.truth.Truth.assertThat;
 import static org.junit.Assert.assertThrows;
 
+import java.time.Duration;
 import java.time.Instant;
 import java.time.temporal.ChronoUnit;
 import java.util.concurrent.atomic.AtomicInteger;
@@ -32,7 +33,9 @@ public void testCloudSqlInstanceDataRetrievedSuccessfully() {
     final ExampleData data = new ExampleData(Instant.now().plus(1, ChronoUnit.HOURS));
     LazyRefreshStrategy r =
         new LazyRefreshStrategy(
-            "LazyRefresherTest.testCloudSqlInstanceDataRetrievedSuccessfully", () -> data);
+            "LazyRefresherTest.testCloudSqlInstanceDataRetrievedSuccessfully",
+            () -> data,
+            Duration.ZERO);
     ConnectionInfo gotInfo = r.getConnectionInfo(TEST_TIMEOUT_MS);
     assertThat(gotInfo).isSameInstanceAs(data);
   }
@@ -44,7 +47,8 @@ public void testInstanceFailsOnConnectionError() {
             "LazyRefresherTest.testInstanceFailsOnConnectionError",
             () -> {
               throw new RuntimeException("always fails");
-            });
+            },
+            Duration.ZERO);
 
     RuntimeException ex =
         assertThrows(RuntimeException.class, () -> r.getConnectionInfo(TEST_TIMEOUT_MS));
@@ -62,7 +66,8 @@ public void testCloudSqlInstanceForcesRefresh() throws Exception {
             () -> {
               refreshCount.incrementAndGet();
               return data;
-            });
+            },
+            Duration.ZERO);
 
     r.getConnectionInfo(TEST_TIMEOUT_MS);
     assertThat(refreshCount.get()).isEqualTo(1);
@@ -96,24 +101,59 @@ public void testCloudSqlRefreshesExpiredData() throws Exception {
                 return initialData;
               }
               return data;
-            });
+            },
+            Duration.ZERO);
 
     // Get the first data that is about to expire
     ConnectionInfo d = r.getConnectionInfo(TEST_TIMEOUT_MS);
     assertThat(refreshCount.get()).isEqualTo(1);
     assertThat(d).isSameInstanceAs(initialData);
 
-    waitForExpiration(initialData);
+    waitForExpiration(initialData.getExpiration());
 
     assertThat(r.getConnectionInfo(TEST_TIMEOUT_MS)).isSameInstanceAs(data);
     assertThat(refreshCount.get()).isEqualTo(2);
   }
 
-  private static void waitForExpiration(ExampleData initialData) throws InterruptedException {
+  @Test
+  public void testCloudSqlRefreshesExpiredDataWithRefreshBuffer() throws Exception {
+    Duration buffer = Duration.ofSeconds(5);
+    ExampleData initialData = new ExampleData(Instant.now().plus(8, ChronoUnit.SECONDS));
+    ExampleData data = new ExampleData(Instant.now().plus(1, ChronoUnit.HOURS));
+
+    AtomicInteger refreshCount = new AtomicInteger();
+
+    LazyRefreshStrategy r =
+        new LazyRefreshStrategy(
+            "LazyRefresherTest.testCloudSqlRefreshesExpiredData",
+            () -> {
+              int c = refreshCount.getAndIncrement();
+              if (c == 0) {
+                return initialData;
+              }
+              return data;
+            },
+            buffer);
+
+    // Get the first data that is about to expire, but not yet expired
+    ConnectionInfo d = r.getConnectionInfo(TEST_TIMEOUT_MS);
+    assertThat(refreshCount.get()).isEqualTo(1);
+    assertThat(d).isSameInstanceAs(initialData);
+
+    // Wait 5 seconds. Now the initialData expires in 3 seconds, less than the buffer.
+    waitForExpiration(Instant.now().plus(buffer));
+
+    // Assert that it gets data instead of initialData.
+    assertThat(r.getConnectionInfo(TEST_TIMEOUT_MS)).isSameInstanceAs(data);
+    assertThat(refreshCount.get()).isEqualTo(2);
+  }
+
+  private static void waitForExpiration(Instant expiration) throws InterruptedException {
     // Wait for the instance to expire
-    while (!Instant.now().isAfter(initialData.getExpiration())) {
+    while (!Instant.now().isAfter(expiration)) {
       Thread.sleep(10);
     }
+
     // Sleep a few more ms to make sure that Instant.now() really is after expiration.
     // Fixes a date math race condition only present in Java 8.
     Thread.sleep(10);
@@ -135,15 +175,16 @@ public void testThatConcurrentRequestsDontCauseDuplicateRefreshAttempts() throws
                 return initialData;
               }
               return data;
-            });
+            },
+            Duration.ZERO);
 
     // Get the first data that is about to expire
     ConnectionInfo d = r.getConnectionInfo(TEST_TIMEOUT_MS);
     assertThat(refreshCount.get()).isEqualTo(1);
     assertThat(d).isSameInstanceAs(initialData);
 
     // Wait for the instance to expire
-    waitForExpiration(initialData);
+    waitForExpiration(initialData.getExpiration());
 
     // Start multiple threads and request connection info
     Thread t1 = new Thread(() -> r.getConnectionInfo(TEST_TIMEOUT_MS));
@@ -166,7 +207,9 @@ public void testClosedCloudSqlInstanceDataThrowsException() {
     ExampleData data = new ExampleData(Instant.now().plus(1, ChronoUnit.HOURS));
     LazyRefreshStrategy r =
         new LazyRefreshStrategy(
-            "RefresherTest.testClosedCloudSqlInstanceDataThrowsException", () -> data);
+            "RefresherTest.testClosedCloudSqlInstanceDataThrowsException",
+            () -> data,
+            Duration.ZERO);
     r.close();
 
     assertThrows(IllegalStateException.class, () -> r.getConnectionInfo(TEST_TIMEOUT_MS));