fix: Improve handling of futures and threads during refresh. #1457

hessjcg · 2023-09-08T01:19:32Z

Rewrite the performRefresh() as a chain of task futures from the ListeningScheduledExecutorService. Now, tasks
submitted to the ListeningScheduledExecutorService never block on another task submitted to the ListeningScheduledExecutorService.

This should fix a category of bugs that show up in exceptions and logs as "connection timed out" or "refresh failed"
or "bad client certificate". These exceptions can occur when the credentials fail to refresh.

This is the underlying bug: The ListeningScheduledExecutorService gets into a state where all its threads are busy
running tasks, all running tasks are blocked waiting for recently submitted task to complete, and the recently
submitted tasks can't start because there are no available threads in the ListeningScheduledExecutorService.

hessjcg · 2023-09-08T02:03:27Z

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

@@ -113,8 +116,19 @@ private InstanceData getInstanceData() {
      instanceDataFuture = currentInstanceData;
    }
    try {
-      return Uninterruptibles.getUninterruptibly(instanceDataFuture);
-    } catch (ExecutionException ex) {
+      return instanceDataFuture.get(30, TimeUnit.SECONDS);


This is a change of behavior:

This method is called by an application thread when it is trying to create a new connection to the database. (It is not called by a ListeningScheduledExecutorService task.) So it is OK to block waiting for a future to complete.

The old implementation:

When no refresh attempt is in progress, returns immediately.

Otherwise blocks application thread until the current refresh attempt finishes. If the refresh attempt succeeds, this returns the InstanceData. If not, this throws a RuntimeException, while a new refresh attempt is submitted to the executor in the background.

The new implementation:

When no refresh attempt is in progress, returns immediately.

Otherwise waits up to 30 seconds. If a refresh attempt succeeds, returns immediately at the end of that successful attempt. If no attempts succeed within the 30 second timeout, throws a RuntimeException with the exception from the last failed refresh attempt as the cause.

We could make this 30 second timeout configurable. Customers who want connection attempts to fail fast
could set this timeout lower. Customers who want connection attempts to block could set the timeout higher.

Minor not: could we pull out the 30 into a constant? MAX_INSTANCE_DATA_WAIT_TIME or similar?

hessjcg · 2023-09-08T02:12:46Z

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

-  private InstanceData performRefresh() throws InterruptedException, ExecutionException {
-    logger.fine(
-        String.format("[%s] Refresh Operation: Acquiring rate limiter permit.", instanceName));
+  private ListenableFuture<InstanceData> performRefresh() {


This is a change of behavior.

The old way: performRefresh() used to block until either (1) an InstanceData was retrieved or (2) an attempt failed, and an exception was thrown.

The new way: performRefresh() does not block. It sets up a chain of futures. The future returned from this method will resolve only when a refresh attempt succeeds.

hessjcg · 2023-09-08T02:16:57Z

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


    RuntimeException ex = Assert.assertThrows(RuntimeException.class, instance::getSslData);
    assertThat(ex).hasMessageThat().contains("always fails");
  }

+  @Test
+  public void testInstanceFailsOnTooLongToRetrieve() throws Exception {


A new test covers the behavior when the refresh attempt never returns.

hessjcg · 2023-09-08T02:17:16Z

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

@@ -139,7 +176,7 @@ public void testCloudSqlInstanceForcesRefresh() throws Exception {
            stubCredentialFactory,
            executorService,
            keyPairFuture,
-            RateLimiter.create(1.0 / 30.0));
+            RateLimiter.create(10));


Speed up tests - allow 10 requests/second.

enocom

This looks like a nice improvement.

enocom · 2023-09-11T16:55:20Z

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

@@ -113,8 +116,19 @@ private InstanceData getInstanceData() {
      instanceDataFuture = currentInstanceData;
    }
    try {
-      return Uninterruptibles.getUninterruptibly(instanceDataFuture);
-    } catch (ExecutionException ex) {
+      return instanceDataFuture.get(30, TimeUnit.SECONDS);


Minor not: could we pull out the 30 into a constant? MAX_INSTANCE_DATA_WAIT_TIME or similar?

enocom · 2023-09-11T16:56:37Z

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

+        // Now update nextInstanceData to perform a refresh after the
+        // scheduled delay
+        ListenableFuture scheduleDelay =
+            executor.schedule(() -> {}, secondsToRefresh, TimeUnit.SECONDS);


Is there any other ways to do this? On the surface it looks unusual.

I found a better method call for this.

enocom · 2023-09-11T16:57:31Z

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

+                    }
+                    throw new RuntimeException("fake read timeout");
+                  });
+          f.get(); // this will throw an ExecutionException


Let's add some more details to the comment -- it will throw an exception because we've configured the connector wait only 30s?

I added comments and cleaned this up.

enocom · 2023-09-29T20:57:51Z

@hessjcg friendly ping on this. This is an important fix and improvement that we want to bake in CI to see if it resolves the flaky tests.

chore: Give methods in CloudSqlInstance names that better reflect their new async roles.

… the token has expired.

…sh is scheduled.

enocom · 2023-10-03T17:26:35Z

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

@@ -47,6 +47,8 @@ class CloudSqlInstance {

  private static final Logger logger = Logger.getLogger(CloudSqlInstance.class.getName());

+  public static final int MAX_INSTANCE_DATA_WAIT_MS = 30000;


Let's add a comment explaining what this constant represents.

enocom · 2023-10-03T17:40:00Z

pom.xml

@@ -153,6 +153,7 @@
          <compilerArgs>
            <arg>-XDcompilePolicy=simple</arg>
            <arg>-Xplugin:ErrorProne</arg>
+            <arg>-Xlint:-options</arg>


Should this be a separate PR?

enocom · 2023-10-03T17:40:51Z

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

@@ -159,45 +216,88 @@ String getPreferredIp(List<String> preferredTypes) {
   * new refresh is already in progress. If successful, other methods will block until refresh has
   * been completed.
   */
-  void forceRefresh() {
+  boolean forceRefresh() {


Should this be returning a boolean? I don't see it being used.

enocom · 2023-10-03T17:48:12Z

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

+        Instant expiration;
+        try {
+          expiration = instanceDataFuture.get().getExpiration();
+          if (expiration == null || expiration.isBefore(Instant.now())) {


If the current instance data has already expired, won't we ended up initiating a force refresh when the socket creation fails? In other words, do we really need to do this work here?

enocom · 2023-10-03T17:49:42Z

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

+      return instanceDataFuture.get(timeoutMs, TimeUnit.MILLISECONDS);
+    } catch (TimeoutException e) {
+      synchronized (instanceDataGuard) {
+        if (currentRefreshFailure != null) {


Could we split this out as a separate PR? It's nice to surface the refresh failure like this.

enocom · 2023-10-03T17:50:15Z

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

      // has produced a successful refresh.
-      if (forceRefreshRunning) {
-        return;
+      if (refreshRunning) {


Could this rename be a separate PR? Seems like a nice improvement.

hessjcg · 2023-10-03T18:45:11Z

Closing, too big. I'll submit this as a sequence of PRs.

product-auto-label bot added size: m labels Sep 8, 2023

hessjcg force-pushed the fix-refresh-threads branch from b753d95 to 5afe088 Compare September 8, 2023 01:22

hessjcg commented Sep 8, 2023

View reviewed changes

hessjcg force-pushed the fix-refresh-threads branch from 5afe088 to feae3b3 Compare September 8, 2023 02:16

hessjcg commented Sep 8, 2023

View reviewed changes

hessjcg force-pushed the fix-refresh-threads branch from feae3b3 to 86f06c8 Compare September 8, 2023 02:23

hessjcg marked this pull request as ready for review September 8, 2023 02:25

hessjcg requested a review from a team as a code owner September 8, 2023 02:25

blunderbuss-gcf bot assigned ttosta-google Sep 8, 2023

hessjcg force-pushed the fix-refresh-threads branch from 4f01388 to 8519aff Compare September 8, 2023 14:45

hessjcg requested review from enocom and ttosta-google September 8, 2023 14:46

github-actions bot removed size: m labels Sep 8, 2023

product-auto-label bot added the api: cloudsql label Sep 9, 2023

enocom reviewed Sep 11, 2023

View reviewed changes

github-actions bot removed the api: cloudsql label Sep 11, 2023

hessjcg force-pushed the fix-refresh-threads branch from 8519aff to 69cc22a Compare September 11, 2023 20:42

product-auto-label bot added the size: l label Sep 11, 2023

hessjcg requested a review from enocom September 11, 2023 21:01

hessjcg force-pushed the fix-refresh-threads branch from 69cc22a to ff3646c Compare September 11, 2023 21:05

github-actions bot removed the size: l label Sep 11, 2023

hessjcg force-pushed the fix-refresh-threads branch from ff3646c to a4f0db0 Compare September 11, 2023 23:03

product-auto-label bot added the size: l label Sep 11, 2023

hessjcg force-pushed the fix-refresh-threads branch 2 times, most recently from aded0c8 to e5d3e5b Compare September 11, 2023 23:10

github-actions bot removed the size: l label Sep 11, 2023

product-auto-label bot added the api: cloudsql label Sep 12, 2023

github-actions bot removed the api: cloudsql label Sep 12, 2023

product-auto-label bot added the api: cloudsql label Sep 22, 2023

github-actions bot removed the api: cloudsql label Sep 22, 2023

product-auto-label bot added the api: cloudsql label Sep 23, 2023

github-actions bot removed the api: cloudsql label Sep 25, 2023

product-auto-label bot added the api: cloudsql label Sep 26, 2023

github-actions bot removed the api: cloudsql label Sep 26, 2023

product-auto-label bot added the api: cloudsql label Sep 27, 2023

github-actions bot removed the api: cloudsql label Sep 27, 2023

product-auto-label bot added the api: cloudsql label Sep 28, 2023

github-actions bot removed the api: cloudsql label Sep 28, 2023

product-auto-label bot added the api: cloudsql label Sep 29, 2023

github-actions bot removed the api: cloudsql label Oct 2, 2023

hessjcg added 5 commits October 2, 2023 14:38

fix: Improve handling of futures and threads during refresh.

643e7c7

chore: Give methods in CloudSqlInstance names that better reflect their new async roles.

fix: Make the getInstanceData() block until a successful refresh when…

e8138dd

… the token has expired.

chore: fix lint errors.

bdde609

fix: Correct race condition in forceRefresh() when a background refre…

c06a69f

…sh is scheduled.

fix: correct race condition in unit test.

4904931

hessjcg force-pushed the fix-refresh-threads branch from 53d3751 to 4b4712f Compare October 2, 2023 21:01

product-auto-label bot added size: l labels Oct 2, 2023

hessjcg force-pushed the fix-refresh-threads branch 2 times, most recently from 34cc99b to a7f9a7f Compare October 3, 2023 15:18

fix: rebase and clean up compiler warnings

9727951

hessjcg force-pushed the fix-refresh-threads branch from a7f9a7f to 9727951 Compare October 3, 2023 15:35

enocom reviewed Oct 3, 2023

View reviewed changes

hessjcg closed this Oct 3, 2023

hessjcg deleted the fix-refresh-threads branch October 3, 2023 19:24

enocom mentioned this pull request Oct 10, 2023

fix: Improve handling of futures and threads during refresh. #1573

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: Improve handling of futures and threads during refresh. #1457

fix: Improve handling of futures and threads during refresh. #1457

hessjcg commented Sep 8, 2023 •

edited

Loading

hessjcg Sep 8, 2023 •

edited

Loading

enocom Sep 11, 2023

hessjcg Sep 11, 2023

hessjcg Sep 8, 2023

hessjcg Sep 8, 2023

hessjcg Sep 8, 2023

enocom left a comment

enocom Sep 11, 2023

enocom Sep 11, 2023

hessjcg Sep 11, 2023

enocom Sep 11, 2023

hessjcg Sep 11, 2023

enocom commented Sep 29, 2023

enocom Oct 3, 2023

enocom Oct 3, 2023

enocom Oct 3, 2023

enocom Oct 3, 2023

enocom Oct 3, 2023

enocom Oct 3, 2023

hessjcg commented Oct 3, 2023

		@@ -47,6 +47,8 @@ class CloudSqlInstance {

		private static final Logger logger = Logger.getLogger(CloudSqlInstance.class.getName());

		public static final int MAX_INSTANCE_DATA_WAIT_MS = 30000;

fix: Improve handling of futures and threads during refresh. #1457

fix: Improve handling of futures and threads during refresh. #1457

Conversation

hessjcg commented Sep 8, 2023 • edited Loading

hessjcg Sep 8, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

enocom left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

enocom commented Sep 29, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hessjcg commented Oct 3, 2023

hessjcg commented Sep 8, 2023 •

edited

Loading

hessjcg Sep 8, 2023 •

edited

Loading