[flaky tests] MultiStageEngineIntegrationTest
- Dominant language
- Java
- Stars
- 6.1k
- Forks
- 1.5k
- Avg merge
- 2d 3h
- Merged PRs (30d)
- 195
Description
https://github.com/apache/pinot/actions/runs/6523552716/attempts/1?pr=11782
```
2023-10-15T11:03:02.4807195Z [INFO] Running org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest
2023-10-15T11:03:04.8434214Z 11:03:04.828 ERROR [ZkAsyncCallbacks] [ZkClient-EventThread-36-localhost:2191] Interrupted waiting for success
2023-10-15T11:03:04.8435288Z java.lang.InterruptedException: null
2023-10-15T11:03:04.8435904Z at java.lang.Object.wait0(Native Method) ~[?:?]
2023-10-15T11:03:04.8436563Z at java.lang.Object.wait(Object.java:366) ~[?:?]
2023-10-15T11:03:04.8437701Z at java.lang.Object.wait(Object.java:339) ~[?:?]
2023-10-15T11:03:04.8439330Z at org.apache.helix.zookeeper.zkclient.callback.ZkAsyncCallbacks$DefaultCallback.waitForSuccess(ZkAsyncCallbacks.java:265) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:04.8441326Z at org.apache.helix.zookeeper.zkclient.ZkClient.issueSync(ZkClient.java:1692) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:04.8442936Z at org.apache.helix.zookeeper.zkclient.ZkClient$4.run(ZkClient.java:1718) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:04.8444550Z at org.apache.helix.zookeeper.zkclient.ZkEventThread.run(ZkEventThread.java:97) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:07.2494523Z 11:03:07.180 WARN [ServiceStartableUtils] [main] Failed to find cluster config for cluster: MultiStageEngineIntegrationTest, skipping applying cluster config
2023-10-15T11:03:09.5686934Z 11:03:09.553 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(5911e591_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:09.6688319Z 11:03:09.587 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(6b93ddc9_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:09.6692839Z 11:03:09.600 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(12e30027_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:09.6696908Z 11:03:09.626 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(4607eda4_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:09.6700942Z 11:03:09.645 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(fc1a711f_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:09.6705542Z 11:03:09.658 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(362b09df_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:10.2697410Z 11:03:10.179 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(86a608ce_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:10.2702315Z 11:03:10.231 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(d1c9d51e_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:10.2708145Z 11:03:10.262 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(207704dc_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:10.3699143Z 11:03:10.284 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(4dc4990a_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
2023-10-15T11:03:13.1776642Z Oct 15, 2023 11:03:13 AM org.glassfish.grizzly.http.server.NetworkListener start
2023-10-15T11:03:13.1777569Z INFO: Started listener bound to [0.0.0.0:18998]
2023-10-15T11:03:13.1778380Z Oct 15, 2023 11:03:13 AM org.glassfish.grizzly.http.server.HttpServer start
2023-10-15T11:03:13.1779144Z INFO: [HttpServer] Started.
2023-10-15T11:03:14.1778935Z linux
2023-10-15T11:03:14.8812284Z 11:03:14.866 WARN [Tracing] [main] No thread accountant factory provided, using default implementation
2023-10-15T11:03:15.0793090Z Oct 15, 2023 11:03:15 AM org.glassfish.grizzly.http.server.NetworkListener start
2023-10-15T11:03:15.0794700Z INFO: Started listener bound to [0.0.0.0:18099]
2023-10-15T11:03:15.0795939Z Oct 15, 2023 11:03:15 AM org.glassfish.grizzly.http.server.HttpServer start
2023-10-15T11:03:15.0797510Z INFO: [HttpServer-1] Started.
2023-10-15T11:03:15.1798692Z 11:03:15.091 ERROR [ZkAsyncCallbacks] [ZkClient-EventThread-201-localhost:2191] Interrupted waiting for success
2023-10-15T11:03:15.1799980Z java.lang.InterruptedException: null
2023-10-15T11:03:15.1800657Z at java.lang.Object.wait0(Native Method) ~[?:?]
2023-10-15T11:03:15.1801378Z at java.lang.Object.wait(Object.java:366) ~[?:?]
2023-10-15T11:03:15.1802094Z at java.lang.Object.wait(Object.java:339) ~[?:?]
2023-10-15T11:03:15.1803791Z at org.apache.helix.zookeeper.zkclient.callback.ZkAsyncCallbacks$DefaultCallback.waitForSuccess(ZkAsyncCallbacks.java:265) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:15.1805850Z at org.apache.helix.zookeeper.zkclient.ZkClient.issueSync(ZkClient.java:1692) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:15.1807542Z at org.apache.helix.zookeeper.zkclient.ZkClient$4.run(ZkClient.java:1718) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:15.1809247Z at org.apache.helix.zookeeper.zkclient.ZkEventThread.run(ZkEventThread.java:97) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:03:17.5921761Z 11:03:17.506 WARN [ZKMetadataProvider] [main] Path: /CONFIGS/TABLE does not exist
2023-10-15T11:03:17.5923542Z 11:03:17.509 WARN [HelixHelper] [main] Idempotent or null ideal state update for resource brokerResource, skipping update.
2023-10-15T11:03:18.2936409Z 11:03:18.291 WARN [Tracing] [main] No thread accountant factory provided, using default implementation
2023-10-15T11:03:18.6966287Z Oct 15, 2023 11:03:18 AM org.glassfish.grizzly.http.server.NetworkListener start
2023-10-15T11:03:18.6967223Z INFO: Started listener bound to [0.0.0.0:8097]
2023-10-15T11:03:18.6968034Z Oct 15, 2023 11:03:18 AM org.glassfish.grizzly.http.server.HttpServer start
2023-10-15T11:03:18.6969081Z INFO: [HttpServer-2] Started.
2023-10-15T11:03:50.3747291Z 11:03:50.368 WARN [MultiStageBrokerRequestHandler] [jersey-server-managed-async-executor-1] Caught exception planning request 1460816244000000012: SELECT toBase64('hello!') FROM mytable, Error composing query plan for: SELECT toBase64('hello!') FROM mytable
2023-10-15T11:03:50.3749742Z org.apache.pinot.query.QueryEnvironment.planQuery(QueryEnvironment.java:182)
2023-10-15T11:03:50.3751355Z org.apache.pinot.broker.requesthandler.MultiStageBrokerRequestHandler.handleRequest(MultiStageBrokerRequestHandler.java:138)
2023-10-15T11:03:50.3753278Z org.apache.pinot.broker.requesthandler.BaseBrokerRequestHandler.handleRequest(BaseBrokerRequestHandler.java:279)
2023-10-15T11:03:50.3755024Z org.apache.pinot.broker.requesthandler.BrokerRequestHandler.handleRequest(BrokerRequestHandler.java:48)
2023-10-15T11:03:50.3756407Z value hello! does not match type class org.apache.calcite.avatica.util.ByteString
2023-10-15T11:03:50.3757785Z org.apache.calcite.linq4j.tree.ConstantExpression.(ConstantExpression.java:51)
2023-10-15T11:03:50.3758984Z org.apache.calcite.linq4j.tree.Expressions.constant(Expressions.java:576)
2023-10-15T11:03:50.3760115Z org.apache.calcite.linq4j.tree.OptimizeShuttle.visit(OptimizeShuttle.java:291)
2023-10-15T11:03:50.3761290Z org.apache.calcite.linq4j.tree.UnaryExpression.accept(UnaryExpression.java:39)
2023-10-15T11:03:50.3761979Z
2023-10-15T11:03:50.4742832Z 11:03:50.417 WARN [MultiStageBrokerRequestHandler] [jersey-server-managed-async-executor-1] Caught exception planning request 1460816244000000013: SELECT fromBase64('hello!') FROM mytable, Error composing query plan for: SELECT fromBase64('hello!') FROM mytable
2023-10-15T11:03:50.4745432Z org.apache.pinot.query.QueryEnvironment.planQuery(QueryEnvironment.java:182)
2023-10-15T11:03:50.4747044Z org.apache.pinot.broker.requesthandler.MultiStageBrokerRequestHandler.handleRequest(MultiStageBrokerRequestHandler.java:138)
2023-10-15T11:03:50.4749018Z org.apache.pinot.broker.requesthandler.BaseBrokerRequestHandler.handleRequest(BaseBrokerRequestHandler.java:279)
2023-10-15T11:03:50.4750783Z org.apache.pinot.broker.requesthandler.BrokerRequestHandler.handleRequest(BrokerRequestHandler.java:48)
2023-10-15T11:03:50.4752463Z Cannot generate a valid execution plan for the given query: LogicalProject(EXPR$0=[fromBase64('hello!')])
2023-10-15T11:03:50.4753421Z LogicalTableScan(table=[[mytable]])
2023-10-15T11:03:50.4753772Z
2023-10-15T11:03:50.4754256Z org.apache.pinot.query.QueryEnvironment.optimize(QueryEnvironment.java:342)
2023-10-15T11:03:50.4755405Z org.apache.pinot.query.QueryEnvironment.compileQuery(QueryEnvironment.java:284)
2023-10-15T11:03:50.4756578Z org.apache.pinot.query.QueryEnvironment.planQuery(QueryEnvironment.java:173)
2023-10-15T11:03:50.4762708Z org.apache.pinot.broker.requesthandler.MultiStageBrokerRequestHandler.handleRequest(MultiStageBrokerRequestHandler.java:138)
2023-10-15T11:03:50.4764999Z Caught exception while invoking method: public static byte[] org.apache.pinot.common.function.scalar.StringFunctions.fromBase64(java.lang.String) with arguments: [hello!]
2023-10-15T11:03:50.4767194Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule.evaluateLiteralOnlyFunction(PinotEvaluateLiteralRule.java:164)
2023-10-15T11:03:50.4769089Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule$EvaluateLiteralShuttle.visitCall(PinotEvaluateLiteralRule.java:131)
2023-10-15T11:03:50.4770910Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule$EvaluateLiteralShuttle.visitCall(PinotEvaluateLiteralRule.java:119)
2023-10-15T11:03:50.4772221Z org.apache.calcite.rex.RexCall.accept(RexCall.java:189)
2023-10-15T11:03:50.4773840Z Caught exception while invoking method: public static byte[] org.apache.pinot.common.function.scalar.StringFunctions.fromBase64(java.lang.String) with arguments: [hello!]
2023-10-15T11:03:50.4775654Z org.apache.pinot.common.function.FunctionInvoker.invoke(FunctionInvoker.java:142)
2023-10-15T11:03:50.4777233Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule.evaluateLiteralOnlyFunction(PinotEvaluateLiteralRule.java:161)
2023-10-15T11:03:50.4779685Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule$EvaluateLiteralShuttle.visitCall(PinotEvaluateLiteralRule.java:131)
2023-10-15T11:03:50.4781684Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule$EvaluateLiteralShuttle.visitCall(PinotEvaluateLiteralRule.java:119)
2023-10-15T11:03:50.4782855Z null
2023-10-15T11:03:50.4783696Z java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:119)
2023-10-15T11:03:50.4784870Z java.base/java.lang.reflect.Method.invoke(Method.java:578)
2023-10-15T11:03:50.4785883Z org.apache.pinot.common.function.FunctionInvoker.invoke(FunctionInvoker.java:139)
2023-10-15T11:03:50.4787458Z org.apache.calcite.rel.rules.PinotEvaluateLiteralRule.evaluateLiteralOnlyFunction(PinotEvaluateLiteralRule.java:161)
2023-10-15T11:03:50.4788656Z Illegal base64 character 21
2023-10-15T11:03:50.4789246Z java.base/java.util.Base64$Decoder.decode0(Base64.java:848)
2023-10-15T11:03:50.4790019Z java.base/java.util.Base64$Decoder.decode(Base64.java:566)
2023-10-15T11:03:50.4790788Z java.base/java.util.Base64$Decoder.decode(Base64.java:589)
2023-10-15T11:03:50.4791892Z org.apache.pinot.common.function.scalar.StringFunctions.fromBase64(StringFunctions.java:670)
2023-10-15T11:03:50.4792709Z
2023-10-15T11:04:39.4664317Z 11:04:39.437 WARN [SegmentDeletionManager] [grizzly-http-server-1] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1697367783538/mytable/mytable_16160_16189_6+%25
2023-10-15T11:04:39.4667209Z 11:04:39.437 WARN [SegmentDeletionManager] [grizzly-http-server-1] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1697367783538/mytable/mytable_16221_16250_8+%25
2023-10-15T11:04:39.4670059Z 11:04:39.438 WARN [SegmentDeletionManager] [grizzly-http-server-1] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1697367783538/mytable/mytable_16282_16312_10+%25
2023-10-15T11:04:39.4672929Z 11:04:39.438 WARN [SegmentDeletionManager] [grizzly-http-server-1] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1697367783538/mytable/mytable_16313_16342_11+%25
2023-10-15T11:04:39.4675994Z 11:04:39.438 WARN [SegmentDeletionManager] [grizzly-http-server-1] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1697367783538/mytable/mytable_16343_16373_0+%25
2023-10-15T11:04:39.7657772Z 11:04:39.707 ERROR [mytable_OFFLINE-TableDeletionMessageHandler] [HelixTaskExecutor-message_handle_thread_53] onError: INTERNAL, CANCEL
2023-10-15T11:04:39.7659093Z java.lang.InterruptedException: sleep interrupted
2023-10-15T11:04:39.7659766Z at java.lang.Thread.sleep0(Native Method) ~[?:?]
2023-10-15T11:04:39.7660427Z at java.lang.Thread.sleep(Thread.java:484) [?:?]
2023-10-15T11:04:39.7662504Z at org.apache.pinot.server.starter.helix.HelixInstanceDataManager.deleteTable(HelixInstanceDataManager.java:277) ~[pinot-server-1.1.0-SNAPSHOT.jar:1.1.0-SNAPSHOT-ebf24007b2eb9848107205eb40c73b43076230c7]
2023-10-15T11:04:39.7666075Z at org.apache.pinot.server.starter.helix.SegmentMessageHandlerFactory$TableDeletionMessageHandler.handleMessage(SegmentMessageHandlerFactory.java:174) ~[pinot-server-1.1.0-SNAPSHOT.jar:1.1.0-SNAPSHOT-ebf24007b2eb9848107205eb40c73b43076230c7]
2023-10-15T11:04:39.7668691Z at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:97) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:39.7670844Z at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:49) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:39.7696696Z at java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
2023-10-15T11:04:39.7698171Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
2023-10-15T11:04:39.7699444Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
2023-10-15T11:04:39.7700362Z at java.lang.Thread.run(Thread.java:1623) [?:?]
2023-10-15T11:04:39.8658681Z 11:04:39.834 ERROR [DataTableHandler] [nioEventLoopGroup-2-1] Channel for server: localhost_O is now inactive, marking server down
2023-10-15T11:04:39.9662865Z Oct 15, 2023 11:04:39 AM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
2023-10-15T11:04:39.9664592Z INFO: Stopped listener bound to [0.0.0.0:8097]
2023-10-15T11:04:40.0661546Z Oct 15, 2023 11:04:40 AM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
2023-10-15T11:04:40.0662533Z INFO: Stopped listener bound to [0.0.0.0:18099]
2023-10-15T11:04:40.0664739Z 11:04:40.022 WARN [ClusterChangeMediator] [Cleanup thread for MultiStageEngineIntegrationTest-Broker_10.1.0.17_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the IDEAL_STATE change
2023-10-15T11:04:40.0667732Z 11:04:40.024 WARN [ClusterChangeMediator] [Cleanup thread for MultiStageEngineIntegrationTest-Broker_10.1.0.17_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the EXTERNAL_VIEW change
2023-10-15T11:04:40.0670708Z 11:04:40.024 WARN [ClusterChangeMediator] [Cleanup thread for MultiStageEngineIntegrationTest-Broker_10.1.0.17_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the INSTANCE_CONFIG change
2023-10-15T11:04:40.1662690Z Oct 15, 2023 11:04:40 AM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
2023-10-15T11:04:40.1663713Z INFO: Stopped listener bound to [0.0.0.0:18998]
2023-10-15T11:04:40.3670365Z 11:04:40.277 ERROR [WagedRebalancer] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(b00367ed_DEFAULT)] Failed to calculate the new assignments.
2023-10-15T11:04:40.3673615Z org.apache.helix.HelixRebalanceException: Failed to get the current best possible assignment because of unexpected error. Failure Type: INVALID_REBALANCER_STATUS
2023-10-15T11:04:40.3676548Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:92) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3679963Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.emergencyRebalance(WagedRebalancer.java:459) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3682932Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeBestPossibleAssignment(WagedRebalancer.java:336) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3685877Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeBestPossibleStates(WagedRebalancer.java:313) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3688719Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeNewIdealStates(WagedRebalancer.java:248) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3693437Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.computeResourceBestPossibleStateWithWagedRebalancer(BestPossibleStateCalcStage.java:314) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3696650Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.compute(BestPossibleStateCalcStage.java:168) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3699210Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.process(BestPossibleStateCalcStage.java:88) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3701414Z at org.apache.helix.controller.pipeline.Pipeline.handle(Pipeline.java:75) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3703514Z at org.apache.helix.controller.GenericHelixController.handleEvent(GenericHelixController.java:903) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3719974Z at org.apache.helix.controller.GenericHelixController$ClusterEventProcessor.run(GenericHelixController.java:1554) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3722035Z Caused by: org.apache.helix.zookeeper.zkclient.exception.ZkInterruptedException: java.lang.InterruptedException
2023-10-15T11:04:40.3724055Z at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:2097) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3725809Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3727916Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2235) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3729783Z at org.apache.helix.manager.zk.ZkBaseDataAccessor.get(ZkBaseDataAccessor.java:495) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3731736Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:271) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3733870Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:249) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3736316Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.fetchAssignmentOrDefault(AssignmentMetadataStore.java:94) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3739033Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.getBestPossibleAssignment(AssignmentMetadataStore.java:85) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3741630Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:89) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3743020Z ... 10 more
2023-10-15T11:04:40.3743430Z Caused by: java.lang.InterruptedException
2023-10-15T11:04:40.3744053Z at java.lang.Object.wait0(Native Method) ~[?:?]
2023-10-15T11:04:40.3744698Z at java.lang.Object.wait(Object.java:366) ~[?:?]
2023-10-15T11:04:40.3745337Z at java.lang.Object.wait(Object.java:339) ~[?:?]
2023-10-15T11:04:40.3746448Z at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1594) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3747942Z at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1566) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3749375Z at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:2356) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3750728Z at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:2385) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3752300Z at org.apache.helix.zookeeper.zkclient.ZkConnection.readData(ZkConnection.java:196) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3753964Z at org.apache.helix.zookeeper.zkclient.ZkClient$12.call(ZkClient.java:2248) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3755519Z at org.apache.helix.zookeeper.zkclient.ZkClient$12.call(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3757415Z at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:2079) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3759144Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3760767Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2235) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3762445Z at org.apache.helix.manager.zk.ZkBaseDataAccessor.get(ZkBaseDataAccessor.java:495) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3764396Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:271) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3766529Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:249) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3768993Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.fetchAssignmentOrDefault(AssignmentMetadataStore.java:94) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3771709Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.getBestPossibleAssignment(AssignmentMetadataStore.java:85) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3774305Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:89) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3775692Z ... 10 more
2023-10-15T11:04:40.3777894Z 11:04:40.280 ERROR [BestPossibleStateCalcStage] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(b00367ed_DEFAULT)] Event b00367ed_DEFAULT : Failed to calculate the new Ideal States using the rebalancer WagedRebalancer due to INVALID_REBALANCER_STATUS
2023-10-15T11:04:40.3781169Z org.apache.helix.HelixRebalanceException: Failed to get the current best possible assignment because of unexpected error. Failure Type: INVALID_REBALANCER_STATUS
2023-10-15T11:04:40.3783590Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:92) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3785993Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.emergencyRebalance(WagedRebalancer.java:459) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3788422Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeBestPossibleAssignment(WagedRebalancer.java:336) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3790896Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeBestPossibleStates(WagedRebalancer.java:313) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3793288Z at org.apache.helix.controller.rebalancer.waged.WagedRebalancer.computeNewIdealStates(WagedRebalancer.java:248) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3796129Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.computeResourceBestPossibleStateWithWagedRebalancer(BestPossibleStateCalcStage.java:314) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3799013Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.compute(BestPossibleStateCalcStage.java:168) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3801228Z at org.apache.helix.controller.stages.BestPossibleStateCalcStage.process(BestPossibleStateCalcStage.java:88) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3803133Z at org.apache.helix.controller.pipeline.Pipeline.handle(Pipeline.java:75) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3804953Z at org.apache.helix.controller.GenericHelixController.handleEvent(GenericHelixController.java:903) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3807066Z at org.apache.helix.controller.GenericHelixController$ClusterEventProcessor.run(GenericHelixController.java:1554) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3808948Z Caused by: org.apache.helix.zookeeper.zkclient.exception.ZkInterruptedException: java.lang.InterruptedException
2023-10-15T11:04:40.3810810Z at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:2097) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3812568Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3814200Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2235) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3815891Z at org.apache.helix.manager.zk.ZkBaseDataAccessor.get(ZkBaseDataAccessor.java:495) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3817846Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:271) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3819973Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:249) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3822424Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.fetchAssignmentOrDefault(AssignmentMetadataStore.java:94) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3825167Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.getBestPossibleAssignment(AssignmentMetadataStore.java:85) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3827788Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:89) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3829178Z ... 10 more
2023-10-15T11:04:40.3829585Z Caused by: java.lang.InterruptedException
2023-10-15T11:04:40.3830207Z at java.lang.Object.wait0(Native Method) ~[?:?]
2023-10-15T11:04:40.3830845Z at java.lang.Object.wait(Object.java:366) ~[?:?]
2023-10-15T11:04:40.3831678Z at java.lang.Object.wait(Object.java:339) ~[?:?]
2023-10-15T11:04:40.3832799Z at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1594) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3834416Z at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1566) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3835846Z at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:2356) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3837296Z at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:2385) ~[zookeeper-3.6.3.jar:3.6.3]
2023-10-15T11:04:40.3838870Z at org.apache.helix.zookeeper.zkclient.ZkConnection.readData(ZkConnection.java:196) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3840532Z at org.apache.helix.zookeeper.zkclient.ZkClient$12.call(ZkClient.java:2248) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3842087Z at org.apache.helix.zookeeper.zkclient.ZkClient$12.call(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3843790Z at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:2079) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3845529Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2244) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3847159Z at org.apache.helix.zookeeper.zkclient.ZkClient.readData(ZkClient.java:2235) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3848840Z at org.apache.helix.manager.zk.ZkBaseDataAccessor.get(ZkBaseDataAccessor.java:495) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3850788Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:271) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3852940Z at org.apache.helix.manager.zk.ZkBucketDataAccessor.compressedBucketRead(ZkBucketDataAccessor.java:249) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3855380Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.fetchAssignmentOrDefault(AssignmentMetadataStore.java:94) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3859078Z at org.apache.helix.controller.rebalancer.waged.AssignmentMetadataStore.getBestPossibleAssignment(AssignmentMetadataStore.java:85) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3861726Z at org.apache.helix.controller.rebalancer.waged.AssignmentManager.getBestPossibleAssignment(AssignmentManager.java:89) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3863119Z ... 10 more
2023-10-15T11:04:40.3865219Z 11:04:40.285 ERROR [GenericHelixController] [HelixController-pipeline-default-MultiStageEngineIntegrationTest-(b00367ed_DEFAULT)] Exception while executing DEFAULT pipeline for cluster MultiStageEngineIntegrationTest. Will not continue to next pipeline
2023-10-15T11:04:40.3867838Z org.apache.helix.zookeeper.zkclient.exception.ZkInterruptedException: java.lang.InterruptedException
2023-10-15T11:04:40.3869611Z at org.apache.helix.zookeeper.zkclient.ZkClient.acquireEventLock(ZkClient.java:2033) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3871413Z at org.apache.helix.zookeeper.zkclient.ZkClient.waitForKeeperState(ZkClient.java:2010) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3873261Z at org.apache.helix.zookeeper.zkclient.ZkClient.waitUntilConnected(ZkClient.java:2001) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3875072Z at org.apache.helix.manager.zk.ZKHelixManager.checkConnected(ZKHelixManager.java:411) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3876931Z at org.apache.helix.manager.zk.ZKHelixManager.getHelixDataAccessor(ZKHelixManager.java:681) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3879038Z at org.apache.helix.controller.stages.MessageDispatchStage.processEvent(MessageDispatchStage.java:65) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3881360Z at org.apache.helix.controller.stages.resource.ResourceMessageDispatchStage.process(ResourceMessageDispatchStage.java:33) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3883407Z at org.apache.helix.controller.pipeline.Pipeline.handle(Pipeline.java:75) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3885469Z at org.apache.helix.controller.GenericHelixController.handleEvent(GenericHelixController.java:903) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3887754Z at org.apache.helix.controller.GenericHelixController$ClusterEventProcessor.run(GenericHelixController.java:1554) [helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3889074Z Caused by: java.lang.InterruptedException
2023-10-15T11:04:40.3890177Z at java.util.concurrent.locks.ReentrantLock$Sync.lockInterruptibly(ReentrantLock.java:159) ~[?:?]
2023-10-15T11:04:40.3893047Z at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:372) ~[?:?]
2023-10-15T11:04:40.3894851Z at org.apache.helix.zookeeper.zkclient.ZkClient.acquireEventLock(ZkClient.java:2031) ~[helix-core-1.3.1.jar:1.3.1]
2023-10-15T11:04:40.3895911Z ... 9 more
2023-10-15T11:04:40.6799124Z [ERROR] Tests run: 25, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 98.18 s <<< FAILURE! -- in org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest
2023-10-15T11:04:40.6801654Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.selectStarDoesNotProjectSystemColumns -- Time elapsed: 0.987 s
2023-10-15T11:04:40.6804339Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeSelected[$docId](1) -- Time elapsed: 0.021 s
2023-10-15T11:04:40.6966530Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeSelected[$hostName](2) -- Time elapsed: 0.015 s
2023-10-15T11:04:40.6969025Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeSelected[$segmentName](3) -- Time elapsed: 0.022 s
2023-10-15T11:04:40.6971457Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeUsedInWhere[$docId](1) -- Time elapsed: 0.026 s
2023-10-15T11:04:40.6973901Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeUsedInWhere[$hostName](2) -- Time elapsed: 0.015 s
2023-10-15T11:04:40.6976834Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.systemColumnsCanBeUsedInWhere[$segmentName](3) -- Time elapsed: 0.015 s
2023-10-15T11:04:40.6979078Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testBase64Func -- Time elapsed: 2.934 s
2023-10-15T11:04:40.6981188Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testDistinctCountQueries[false](1) -- Time elapsed: 0.305 s
2023-10-15T11:04:40.6983453Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testDistinctCountQueries[true](2) -- Time elapsed: 0.300 s
2023-10-15T11:04:40.6985709Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testGeneratedQueries -- Time elapsed: 36.62 s <<< FAILURE!
2023-10-15T11:04:40.6987039Z java.lang.AssertionError:
2023-10-15T11:04:40.6987517Z Caught exception while testing query!
2023-10-15T11:04:40.6989106Z Pinot query: SELECT MAX(OriginAirportID), MIN(CRSDepTime) FROM mytable WHERE ARRAY_TO_MV(DivTailNums) > 'N4YBAA' AND WheelsOn <= 1648 AND ARRAY_TO_MV(DivTailNums) = 'N3LDAA'
2023-10-15T11:04:40.6993012Z H2 query: SELECT MAX(CAST(`OriginAirportID` AS DOUBLE)), MIN(CAST(`CRSDepTime` AS DOUBLE)) FROM mytable WHERE ( DivTailNums[1] > 'N4YBAA' OR DivTailNums[2] > 'N4YBAA' OR DivTailNums[3] > 'N4YBAA' OR DivTailNums[4] > 'N4YBAA' OR DivTailNums[5] > 'N4YBAA' ) AND `WheelsOn` <= 1648 AND ( DivTailNums[1] = 'N3LDAA' OR DivTailNums[2] = 'N3LDAA' OR DivTailNums[3] = 'N3LDAA' OR DivTailNums[4] = 'N3LDAA' OR DivTailNums[5] = 'N3LDAA' )
2023-10-15T11:04:40.6995677Z at org.testng.Assert.fail(Assert.java:99)
2023-10-15T11:04:40.6996872Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.failure(ClusterIntegrationTestUtils.java:1076)
2023-10-15T11:04:40.6998799Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.failure(ClusterIntegrationTestUtils.java:1060)
2023-10-15T11:04:40.7000570Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.testQuery(ClusterIntegrationTestUtils.java:699)
2023-10-15T11:04:40.7002815Z at org.apache.pinot.integration.tests.BaseClusterIntegrationTest.testQuery(BaseClusterIntegrationTest.java:738)
2023-10-15T11:04:40.7004932Z at org.apache.pinot.integration.tests.BaseClusterIntegrationTestSet.testGeneratedQueries(BaseClusterIntegrationTestSet.java:477)
2023-10-15T11:04:40.7007094Z at org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testGeneratedQueries(MultiStageEngineIntegrationTest.java:133)
2023-10-15T11:04:40.7008979Z at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
2023-10-15T11:04:40.7010196Z at java.base/java.lang.reflect.Method.invoke(Method.java:578)
2023-10-15T11:04:40.7011400Z at org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:139)
2023-10-15T11:04:40.7012763Z at org.testng.internal.invokers.TestInvoker.invokeMethod(TestInvoker.java:664)
2023-10-15T11:04:40.7013964Z at org.testng.internal.invokers.TestInvoker.invokeTestMethod(TestInvoker.java:227)
2023-10-15T11:04:40.7015188Z at org.testng.internal.invokers.MethodRunner.runInSequence(MethodRunner.java:50)
2023-10-15T11:04:40.7016468Z at org.testng.internal.invokers.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:957)
2023-10-15T11:04:40.7017765Z at org.testng.internal.invokers.TestInvoker.invokeTestMethods(TestInvoker.java:200)
2023-10-15T11:04:40.7019108Z at org.testng.internal.invokers.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:148)
2023-10-15T11:04:40.7020407Z at org.testng.internal.invokers.TestMethodWorker.run(TestMethodWorker.java:128)
2023-10-15T11:04:40.7021419Z at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
2023-10-15T11:04:40.7022236Z at org.testng.TestRunner.privateRun(TestRunner.java:848)
2023-10-15T11:04:40.7022969Z at org.testng.TestRunner.run(TestRunner.java:621)
2023-10-15T11:04:40.7023697Z at org.testng.SuiteRunner.runTest(SuiteRunner.java:443)
2023-10-15T11:04:40.7024535Z at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:437)
2023-10-15T11:04:40.7025380Z at org.testng.SuiteRunner.privateRun(SuiteRunner.java:397)
2023-10-15T11:04:40.7117884Z at org.testng.SuiteRunner.run(SuiteRunner.java:336)
2023-10-15T11:04:40.7119247Z at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
2023-10-15T11:04:40.7120194Z at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:95)
2023-10-15T11:04:40.7121075Z at org.testng.TestNG.runSuitesSequentially(TestNG.java:1280)
2023-10-15T11:04:40.7121892Z at org.testng.TestNG.runSuitesLocally(TestNG.java:1200)
2023-10-15T11:04:40.7122610Z at org.testng.TestNG.runSuites(TestNG.java:1114)
2023-10-15T11:04:40.7123238Z at org.testng.TestNG.run(TestNG.java:1082)
2023-10-15T11:04:40.7124120Z at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:155)
2023-10-15T11:04:40.7125636Z at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:102)
2023-10-15T11:04:40.7134825Z at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:91)
2023-10-15T11:04:40.7136444Z at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:137)
2023-10-15T11:04:40.7137799Z at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
2023-10-15T11:04:40.7139091Z at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
2023-10-15T11:04:40.7140240Z at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
2023-10-15T11:04:40.7141368Z at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)
2023-10-15T11:04:40.7143335Z Caused by: java.lang.NullPointerException: Cannot invoke "com.fasterxml.jackson.databind.JsonNode.get(String)" because the return value of "com.fasterxml.jackson.databind.JsonNode.get(String)" is null
2023-10-15T11:04:40.7145440Z at org.apache.pinot.tools.utils.ExplainPlanUtils.formatExplainPlan(ExplainPlanUtils.java:33)
2023-10-15T11:04:40.7147594Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.getExplainPlan(ClusterIntegrationTestUtils.java:852)
2023-10-15T11:04:40.7149707Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.testQueryInternal(ClusterIntegrationTestUtils.java:808)
2023-10-15T11:04:40.7151605Z at org.apache.pinot.integration.tests.ClusterIntegrationTestUtils.testQuery(ClusterIntegrationTestUtils.java:696)
2023-10-15T11:04:40.7152714Z ... 34 more
2023-10-15T11:04:40.7152923Z
2023-10-15T11:04:40.7154220Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testHardcodedQueries -- Time elapsed: 7.077 s
2023-10-15T11:04:40.7156288Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testLiteralOnlyFunc -- Time elapsed: 0.138 s
2023-10-15T11:04:40.7158828Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnAggregationQuery[false](1) -- Time elapsed: 0.872 s
2023-10-15T11:04:40.7161438Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnAggregationQuery[true](2) -- Time elapsed: 0.559 s
2023-10-15T11:04:40.7163820Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnGroupBy -- Time elapsed: 0.207 s
2023-10-15T11:04:40.7166142Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnGroupByOrderBy -- Time elapsed: 0.185 s
2023-10-15T11:04:40.7168545Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnSelectionQuery -- Time elapsed: 0.239 s
2023-10-15T11:04:40.7170876Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testMultiValueColumnTransforms -- Time elapsed: 0.135 s
2023-10-15T11:04:40.7173023Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testQueryOptions -- Time elapsed: 0.038 s
2023-10-15T11:04:40.7174993Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testRegexpReplace -- Time elapsed: 0.565 s
2023-10-15T11:04:40.7176894Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testSearch -- Time elapsed: 0.049 s
2023-10-15T11:04:40.7243042Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testSingleValueQuery -- Time elapsed: 0.181 s
2023-10-15T11:04:40.7245466Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testTimeFunc -- Time elapsed: 0.121 s
2023-10-15T11:04:40.7247351Z [ERROR] org.apache.pinot.integration.tests.MultiStageEngineIntegrationTest.testUrlFunc -- Time elapsed: 0.155 s
```
Contributor guide
Research direction
Open the linked GitHub Actions run and reproduce MultiStageEngineIntegrationTest. Start by tracing the Helix/Zookeeper startup messages and query-planning failures through QueryEnvironment and MultiStageBrokerRequestHandler. Done means the integration test's flaky failure is understood and the test completes reliably.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- distributed-systems, testing-qa
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Needs clarification
- Newbie friendliness
- 35/100