servicetalk icon indicating copy to clipboard operation
servicetalk copied to clipboard

Published 20 hours ago • verified publisher icon apple

InsufficientlySizedExecutorHttpTest

Open Scottmitch opened this issue 6 years ago • 7 comments

failed while building locally

org.junit.runners.model.TestTimedOutException: test timed out after 10000 milliseconds
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage$GetListener.blockingWait(ExecutorCompletionStage.java:820)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage.waitingGet(ExecutorCompletionStage.java:652)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage.get(ExecutorCompletionStage.java:509)
	at io.servicetalk.http.netty.InsufficientlySizedExecutorHttpTest.insufficientServerCapacityStreaming(InsufficientlySizedExecutorHttpTest.java:128)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:239)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:167)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:159)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

Scottmitch avatar Feb 23 '19 00:02 Scottmitch

https://ci.servicetalk.io/job/servicetalk-master-prb/915/testReport/junit/io.servicetalk.http.netty/InsufficientlySizedExecutorHttpTest/insufficientServerCapacityStreaming_1___capacity__0_thread_based__false_/

org.junit.runners.model.TestTimedOutException: test timed out after 90000 milliseconds
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage$GetListener.blockingWait(ExecutorCompletionStage.java:820)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage.waitingGet(ExecutorCompletionStage.java:652)
	at io.servicetalk.concurrent.api.ExecutorCompletionStage.get(ExecutorCompletionStage.java:509)
	at io.servicetalk.http.netty.InsufficientlySizedExecutorHttpTest.insufficientServerCapacityStreaming(InsufficientlySizedExecutorHttpTest.java:128)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:239)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:167)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:159)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

Scottmitch avatar Feb 27 '19 23:02 Scottmitch

@Scottmitch is this fixed by https://github.com/servicetalk/servicetalk/pull/346 ?

NiteshKant avatar Feb 28 '19 21:02 NiteshKant

I wouldn't say #346 fixes the issue but is a work around so the test no longer fails. I think https://github.com/servicetalk/servicetalk/pull/353 should be the proper fix, and we can backout the workaround.

Scottmitch avatar Mar 01 '19 02:03 Scottmitch

edit: failure was a different cause, related to the PR being tested.

lewisd32 avatar May 23 '19 17:05 lewisd32

We haven't seen this problem for a long time. I will close the issue and we can reopen if necessary.

idelpivnitskiy avatar Oct 09 '19 01:10 idelpivnitskiy

https://ci.servicetalk.io/job/servicetalk-java8-prb/772/testReport/junit/io.servicetalk.http.netty/InsufficientlySizedExecutorHttpTest/insufficientServerCapacityStreamingWithConnectionAcceptor_2___capacity__1_thread_based__true_/

Error Message

java.util.concurrent.ExecutionException: io.servicetalk.transport.netty.internal.CloseHandler$CloseEventObservedException: CHANNEL_CLOSED_INBOUND(The transport backing this connection has been shutdown (read)) [id: 0x97b40570, L:/127.0.0.1:36556 ! R:127.0.0.1/127.0.0.1:37549]

Stacktrace

java.util.concurrent.ExecutionException: io.servicetalk.transport.netty.internal.CloseHandler$CloseEventObservedException: CHANNEL_CLOSED_INBOUND(The transport backing this connection has been shutdown (read)) [id: 0x97b40570, L:/127.0.0.1:36556 ! R:127.0.0.1/127.0.0.1:37549]
	at io.servicetalk.concurrent.api.SourceToFuture.reportGet(SourceToFuture.java:121)
	at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:92)
	at io.servicetalk.http.netty.InsufficientlySizedExecutorHttpTest.insufficientServerCapacityStreaming0(InsufficientlySizedExecutorHttpTest.java:136)
	at io.servicetalk.http.netty.InsufficientlySizedExecutorHttpTest.insufficientServerCapacityStreamingWithConnectionAcceptor(InsufficientlySizedExecutorHttpTest.java:122)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:239)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:171)
	at io.servicetalk.concurrent.internal.ServiceTalkTestTimeout$TimeoutStatement$CallableStatement.call(ServiceTalkTestTimeout.java:163)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)
Caused by: io.servicetalk.transport.netty.internal.CloseHandler$CloseEventObservedException: CHANNEL_CLOSED_INBOUND(The transport backing this connection has been shutdown (read)) [id: 0x97b40570, L:/127.0.0.1:36556 ! R:127.0.0.1/127.0.0.1:37549]
Caused by: java.nio.channels.ClosedChannelException
	at io.servicetalk.transport.netty.internal.NettyChannelPublisher.channelInboundClosed(Unknown Source)

idelpivnitskiy avatar Oct 24 '19 01:10 idelpivnitskiy

I see the same exception occurring more frequently on windows too https://github.com/apple/servicetalk/pull/977#discussion_r396612874

Scottmitch avatar Mar 23 '20 23:03 Scottmitch

This test was not flaky for more than a year. Reopen if it fails again

idelpivnitskiy avatar Oct 25 '23 22:10 idelpivnitskiy