MongoExceptionTranslator hides WriteConflicts [DATAMONGO-2291]

[spring-projects-issues]

Christian opened DATAMONGO-2291 and commented

With transactions enabled, it can happen, that the mongodb throws a WriteConflict-Exception. This kind of exception can happen, if two transactions modify the same document in parallel.

In this case, the application could retry the transacion and would probably succeed.

Sadly spring-data-mongodb hides the transaction by wrapping it into an UncategorizedMongoDBException. Further down in the stack it first created a MongoCommandException, where the errorcode was at east still present.

Solutions:

Wrap the exception instead into TransientDataAccessException or into a OptimisticLockingException or keep the errorCode in the UncategorizedMongoDBException.

Here the stacktrace:

org.springframework.data.mongodb.UncategorizedMongoDbException: Command failed with error 112 (WriteConflict): 'WriteConflict' on server kraken-som-develop-shard-00-00-dbwuy.mongodb.net:27017. The full response is \{ \"errorLabels\" : [\"TransientTransactionError\"], \"operationTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"ok\" : 0.0, \"errmsg\" : \"WriteConflict\", \"code\" : 112, \"codeName\" : \"WriteConflict\", \"$clusterTime\" : \{ \"clusterTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"signature\" : \{ \"hash\" : { \"$binary\" : \"Kg7qw+L3BjCFY45C2eP67iboOW0=\", \"$type\" : \"00\" }, \"keyId\" : \{ \"$numberLong\" : \"6662760578483748865\" } } } }; nested exception is com.mongodb.MongoCommandException: Command failed with error 112 (WriteConflict): 'WriteConflict' on server kraken-som-develop-shard-00-00-dbwuy.mongodb.net:27017. The full response is \{ \"errorLabels\" : [\"TransientTransactionError\"], \"operationTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"ok\" : 0.0, \"errmsg\" : \"WriteConflict\", \"code\" : 112, \"codeName\" : \"WriteConflict\", \"$clusterTime\" : \{ \"clusterTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"signature\" : \{ \"hash\" : { \"$binary\" : \"Kg7qw+L3BjCFY45C2eP67iboOW0=\", \"$type\" : \"00\" }, \"keyId\" : \{ \"$numberLong\" : \"6662760578483748865\" } } } }
\tat org.springframework.data.mongodb.core.MongoExceptionTranslator.translateExceptionIfPossible(MongoExceptionTranslator.java:138)
\tat org.springframework.data.mongodb.core.MongoTemplate.potentiallyConvertRuntimeException(MongoTemplate.java:2781)
\tat org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:547)
\tat org.springframework.data.mongodb.core.MongoTemplate.doUpdate(MongoTemplate.java:1578)
\tat org.springframework.data.mongodb.core.MongoTemplate.doSaveVersioned(MongoTemplate.java:1398)
\tat org.springframework.data.mongodb.core.MongoTemplate.save(MongoTemplate.java:1371)
\tat org.springframework.data.mongodb.repository.support.SimpleMongoRepository.save(SimpleMongoRepository.java:84)
\tat jdk.internal.reflect.GeneratedMethodAccessor250.invoke(Unknown Source)
\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
\tat java.base/java.lang.reflect.Method.invoke(Method.java:566)
\tat org.springframework.data.repository.core.support.RepositoryComposition$RepositoryFragments.invoke(RepositoryComposition.java:359)
\tat org.springframework.data.repository.core.support.RepositoryComposition.invoke(RepositoryComposition.java:200)
\tat org.springframework.data.repository.core.support.RepositoryFactorySupport$ImplementationMethodExecutionInterceptor.invoke(RepositoryFactorySupport.java:644)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:608)
\tat org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.lambda$invoke$3(RepositoryFactorySupport.java:595)
\tat org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:595)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:59)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
\tat com.sun.proxy.$Proxy146.save(Unknown Source)
\tat de.otto.order.som.services.salesorder.SalesOrderService.save(SalesOrderService.java:141)
\tat de.otto.order.som.event.processing.ShipmentSentByPartnerEventHandler.handleItemsBySalesOrderId(ShipmentSentByPartnerEventHandler.java:86)
\tat de.otto.order.som.event.processing.ShipmentSentByPartnerEventHandler.handleEvent(ShipmentSentByPartnerEventHandler.java:58)
 
\tat de.otto.order.som.common.event.incoming.consumers.AbstractQueueConsumer.lambda$consume$0(AbstractQueueConsumer.java:56)
\tat io.micrometer.core.instrument.AbstractTimer.record(AbstractTimer.java:149)
\tat de.otto.order.som.common.event.incoming.consumers.AbstractQueueConsumer.lambda$consume$1(AbstractQueueConsumer.java:56)
\tat java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
\tat java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1654)
\tat java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
\tat java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
\tat java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913)
\tat java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
\tat java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578)
\tat de.otto.order.som.common.event.incoming.consumers.AbstractQueueConsumer.consume(AbstractQueueConsumer.java:59)
\tat de.otto.order.som.common.event.incoming.consumers.AbstractQueueConsumer.consumeAndDelete(AbstractQueueConsumer.java:42)
\tat de.otto.order.som.common.event.incoming.consumers.tnt.SomTntIncomingMessageConsumer.processMessages(SomTntIncomingMessageConsumer.java:26)
\tat jdk.internal.reflect.GeneratedMethodAccessor62.invoke(Unknown Source)
\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
\tat java.base/java.lang.reflect.Method.invoke(Method.java:566)
\tat org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
\tat org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
\tat java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
\tat java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
\tat java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
\tat java.base/java.lang.Thread.run(Thread.java:834)
Caused by: com.mongodb.MongoCommandException: Command failed with error 112 (WriteConflict): 'WriteConflict' on server kraken-som-develop-shard-00-00-dbwuy.mongodb.net:27017. The full response is \{ \"errorLabels\" : [\"TransientTransactionError\"], \"operationTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"ok\" : 0.0, \"errmsg\" : \"WriteConflict\", \"code\" : 112, \"codeName\" : \"WriteConflict\", \"$clusterTime\" : \{ \"clusterTime\" : { \"$timestamp\" : { \"t\" : 1559261060, \"i\" : 126 } }, \"signature\" : \{ \"hash\" : { \"$binary\" : \"Kg7qw+L3BjCFY45C2eP67iboOW0=\", \"$type\" : \"00\" }, \"keyId\" : \{ \"$numberLong\" : \"6662760578483748865\" } } } }
\tat com.mongodb.internal.connection.ProtocolHelper.getCommandFailureException(ProtocolHelper.java:179)
\tat com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:293)
\tat com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:255)
\tat com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:99)
\tat com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:444)
\tat com.mongodb.internal.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:72)
\tat com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:200)
\tat com.mongodb.internal.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:269)
\tat com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:131)
\tat com.mongodb.operation.MixedBulkWriteOperation.executeCommand(MixedBulkWriteOperation.java:418)
\tat com.mongodb.operation.MixedBulkWriteOperation.executeBulkWriteBatch(MixedBulkWriteOperation.java:256)
\tat com.mongodb.operation.MixedBulkWriteOperation.access$700(MixedBulkWriteOperation.java:67)
\tat com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:200)
\tat com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:191)
\tat com.mongodb.operation.OperationHelper.withReleasableConnection(OperationHelper.java:424)
\tat com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:191)
\tat com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:67)
\tat com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:193)
\tat com.mongodb.client.internal.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:960)
\tat com.mongodb.client.internal.MongoCollectionImpl.executeReplaceOne(MongoCollectionImpl.java:602)
\tat com.mongodb.client.internal.MongoCollectionImpl.replaceOne(MongoCollectionImpl.java:597)
\tat jdk.internal.reflect.GeneratedMethodAccessor251.invoke(Unknown Source)
\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
\tat java.base/java.lang.reflect.Method.invoke(Method.java:566)
\tat org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282)
\tat org.springframework.data.mongodb.SessionAwareMethodInterceptor.invoke(SessionAwareMethodInterceptor.java:123)
\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
\tat org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
\tat com.sun.proxy.$Proxy197.replaceOne(Unknown Source)
\tat org.springframework.data.mongodb.core.MongoTemplate$8.doInCollection(MongoTemplate.java:1620)
\tat org.springframework.data.mongodb.core.MongoTemplate$8.doInCollection(MongoTemplate.java:1578)
\tat org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:545)
\t... 55 common frames omitted
","throwable_class":"UncategorizedMongoDbException","throwable_root_cause_class":"MongoCommandException","msg":"Exception during event processing"

---

Affects: 2.1.8 (Lovelace SR8)

Issue Links:

• DATAMONGO-2073 Check MongoException error labels for recoverable transaction errors

1 votes, 3 watchers

[spring-projects-issues]

Christoph Strobl commented

A workaround, until DATAMONGO-2073 is resolved, could be Spring Retry and its annotation based approach that allows to evaluate a SpEL expression on failure via @Retryable(exceptionExpression = ....

[tinesoft]

Any update on that issue?

[sanmibuh]

Any updates?

[Kevincifuentes]

We have the same issue here! Any news?

[christophstrobl]

Rebased and modified existing PR #605 that introduces TransientMongoDbException and evaluates the MongoDB TransientTransactionError label. The PR also fixes an issue where WriteConflict was resolved to UncategorizedMongoDbException instead of the expected DataIntegrityViolationException.

[MarcBridner]

Are there any plans to merge this PR? I just hit the same issue and the PR looks like it'd fix it.

[kliarist]

so what is the status of this please?

[gklijs]

Also just spend some time finding out the problem. In my case, the collection didn't exist yet, and creating it multiple times failed. Would be nice to have more in the logs.

[voodemsanthosh]

I am also standing on same issue, any updates on this issue fix