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

TestQueryTracker.testInterruptApplyFilter is flaky #8432

Closed
kokosing opened this issue Jun 30, 2021 · 21 comments
Closed

TestQueryTracker.testInterruptApplyFilter is flaky #8432

kokosing opened this issue Jun 30, 2021 · 21 comments
Labels
bug Something isn't working test

Comments

@kokosing
Copy link
Member

2021-06-30T12:05:14.5160337Z org.testng.internal.thread.ThreadTimeoutException: Method io.trino.execution.TestQueryTracker.testInterruptApplyFilter() didn't finish within the time-out 5000
2021-06-30T12:05:14.5162691Z 	at [email protected]/java.net.SocketInputStream.socketRead0(Native Method)
2021-06-30T12:05:14.5166376Z 	at [email protected]/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
2021-06-30T12:05:14.5167620Z 	at [email protected]/java.net.SocketInputStream.read(SocketInputStream.java:168)
2021-06-30T12:05:14.5168754Z 	at [email protected]/java.net.SocketInputStream.read(SocketInputStream.java:140)
2021-06-30T12:05:14.5169543Z 	at app//okio.Okio$2.read(Okio.java:140)
2021-06-30T12:05:14.5170114Z 	at app//okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
2021-06-30T12:05:14.5171004Z 	at app//okio.RealBufferedSource.indexOf(RealBufferedSource.java:358)
2021-06-30T12:05:14.5172308Z 	at app//okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:230)
2021-06-30T12:05:14.5173992Z 	at app//okhttp3.internal.http1.Http1ExchangeCodec.readHeaderLine(Http1ExchangeCodec.java:242)
2021-06-30T12:05:14.5176310Z 	at app//okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.java:213)
2021-06-30T12:05:14.5178454Z 	at app//okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.java:115)
2021-06-30T12:05:14.5181437Z 	at app//okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:94)
2021-06-30T12:05:14.5190569Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2021-06-30T12:05:14.5192472Z 	at app//okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:43)
2021-06-30T12:05:14.5194330Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2021-06-30T12:05:14.5196092Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2021-06-30T12:05:14.5197773Z 	at app//okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:94)
2021-06-30T12:05:14.5219330Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2021-06-30T12:05:14.5221108Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2021-06-30T12:05:14.5222812Z 	at app//okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
2021-06-30T12:05:14.5224515Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2021-06-30T12:05:14.5226868Z 	at app//okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:88)
2021-06-30T12:05:14.5228938Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2021-06-30T12:05:14.5230682Z 	at app//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2021-06-30T12:05:14.5232308Z 	at app//okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:229)
2021-06-30T12:05:14.5233407Z 	at app//okhttp3.RealCall.execute(RealCall.java:81)
2021-06-30T12:05:14.5234311Z 	at app//io.trino.client.JsonResponse.execute(JsonResponse.java:130)
2021-06-30T12:05:14.5235533Z 	at app//io.trino.client.StatementClientV1.advance(StatementClientV1.java:372)
2021-06-30T12:05:14.5237184Z 	at app//io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:97)
2021-06-30T12:05:14.5239151Z 	at app//io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:85)
2021-06-30T12:05:14.5241047Z 	at app//io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:464)
2021-06-30T12:05:14.5242754Z 	at app//io.trino.execution.TestQueryTracker.lambda$testInterruptApplyFilter$0(TestQueryTracker.java:85)
2021-06-30T12:05:14.5244279Z 	at app//io.trino.execution.TestQueryTracker$$Lambda$7168/0x00000008037c3040.call(Unknown Source)
2021-06-30T12:05:14.5245656Z 	at app//org.assertj.core.api.ThrowableAssert.catchThrowable(ThrowableAssert.java:62)
2021-06-30T12:05:14.5247611Z 	at app//org.assertj.core.api.AssertionsForClassTypes.catchThrowable(AssertionsForClassTypes.java:877)
2021-06-30T12:05:14.5249398Z 	at app//org.assertj.core.api.Assertions.catchThrowable(Assertions.java:1306)
2021-06-30T12:05:14.5250858Z 	at app//org.assertj.core.api.Assertions.assertThatThrownBy(Assertions.java:1178)
2021-06-30T12:05:14.5252694Z 	at app//io.trino.execution.TestQueryTracker.testInterruptApplyFilter(TestQueryTracker.java:85)
2021-06-30T12:05:14.5254609Z 	at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-06-30T12:05:14.5256476Z 	at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-06-30T12:05:14.5258644Z 	at [email protected]/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-06-30T12:05:14.5260253Z 	at [email protected]/java.lang.reflect.Method.invoke(Method.java:566)
2021-06-30T12:05:14.5261732Z 	at app//org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-06-30T12:05:14.5263561Z 	at app//org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
2021-06-30T12:05:14.5265145Z 	at app//org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
2021-06-30T12:05:14.5266476Z 	at [email protected]/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
2021-06-30T12:05:14.5279107Z 	at [email protected]/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2021-06-30T12:05:14.5280558Z 	at [email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-06-30T12:05:14.5282164Z 	at [email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-06-30T12:05:14.5293251Z 	at [email protected]/java.lang.Thread.run(Thread.java:829)
2021-06-30T12:05:14.5293696Z 
2021-06-30T12:05:14.5310347Z 2021-06-30T07:05:14.529-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5315563Z 2021-06-30T07:05:14.529-0500 INFO Life cycle stopping...
2021-06-30T12:05:14.5325466Z 2021-06-30T07:05:14.530-0500 SEVERE Exception in PreDestroy method io.trino.memory.ClusterMemoryManager::destroy()
2021-06-30T12:05:14.5335352Z org.weakref.jmx.JmxException: MBean not found: io.trino.memory:type=ClusterMemoryPool,name=general
2021-06-30T12:05:14.5341377Z 	at org.weakref.jmx.MBeanExporter.unexport(MBeanExporter.java:170)
2021-06-30T12:05:14.5347340Z 	at org.weakref.jmx.MBeanExporter.unexport(MBeanExporter.java:155)
2021-06-30T12:05:14.5354681Z 	at org.weakref.jmx.MBeanExporter.unexportWithGeneratedName(MBeanExporter.java:143)
2021-06-30T12:05:14.5362178Z 	at io.trino.memory.ClusterMemoryManager.lambda$destroy$4(ClusterMemoryManager.java:534)
2021-06-30T12:05:14.5367798Z 	at com.google.common.io.Closer.close(Closer.java:213)
2021-06-30T12:05:14.5374394Z 	at io.trino.memory.ClusterMemoryManager.destroy(ClusterMemoryManager.java:537)
2021-06-30T12:05:14.5381179Z 	at jdk.internal.reflect.GeneratedMethodAccessor4309.invoke(Unknown Source)
2021-06-30T12:05:14.5390258Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-06-30T12:05:14.5396459Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-06-30T12:05:14.5403178Z 	at io.airlift.bootstrap.LifeCycleManager.stopInstance(LifeCycleManager.java:225)
2021-06-30T12:05:14.5413334Z 	at io.airlift.bootstrap.LifeCycleManager.stop(LifeCycleManager.java:193)
2021-06-30T12:05:14.5422798Z 	at io.airlift.bootstrap.LifeCycleManager.stop(LifeCycleManager.java:158)
2021-06-30T12:05:14.5430475Z 	at io.airlift.bootstrap.LifeCycleManager.lambda$start$0(LifeCycleManager.java:111)
2021-06-30T12:05:14.5435675Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-06-30T12:05:14.5437171Z 
2021-06-30T12:05:14.5441934Z 2021-06-30T07:05:14.532-0500 INFO Life cycle stopped
2021-06-30T12:05:14.5446968Z 2021-06-30T07:05:14.532-0500 SEVERE Trying to shut down
2021-06-30T12:05:14.5453625Z io.airlift.bootstrap.LifeCycleStopException: Exceptions occurred during lifecycle stop
2021-06-30T12:05:14.5459883Z 	at io.airlift.bootstrap.LifeCycleManager.stop(LifeCycleManager.java:164)
2021-06-30T12:05:14.5466417Z 	at io.airlift.bootstrap.LifeCycleManager.lambda$start$0(LifeCycleManager.java:111)
2021-06-30T12:05:14.5470926Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-06-30T12:05:14.5472417Z 
2021-06-30T12:05:14.5477286Z 2021-06-30T07:05:14.540-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5481868Z 2021-06-30T07:05:14.541-0500 INFO Life cycle stopping...
2021-06-30T12:05:14.5487618Z 2021-06-30T07:05:14.547-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5492268Z 2021-06-30T07:05:14.547-0500 INFO Life cycle stopping...
2021-06-30T12:05:14.5498474Z 2021-06-30T07:05:14.547-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5503155Z 2021-06-30T07:05:14.547-0500 INFO Life cycle stopping...
2021-06-30T12:05:14.5508541Z 2021-06-30T07:05:14.549-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5513215Z 2021-06-30T07:05:14.549-0500 INFO Life cycle stopping...
2021-06-30T12:05:14.5518703Z 2021-06-30T07:05:14.549-0500 INFO JVM is shutting down, cleaning up
2021-06-30T12:05:14.5523840Z 2021-06-30T07:05:14.549-0500 INFO Life cycle stopping...
2021-06-30T12:05:18.0124757Z [INFO] 
@findepi
Copy link
Member

findepi commented Jul 26, 2021

@hashhar
Copy link
Member

hashhar commented Aug 2, 2021

@sopel39
Copy link
Member

sopel39 commented Aug 25, 2021

@findepi
Copy link
Member

findepi commented Sep 20, 2021

@findepi
Copy link
Member

findepi commented Sep 28, 2021

@findepi
Copy link
Member

findepi commented Sep 28, 2021

@ebyhr
Copy link
Member

ebyhr commented Sep 29, 2021

@ebyhr
Copy link
Member

ebyhr commented Sep 30, 2021

@findepi
Copy link
Member

findepi commented Oct 25, 2021

@findepi
Copy link
Member

findepi commented Nov 9, 2021

@skrzypo987
Copy link
Member

I see this is pretty frequent. I can probably take a look sometime next week.

@findepi
Copy link
Member

findepi commented Dec 6, 2021

@findepi
Copy link
Member

findepi commented Dec 8, 2021

@findepi
Copy link
Member

findepi commented Dec 8, 2021

@findepi
Copy link
Member

findepi commented Dec 8, 2021

Undoubtedly, this is currently the top flake. cc @nineinchnick

@findepi
Copy link
Member

findepi commented Dec 8, 2021

@skrzypo987
Copy link
Member

What is the policy on adding a flake annotation? I tried to reproduce it by any means and failed. And i don't think increasing the timeout will help here.

@kokosing
Copy link
Member Author

I am not sure if flaky annotation handles timeouts.

What is the policy on adding a flake annotation?

It goes as regular PR.

And i don't think increasing the timeout will help here.

Have you tried that? Maybe you can increase the timeout and decrease the time in io.trino.testng.services.LogTestDurationListener to capture the stack traces?

Are you able to stress CI enough that reproduce it?

@homar
Copy link
Member

homar commented Dec 14, 2021

@ebyhr
Copy link
Member

ebyhr commented Jan 1, 2022

@sopel39
Copy link
Member

sopel39 commented Jun 1, 2022

Last happened on Jan. Closing until someone reopens

@sopel39 sopel39 closed this as completed Jun 1, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working test
Development

No branches or pull requests

7 participants