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.

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

With simple performance load get: java.lang.IllegalStateException: No MssqlRowMetadata #160

Open
ravredd opened this issue Jun 29, 2020 · 12 comments
Labels
status: waiting-for-feedback We need additional information before we can continue type: bug Something isn't working

Comments

@ravredd
Copy link

ravredd commented Jun 29, 2020

Bug Report

Versions

  • Driver: com.microsoft.sqlserver:mssql-jdbc
  • Database: Azure sql server
  • Java: 1.8 - Hoxton.SR3
  • OS: Cloud deployment - docker base openjdk:8-jdk-alpine

Current Behavior

Essentially copied https://docs.microsoft.com/en-us/azure/developer/java/spring-framework/configure-spring-data-r2dbc-with-azure-sql-server

Changed from TODOs to Mandates for my purpose. There is only a post and a get controller as the todo example. Only difference is the word todo to mandate

This works on a very simple load. So it starts up and works on single user using postman. However when I put it under a simulated load of 25 concurrent users it immediately throws an exception for approx 40% of all requests : java.lang.IllegalStateException: No MssqlRowMetadata available

See stack trace below. This happens almost immediately when tests start using jmeter

Stack trace
2020-06-29T15:20:36.154826427Z 2020-06-29 15:20:36.110 ERROR 1 --- [or-http-epoll-2] a.w.r.e.AbstractErrorWebExceptionHandler : [ef6b74c6-763]  500 Server Error for HTTP GET "/mandates"
2020-06-29T15:20:36.154862326Z
2020-06-29T15:20:36.154867426Z java.lang.IllegalStateException: No MssqlRowMetadata available
2020-06-29T15:20:36.154871126Z 	at io.r2dbc.mssql.MssqlResult.lambda$map$1(MssqlResult.java:167) ~[r2dbc-mssql-0.8.3.RELEASE.jar:0.8.3.RELEASE]
2020-06-29T15:20:36.154875026Z 	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
2020-06-29T15:20:36.154878426Z Error has been observed at the following site(s):
2020-06-29T15:20:36.154881926Z 	|_ checkpoint ⇢ Handler com.sams.merch.itemrestriction.mandateservice.web.MandateController#getMandates() [DispatcherHandler]
2020-06-29T15:20:36.154885926Z 	|_ checkpoint ⇢ HTTP GET "/mandates" [ExceptionHandlingWebHandler]
2020-06-29T15:20:36.154896926Z Stack trace:
2020-06-29T15:20:36.154900426Z 		at io.r2dbc.mssql.MssqlResult.lambda$map$1(MssqlResult.java:167) ~[r2dbc-mssql-0.8.3.RELEASE.jar:0.8.3.RELEASE]
2020-06-29T15:20:36.154903826Z 		at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:163) [reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154907326Z 		at reactor.core.publisher.FluxWindowPredicate$WindowFlux.drainRegular(FluxWindowPredicate.java:650) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154910726Z 		at reactor.core.publisher.FluxWindowPredicate$WindowFlux.drain(FluxWindowPredicate.java:728) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154914026Z 		at reactor.core.publisher.FluxWindowPredicate$WindowFlux.onNext(FluxWindowPredicate.java:770) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154917826Z 		at reactor.core.publisher.FluxWindowPredicate$WindowPredicateMain.onNext(FluxWindowPredicate.java:249) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154921326Z 		at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onNext(FluxContextStart.java:96) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154924726Z 		at io.r2dbc.mssql.util.FluxDiscardOnCancel$FluxDiscardOnCancelSubscriber.onNext(FluxDiscardOnCancel.java:88) ~[r2dbc-mssql-0.8.3.RELEASE.jar:0.8.3.RELEASE]
2020-06-29T15:20:36.154928226Z 		at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:192) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154932526Z 		at reactor.core.publisher.FluxFilter$FilterSubscriber.onNext(FluxFilter.java:107) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154935926Z 		at reactor.core.publisher.FluxHandle$HandleConditionalSubscriber.onNext(FluxHandle.java:319) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154939326Z 		at reactor.core.publisher.EmitterProcessor.drain(EmitterProcessor.java:426) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154942826Z 		at reactor.core.publisher.EmitterProcessor.subscribe(EmitterProcessor.java:179) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154946126Z 		at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154949526Z 		at io.r2dbc.mssql.util.FluxDiscardOnCancel.subscribe(FluxDiscardOnCancel.java:51) ~[r2dbc-mssql-0.8.3.RELEASE.jar:0.8.3.RELEASE]
2020-06-29T15:20:36.154952926Z 		at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154956426Z 		at reactor.core.publisher.FluxDefer.subscribe(FluxDefer.java:54) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154959826Z 		at reactor.core.publisher.FluxDefer.subscribe(FluxDefer.java:54) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154963126Z 		at reactor.core.publisher.Flux.subscribe(Flux.java:8325) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154969126Z 		at reactor.core.publisher.FluxUsingWhen$ResourceSubscriber.onNext(FluxUsingWhen.java:201) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154972626Z 		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154976026Z 		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154979426Z 		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154982825Z 		at reactor.core.publisher.FluxRetry$RetrySubscriber.onNext(FluxRetry.java:80) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154986225Z 		at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154989925Z 		at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1782) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154993325Z 		at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:241) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.154996725Z 		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155000225Z 		at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1782) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155003625Z 		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:147) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155007025Z 		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:56) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155010425Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155013825Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:150) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155017225Z 		at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:192) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155020625Z 		at reactor.pool.AbstractPool$Borrower.deliver(AbstractPool.java:400) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155024025Z 		at reactor.pool.SimplePool.lambda$drainLoop$12(SimplePool.java:267) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155027425Z 		at reactor.core.scheduler.ImmediateScheduler.schedule(ImmediateScheduler.java:47) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155030825Z 		at reactor.pool.SimplePool.drainLoop(SimplePool.java:267) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155036025Z 		at reactor.pool.SimplePool.drain(SimplePool.java:187) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155039525Z 		at reactor.pool.SimplePool.doAcquire(SimplePool.java:136) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155042925Z 		at reactor.pool.AbstractPool$Borrower.request(AbstractPool.java:363) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155046525Z 		at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:130) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155050025Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:103) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155053325Z 		at reactor.core.publisher.FluxPeek$PeekSubscriber.onSubscribe(FluxPeek.java:163) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155056725Z 		at reactor.pool.SimplePool$QueueBorrowerMono.subscribe(SimplePool.java:351) ~[reactor-pool-0.1.4.RELEASE.jar:0.1.4.RELEASE]
2020-06-29T15:20:36.155060125Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155063425Z 		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155066725Z 		at reactor.core.publisher.FluxRetry$RetrySubscriber.resubscribe(FluxRetry.java:110) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155070125Z 		at reactor.core.publisher.MonoRetry.subscribeOrReturn(MonoRetry.java:49) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155073525Z 		at reactor.core.publisher.Mono.subscribe(Mono.java:4204) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155076925Z 		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:97) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155080325Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onError(MonoFlatMap.java:165) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155083725Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155087125Z 		at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:185) [reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155090525Z 		at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2344) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155093825Z 		at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.request(FluxHandleFuseable.java:243) [reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155097425Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:162) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155100925Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:103) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155106625Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:90) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155110025Z 		at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onSubscribe(FluxHandleFuseable.java:148) [reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155113425Z 		at reactor.core.publisher.MonoCurrentContext.subscribe(MonoCurrentContext.java:35) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155116825Z 		at reactor.core.publisher.Mono.subscribe(Mono.java:4219) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155120225Z 		at reactor.core.publisher.FluxUsingWhen.subscribe(FluxUsingWhen.java:103) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155123525Z 		at reactor.core.publisher.FluxFromMonoOperator.subscribe(FluxFromMonoOperator.java:83) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155126925Z 		at org.springframework.http.server.reactive.ChannelSendOperator.subscribe(ChannelSendOperator.java:77) ~[spring-web-5.2.7.RELEASE.jar:5.2.7.RELEASE]
2020-06-29T15:20:36.155130225Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155133625Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:150) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155137024Z 		at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1782) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155140324Z 		at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:241) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155143824Z 		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155147124Z 		at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155150724Z 		at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155154124Z 		at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1782) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155157524Z 		at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onNext(MonoIgnoreThen.java:296) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155160824Z 		at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2344) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155164124Z 		at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onSubscribe(MonoIgnoreThen.java:285) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155169624Z 		at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:191) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155173124Z 		at reactor.core.publisher.MonoFlatMap.subscribeOrReturn(MonoFlatMap.java:53) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155176524Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:57) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155179824Z 		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155183224Z 		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:153) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155186624Z 		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:56) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155189924Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155193324Z 		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:150) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155196724Z 		at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:67) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155200124Z 		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155203724Z 		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.innerNext(FluxConcatMap.java:274) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155207024Z 		at reactor.core.publisher.FluxConcatMap$ConcatMapInner.onNext(FluxConcatMap.java:851) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155210424Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155213724Z 		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onNext(MonoPeekTerminal.java:173) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155217224Z 		at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2344) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155220524Z 		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.request(MonoPeekTerminal.java:132) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155223924Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:162) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155227324Z 		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2152) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155230724Z 		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onSubscribe(Operators.java:2026) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155235924Z 		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:90) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155239324Z 		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onSubscribe(MonoPeekTerminal.java:145) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155242724Z 		at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:54) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155246124Z 		at reactor.core.publisher.Mono.subscribe(Mono.java:4219) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155249524Z 		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.drain(FluxConcatMap.java:441) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155252824Z 		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.onSubscribe(FluxConcatMap.java:211) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155256524Z 		at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:161) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155259924Z 		at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:86) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155263324Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155266624Z 		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155270024Z 		at reactor.core.publisher.Mono.subscribe(Mono.java:4219) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155273324Z 		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:172) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155276624Z 		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:56) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155280024Z 		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.3.6.RELEASE.jar:3.3.6.RELEASE]
2020-06-29T15:20:36.155283324Z 		at reactor.netty.http.server.HttpServerHandle.onStateChange(HttpServerHandle.java:64) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155286624Z 		at reactor.netty.ReactorNetty$CompositeConnectionObserver.onStateChange(ReactorNetty.java:514) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155290023Z 		at reactor.netty.tcp.TcpServerBind$ChildObserver.onStateChange(TcpServerBind.java:267) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155293423Z 		at reactor.netty.http.server.HttpServerOperations.onInboundNext(HttpServerOperations.java:465) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155296823Z 		at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:96) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155300223Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155305123Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155308823Z 		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155312223Z 		at reactor.netty.http.server.HttpTrafficHandler.channelRead(HttpTrafficHandler.java:170) ~[reactor-netty-0.9.8.RELEASE.jar:0.9.8.RELEASE]
2020-06-29T15:20:36.155315523Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155318923Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155322323Z 		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155325723Z 		at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155329223Z 		at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324) ~[netty-codec-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155332523Z 		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296) ~[netty-codec-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155335923Z 		at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155339323Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155342623Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155346023Z 		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155349423Z 		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155353123Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155356523Z 		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155359923Z 		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155365723Z 		at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792) ~[netty-transport-native-epoll-4.1.50.Final-linux-x86_64.jar:4.1.50.Final]
2020-06-29T15:20:36.155369223Z 		at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe$1.run(AbstractEpollChannel.java:387) ~[netty-transport-native-epoll-4.1.50.Final-linux-x86_64.jar:4.1.50.Final]
2020-06-29T15:20:36.155380323Z 		at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[netty-common-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155383823Z 		at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) ~[netty-common-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155387123Z 		at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) ~[netty-transport-native-epoll-4.1.50.Final-linux-x86_64.jar:4.1.50.Final]
2020-06-29T15:20:36.155390523Z 		at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155393923Z 		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155397223Z 		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.50.Final.jar:4.1.50.Final]
2020-06-29T15:20:36.155400623Z 		at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_212]

Table schema

id VARCHAR(255) PRIMARY KEY,
name VARCHAR(255) NULL,
description VARCHAR(255) NULL,
internal BIT ,
start_date VARCHAR(255) NULL,
end_date VARCHAR(255) NULL,
state VARCHAR(255) NULL
Input Code On post mandateRepository.save(mandate); -- ReactiveCrudRepository

On get
mandateRepository.findAll();

-- your SQL here;
Using base ReactiveCrudRepository

Steps to reproduce

You can use the todo example, deploy as docker container to Azure app service, connected to azure sql server db. Run JMeter with 25 concurrent users, 10 cycles, 1 post and 1 get on each. Error will begin showing.

Java spring boot as reference TODO example

Input Code
// your code here;

Expected behavior/code

No exception nor failed requests.

Possible Solution

Additional context

@mp911de mp911de added the type: bug Something isn't working label Jul 3, 2020
@mp911de
Copy link
Member

mp911de commented Jul 7, 2020

Thanks for the report. I wasn't able to reproduce the mentioned issue, neither locally nor using Azure SQL Servers.

@mp911de mp911de added the status: waiting-for-feedback We need additional information before we can continue label Jul 7, 2020
@ravredd
Copy link
Author

ravredd commented Jul 7, 2020

Have been able to reproduce with more simple service with JMeter. So will push example to github shortly with how to reproduce.

@ravredd
Copy link
Author

ravredd commented Jul 7, 2020

Ok posted my example code here. https://github.com/ravredd/test-spring-r2dbc-mssql The README has instructions. It is a very simple spring app with not a lot to it. two columns in a db. I cannot get this to fail when running service locally. Only when deployed to Azure. I even tried given my container locally the minimum cpu, memory etc. And tried different max pooling settings. No change in result. In Azure it fails but locally passes. Uses Azure App Service on S1-1 plan. Nothing special on the Azure SQL Server side.

@mp911de
Copy link
Member

mp911de commented Jul 13, 2020

I tried to reproduce the issue with no luck. Can you

  1. Use the most recent snapshot (0.8.4.BUILD-SNAPSHOT)
  2. If the issue persists for you, post a debug log (start the app with io.r2dbc.mssql set to DEBUG)?

@levi85
Copy link

levi85 commented Apr 15, 2021

My team also encountered this strange issue as well. Our project setup is on SpringBoot 2.3.4, WebFlux, r2dbc-mssql. Our database instance is running on MSSQL 2017

After deploying our app to our on-premise kubernetes cluster we started experiencing this issue of the database result getting mixed up. This never happen on our local machine.

To share, we proceeded to upgrade our SpringBoot to the latest stable 2.4.4, unfortunately the issue still persist. In the spirit to achieve not blocking IO, we are switching to reactive mongo which seems to be a more mature in this reactive community, hope that this issue with MS SQL driver can be resolved in the future.

@ravredd
Copy link
Author

ravredd commented Apr 15, 2021 via email

@mp911de
Copy link
Member

mp911de commented Apr 15, 2021

Part of the problem is that we're not able to reproduce the issue. Without that, it's next to impossible to diagnose the problem.

@anderius
Copy link

It happened to our team as well, sporadically on our cheap build server in Azure (Standard_F4s_v2). We changed to a faster machine (Standard_D8s_v3), and it has not happened since.

@SantoshDeepak1

This comment has been minimized.

@spachip

This comment has been minimized.

@mp911de
Copy link
Member

mp911de commented Jul 7, 2021

Please refrain from posting further stack traces without providing a reproducer. Thank you.

@Szczepaniak-M
Copy link

I had the same problem running my Application (Spring Boot 2.6.2, r2dbc-mssql 0.8.7.RELEASE, Java 17). The problem occurred only on Azure App Service (B1). On the local environment, everything was perfect. But I have added to url parameter maxLifeTime=PT0.3S and problem is gone.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: waiting-for-feedback We need additional information before we can continue type: bug Something isn't working
Projects
None yet
Development

No branches or pull requests

7 participants