search

vlingo / xoom-wire

The VLINGO XOOM platform SDK wire protocol messaging implementations, such as with full-duplex TCP and UDP multicast, and RSocket, using VLINGO XOOM ACTORS.
Mozilla Public License 2.0
13 stars 11 forks source link

Flaky test RSocketServerChannelActorTest #35

Closed pflueras closed 4 years ago

pflueras commented 4 years ago 
[INFO] Running io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActorTest
17:13:23.989 [pool-11-thread-3] INFO  io.vlingo.actors.Logger - RSocket inbound channel OP at port 37372 is closed
17:13:23.998 [pool-11-thread-2] INFO  i.v.w.f.o.r.RSocketOutboundChannel - RSocket outbound channel for Address[Host[localhost],37371,OP] is closed
17:13:24.002 [pool-11-thread-1] INFO  i.v.w.f.o.r.RSocketOutboundChannel - RSocket outbound channel for Address[Host[localhost],37371,OP] is closed
17:13:24.019 [pool-20-thread-2] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel opened at port 0
17:13:24.104 [main] INFO  io.vlingo.actors.Logger - RSocket client channel opened for address Address[Host[127.0.0.1],0,NONE]
17:13:24.143 [pool-20-thread-1] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel closed
17:13:24.158 [main] ERROR io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] received unrecoverable error
java.nio.channels.ClosedChannelException: null
17:13:24.162 [pool-20-thread-1] ERROR io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - Unexpected error in server channel
java.nio.channels.ClosedChannelException: null
17:13:24.166 [main] INFO  io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] is closed
17:13:25.259 [pool-20-thread-3] DEBUG io.vlingo.actors.Logger - io.vlingo.actors.PrivateRootActor - io.vlingo.actors.DeadLettersActor - DeadLetter[Actor[type=Slf4jLoggerActor address=Address[id=11, name=(none)]].close()]
17:13:25.269 [pool-23-thread-2] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel opened at port 0
17:13:25.276 [main] INFO  io.vlingo.actors.Logger - RSocket client channel opened for address Address[Host[127.0.0.1],0,NONE]
17:13:25.320 [pool-23-thread-2] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel closed
17:13:25.322 [main] ERROR io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] received unrecoverable error
java.nio.channels.ClosedChannelException: null
17:13:25.325 [pool-23-thread-2] ERROR io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - Unexpected error in server channel
java.nio.channels.ClosedChannelException: null
17:13:25.325 [main] INFO  io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] is closed
17:13:26.417 [pool-23-thread-3] DEBUG io.vlingo.actors.Logger - io.vlingo.actors.PrivateRootActor - io.vlingo.actors.DeadLettersActor - DeadLetter[Actor[type=Slf4jLoggerActor address=Address[id=11, name=(none)]].close()]
17:13:26.429 [pool-25-thread-1] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel opened at port 0
17:13:26.433 [main] INFO  io.vlingo.actors.Logger - RSocket client channel opened for address Address[Host[127.0.0.1],0,NONE]
17:13:26.737 [main] ERROR io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] received unrecoverable error
java.nio.channels.ClosedChannelException: null
17:13:26.737 [main] INFO  io.vlingo.actors.Logger - RSocket client channel for address Address[Host[127.0.0.1],0,NONE] is closed
17:13:26.738 [pool-25-thread-1] ERROR io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - Unexpected error in server channel
java.nio.channels.ClosedChannelException: null
17:13:26.738 [pool-25-thread-1] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel closed
17:13:27.829 [pool-25-thread-2] DEBUG io.vlingo.actors.Logger - io.vlingo.actors.PrivateRootActor - io.vlingo.actors.DeadLettersActor - DeadLetter[Actor[type=Slf4jLoggerActor address=Address[id=11, name=(none)]].close()]
17:13:27.837 [pool-27-thread-1] INFO  io.vlingo.actors.Logger - io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActor - RSocket server channel opened at port 0
17:13:27.841 [main] INFO  io.vlingo.actors.Logger - RSocket client channel opened for address Address[Host[127.0.0.1],0,NONE]
17:13:27.858 [main] ERROR io.vlingo.actors.Logger - Unexpected error reading incoming payload
java.lang.NullPointerException: null
    at io.vlingo.wire.fdx.bidirectional.TestResponseChannelConsumer.consume(TestResponseChannelConsumer.java:48) ~[test-classes/:na]
    at io.vlingo.wire.fdx.bidirectional.rsocket.RSocketClientChannel$ChannelResponseHandler.handle(RSocketClientChannel.java:150) [classes/:na]
    at io.vlingo.wire.fdx.bidirectional.rsocket.RSocketClientChannel$ChannelResponseHandler.access$100(RSocketClientChannel.java:135) [classes/:na]
    at io.vlingo.wire.fdx.bidirectional.rsocket.RSocketClientChannel.lambda$prepareChannel$3(RSocketClientChannel.java:114) [classes/:na]
    at reactor.core.publisher.LambdaSubscriber.onNext(LambdaSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.SerializedSubscriber.onNext(SerializedSubscriber.java:89) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.onNext(FluxRetryWhen.java:162) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onNext(FluxDoFinally.java:123) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:203) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.UnicastProcessor.drainRegular(UnicastProcessor.java:240) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.UnicastProcessor.drain(UnicastProcessor.java:312) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.UnicastProcessor.onNext(UnicastProcessor.java:386) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.RSocketRequester.handleFrame(RSocketRequester.java:494) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketRequester.handleIncomingFrames(RSocketRequester.java:441) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.LambdaSubscriber.onNext(LambdaSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:242) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.drainRegular(FluxGroupBy.java:554) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.drain(FluxGroupBy.java:630) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.onNext(FluxGroupBy.java:670) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$GroupByMain.onNext(FluxGroupBy.java:205) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.UnboundedProcessor.drainRegular(UnboundedProcessor.java:118) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.drain(UnboundedProcessor.java:188) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.onNext(UnboundedProcessor.java:276) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:189) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.UnboundedProcessor.drainRegular(UnboundedProcessor.java:118) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.drain(UnboundedProcessor.java:188) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.onNext(UnboundedProcessor.java:276) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketResponder$3.hookOnNext(RSocketResponder.java:461) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketResponder$3.hookOnNext(RSocketResponder.java:447) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.BaseSubscriber.onNext(BaseSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.RateLimitableRequestPublisher$InnerOperator.onNext(RateLimitableRequestPublisher.java:173) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.UnicastProcessor.drainRegular(UnicastProcessor.java:240) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.UnicastProcessor.drain(UnicastProcessor.java:312) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.UnicastProcessor.subscribe(UnicastProcessor.java:427) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.Flux.subscribe(Flux.java:8264) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.RateLimitableRequestPublisher.subscribe(RateLimitableRequestPublisher.java:74) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketResponder.handleStream(RSocketResponder.java:446) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketResponder.handleChannel(RSocketResponder.java:502) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketResponder.handleFrame(RSocketResponder.java:315) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.LambdaSubscriber.onNext(LambdaSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:242) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.drainRegular(FluxGroupBy.java:554) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.drain(FluxGroupBy.java:630) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$UnicastGroupedFlux.subscribe(FluxGroupBy.java:696) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.Flux.subscribe(Flux.java:8264) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onNext(MonoFlatMapMany.java:188) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1712) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.MonoProcessor.onNext(MonoProcessor.java:317) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.ClientServerInputMultiplexer.lambda$new$1(ClientServerInputMultiplexer.java:116) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.LambdaSubscriber.onNext(LambdaSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$GroupByMain.drainLoop(FluxGroupBy.java:380) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$GroupByMain.drain(FluxGroupBy.java:316) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.FluxGroupBy$GroupByMain.onNext(FluxGroupBy.java:201) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.UnboundedProcessor.drainRegular(UnboundedProcessor.java:118) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.drain(UnboundedProcessor.java:188) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.onNext(UnboundedProcessor.java:276) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onNext(FluxPeekFuseable.java:189) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.UnboundedProcessor.drainRegular(UnboundedProcessor.java:118) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.drain(UnboundedProcessor.java:188) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.internal.UnboundedProcessor.onNext(UnboundedProcessor.java:276) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketRequester$3$1.hookOnNext(RSocketRequester.java:358) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at io.rsocket.RSocketRequester$3$1.hookOnNext(RSocketRequester.java:333) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.BaseSubscriber.onNext(BaseSubscriber.java:160) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.rsocket.internal.RateLimitableRequestPublisher$InnerOperator.onNext(RateLimitableRequestPublisher.java:173) ~[rsocket-core-1.0.0-RC7-SNAPSHOT.jar:na]
    at reactor.core.publisher.EmitterProcessor.drain(EmitterProcessor.java:426) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at reactor.core.publisher.EmitterProcessor.onNext(EmitterProcessor.java:268) ~[reactor-core-3.3.4.RELEASE.jar:3.3.4.RELEASE]
    at io.vlingo.wire.fdx.bidirectional.rsocket.RSocketClientChannel.requestWith(RSocketClientChannel.java:76) [classes/:na]
    at io.vlingo.wire.fdx.bidirectional.rsocket.RSocketServerChannelActorTest.request(RSocketServerChannelActorTest.java:63) ~[test-classes/:na]
    at io.vlingo.wire.fdx.bidirectional.BaseServerChannelTest.testBasicRequestResponse(BaseServerChannelTest.java:45) ~[test-classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_151]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_151]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_151]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_151]
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) ~[junit-4.11.jar:na]
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.11.jar:na]
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) ~[junit-4.11.jar:na]
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.11.jar:na]
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) ~[junit-4.11.jar:na]
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) ~[junit-4.11.jar:na]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) ~[junit-4.11.jar:na]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) ~[junit-4.11.jar:na]
    at org.junit.runners.ParentRunner.run(ParentRunner.java:309) ~[junit-4.11.jar:na]
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) ~[surefire-junit4-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) ~[surefire-junit4-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) ~[surefire-junit4-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) ~[surefire-junit4-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379) ~[surefire-booter-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340) ~[surefire-booter-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125) ~[surefire-booter-2.21.0.jar:2.21.0]
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413) ~[surefire-booter-2.21.0.jar:2.21.0]
No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself.
VaughnVernon commented 4 years ago

Fixed by #36