Code changes in 1.15.2 seem to impact how r2dbc-pool works

[turneand]

Bug Description

Code changes introduced in 1.15.2 seems to have impacted the way that r2dbc-pool with ValidationDepth.REMOTE works. Using the same program below, with 1.15.1 everything works correctly, and we are able to extract a connection from each ConnectionFactory/pool, however with 1.15.2 the pool using ValidationDepth.REMOTE results in an exception like below.

The database backing this is a postgres 15 instance, using IAM authenticatin. The sample app is currently running within a GKE container, and is a massively cut down version of our "full" application, but isolated to the minimum reproducible issue.

Example code (or command)

<!-- maven dependencies... -->
  <dependencies>
    <dependency>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-classic</artifactId>
      <version>1.4.14</version>
    </dependency>
    <dependency>
      <groupId>io.r2dbc</groupId>
      <artifactId>r2dbc-pool</artifactId>
      <version>1.0.1.RELEASE</version>
    </dependency>
    <dependency>
      <groupId>org.postgresql</groupId>
      <artifactId>r2dbc-postgresql</artifactId>
      <version>1.0.2.RELEASE</version>
    </dependency>
    <dependency>
      <groupId>com.google.cloud.sql</groupId>
      <artifactId>cloud-sql-connector-r2dbc-postgres</artifactId>
      <!-- with 1.15.1, this app works -->
      <!-- <version>1.15.1</version> -->
      <version>1.15.2</version>
    </dependency>
  </dependencies>

import io.r2dbc.pool.ConnectionPool;
import io.r2dbc.pool.ConnectionPoolConfiguration;
import io.r2dbc.spi.Connection;
import io.r2dbc.spi.ConnectionFactories;
import io.r2dbc.spi.ConnectionFactory;
import io.r2dbc.spi.ConnectionFactoryOptions;
import io.r2dbc.spi.Option;
import io.r2dbc.spi.ValidationDepth;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import reactor.core.publisher.Mono;
import java.time.Duration;

public class Application {
  private static final Logger log = LoggerFactory.getLogger(Application.class);

  public static void main(String[] args) {
    log.info("running");

    var user = "...";
    var database = "...";
    var host = "...";

    var connectionFactory = ConnectionFactories.get(ConnectionFactoryOptions.builder()
        .option(ConnectionFactoryOptions.DRIVER, "gcp")
        .option(ConnectionFactoryOptions.PROTOCOL, "postgres")
        .option(ConnectionFactoryOptions.PASSWORD, "ignored")
        .option(ConnectionFactoryOptions.USER, user)
        .option(ConnectionFactoryOptions.DATABASE, database)
        .option(ConnectionFactoryOptions.HOST, host)
        .option(Option.valueOf("ENABLE_IAM_AUTH"), true)
        .build());

    // direct works fine
    execute("direct", connectionFactory);

    // pool with LOCAL validation works fine
    executeWithPool("pool-local", ConnectionPoolConfiguration.builder(connectionFactory).validationDepth(ValidationDepth.LOCAL).build());

    // pool with REMOTE validation errors
    executeWithPool("pool-remote", ConnectionPoolConfiguration.builder(connectionFactory).validationDepth(ValidationDepth.REMOTE).build());
  }

  private static void executeWithPool(String prefix, ConnectionPoolConfiguration config) {
    var pool = new ConnectionPool(config);
    try {
      execute(prefix, pool);
    } finally {
      try {
        pool.close().block(Duration.ofSeconds(30));
      } catch (Exception e) {
        log.error("{} - can't close", prefix, e);
      }
    }
  }

  private static void execute(String prefix, ConnectionFactory factory) {
    try {
      var result = Mono.usingWhen(Mono.fromDirect(factory.create()),
                   (con) -> Mono.fromDirect(con.createStatement("SELECT 1").execute())
                  .flatMapMany((rs) -> rs.map(Object::toString))
                  .next(), Connection::close, (con, t) -> con.close(), Connection::close)
            .block(Duration.ofSeconds(10));
      log.info("{} - success: {}", prefix, result);
    } catch (Exception e) {
      log.error("{} - error", prefix, e);
    }
  }
}

Stacktrace

java.lang.IllegalStateException: Timeout on blocking read for 10000000000 NANOSECONDS
      at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:127)
      at reactor.core.publisher.Mono.block(Mono.java:1738)
      at andy.Application.executeWithPool(Application.java:69)
      at andy.Application.execute(Application.java:79)

Steps to reproduce?

1. Execute above sample application
2. connection for "direct" is acquired successfully
3. connection for "ValidationDepth.LOCAL" is acquired successfully
4. connection for "ValidationDepth.REMOTE" will always timeout (even with a significantly longer timeout)

Environment

1. Running in a linux image
2. Java openjdk17
3. Cloud SQL Java Socket Factory version 1.15.1 works, 1.15.2 breaks

Additional Details

Not sure if this is 100% an issue with this library, or in the r2dbc-pool code, but we've been using the earlier versions without issue previously, but since the upgradeof this component we are unable to use REMOTE validation, which we've utilised heavily.

[ttosta-google]

@turneand Thank you for reporting this issue!

I am currently investigating it.

[ttosta-google]

@turneand the fix will be part of our next release. Thanks again for reporting it.