johanhaleby / occurrent

Unintrusive Event Sourcing Library for the JVM
https://occurrent.org
120 stars 16 forks source link

Retry automatically in event stores for multi doc tx errors? #85

Closed johanhaleby closed 3 years ago

johanhaleby commented 3 years ago
[my-service-5c7f85bb78-6kpz5] 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 pushnotification-prod-shard-00-02.lp5q7.mongodb.net:27017. The full response is {"errorLabels": ["TransientTransactionError"], "operationTime": {"$timestamp": {"t": 1617689689, "i": 16}}, "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": 1617689689, "i": 16}}, "signature": {"hash": {"$binary": {"base64": "KSZ0lSJOW8/IfWPt4g45DUpPTxk=", "subType": "00"}}, "keyId": 6939854684257517572}}}
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.ProtocolHelper.getCommandFailureException(ProtocolHelper.java:175)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:359)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:280)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:100)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:490)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:71)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:255)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:202)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.connection.DefaultServerConnection.command(DefaultServerConnection.java:118)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation.executeCommand(MixedBulkWriteOperation.java:431)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation.executeBulkWriteBatch(MixedBulkWriteOperation.java:251)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation.access$700(MixedBulkWriteOperation.java:76)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:194)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:185)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.OperationHelper.withReleasableConnection(OperationHelper.java:620)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:185)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.internal.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:76)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:195)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.client.internal.MongoCollectionImpl.executeInsertMany(MongoCollectionImpl.java:498)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.client.internal.MongoCollectionImpl.insertMany(MongoCollectionImpl.java:493)
[my-service-5c7f85bb78-6kpz5]   at com.mongodb.client.internal.MongoCollectionImpl.insertMany(MongoCollectionImpl.java:485)
[my-service-5c7f85bb78-6kpz5]   at jdk.internal.reflect.GeneratedMethodAccessor109.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at java.base/java.lang.reflect.Method.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.data.mongodb.SessionAwareMethodInterceptor.invoke(SessionAwareMethodInterceptor.java:123)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
[my-service-5c7f85bb78-6kpz5]   at com.sun.proxy.$Proxy204.insertMany(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.eventstore.mongodb.spring.blocking.SpringMongoEventStore.insertAll(SpringMongoEventStore.java:261)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.eventstore.mongodb.spring.blocking.SpringMongoEventStore.lambda$write$3(SpringMongoEventStore.java:117)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.transaction.support.TransactionOperations.lambda$executeWithoutResult$0(TransactionOperations.java:68)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.transaction.support.TransactionOperations.executeWithoutResult(TransactionOperations.java:67)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.eventstore.mongodb.spring.blocking.SpringMongoEventStore.write(SpringMongoEventStore.java:107)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.eventstore.api.blocking.ConditionallyWriteToEventStream.write(ConditionallyWriteToEventStream.java:44)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.application.service.blocking.generic.GenericApplicationService.execute(GenericApplicationService.java:67)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.application.service.blocking.ApplicationService.execute(ApplicationService.java:72)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.application.service.blocking.ApplicationServiceExtensionsKt.executeList(ApplicationServiceExtensions.kt:65)
[my-service-5c7f85bb78-6kpz5]   at com.myapp.MyClass
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.retry.internal.RetryExecution.lambda$executeWithRetry$0(RetryExecution.java:72)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.retry.internal.RetryExecution.lambda$executeWithRetry$2(RetryExecution.java:79)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.retry.internal.RetryExecution.lambda$executeWithRetry$1(RetryExecution.java:73)
[my-service-5c7f85bb78-6kpz5]   at org.occurrent.retry.RetryStrategy.execute(RetryStrategy.java:138)
[my-service-5c7f85bb78-6kpz5]   at com.myapp.MyClass
[my-service-5c7f85bb78-6kpz5]   at com.myapp.MyClass
[my-service-5c7f85bb78-6kpz5]   at com.myapp.MyClass
[my-service-5c7f85bb78-6kpz5]   at com.myapp.MyClass
[my-service-5c7f85bb78-6kpz5]   at jdk.internal.reflect.GeneratedMethodAccessor108.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at java.base/java.lang.reflect.Method.invoke(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1060)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:962)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.FrameworkServlet.doPut(FrameworkServlet.java:920)
[my-service-5c7f85bb78-6kpz5]   at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
[my-service-5c7f85bb78-6kpz5]   at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.cloud.sleuth.instrument.web.servlet.TracingFilter.doFilter(TracingFilter.java:89)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.cloud.sleuth.autoconfig.instrument.web.LazyTracingFilter.doFilter(TraceWebServletConfiguration.java:114)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:93)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:103)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:764)
[my-service-5c7f85bb78-6kpz5]   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
[my-service-5c7f85bb78-6kpz5]   at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374)
[my-service-5c7f85bb78-6kpz5]   at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
[my-service-5c7f85bb78-6kpz5]   at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
[my-service-5c7f85bb78-6kpz5]   at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707)
[my-service-5c7f85bb78-6kpz5]   at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
[my-service-5c7f85bb78-6kpz5]   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
[my-service-5c7f85bb78-6kpz5]   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
[my-service-5c7f85bb78-6kpz5]   at java.base/java.lang.Thread.run(Unknown Source)
[my-service-5c7f85bb78-6kpz5]
johanhaleby commented 3 years ago

Maybe treat it as a WriteConditionNotFulfilledException?

johanhaleby commented 3 years ago

https://developpaper.com/solve-the-problem-of-mongodb-transaction-writeconflict/

johanhaleby commented 3 years ago
johanhaleby commented 3 years ago

When we saw this in prod, the issue was that two clients sent the same request twice in parallel. So it makes sense to treat it as a WriteConditionNotFulfilledException.