Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-53464

Transaction with many documents working on MongoDB 4.2 but not 4.4

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Done
    • Affects Version/s: 4.4.0, 4.4.1, 4.4.2
    • Fix Version/s: None
    • Component/s: Write Ops
    • Labels:
      None
    • Sprint:
      Storage - Ra 2021-01-25, Storage - Ra 2021-02-08
    • Case:
    • Story Points:
      3

      Description

      Hello,

      I am trying to upgrade our MongoDB 4.2.1 replica set to 4.4.2. Our Spring Boot 2.4 application with Java driver 4.1.1 uses multi-documents transactions and manipulates lots of documents in the same transaction (batch writting).

      We do not have any issue on MongoDB 4.2 but theses transactions fails on WriteConflict on 4.4.

       

      I add here a Java/Spring simple unit test case which pass on mongo 4.2 but not on mongo 4.4 which do the following :
       

      • init the collection outside the transaction with 20 000 docs (with 2 properties, id and string with 1000 chars)
      • in a transaction, removes all the 20 000 docs and re-insert 20 000 similar docs

      Step to reproduce : 

      • Run the following test on mongo 4.2.1 : it passes 

      @RunWith(SpringRunner.class)
      @ActiveProfiles(value = "test-mongo44")
      @Import(
              {MongoAutoConfiguration.class, MongoDataAutoConfiguration.class}
      )
      @SpringBootTest()
      public class Mongo44Test {
          @Autowired
          private MongoTemplate mongoTemplate;    
          @Autowired
          private MongoTransactionManager mongoTransactionManager;    
       
          @Test
          public void test1() {        
             // init the collection with 20 000 docs with a 1000 chars length string
              Collection<Document> elements = new ArrayList<Document>();
              IntStream.range(0,20000).forEach(i -> {
                  Document doc = new Document();
                  doc.put("id", "site");
                  doc.put("string", RandomStringUtils.random(1000, true, true));
                  elements.add(doc);
              });
              mongoTemplate.insert(elements, "mongo44");        
               TransactionTemplate transactionTemplate = new TransactionTemplate(mongoTransactionManager);
              transactionTemplate.execute(new TransactionCallbackWithoutResult() {           
                 @Override
                  protected void doInTransactionWithoutResult(TransactionStatus status) {
                      // remove all docs in transaction
                      mongoTemplate.remove(Query.query(Criteria.where("id").is("site")), "mongo44");
                      elements.clear();
                      // and re-insert 20 000 docs with a 1000 chars length string in the transaction
                      IntStream.range(0,20000).forEach(i -> {
                          Document doc = new Document();
                          doc.put("id", "site");
                          doc.put("string", RandomStringUtils.random(1000, true, true));
                          elements.add(doc);
                      });
                      mongoTemplate.insert(elements, "mongo44");
                  };
              });    }
      }
      

      • Run the same test on mongo 4.4.2 : it fails on following error

      Could not commit Mongo transaction for session [ClientSessionImpl@6d4a8c85 id = {"id": {"$binary": {"base64": "uCifnjaYRkqu73ku3PC4Tw==", "subType": "04"}}}, causallyConsistent = true, txActive = false, txNumber = 3, error = d != java.lang.Boolean].; 
      nested exception is com.mongodb.MongoCommandException: Command failed with error 112 (WriteConflict): 'WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.' on server localhost:27017. 
      The full response is {"errorLabels": ["TransientTransactionError"], "operationTime": {"$timestamp": {"t": 1608556898, "i": 20000}}, "ok": 0.0, "errmsg": "WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.", "code": 112, "codeName": "WriteConflict", "$clusterTime": {"clusterTime": {"$timestamp": {"t": 1608556900, "i": 70000}}, "signature": {"hash": {"$binary": {"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "00"}}, "keyId": 0}}}org.springframework.transaction.TransactionSystemException: Could not commit Mongo transaction for session [ClientSessionImpl@6d4a8c85 id = {"id": {"$binary": {"base64": "uCifnjaYRkqu73ku3PC4Tw==", "subType": "04"}}}, causallyConsistent = true, txActive = false, txNumber = 3, error = d != java.lang.Boolean].; 
      nested exception is com.mongodb.MongoCommandException: Command failed with error 112 (WriteConflict): 'WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.' on server localhost:27017. 
      The full response is {"errorLabels": ["TransientTransactionError"], "operationTime": {"$timestamp": {"t": 1608556898, "i": 20000}}, "ok": 0.0, "errmsg": "WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.", "code": 112, "codeName": "WriteConflict", "$clusterTime": {"clusterTime": {"$timestamp": {"t": 1608556900, "i": 70000}}, "signature": {"hash": {"$binary": {"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "00"}}, "keyId": 0}}} 
      at org.springframework.data.mongodb.MongoTransactionManager.doCommit(MongoTransactionManager.java:203) 
      at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743) 
      at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711) 
      at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152) 
      at com.myproject.mongo44.Mongo44Test.test1(Mongo44Test.java:54) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 
      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
      at java.base/java.lang.reflect.Method.invoke(Method.java:566) 
      at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) 
      at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) 
      at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) 
      at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) 
      at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74) 
      at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84) 
      at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) 
      at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) 
      at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) 
      at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366) 
      at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97) at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) at org.junit.runners.ParentRunner.run(ParentRunner.java:413) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38) at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:62) at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33) at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94) at com.sun.proxy.$Proxy5.processTestClass(Unknown Source) at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:118) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182) at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164) at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:413) at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64) at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56) at java.base/java.lang.Thread.run(Thread.java:834)Caused by: com.mongodb.MongoCommandException: Command failed with error 112 (WriteConflict): 'WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.' on server localhost:27017. The full response is {"errorLabels": ["TransientTransactionError"], "operationTime": {"$timestamp": {"t": 1608556898, "i": 20000}}, "ok": 0.0, "errmsg": "WriteConflict error: this operation conflicted with another operation. Please retry your operation or multi-document transaction.", "code": 112, "codeName": "WriteConflict", "$clusterTime": {"clusterTime": {"$timestamp": {"t": 1608556900, "i": 70000}}, "signature": {"hash": {"$binary": {"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "00"}}, "keyId": 0}}} at com.mongodb.internal.connection.ProtocolHelper.getCommandFailureException(ProtocolHelper.java:175) at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:302) at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:258) at com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:99) at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:500) at com.mongodb.internal.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:71) at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:224) at com.mongodb.internal.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:202) at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:118) at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:110) at com.mongodb.internal.operation.CommandOperationHelper$13.call(CommandOperationHelper.java:710) at com.mongodb.internal.operation.OperationHelper.withReleasableConnection(OperationHelper.java:500) at com.mongodb.internal.operation.CommandOperationHelper.executeRetryableCommand(CommandOperationHelper.java:703) at com.mongodb.internal.operation.TransactionOperation.execute(TransactionOperation.java:69) at com.mongodb.internal.operation.CommitTransactionOperation.execute(CommitTransactionOperation.java:132) at com.mongodb.internal.operation.CommitTransactionOperation.execute(CommitTransactionOperation.java:53) at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:207) at com.mongodb.client.internal.ClientSessionImpl.commitTransaction(ClientSessionImpl.java:129) at org.springframework.data.mongodb.MongoTransactionManager$MongoTransactionObject.commitTransaction(MongoTransactionManager.java:469) at org.springframework.data.mongodb.MongoTransactionManager.doCommit(MongoTransactionManager.java:236) at org.springframework.data.mongodb.MongoTransactionManager.doCommit(MongoTransactionManager.java:200) ... 60 more
      

      Is there a change in  

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              backlog-server-storage-engines Backlog - Storage Engines Team
              Reporter:
              o.boudet@gmail.com Olivier Boudet
              Participants:
              Votes:
              3 Vote for this issue
              Watchers:
              33 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: