Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

MongoExceptionTranslator hides WriteConflicts [DATAMONGO-2291] #3148

Open
spring-projects-issues opened this issue May 31, 2019 · 9 comments · May be fixed by #605
Open

MongoExceptionTranslator hides WriteConflicts [DATAMONGO-2291] #3148

spring-projects-issues opened this issue May 31, 2019 · 9 comments · May be fixed by #605
Assignees
@christophstrobl
Labels
in: core Issues in core support type: bug A general bug

Comments

@spring-projects-issues
Copy link

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
Copy link
Author

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 = ....

@spring-projects-issues spring-projects-issues added type: bug A general bug in: core Issues in core support labels Dec 30, 2020
@tinesoft
Copy link

Any update on that issue?

@sanmibuh
Copy link

Any updates?

@Kevincifuentes
Copy link

We have the same issue here! Any news?

@mp911de mp911de added the status: waiting-for-triage An issue we've not yet triaged label May 17, 2021
@schauder schauder removed the status: waiting-for-triage An issue we've not yet triaged label May 17, 2021
@christophstrobl
Copy link
Member

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.

@christophstrobl christophstrobl linked a pull request May 25, 2021 that will close this issue
DATAMONGO-2073 - Evaluate exception label when translating MongoException. #605
Open
@MarcBridner
Copy link

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

@kliarist
Copy link

so what is the status of this please?

@gklijs
Copy link

gklijs commented Oct 12, 2022

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
Copy link

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@christophstrobl christophstrobl

Labels
in: core Issues in core support type: bug A general bug
Projects
None yet
Milestone
No milestone