Open bondolo opened 2 years ago
https://github.com/apple/servicetalk/pull/1910/checks?check_run_id=4174863283
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1343)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:91)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725)
at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at org.junit.jupiter.engine.extension.TimeoutInvocation.proceed(TimeoutInvocation.java:46)
... 53 more
https://github.com/apple/servicetalk/pull/2120/checks?check_run_id=5369476655
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:230)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:91)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent()
java.util.concurrent.TimeoutException: deferResponseUntilAfterRequestSent() timed out after 30 seconds
Suppressed: java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent(FullDuplexAndSequentialModeTest.java:80)
https://github.com/apple/servicetalk/pull/2278/checks?check_run_id=7530726644
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
at org.junit.jupiter.engine.extension.TimeoutInvocation.createTimeoutException(TimeoutInvocation.java:70)
at org.junit.jupiter.engine.extension.TimeoutInvocation.proceed(TimeoutInvocation.java:59)
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1343)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:91)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725)
at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at org.junit.jupiter.engine.extension.TimeoutInvocation.proceed(TimeoutInvocation.java:46)
... 53 more
...
https://github.com/apple/servicetalk/pull/2384/checks?check_run_id=8692706122
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
...
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:230)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:91)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
https://github.com/apple/servicetalk/pull/2412/checks?check_run_id=9259610509
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1343)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:91)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
https://github.com/apple/servicetalk/pull/2617/checks?check_run_id=14275302128
FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent()
java.util.concurrent.TimeoutException: deferResponseUntilAfterRequestSent() timed out after 30 seconds
Suppressed: java.lang.InterruptedException: sleep interrupted
at java.base/java.lang.Thread.sleep0(Native Method)
at java.base/java.lang.Thread.sleep(Thread.java:484)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent(FullDuplexAndSequentialModeTest.java:80)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
at java.base/java.lang.reflect.Method.invoke(Method.java:578)
at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:45)
... 53 more
https://github.com/apple/servicetalk/pull/2632/checks?check_run_id=14668901643
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1100)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:230)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:94)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
https://github.com/apple/servicetalk/pull/2637/checks?check_run_id=14772117181
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
Suppressed: java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1306)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:94)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
https://github.com/apple/servicetalk/runs/17378458627
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
...
Suppressed: java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048)
at java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:230)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:94)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
https://github.com/apple/servicetalk/pull/2746/checks?check_run_id=18514248259
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
...
Suppressed: java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1306)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:94)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
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.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:45)
... 52 more
https://github.com/apple/servicetalk/pull/2787/checks?check_run_id=19649058298
FullDuplexAndSequentialModeTest > defaultFullDuplex() FAILED
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
...
Suppressed: java.lang.InterruptedException: sleep interrupted
at java.base/java.lang.Thread.sleep(Native Method)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent(FullDuplexAndSequentialModeTest.java:80)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
The failures in FullDuplexAndSequentialModeTest.deferResponseUntilAfterRequestSent
are pretty interesting: the InterruptedException
is coming from a Thread.sleep(100)
call which is not something that is going to have forever. It is also a place where you can tell the test thread is making progress: it had to get there and it's clearly a call that won't hang unless the JVM is really borked. What is most likely happening is that the thread is getting interrupted by the test runner before it gets there but we don't see it.
The next question is how that could be happening given it has 30 seconds to get there which is a good amount of time even in CI. These tests are starting and stoping listeners and making connections, and the base class of this test alone is running on the order of 500 tests, meaning creating and destroying at roughly that many servers and clients. Maybe the tests are running into ephemeral port starvation issues which result in timeouts.
https://github.com/apple/servicetalk/pull/2798/checks?check_run_id=20393836300
FullDuplexAndSequentialModeTest.defaultFullDuplex()
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
...
Suppressed: java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1306)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
at io.servicetalk.concurrent.api.SourceToFuture.get(SourceToFuture.java:94)
at io.servicetalk.http.netty.FullDuplexAndSequentialModeTest.defaultFullDuplex(FullDuplexAndSequentialModeTest.java:59)
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.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:45)
... 52 more
https://github.com/apple/servicetalk/actions/runs/8456122982/job/23165152255?pr=2776
FullDuplexAndSequentialModeTest > defaultFullDuplex() FAILED
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
at org.junit.jupiter.engine.extension.TimeoutExceptionFactory.create(TimeoutExceptionFactory.java:29)
at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:58)
at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156)
at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147)
at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86)
at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
https://github.com/apple/servicetalk/actions/runs/9467368345/job/26081235133#step:8:868
FullDuplexAndSequentialModeTest > defaultFullDuplex() FAILED
java.util.concurrent.TimeoutException: defaultFullDuplex() timed out after 30 seconds
at org.junit.jupiter.engine.extension.TimeoutExceptionFactory.create(TimeoutExceptionFactory.java:29)
at org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:58)
at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156)
at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147)
at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86)
at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
https://github.com/apple/servicetalk/pull/1892/checks?check_run_id=3921774002