Loading...

XML

Word

Printable

JSON

Type: Question
Resolution: Works as Designed
Priority: Major - P3
Fix Version/s: None
Affects Version/s: None
Component/s: Transaction Management
Labels:
- internal-user

Case:

When using the ClientSession.withTransaction helper the MongoClient's serverSelectionTimeout value is not respected.

This same behavior does not happen if the transaction is manually created using ClientSession.startTransaction() and committed using ClientSession.commitTransaction

# setup
mlaunch init --replicaset --nodes 3 --hostname 192.168.2.13 --bind_ip_all --binarypath $(m bin 5.0.5-ent)

pom.xml

<?xml version="1.0" encoding="UTF-8"?>

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>

  <groupId>com.example</groupId>
  <artifactId>demo</artifactId>
  <version>1.0-SNAPSHOT</version>

  <name>demo</name>
  <!-- FIXME change it to the project's website -->
  <url>http://www.example.com</url>

  <properties>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    <maven.compiler.source>1.8</maven.compiler.source>
    <maven.compiler.target>1.8</maven.compiler.target>
  </properties>

  <dependencies>
    <dependency>
      <groupId>org.mongodb</groupId>
      <artifactId>mongodb-driver-sync</artifactId>
      <version>4.4.0</version>
    </dependency>
  </dependencies>

  <build>
    <pluginManagement>
      <!-- lock down plugins versions to avoid using Maven defaults (may be moved to parent pom) -->
      <plugins>
        <!-- clean lifecycle, see https://maven.apache.org/ref/current/maven-core/lifecycles.html#clean_Lifecycle -->
        <plugin>
          <artifactId>maven-clean-plugin</artifactId>
          <version>3.1.0</version>
        </plugin>
        <!-- default lifecycle, jar packaging: see https://maven.apache.org/ref/current/maven-core/default-bindings.html#Plugin_bindings_for_jar_packaging -->
        <plugin>
          <artifactId>maven-resources-plugin</artifactId>
          <version>3.0.2</version>
        </plugin>
        <plugin>
          <artifactId>maven-compiler-plugin</artifactId>
          <version>3.8.0</version>
        </plugin>
        <plugin>
          <artifactId>maven-surefire-plugin</artifactId>
          <version>2.22.1</version>
        </plugin>
        <plugin>
          <artifactId>maven-jar-plugin</artifactId>
          <version>3.0.2</version>
        </plugin>
        <plugin>
          <artifactId>maven-install-plugin</artifactId>
          <version>2.5.2</version>
        </plugin>
        <plugin>
          <artifactId>maven-deploy-plugin</artifactId>
          <version>2.8.2</version>
        </plugin>
        <!-- site lifecycle, see https://maven.apache.org/ref/current/maven-core/lifecycles.html#site_Lifecycle -->
        <plugin>
          <artifactId>maven-site-plugin</artifactId>
          <version>3.7.1</version>
        </plugin>
        <plugin>
          <artifactId>maven-project-info-reports-plugin</artifactId>
          <version>3.0.0</version>
        </plugin>
      </plugins>
    </pluginManagement>
  </build>
</project>

EmptyServerSelector.java

package com.example;

import java.util.ArrayList;
import java.util.List;
import java.util.logging.Logger;

import com.mongodb.connection.ClusterDescription;
import com.mongodb.connection.ServerDescription;
import com.mongodb.selector.ServerSelector;

public class EmptyServerSelector implements ServerSelector {
  private static Logger LOGGER = null;
  static {
    System.setProperty("java.util.logging.SimpleFormatter.format", "[%1$tF %1$tT] [%4$-7s] %5$s %n");
    LOGGER = Logger.getLogger(EmptyServerSelector.class.getName());
  }

  @Override
  public List<ServerDescription> select(ClusterDescription clusterDescription) {
    LOGGER.info("Returning empty list of server descriptions");
    return new ArrayList<>();
  }
}

ServerSelectionTxnLoopTest.java

package com.example;

import java.util.Arrays;
import java.util.List;
import java.util.concurrent.TimeUnit;

import com.mongodb.*;
import com.mongodb.client.*;
import com.mongodb.client.result.UpdateResult;

import org.bson.Document;
import org.bson.conversions.Bson;

import static com.mongodb.client.model.Updates.inc;
import static com.mongodb.client.model.Filters.*;

public class ServerSelectionTxnLoopTest {
  private static Bson _filter = eq("_id", 1);
  private static Bson _update = inc("items.$.quantity", 2);
  private static MongoCollection<Document> _coll;

  private static void usingManualTransaction(ClientSession session) {
    session.startTransaction(TransactionOptions.builder().writeConcern(WriteConcern.MAJORITY).build());
    _coll.updateOne(session, _filter, _update);
    session.commitTransaction();
  }

  private static void usingWithTransaction(ClientSession session) {
    TransactionBody<UpdateResult> txnUpdateBody = () -> _coll.updateOne(session, _filter, _update);
    session.withTransaction(txnUpdateBody);
  }

  public static void main(final String[] args) {
    List<ServerAddress> hosts = Arrays.asList(
        new ServerAddress("192.168.2.13:27017"),
        new ServerAddress("192.168.2.13:27018"),
        new ServerAddress("192.168.2.13:27019"));

    MongoClient client = MongoClients.create(
        MongoClientSettings.builder()
            .applyToClusterSettings(builder -> builder
                .hosts(hosts)
                .serverSelector(new EmptyServerSelector())
                .serverSelectionTimeout(2, TimeUnit.SECONDS))
            .build());

    System.out.println("MongoClient created with a serverSelectionTimeout of 2 seconds");

    MongoDatabase db = client.getDatabase("test");
    _coll = db.getCollection("foo");

    ClientSession session = client.startSession();
    try {
      // usingManualTransaction(session); // this one will work
      usingWithTransaction(session); // this one will FAIL

    } catch (MongoCommandException | MongoWriteException e) {
      session.abortTransaction();
    } finally {
      session.close();
    }
  }
}

If the above code is run with usingManualTransaction(session) uncommented, the application will exit with a MongoTimeoutException being raised after 2 seconds (as expected)

MongoClient created with a serverSelectionTimeout of 2 seconds
[2022-01-26 14:54:05] [INFO   ] Returning empty list of server descriptions 
... 
[2022-01-26 14:54:07] [INFO   ] Returning empty list of server descriptions 
Exception in thread "main" com.mongodb.MongoTimeoutException: Timed out after 2000 ms while waiting for a server that matches WritableServerSelector. Client view of cluster state is {type=SHARDED, servers=[{address=192.168.2.13:27019, type=SHARD_ROUTER, roundTripTime=34.5 ms, state=CONNECTED}, {address=192.168.2.13:27017, type=SHARD_ROUTER, roundTripTime=32.0 ms, state=CONNECTED}, {address=192.168.2.13:27018, type=SHARD_ROUTER, roundTripTime=34.8 ms, state=CONNECTED}]
        at com.mongodb.internal.connection.BaseCluster.createTimeoutException(BaseCluster.java:414)
        at com.mongodb.internal.connection.BaseCluster.selectServer(BaseCluster.java:122)
        at com.mongodb.internal.connection.AbstractMultiServerCluster.selectServer(AbstractMultiServerCluster.java:50)
        at com.mongodb.internal.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:128)
        at com.mongodb.client.internal.ClientSessionBinding.getPinnedConnectionSource(ClientSessionBinding.java:133) 
        at com.mongodb.client.internal.ClientSessionBinding.getWriteConnectionSource(ClientSessionBinding.java:102)  
        at com.mongodb.internal.operation.OperationHelper.withSuppliedResource(OperationHelper.java:581)
        at com.mongodb.internal.operation.OperationHelper.withSourceAndConnection(OperationHelper.java:562)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.lambda$execute$3(MixedBulkWriteOperation.java:232) 
        at com.mongodb.internal.async.function.RetryingSyncSupplier.get(RetryingSyncSupplier.java:65)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:268)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:84)
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:212)
        at com.mongodb.client.internal.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:1010)  
        at com.mongodb.client.internal.MongoCollectionImpl.executeUpdate(MongoCollectionImpl.java:994)
        at com.mongodb.client.internal.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:591)
        at com.mongodb.client.internal.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:584)
        at com.example.App.usingManualTransaction(App.java:24)
        at com.example.App.main(App.java:54)

If however this is run with the usingWithTransaction(session) call uncommented the application will loop for 2 minutes and then exit, though the MongoTimeoutException that is thrown indicates the configured 2 second value:

MongoClient created with a serverSelectionTimeout of 2 seconds
[2022-01-26 14:07:53] [INFO   ] Returning empty list of server descriptions 
...
[2022-01-26 14:09:54] [INFO   ] Returning empty list of server descriptions
Exception in thread "main" com.mongodb.MongoTimeoutException: Timed out after 2000 ms while waiting for a server that matches WritableServerSelector. Client view of cluster state is {type=SHARDED, servers=[{address=192.168.2.13:27019, type=SHARD_ROUTER, roundTripTime=7.7 ms, state=CONNECTED}, {address=192.168.2.13:27017, type=SHARD_ROUTER, roundTripTime=7.7 ms, state=CONNECTED}, {address=192.168.2.13:27018, type=SHARD_ROUTER, roundTripTime=7.6 ms, state=CONNECTED}]
        at com.mongodb.internal.connection.BaseCluster.createTimeoutException(BaseCluster.java:414)
        at com.mongodb.internal.connection.BaseCluster.selectServer(BaseCluster.java:122)
        at com.mongodb.internal.connection.AbstractMultiServerCluster.selectServer(AbstractMultiServerCluster.java:50)
        at com.mongodb.internal.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:128)
        at com.mongodb.client.internal.ClientSessionBinding.getPinnedConnectionSource(ClientSessionBinding.java:133) 
        at com.mongodb.client.internal.ClientSessionBinding.getWriteConnectionSource(ClientSessionBinding.java:102)  
        at com.mongodb.internal.operation.OperationHelper.withSuppliedResource(OperationHelper.java:581)
        at com.mongodb.internal.operation.OperationHelper.withSourceAndConnection(OperationHelper.java:562)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.lambda$execute$3(MixedBulkWriteOperation.java:232) 
        at com.mongodb.internal.async.function.RetryingSyncSupplier.get(RetryingSyncSupplier.java:65)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:268)
        at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:84)
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:212)
        at com.mongodb.client.internal.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:1010)  
        at com.mongodb.client.internal.MongoCollectionImpl.executeUpdate(MongoCollectionImpl.java:994)
        at com.mongodb.client.internal.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:591)
        at com.mongodb.client.internal.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:584)
        at com.example.App.lambda$0(App.java:29)
        at com.mongodb.client.internal.ClientSessionImpl.withTransaction(ClientSessionImpl.java:211)
        at com.mongodb.client.internal.ClientSessionImpl.withTransaction(ClientSessionImpl.java:199)
        at com.example.App.usingWithTransaction(App.java:30)
        at com.example.App.main(App.java:55)

is related to

DRIVERS-2185 withTransaction should not retry after server selection timeout errors

Backlog

Assignee:: Jeffrey Yemin

Reporter:: Alex Bevilacqua

Votes:: 0 Vote for this issue

Watchers:: 3 Start watching this issue

Created:: Jan 26 2022 08:42:45 PM UTC

Updated:: Oct 27 2023 01:20:54 PM UTC

Resolved:: Jan 26 2022 10:46:31 PM UTC

Details

Description

Attachments

Issue Links

Activity

People

Dates