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

Sporadic failure: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator #6220

Closed
findepi opened this issue Dec 7, 2020 · 19 comments · Fixed by #11758
Labels
bug Something isn't working

Comments

@findepi
Copy link
Member

findepi commented Dec 7, 2020

Relates to df4fe40 #6120

@findepi findepi added the bug Something isn't working label Dec 7, 2020
@findepi
Copy link
Member Author

findepi commented Dec 7, 2020

Observed on a fork https://github.com/findepi/presto/runs/1503892606?check_suite_focus=true but the tested branch has no execution related changes

2020-12-05T16:45:50.2856348Z [ERROR] Tests run: 160, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 407.064 s <<< FAILURE! - in TestSuite
2020-12-05T16:45:50.2864796Z [ERROR] testHighCardinalityReducedIndexProbeKey(io.prestosql.plugin.thrift.integration.TestThriftDistributedQueriesIndexed)  Time elapsed: 3.723 s  <<< FAILURE!
2020-12-05T16:45:50.2869246Z java.lang.AssertionError: 
2020-12-05T16:45:50.2872269Z Execution of 'actual' query failed: SELECT *
2020-12-05T16:45:50.2873971Z FROM (
2020-12-05T16:45:50.2876249Z   SELECT *, custkey % 4 AS x, custkey % 2 AS y
2020-12-05T16:45:50.2877984Z   FROM orders
2020-12-05T16:45:50.2880060Z   WHERE orderkey % 10000 = 0) o1
2020-12-05T16:45:50.2880619Z JOIN (
2020-12-05T16:45:50.2885139Z   SELECT *, custkey % 5 AS x, custkey % 3 AS y
2020-12-05T16:45:50.2887491Z   FROM orders
2020-12-05T16:45:50.2890743Z   WHERE orderkey % 4 = 0) o2
2020-12-05T16:45:50.2899631Z   ON o1.orderstatus = o2.orderstatus AND o1.shippriority = o2.shippriority AND o1.x = o2.x AND o1.y = o2.y
2020-12-05T16:45:50.2906102Z 	at org.testng.Assert.fail(Assert.java:83)
2020-12-05T16:45:50.2942555Z 	at io.prestosql.testing.QueryAssertions.assertQuery(QueryAssertions.java:150)
2020-12-05T16:45:50.2951244Z 	at io.prestosql.testing.QueryAssertions.assertQuery(QueryAssertions.java:106)
2020-12-05T16:45:50.2961791Z 	at io.prestosql.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:154)
2020-12-05T16:45:50.2972406Z 	at io.prestosql.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:149)
2020-12-05T16:45:50.2993908Z 	at io.prestosql.testing.AbstractTestIndexedQueries.testHighCardinalityReducedIndexProbeKey(AbstractTestIndexedQueries.java:442)
2020-12-05T16:45:50.3004078Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-12-05T16:45:50.3018036Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-12-05T16:45:50.3058928Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-12-05T16:45:50.3067224Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-12-05T16:45:50.3076330Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-12-05T16:45:50.3083468Z 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2020-12-05T16:45:50.3090332Z 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2020-12-05T16:45:50.3097439Z 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2020-12-05T16:45:50.3107396Z 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2020-12-05T16:45:50.3118326Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2020-12-05T16:45:50.3130365Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-12-05T16:45:50.3147294Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-12-05T16:45:50.3160971Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-12-05T16:45:50.3180080Z Caused by: java.lang.RuntimeException: Expected response code from http://127.0.0.1:42877/v1/task/20201205_164010_00010_wzavx.1.2?summarize to be 200, but was 500
2020-12-05T16:45:50.3193661Z java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
2020-12-05T16:45:50.3202754Z 	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:441)
2020-12-05T16:45:50.3211276Z 	at io.prestosql.operator.OperatorStats.add(OperatorStats.java:478)
2020-12-05T16:45:50.3229847Z 	at io.prestosql.operator.OperatorStats.add(OperatorStats.java:428)
2020-12-05T16:45:50.3239082Z 	at io.prestosql.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
2020-12-05T16:45:50.3246747Z 	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
2020-12-05T16:45:50.3254959Z 	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
2020-12-05T16:45:50.3264781Z 	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:459)
2020-12-05T16:45:50.3273231Z 	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:847)
2020-12-05T16:45:50.3280907Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:275)
2020-12-05T16:45:50.3289044Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:232)
2020-12-05T16:45:50.3296698Z 	at io.prestosql.operator.TaskContext.getTaskStats(TaskContext.java:417)
2020-12-05T16:45:50.3305066Z 	at io.prestosql.execution.SqlTask.getTaskStats(SqlTask.java:340)
2020-12-05T16:45:50.3309546Z 	at io.prestosql.execution.SqlTask.createTaskInfo(SqlTask.java:362)
2020-12-05T16:45:50.3313343Z 	at io.prestosql.execution.SqlTask.getTaskInfo(SqlTask.java:224)
2020-12-05T16:45:50.3319066Z 	at io.prestosql.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:316)
2020-12-05T16:45:50.3325438Z 	at io.prestosql.server.TaskResource.getTaskInfo(TaskResource.java:160)
2020-12-05T16:45:50.3331303Z 	at jdk.internal.reflect.GeneratedMethodAccessor285.invoke(Unknown Source)
2020-12-05T16:45:50.3338595Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-12-05T16:45:50.3345021Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-12-05T16:45:50.3354898Z 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
2020-12-05T16:45:50.3363986Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
2020-12-05T16:45:50.3372882Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
2020-12-05T16:45:50.3382127Z 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
2020-12-05T16:45:50.3391288Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
2020-12-05T16:45:50.3398560Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
2020-12-05T16:45:50.3404121Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
2020-12-05T16:45:50.3465939Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
2020-12-05T16:45:50.3468504Z 	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
2020-12-05T16:45:50.3469980Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
2020-12-05T16:45:50.3471250Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
2020-12-05T16:45:50.3472676Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
2020-12-05T16:45:50.3475072Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
2020-12-05T16:45:50.3476692Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
2020-12-05T16:45:50.3479228Z 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
2020-12-05T16:45:50.3481612Z 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
2020-12-05T16:45:50.3483803Z 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
2020-12-05T16:45:50.3486089Z 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
2020-12-05T16:45:50.3488162Z 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
2020-12-05T16:45:50.3490357Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
2020-12-05T16:45:50.3492668Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
2020-12-05T16:45:50.3494977Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
2020-12-05T16:45:50.3497040Z 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:755)
2020-12-05T16:45:50.3498945Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1617)
2020-12-05T16:45:50.3500917Z 	at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
2020-12-05T16:45:50.3502890Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
2020-12-05T16:45:50.3504887Z 	at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
2020-12-05T16:45:50.3506695Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
2020-12-05T16:45:50.3508682Z 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)
2020-12-05T16:45:50.3510795Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
2020-12-05T16:45:50.3513052Z 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
2020-12-05T16:45:50.3515330Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2020-12-05T16:45:50.3517714Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
2020-12-05T16:45:50.3520127Z 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)
2020-12-05T16:45:50.3522712Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
2020-12-05T16:45:50.3524902Z 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)
2020-12-05T16:45:50.3527627Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
2020-12-05T16:45:50.3530675Z 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)
2020-12-05T16:45:50.3532969Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2020-12-05T16:45:50.3535320Z 	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
2020-12-05T16:45:50.3537825Z 	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
2020-12-05T16:45:50.3540083Z 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
2020-12-05T16:45:50.3542230Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2020-12-05T16:45:50.3548566Z 	at org.eclipse.jetty.server.Server.handle(Server.java:500)
2020-12-05T16:45:50.3550154Z 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
2020-12-05T16:45:50.3551889Z 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
2020-12-05T16:45:50.3553575Z 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
2020-12-05T16:45:50.3555435Z 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
2020-12-05T16:45:50.3557523Z 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
2020-12-05T16:45:50.3559322Z 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
2020-12-05T16:45:50.3560852Z 	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
2020-12-05T16:45:50.3570969Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
2020-12-05T16:45:50.3573796Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
2020-12-05T16:45:50.3577515Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
2020-12-05T16:45:50.3580123Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
2020-12-05T16:45:50.3583704Z 	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
2020-12-05T16:45:50.3586188Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
2020-12-05T16:45:50.3589577Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
2020-12-05T16:45:50.3591001Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-12-05T16:45:50.3591483Z 
2020-12-05T16:45:50.3593082Z 	at io.prestosql.testing.AbstractTestingPrestoClient.execute(AbstractTestingPrestoClient.java:115)
2020-12-05T16:45:50.3595717Z 	at io.prestosql.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:462)
2020-12-05T16:45:50.3598974Z 	at io.prestosql.plugin.thrift.integration.ThriftQueryRunner$ThriftQueryRunnerWithServers.execute(ThriftQueryRunner.java:258)
2020-12-05T16:45:50.3601685Z 	at io.prestosql.testing.QueryAssertions.assertQuery(QueryAssertions.java:147)
2020-12-05T16:45:50.3602865Z 	... 17 more
2020-12-05T16:45:50.3603978Z Caused by: io.prestosql.spi.PrestoException: Expected response code from http://127.0.0.1:42877/v1/task/20201205_164010_00010_wzavx.1.2?summarize to be 200, but was 500
2020-12-05T16:45:50.3605929Z java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
2020-12-05T16:45:50.3608115Z 	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:441)
2020-12-05T16:45:50.3610474Z 	at io.prestosql.operator.OperatorStats.add(OperatorStats.java:478)
2020-12-05T16:45:50.3612021Z 	at io.prestosql.operator.OperatorStats.add(OperatorStats.java:428)
2020-12-05T16:45:50.3614160Z 	at io.prestosql.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
2020-12-05T16:45:50.3616024Z 	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
2020-12-05T16:45:50.3617775Z 	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
2020-12-05T16:45:50.3622029Z 	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:459)
2020-12-05T16:45:50.3624044Z 	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:847)
2020-12-05T16:45:50.3625787Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:275)
2020-12-05T16:45:50.3627618Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:232)
2020-12-05T16:45:50.3629438Z 	at io.prestosql.operator.TaskContext.getTaskStats(TaskContext.java:417)
2020-12-05T16:45:50.3631140Z 	at io.prestosql.execution.SqlTask.getTaskStats(SqlTask.java:340)
2020-12-05T16:45:50.3632899Z 	at io.prestosql.execution.SqlTask.createTaskInfo(SqlTask.java:362)
2020-12-05T16:45:50.3634486Z 	at io.prestosql.execution.SqlTask.getTaskInfo(SqlTask.java:224)
2020-12-05T16:45:50.3636241Z 	at io.prestosql.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:316)
2020-12-05T16:45:50.3638122Z 	at io.prestosql.server.TaskResource.getTaskInfo(TaskResource.java:160)
2020-12-05T16:45:50.3640045Z 	at jdk.internal.reflect.GeneratedMethodAccessor285.invoke(Unknown Source)
2020-12-05T16:45:50.3642610Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-12-05T16:45:50.3645488Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-12-05T16:45:50.3648906Z 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
2020-12-05T16:45:50.3655750Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
2020-12-05T16:45:50.3663336Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
2020-12-05T16:45:50.3670277Z 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
2020-12-05T16:45:50.3675682Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
2020-12-05T16:45:50.3682787Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
2020-12-05T16:45:50.3689228Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
2020-12-05T16:45:50.3692170Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
2020-12-05T16:45:50.3696167Z 	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
2020-12-05T16:45:50.3697630Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
2020-12-05T16:45:50.3698906Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
2020-12-05T16:45:50.3701975Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
2020-12-05T16:45:50.3703694Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
2020-12-05T16:45:50.3706893Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
2020-12-05T16:45:50.3710922Z 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
2020-12-05T16:45:50.3713258Z 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
2020-12-05T16:45:50.3715426Z 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
2020-12-05T16:45:50.3718588Z 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
2020-12-05T16:45:50.3720661Z 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
2020-12-05T16:45:50.3722763Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
2020-12-05T16:45:50.3726231Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
2020-12-05T16:45:50.3728504Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
2020-12-05T16:45:50.3731487Z 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:755)
2020-12-05T16:45:50.3733384Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1617)
2020-12-05T16:45:50.3736252Z 	at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
2020-12-05T16:45:50.3738225Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
2020-12-05T16:45:50.3740023Z 	at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
2020-12-05T16:45:50.3742759Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
2020-12-05T16:45:50.3744853Z 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)
2020-12-05T16:45:50.3747941Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
2020-12-05T16:45:50.3750188Z 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
2020-12-05T16:45:50.3755489Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2020-12-05T16:45:50.3767177Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
2020-12-05T16:45:50.3783974Z 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)
2020-12-05T16:45:50.3787633Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
2020-12-05T16:45:50.3790290Z 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)
2020-12-05T16:45:50.3792849Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
2020-12-05T16:45:50.3795232Z 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)
2020-12-05T16:45:50.3797495Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2020-12-05T16:45:50.3800140Z 	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
2020-12-05T16:45:50.3802847Z 	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
2020-12-05T16:45:50.3805092Z 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
2020-12-05T16:45:50.3807242Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2020-12-05T16:45:50.3809034Z 	at org.eclipse.jetty.server.Server.handle(Server.java:500)
2020-12-05T16:45:50.3810556Z 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
2020-12-05T16:45:50.3812283Z 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
2020-12-05T16:45:50.3813982Z 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
2020-12-05T16:45:50.3815868Z 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
2020-12-05T16:45:50.3817899Z 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
2020-12-05T16:45:50.3819687Z 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
2020-12-05T16:45:50.3821234Z 	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
2020-12-05T16:45:50.3823362Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
2020-12-05T16:45:50.3826054Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
2020-12-05T16:45:50.3828824Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
2020-12-05T16:45:50.3831403Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
2020-12-05T16:45:50.3833939Z 	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
2020-12-05T16:45:50.3836567Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
2020-12-05T16:45:50.3838711Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
2020-12-05T16:45:50.3841299Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-12-05T16:45:50.3841791Z 
2020-12-05T16:45:50.3843681Z 	at io.prestosql.server.remotetask.SimpleHttpResponseHandler.onSuccess(SimpleHttpResponseHandler.java:62)
2020-12-05T16:45:50.3847101Z 	at io.prestosql.server.remotetask.SimpleHttpResponseHandler.onSuccess(SimpleHttpResponseHandler.java:27)
2020-12-05T16:45:50.3849689Z 	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1089)
2020-12-05T16:45:50.3851550Z 	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:80)
2020-12-05T16:45:50.3853663Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-12-05T16:45:50.3855714Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-12-05T16:45:50.3857049Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-12-05T16:45:50.3857530Z 

@sopel39
Copy link
Member

sopel39 commented Dec 7, 2020

cc @erichwang

@erichwang
Copy link
Contributor

The underlying problem here is here:

https://github.com/prestosql/presto/blob/master/presto-main/src/main/java/io/prestosql/operator/index/IndexBuildDriverFactoryProvider.java#L77
AND
https://github.com/prestosql/presto/blob/master/presto-main/src/main/java/io/prestosql/operator/index/IndexBuildDriverFactoryProvider.java#L102

In the index join code, the same driver can dynamically have two different output types depending on whether the results are going to be streamed without caching, or cached. This is currently a decision that occurs at runtime based on how much memory is available in the cache, and so that might explain why this is non-deterministic. It seems like we have a couple options here:

  1. Split the streaming and caching variants into 2 separate DriverFactoryProviders with completely different ID spaces
  2. Make a compound Operator that can either be used for streaming or caching results (maybe constructor flag toggled) so that it is literally the same class but with configurable behavior.

This really comes down to how we want to tabulate these stats. Either way, none of these are going to be super clean since the execution framework isn't really set up for these exact operations.

@findepi
Copy link
Member Author

findepi commented Dec 16, 2020

https://github.com/prestosql/presto/runs/1557282633

[ERROR]   TestThriftDistributedQueriesIndexed>AbstractTestIndexedQueries.testHighCardinalityIndexJoinResult:393->AbstractTestQueryFramework.assertQuery:149->AbstractTestQueryFramework.assertQuery:154 Execution of 'actual' query failed: SELECT *
...
Caused by: io.prestosql.spi.PrestoException: Expected response code from http://127.0.0.1:37611/v1/task/20201215_141157_00009_yzw2m.1.0?summarize to be 200, but was 500
java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator

@sopel39
Copy link
Member

sopel39 commented Dec 16, 2020

This is currently a decision that occurs at runtime based on how much memory is available in the cache, and so that might explain why this is non-deterministic. It seems like we have a couple options here:

Could we make static (and settable via feature/session toggle)?

@erichwang
Copy link
Contributor

erichwang commented Dec 16, 2020

Could we make static (and settable via feature/session toggle)?

We should fix this more properly, or maybe temporarily remove the check that was added until it is fixed.

@sopel39
Copy link
Member

sopel39 commented Dec 17, 2020

We should fix this more properly, or maybe temporarily remove the check that was added until it is fixed.

I think it's a good idea.

@findepi
Copy link
Member Author

findepi commented Jan 4, 2021

https://github.com/trinodb/trino/runs/1644344275

2021-01-04T17:33:00.9254663Z [ERROR] Tests run: 149, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 283.469 s <<< FAILURE! - in TestSuite
2021-01-04T17:33:00.9265760Z [ERROR] testHighCardinalityIndexJoinResult(io.trino.plugin.thrift.integration.TestThriftDistributedQueriesIndexed)  Time elapsed: 4.241 s  <<< FAILURE!
2021-01-04T17:33:00.9269931Z java.lang.AssertionError: 
2021-01-04T17:33:00.9273710Z Execution of 'actual' query failed: SELECT *
2021-01-04T17:33:00.9275787Z FROM (
2021-01-04T17:33:00.9277813Z   SELECT *
2021-01-04T17:33:00.9280055Z   FROM orders
2021-01-04T17:33:00.9283494Z   WHERE orderkey % 10000 = 0) o1
2021-01-04T17:33:00.9285356Z JOIN (
2021-01-04T17:33:00.9289136Z   SELECT *
2021-01-04T17:33:00.9291397Z   FROM orders
2021-01-04T17:33:00.9294595Z   WHERE orderkey % 4 = 0) o2
2021-01-04T17:33:00.9301021Z   ON o1.orderstatus = o2.orderstatus AND o1.shippriority = o2.shippriority
2021-01-04T17:33:00.9305226Z 	at org.testng.Assert.fail(Assert.java:83)
2021-01-04T17:33:00.9311627Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:150)
2021-01-04T17:33:00.9318557Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:106)
2021-01-04T17:33:00.9327494Z 	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:154)
2021-01-04T17:33:00.9337669Z 	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:149)
2021-01-04T17:33:00.9349920Z 	at io.trino.testing.AbstractTestIndexedQueries.testHighCardinalityIndexJoinResult(AbstractTestIndexedQueries.java:393)
2021-01-04T17:33:00.9359183Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-01-04T17:33:00.9367317Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-01-04T17:33:00.9376193Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-01-04T17:33:00.9382766Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-01-04T17:33:00.9390790Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-01-04T17:33:00.9397377Z 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2021-01-04T17:33:00.9403422Z 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2021-01-04T17:33:00.9409216Z 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2021-01-04T17:33:00.9415957Z 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2021-01-04T17:33:00.9422785Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2021-01-04T17:33:00.9432119Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-01-04T17:33:00.9442680Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-01-04T17:33:00.9448263Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2021-01-04T17:33:00.9457748Z Caused by: java.lang.RuntimeException: Expected response code from http://127.0.0.1:39987/v1/task/20210104_172904_00009_icnck.1.0?summarize to be 200, but was 500
2021-01-04T17:33:00.9466458Z java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
2021-01-04T17:33:00.9474510Z 	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:441)
2021-01-04T17:33:00.9481392Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:478)
2021-01-04T17:33:00.9488468Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:428)
2021-01-04T17:33:00.9497149Z 	at io.trino.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
2021-01-04T17:33:00.9505476Z 	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
2021-01-04T17:33:00.9514149Z 	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
2021-01-04T17:33:00.9523393Z 	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:459)
2021-01-04T17:33:00.9531347Z 	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:847)
2021-01-04T17:33:00.9538378Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:275)
2021-01-04T17:33:00.9545569Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:232)
2021-01-04T17:33:00.9552114Z 	at io.trino.operator.TaskContext.getTaskStats(TaskContext.java:417)
2021-01-04T17:33:00.9558114Z 	at io.trino.execution.SqlTask.getTaskStats(SqlTask.java:340)
2021-01-04T17:33:00.9564173Z 	at io.trino.execution.SqlTask.createTaskInfo(SqlTask.java:362)
2021-01-04T17:33:00.9570222Z 	at io.trino.execution.SqlTask.getTaskInfo(SqlTask.java:224)
2021-01-04T17:33:00.9576325Z 	at io.trino.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:316)
2021-01-04T17:33:00.9581930Z 	at io.trino.server.TaskResource.getTaskInfo(TaskResource.java:160)
2021-01-04T17:33:00.9588943Z 	at jdk.internal.reflect.GeneratedMethodAccessor289.invoke(Unknown Source)
2021-01-04T17:33:00.9600451Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-01-04T17:33:00.9606312Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-01-04T17:33:00.9616764Z 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
2021-01-04T17:33:00.9627959Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
2021-01-04T17:33:00.9638973Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
2021-01-04T17:33:00.9651255Z 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
2021-01-04T17:33:00.9667500Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
2021-01-04T17:33:00.9676363Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
2021-01-04T17:33:00.9684494Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
2021-01-04T17:33:00.9692249Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
2021-01-04T17:33:00.9698429Z 	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
2021-01-04T17:33:00.9703231Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
2021-01-04T17:33:00.9707677Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
2021-01-04T17:33:00.9712225Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
2021-01-04T17:33:00.9716955Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
2021-01-04T17:33:00.9721675Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
2021-01-04T17:33:00.9728371Z 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
2021-01-04T17:33:00.9734285Z 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
2021-01-04T17:33:00.9740280Z 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
2021-01-04T17:33:00.9747891Z 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
2021-01-04T17:33:00.9755806Z 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
2021-01-04T17:33:00.9762916Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
2021-01-04T17:33:00.9770133Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
2021-01-04T17:33:00.9777097Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
2021-01-04T17:33:00.9782491Z 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
2021-01-04T17:33:00.9788487Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1631)
2021-01-04T17:33:00.9793991Z 	at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
2021-01-04T17:33:00.9800176Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
2021-01-04T17:33:00.9805281Z 	at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
2021-01-04T17:33:00.9814271Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
2021-01-04T17:33:00.9822264Z 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
2021-01-04T17:33:00.9828359Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
2021-01-04T17:33:00.9834221Z 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
2021-01-04T17:33:00.9840161Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-01-04T17:33:00.9846476Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
2021-01-04T17:33:00.9852749Z 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
2021-01-04T17:33:00.9858789Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
2021-01-04T17:33:00.9864407Z 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
2021-01-04T17:33:00.9870301Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
2021-01-04T17:33:00.9876395Z 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
2021-01-04T17:33:00.9882209Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2021-01-04T17:33:00.9888601Z 	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
2021-01-04T17:33:00.9894974Z 	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
2021-01-04T17:33:00.9901714Z 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
2021-01-04T17:33:00.9910219Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-01-04T17:33:00.9916896Z 	at org.eclipse.jetty.server.Server.handle(Server.java:501)
2021-01-04T17:33:00.9924148Z 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
2021-01-04T17:33:00.9931010Z 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
2021-01-04T17:33:00.9937546Z 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
2021-01-04T17:33:00.9944915Z 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
2021-01-04T17:33:00.9953608Z 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
2021-01-04T17:33:00.9960227Z 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
2021-01-04T17:33:00.9967711Z 	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
2021-01-04T17:33:00.9977195Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
2021-01-04T17:33:00.9985944Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
2021-01-04T17:33:00.9994808Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
2021-01-04T17:33:01.0003172Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
2021-01-04T17:33:01.0013703Z 	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
2021-01-04T17:33:01.0022399Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
2021-01-04T17:33:01.0031272Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
2021-01-04T17:33:01.0036904Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2021-01-04T17:33:01.0038381Z 
2021-01-04T17:33:01.0045487Z 	at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:115)
2021-01-04T17:33:01.0051790Z 	at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:462)
2021-01-04T17:33:01.0062711Z 	at io.trino.plugin.thrift.integration.ThriftQueryRunner$ThriftQueryRunnerWithServers.execute(ThriftQueryRunner.java:258)
2021-01-04T17:33:01.0070765Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:147)
2021-01-04T17:33:01.0073495Z 	... 17 more
2021-01-04T17:33:01.0085538Z Caused by: io.trino.spi.TrinoException: Expected response code from http://127.0.0.1:39987/v1/task/20210104_172904_00009_icnck.1.0?summarize to be 200, but was 500
2021-01-04T17:33:01.0095664Z java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
2021-01-04T17:33:01.0102005Z 	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:441)
2021-01-04T17:33:01.0108260Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:478)
2021-01-04T17:33:01.0114090Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:428)
2021-01-04T17:33:01.0120414Z 	at io.trino.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
2021-01-04T17:33:01.0127911Z 	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
2021-01-04T17:33:01.0136861Z 	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
2021-01-04T17:33:01.0146140Z 	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:459)
2021-01-04T17:33:01.0154154Z 	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:847)
2021-01-04T17:33:01.0162063Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:275)
2021-01-04T17:33:01.0168232Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:232)
2021-01-04T17:33:01.0173142Z 	at io.trino.operator.TaskContext.getTaskStats(TaskContext.java:417)
2021-01-04T17:33:01.0177565Z 	at io.trino.execution.SqlTask.getTaskStats(SqlTask.java:340)
2021-01-04T17:33:01.0182305Z 	at io.trino.execution.SqlTask.createTaskInfo(SqlTask.java:362)
2021-01-04T17:33:01.0186687Z 	at io.trino.execution.SqlTask.getTaskInfo(SqlTask.java:224)
2021-01-04T17:33:01.0192153Z 	at io.trino.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:316)
2021-01-04T17:33:01.0198078Z 	at io.trino.server.TaskResource.getTaskInfo(TaskResource.java:160)
2021-01-04T17:33:01.0204379Z 	at jdk.internal.reflect.GeneratedMethodAccessor289.invoke(Unknown Source)
2021-01-04T17:33:01.0213888Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-01-04T17:33:01.0220917Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-01-04T17:33:01.0233316Z 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
2021-01-04T17:33:01.0244212Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
2021-01-04T17:33:01.0256101Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
2021-01-04T17:33:01.0267392Z 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
2021-01-04T17:33:01.0279078Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
2021-01-04T17:33:01.0289574Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
2021-01-04T17:33:01.0304376Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
2021-01-04T17:33:01.0313766Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
2021-01-04T17:33:01.0319853Z 	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
2021-01-04T17:33:01.0324460Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
2021-01-04T17:33:01.0329167Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
2021-01-04T17:33:01.0333839Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
2021-01-04T17:33:01.0338759Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
2021-01-04T17:33:01.0344161Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
2021-01-04T17:33:01.0351240Z 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
2021-01-04T17:33:01.0359160Z 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
2021-01-04T17:33:01.0368089Z 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
2021-01-04T17:33:01.0376443Z 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
2021-01-04T17:33:01.0384408Z 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
2021-01-04T17:33:01.0407559Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
2021-01-04T17:33:01.0410680Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
2021-01-04T17:33:01.0413811Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
2021-01-04T17:33:01.0416761Z 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
2021-01-04T17:33:01.0419521Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1631)
2021-01-04T17:33:01.0422350Z 	at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
2021-01-04T17:33:01.0425223Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
2021-01-04T17:33:01.0438496Z 	at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
2021-01-04T17:33:01.0440246Z 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
2021-01-04T17:33:01.0442312Z 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
2021-01-04T17:33:01.0444361Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
2021-01-04T17:33:01.0446656Z 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
2021-01-04T17:33:01.0448852Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-01-04T17:33:01.0451128Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
2021-01-04T17:33:01.0453440Z 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
2021-01-04T17:33:01.0455736Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
2021-01-04T17:33:01.0457832Z 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
2021-01-04T17:33:01.0469636Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
2021-01-04T17:33:01.0472077Z 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
2021-01-04T17:33:01.0474664Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2021-01-04T17:33:01.0527590Z 	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
2021-01-04T17:33:01.0530298Z 	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
2021-01-04T17:33:01.0532648Z 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
2021-01-04T17:33:01.0545431Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-01-04T17:33:01.0547335Z 	at org.eclipse.jetty.server.Server.handle(Server.java:501)
2021-01-04T17:33:01.0548918Z 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
2021-01-04T17:33:01.0550699Z 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
2021-01-04T17:33:01.0552451Z 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
2021-01-04T17:33:01.0554379Z 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
2021-01-04T17:33:01.0556470Z 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
2021-01-04T17:33:01.0558351Z 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
2021-01-04T17:33:01.0559937Z 	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
2021-01-04T17:33:01.0562062Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
2021-01-04T17:33:01.0564655Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
2021-01-04T17:33:01.0567774Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
2021-01-04T17:33:01.0570483Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
2021-01-04T17:33:01.0573127Z 	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
2021-01-04T17:33:01.0575698Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
2021-01-04T17:33:01.0577965Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
2021-01-04T17:33:01.0579434Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2021-01-04T17:33:01.0579933Z 
2021-01-04T17:33:01.0581707Z 	at io.trino.server.remotetask.SimpleHttpResponseHandler.onSuccess(SimpleHttpResponseHandler.java:62)
2021-01-04T17:33:01.0584966Z 	at io.trino.server.remotetask.SimpleHttpResponseHandler.onSuccess(SimpleHttpResponseHandler.java:27)
2021-01-04T17:33:01.0587308Z 	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1089)
2021-01-04T17:33:01.0589291Z 	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:80)
2021-01-04T17:33:01.0591473Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-01-04T17:33:01.0593822Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-01-04T17:33:01.0595215Z 	at java.base/java.lang.Thread.run(Thread.java:834)
2021-01-04T17:33:01.0595712Z 
2021-01-04T17:33:01.4751390Z [INFO] 
2021-01-04T17:33:01.4752174Z [INFO] Results:
2021-01-04T17:33:01.4752689Z [INFO] 
2021-01-04T17:33:01.4753269Z [ERROR] Failures: 
2021-01-04T17:33:01.4776969Z [ERROR]   TestThriftDistributedQueriesIndexed>AbstractTestIndexedQueries.testHighCardinalityIndexJoinResult:393->AbstractTestQueryFramework.assertQuery:149->AbstractTestQueryFramework.assertQuery:154 Execution of 'actual' query failed: SELECT *
2021-01-04T17:33:01.4782677Z FROM (
2021-01-04T17:33:01.4783310Z   SELECT *
2021-01-04T17:33:01.4783969Z   FROM orders
2021-01-04T17:33:01.4784739Z   WHERE orderkey % 10000 = 0) o1
2021-01-04T17:33:01.4785443Z JOIN (
2021-01-04T17:33:01.4786039Z   SELECT *
2021-01-04T17:33:01.4786708Z   FROM orders
2021-01-04T17:33:01.4787446Z   WHERE orderkey % 4 = 0) o2
2021-01-04T17:33:01.4788797Z   ON o1.orderstatus = o2.orderstatus AND o1.shippriority = o2.shippriority
2021-01-04T17:33:01.4790320Z [INFO] 
2021-01-04T17:33:01.4791232Z [ERROR] Tests run: 149, Failures: 1, Errors: 0, Skipped: 0

@kokosing
Copy link
Member

kokosing commented Mar 8, 2021

Hit with #7214

@findepi
Copy link
Member Author

findepi commented Mar 19, 2021

@zhangchunyang1024
Copy link
Contributor

zhangchunyang1024 commented May 7, 2021

That's what happened to me:
Expected response code from http://192.168.220.197:8285/v1/task/20210507_062707_00311_a887g.3.0?summarize to be 200, but was 500
java.lang.IllegalArgumentException: Expected operatorType to be ScanFilterAndProjectOperator but was WorkProcessorPipelineSourceOperator
at com.google.common.base.Preconditions.checkArgument(Preconditions.java:441)
at io.trino.operator.OperatorStats.add(OperatorStats.java:478)
at io.trino.operator.OperatorStats.add(OperatorStats.java:428)
at io.trino.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:459)
at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:848)
at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:276)
at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:233)
at io.trino.operator.TaskContext.getTaskStats(TaskContext.java:417)
at io.trino.execution.SqlTask.getTaskStats(SqlTask.java:350)
at io.trino.execution.SqlTask.createTaskInfo(SqlTask.java:372)
at io.trino.execution.SqlTask.getTaskInfo(SqlTask.java:234)
at io.trino.execution.SqlTask.updateTask(SqlTask.java:454)
at io.trino.execution.SqlTaskManager.doUpdateTask(SqlTaskManager.java:403)
at io.trino.execution.SqlTaskManager.lambda$updateTask$6(SqlTaskManager.java:373)
at io.trino.$gen.Trino_353_5_gb9ea641_dirty____20210506_091455_2.call(Unknown Source)
at io.trino.execution.SqlTaskManager.updateTask(SqlTaskManager.java:373)
at io.trino.server.TaskResource.createOrUpdateTask(TaskResource.java:132)
at jdk.internal.reflect.GeneratedMethodAccessor464.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:200)
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1631)
at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:501)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
at java.base/java.lang.Thread.run(Thread.java:835)

@findepi
Copy link
Member Author

findepi commented Jun 8, 2021

https://github.com/trinodb/trino/runs/2771822401

Error:  Tests run: 116, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 216.359 s <<< FAILURE! - in TestSuite
Error:  testHighCardinalityIndexJoinResult(io.trino.plugin.thrift.integration.TestThriftDistributedQueriesIndexed)  Time elapsed: 3.626 s  <<< FAILURE!
java.lang.AssertionError: 
Execution of 'actual' query failed: SELECT *
FROM (
  SELECT *
  FROM orders
  WHERE orderkey % 10000 = 0) o1
JOIN (
  SELECT *
  FROM orders
  WHERE orderkey % 4 = 0) o2
  ON o1.orderstatus = o2.orderstatus AND o1.shippriority = o2.shippriority
	at org.testng.Assert.fail(Assert.java:83)
	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:150)
	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:106)
	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:162)
	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:157)
	at io.trino.testing.AbstractTestIndexedQueries.testHighCardinalityIndexJoinResult(AbstractTestIndexedQueries.java:393)
	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.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.RuntimeException: Expected response code from http://127.0.0.1:43677/v1/task/20210608_094437_00009_45c46.1.0?summarize to be 200, but was 500
java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:443)
	at io.trino.operator.OperatorStats.add(OperatorStats.java:478)
	at io.trino.operator.OperatorStats.add(OperatorStats.java:428)
	at io.trino.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:467)
	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:854)
	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:276)
	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:233)
	at io.trino.operator.TaskContext.getTaskStats(TaskContext.java:417)
	at io.trino.execution.SqlTask.getTaskStats(SqlTask.java:350)
	at io.trino.execution.SqlTask.createTaskInfo(SqlTask.java:372)
	at io.trino.execution.SqlTask.getTaskInfo(SqlTask.java:234)
	at io.trino.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:318)
	at io.trino.server.TaskResource.getTaskInfo(TaskResource.java:160)
	at jdk.internal.reflect.GeneratedMethodAccessor337.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791)

@hashhar
Copy link
Member

hashhar commented Jun 29, 2021

@findepi
Copy link
Member Author

findepi commented Jul 23, 2021

https://github.com/trinodb/trino/runs/3144400785 (in #8645)

2021-07-23T15:26:47.2683828Z [ERROR] testHighCardinalityReducedIndexProbeKey(io.trino.plugin.thrift.integration.TestThriftDistributedQueriesIndexed)  Time elapsed: 4.582 s  <<< FAILURE!
2021-07-23T15:26:47.2692056Z java.lang.AssertionError: 
2021-07-23T15:26:47.2693432Z Execution of 'actual' query failed: SELECT *
2021-07-23T15:26:47.2694231Z FROM (
2021-07-23T15:26:47.2763782Z   SELECT *, custkey % 4 AS x, custkey % 2 AS y
2021-07-23T15:26:47.2765039Z   FROM orders
2021-07-23T15:26:47.2765737Z   WHERE orderkey % 10000 = 0) o1
2021-07-23T15:26:47.2766372Z JOIN (
2021-07-23T15:26:47.2767025Z   SELECT *, custkey % 5 AS x, custkey % 3 AS y
2021-07-23T15:26:47.2767723Z   FROM orders
2021-07-23T15:26:47.2768342Z   WHERE orderkey % 4 = 0) o2
2021-07-23T15:26:47.2769410Z   ON o1.orderstatus = o2.orderstatus AND o1.shippriority = o2.shippriority AND o1.x = o2.x AND o1.y = o2.y
2021-07-23T15:26:47.2770587Z 	at org.testng.Assert.fail(Assert.java:83)
2021-07-23T15:26:47.2772061Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:150)
2021-07-23T15:26:47.2775462Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:106)
2021-07-23T15:26:47.2778060Z 	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:162)
2021-07-23T15:26:47.2781710Z 	at io.trino.testing.AbstractTestQueryFramework.assertQuery(AbstractTestQueryFramework.java:157)
2021-07-23T15:26:47.2785814Z 	at io.trino.testing.AbstractTestIndexedQueries.testHighCardinalityReducedIndexProbeKey(AbstractTestIndexedQueries.java:442)
2021-07-23T15:26:47.2789388Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-23T15:26:47.2791859Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2021-07-23T15:26:47.2796426Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-07-23T15:26:47.2798620Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-07-23T15:26:47.2800755Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2021-07-23T15:26:47.2806568Z 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2021-07-23T15:26:47.2808359Z 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2021-07-23T15:26:47.2810246Z 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2021-07-23T15:26:47.2813489Z 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2021-07-23T15:26:47.2815776Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2021-07-23T15:26:47.2817933Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-07-23T15:26:47.2820178Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-07-23T15:26:47.2821715Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-07-23T15:26:47.2823164Z Caused by: java.lang.RuntimeException: Expected response code from http://127.0.0.1:36161/v1/task/20210723_152241_00010_mj3yk.1.2?summarize to be 200, but was 500
2021-07-23T15:26:47.2825598Z java.lang.IllegalArgumentException: Expected operatorType to be PagesIndexBuilderOperator but was PageBufferOperator
2021-07-23T15:26:47.2827852Z 	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:443)
2021-07-23T15:26:47.2832001Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:489)
2021-07-23T15:26:47.2833936Z 	at io.trino.operator.OperatorStats.add(OperatorStats.java:438)
2021-07-23T15:26:47.2835807Z 	at io.trino.operator.PipelineContext.getPipelineStats(PipelineContext.java:413)
2021-07-23T15:26:47.2843099Z 	at com.google.common.collect.Iterators$6.transform(Iterators.java:783)
2021-07-23T15:26:47.2844875Z 	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
2021-07-23T15:26:47.2847004Z 	at com.google.common.collect.ImmutableCollection$Builder.addAll(ImmutableCollection.java:467)
2021-07-23T15:26:47.2857113Z 	at com.google.common.collect.ImmutableList$Builder.addAll(ImmutableList.java:854)
2021-07-23T15:26:47.2858860Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:276)
2021-07-23T15:26:47.2860654Z 	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:233)
2021-07-23T15:26:47.2862329Z 	at io.trino.operator.TaskContext.getTaskStats(TaskContext.java:424)
2021-07-23T15:26:47.2863816Z 	at io.trino.execution.SqlTask.getTaskStats(SqlTask.java:353)
2021-07-23T15:26:47.2865199Z 	at io.trino.execution.SqlTask.createTaskInfo(SqlTask.java:375)
2021-07-23T15:26:47.2866585Z 	at io.trino.execution.SqlTask.getTaskInfo(SqlTask.java:237)
2021-07-23T15:26:47.2868140Z 	at io.trino.execution.SqlTaskManager.getTaskInfo(SqlTaskManager.java:321)
2021-07-23T15:26:47.2869782Z 	at io.trino.server.TaskResource.getTaskInfo(TaskResource.java:161)
2021-07-23T15:26:47.2871587Z 	at jdk.internal.reflect.GeneratedMethodAccessor336.invoke(Unknown Source)
2021-07-23T15:26:47.2874447Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2021-07-23T15:26:47.2876635Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2021-07-23T15:26:47.2879924Z 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
2021-07-23T15:26:47.2885422Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
2021-07-23T15:26:47.2890378Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
2021-07-23T15:26:47.2895559Z 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183)
2021-07-23T15:26:47.2900784Z 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
2021-07-23T15:26:47.2904997Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
2021-07-23T15:26:47.2907879Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
2021-07-23T15:26:47.2912704Z 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
2021-07-23T15:26:47.2915029Z 	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
2021-07-23T15:26:47.2916474Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
2021-07-23T15:26:47.2917741Z 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
2021-07-23T15:26:47.2919138Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
2021-07-23T15:26:47.2920690Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
2021-07-23T15:26:47.2922381Z 	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
2021-07-23T15:26:47.2924480Z 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
2021-07-23T15:26:47.2926799Z 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
2021-07-23T15:26:47.2928917Z 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
2021-07-23T15:26:47.2931140Z 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
2021-07-23T15:26:47.2933166Z 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
2021-07-23T15:26:47.2935255Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
2021-07-23T15:26:47.2937492Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
2021-07-23T15:26:47.2939754Z 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
2021-07-23T15:26:47.2941807Z 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
2021-07-23T15:26:47.2943627Z 	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626)
2021-07-23T15:26:47.2945541Z 	at io.airlift.http.server.TraceTokenFilter.doFilter(TraceTokenFilter.java:63)
2021-07-23T15:26:47.2947441Z 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
2021-07-23T15:26:47.2949256Z 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
2021-07-23T15:26:47.2950979Z 	at io.airlift.http.server.TimingFilter.doFilter(TimingFilter.java:51)
2021-07-23T15:26:47.2952763Z 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
2021-07-23T15:26:47.2954652Z 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
2021-07-23T15:26:47.2956517Z 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
2021-07-23T15:26:47.2958752Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
2021-07-23T15:26:47.2960949Z 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:763)
2021-07-23T15:26:47.2964134Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-07-23T15:26:47.2966473Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
2021-07-23T15:26:47.2968830Z 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
2021-07-23T15:26:47.2971181Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
2021-07-23T15:26:47.2973313Z 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
2021-07-23T15:26:47.2975467Z 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
2021-07-23T15:26:47.2977764Z 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
2021-07-23T15:26:47.2980035Z 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2021-07-23T15:26:47.2982350Z 	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
2021-07-23T15:26:47.2984807Z 	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:179)
2021-07-23T15:26:47.2987046Z 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
2021-07-23T15:26:47.2989154Z 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
2021-07-23T15:26:47.2990961Z 	at org.eclipse.jetty.server.Server.handle(Server.java:516)
2021-07-23T15:26:48.0016047Z 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
2021-07-23T15:26:48.0018491Z 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
2021-07-23T15:26:48.0020410Z 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
2021-07-23T15:26:48.0022417Z 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
2021-07-23T15:26:48.0024637Z 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
2021-07-23T15:26:48.0028756Z 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
2021-07-23T15:26:48.0030305Z 	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
2021-07-23T15:26:48.0032315Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
2021-07-23T15:26:48.0034932Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
2021-07-23T15:26:48.0037673Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
2021-07-23T15:26:48.0040212Z 	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
2021-07-23T15:26:48.0043187Z 	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
2021-07-23T15:26:48.0045824Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
2021-07-23T15:26:48.0047933Z 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
2021-07-23T15:26:48.0049706Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2021-07-23T15:26:48.0050225Z 
2021-07-23T15:26:48.0051741Z 	at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:120)
2021-07-23T15:26:48.0054228Z 	at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:476)
2021-07-23T15:26:48.0058391Z 	at io.trino.plugin.thrift.integration.ThriftQueryRunner$ThriftQueryRunnerWithServers.execute(ThriftQueryRunner.java:258)
2021-07-23T15:26:48.0066574Z 	at io.trino.testing.QueryAssertions.assertQuery(QueryAssertions.java:147)
2021-07-23T15:26:48.0074590Z 	... 17 more

@ebyhr
Copy link
Member

ebyhr commented Jan 5, 2022

@findepi
Copy link
Member Author

findepi commented Feb 28, 2022

@ebyhr
Copy link
Member

ebyhr commented Mar 9, 2022

@phd3
Copy link
Member

phd3 commented Mar 9, 2022

@findepi
Copy link
Member Author

findepi commented Mar 22, 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
Development

Successfully merging a pull request may close this issue.

8 participants