[INFO] Running org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest
18:48:37.290 ERROR [ZkAsyncCallbacks] [ZkClient-EventThread-25-localhost:2191] Interrupted waiting for success
java.lang.InterruptedException: null
Dec 08, 2022 6:48:45 PM org.glassfish.grizzly.http.server.NetworkListener start
at java.lang.Object.wait(Native Method) ~[?:?]
INFO: Started listener bound to [0.0.0.0:18998]
Dec 08, 2022 6:48:45 PM org.glassfish.grizzly.http.server.HttpServer start
INFO: [HttpServer] Started.
Dec 08, 2022 6:48:46 PM org.glassfish.grizzly.http.server.NetworkListener start
INFO: Started listener bound to [0.0.0.0:18099]
Dec 08, 2022 6:48:46 PM org.glassfish.grizzly.http.server.HttpServer start
INFO: [HttpServer-1] Started.
Dec 08, 2022 6:48:48 PM org.glassfish.grizzly.http.server.NetworkListener start
INFO: Started listener bound to [0.0.0.0:8097]
Dec 08, 2022 6:48:48 PM org.glassfish.grizzly.http.server.HttpServer start
INFO: [HttpServer-2] Started.
Dec 08, 2022 6:48:49 PM org.glassfish.grizzly.http.server.NetworkListener start
INFO: Started listener bound to [0.0.0.0:8096]
Dec 08, 2022 6:48:49 PM org.glassfish.grizzly.http.server.HttpServer start
INFO: [HttpServer-3] Started.
at java.lang.Object.wait(Object.java:328) ~[?:?]
at org.apache.helix.zookeeper.zkclient.callback.ZkAsyncCallbacks$DefaultCallback.waitForSuccess(ZkAsyncCallbacks.java:248) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient.issueSync(ZkClient.java:1616) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient.access$300(ZkClient.java:85) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient$4.run(ZkClient.java:1642) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkEventThread.run(ZkEventThread.java:99) [helix-core-1.0.4.jar:1.0.4]
18:48:39.597 WARN [ServiceStartableUtils] [main] Failed to find cluster config for cluster: StarTreeClusterIntegrationTest, skipping applying cluster config
18:48:41.875 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(1ac22bf7_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:41.904 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(085cbd9d_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:41.922 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(65bcae0d_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:41.934 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(8db083f1_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:41.953 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(3bf90c1e_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:41.970 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(81c29fc5_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.442 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(368d660f_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.500 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(8dd2221d_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.536 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(1271da3c_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.570 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(d1399f63_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.587 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(2c07fb5e_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
18:48:42.602 ERROR [DelayedAutoRebalancer] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(b00dd6f5_DEFAULT)] No instances or active instances available for resource leadControllerResource, allInstances: [], liveInstances: [], activeInstances: []
linux
18:48:47.287 WARN [ZKMetadataProvider] [main] Path: /CONFIGS/TABLE does not exist
18:48:47.290 WARN [HelixHelper] [main] Idempotent or null ideal state update for resource brokerResource, skipping update.
18:48:47.768 WARN [Tracing] [main] Using default implementation of thread accountant, due to invalid thread accountant factory null provided.
18:48:48.972 WARN [ControllerLeaderLocator] [main] Already created
18:48:48.974 WARN [Tracing] [main] Using default implementation of thread accountant, due to invalid thread accountant factory null provided.
Dec 08, 2022 6:49:39 PM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
18:49:39.350 WARN [SegmentDeletionManager] [grizzly-http-server-3] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1670525315444/mytable/mytable_16160_16189_6+%25
INFO: Stopped listener bound to [0.0.0.0:8097]
18:49:39.350 WARN [SegmentDeletionManager] [grizzly-http-server-3] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1670525315444/mytable/mytable_16251_16281_9+%25
Dec 08, 2022 6:49:40 PM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
18:49:39.350 WARN [SegmentDeletionManager] [grizzly-http-server-3] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1670525315444/mytable/mytable_16313_16342_11+%25
INFO: Stopped listener bound to [0.0.0.0:8096]
18:49:39.350 WARN [SegmentDeletionManager] [grizzly-http-server-3] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1670525315444/mytable/mytable_16343_16373_0+%25
Dec 08, 2022 6:49:40 PM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
18:49:39.351 WARN [SegmentDeletionManager] [grizzly-http-server-3] Failed to find local segment file for segment file:/tmp/test-controller-data-dir1670525315444/mytable/mytable_16405_16435_2+%25
INFO: Stopped listener bound to [0.0.0.0:18099]
18:49:39.585 ERROR [mytable_OFFLINE-TableDeletionMessageHandler] [HelixTaskExecutor-message_handle_thread_53] onError: INTERNAL, CANCEL
Dec 08, 2022 6:49:40 PM org.glassfish.grizzly.http.server.NetworkListener shutdownNow
java.lang.InterruptedException: sleep interrupted
INFO: Stopped listener bound to [0.0.0.0:18998]
at java.lang.Thread.sleep(Native Method) ~[?:?]
at org.apache.pinot.server.starter.helix.HelixInstanceDataManager.deleteTable(HelixInstanceDataManager.java:216) ~[classes/:?]
at org.apache.pinot.server.starter.helix.SegmentMessageHandlerFactory$TableDeletionMessageHandler.handleMessage(SegmentMessageHandlerFactory.java:174) ~[classes/:?]
at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:97) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:49) [helix-core-1.0.4.jar:1.0.4]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
18:49:39.715 ERROR [DataTableHandler] [nioEventLoopGroup-2-1] Channel for server: localhost_O is now inactive, marking server down
18:49:39.981 ERROR [mytable_OFFLINE-TableDeletionMessageHandler] [HelixTaskExecutor-message_handle_thread_54] onError: INTERNAL, CANCEL
java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method) ~[?:?]
at org.apache.pinot.server.starter.helix.HelixInstanceDataManager.deleteTable(HelixInstanceDataManager.java:216) ~[classes/:?]
at org.apache.pinot.server.starter.helix.SegmentMessageHandlerFactory$TableDeletionMessageHandler.handleMessage(SegmentMessageHandlerFactory.java:174) ~[classes/:?]
at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:97) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:49) [helix-core-1.0.4.jar:1.0.4]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
18:49:40.107 ERROR [DataTableHandler] [nioEventLoopGroup-2-2] Channel for server: localhost_O is now inactive, marking server down
18:49:40.284 WARN [ClusterChangeMediator] [Cleanup thread for StarTreeClusterIntegrationTest-Broker_10.1.0.183_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the IDEAL_STATE change
18:49:40.286 WARN [ClusterChangeMediator] [Cleanup thread for StarTreeClusterIntegrationTest-Broker_10.1.0.183_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the EXTERNAL_VIEW change
18:49:40.289 WARN [ClusterChangeMediator] [Cleanup thread for StarTreeClusterIntegrationTest-Broker_10.1.0.183_18099-SPECTATOR] ClusterChangeMediator already stopped, skipping enqueuing the INSTANCE_CONFIG change
18:49:40.537 ERROR [GenericHelixController] [HelixController-pipeline-default-StarTreeClusterIntegrationTest-(479e6d23_DEFAULT)] Exception while executing DEFAULT pipeline for cluster StarTreeClusterIntegrationTest. Will not continue to next pipeline
org.apache.helix.zookeeper.zkclient.exception.ZkInterruptedException: java.lang.InterruptedException
at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:2002) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient.getChildren(ZkClient.java:1347) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient.getChildren(ZkClient.java:1340) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.manager.zk.ZkBaseDataAccessor.getChildNames(ZkBaseDataAccessor.java:693) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.manager.zk.ZKHelixDataAccessor.getChildNames(ZKHelixDataAccessor.java:397) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.common.caches.PropertyCache.genSelectiveUpdateInput(PropertyCache.java:133) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.common.caches.PropertyCache.doRefreshWithSelectiveUpdate(PropertyCache.java:174) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.common.caches.PropertyCache.refresh(PropertyCache.java:158) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.dataproviders.BaseControllerDataProvider.refreshLiveInstances(BaseControllerDataProvider.java:309) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.dataproviders.BaseControllerDataProvider.doRefresh(BaseControllerDataProvider.java:418) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.dataproviders.ResourceControllerDataProvider.refresh(ResourceControllerDataProvider.java:143) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.stages.ReadClusterDataStage.process(ReadClusterDataStage.java:64) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.pipeline.Pipeline.handle(Pipeline.java:75) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.GenericHelixController.handleEvent(GenericHelixController.java:903) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.GenericHelixController.access$500(GenericHelixController.java:132) [helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.controller.GenericHelixController$ClusterEventProcessor.run(GenericHelixController.java:1554) [helix-core-1.0.4.jar:1.0.4]
Caused by: java.lang.InterruptedException
at org.apache.helix.zookeeper.zkclient.ZkConnection.handleInvokedMethodException(ZkConnection.java:290) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkConnection.getChildren(ZkConnection.java:183) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient$1.call(ZkClient.java:1353) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient$1.call(ZkClient.java:1347) ~[helix-core-1.0.4.jar:1.0.4]
at org.apache.helix.zookeeper.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1986) ~[helix-core-1.0.4.jar:1.0.4]
... 15 more
Error: Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 66.898 s <<< FAILURE! - in org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest
Error: org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest.testGeneratedQueries Time elapsed: 1.851 s <<< FAILURE!
java.lang.AssertionError:
Query comparison failed for:
Star Query: SELECT Carrier, AirlineID, Flights, sum(ArrDel15), min(DepDel15), min(ArrDel15) FROM mytable WHERE Dest BETWEEN 'GRB' AND 'SJT' AND Flights IN (1) AND AirlineID <= 19690 GROUP BY Carrier, AirlineID, Flights ORDER BY Carrier, AirlineID, Flights
Star Response: {"resultTable":{"dataSchema":{"columnNames":["Carrier","AirlineID","Flights","sum(ArrDel15)","min(DepDel15)","min(ArrDel15)"],"columnDataTypes":["STRING","LONG","INT","DOUBLE","DOUBLE","DOUBLE"]},"rows":[["HA",19690,1,-749837.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]]},"exceptions":[],"numServersQueried":2,"numServersResponded":2,"numSegmentsQueried":12,"numSegmentsProcessed":12,"numSegmentsMatched":12,"numConsumingSegmentsQueried":0,"numConsumingSegmentsProcessed":0,"numConsumingSegmentsMatched":0,"numDocsScanned":10420,"numEntriesScannedInFilter":59517,"numEntriesScannedPostFilter":62520,"numGroupsLimitReached":false,"totalDocs":115545,"timeUsedMs":18,"offlineThreadCpuTimeNs":10088600,"realtimeThreadCpuTimeNs":0,"offlineSystemActivitiesCpuTimeNs":23492305,"realtimeSystemActivitiesCpuTimeNs":0,"offlineResponseSerializationCpuTimeNs":37100,"realtimeResponseSerializationCpuTimeNs":0,"offlineTotalCpuTimeNs":33618005,"realtimeTotalCpuTimeNs":0,"segmentStatistics":[],"traceInfo":{},"minConsumingFreshnessTimeMs":0,"numRowsResultSet":2,"numSegmentsPrunedByBroker":0,"numSegmentsPrunedByServer":0,"numSegmentsPrunedInvalid":0,"numSegmentsPrunedByLimit":0,"numSegmentsPrunedByValue":0,"explainPlanNumEmptyFilterSegments":0,"explainPlanNumMatchAllFilterSegments":0}
Reference Query: SET useStarTree = false; SELECT Carrier, AirlineID, Flights, sum(ArrDel15), min(DepDel15), min(ArrDel15) FROM mytable WHERE Dest BETWEEN 'GRB' AND 'SJT' AND Flights IN (1) AND AirlineID <= 19690 GROUP BY Carrier, AirlineID, Flights ORDER BY Carrier, AirlineID, Flights
Reference Response: {"resultTable":{"dataSchema":{"columnNames":["Carrier","AirlineID","Flights","sum(ArrDel15)","min(DepDel15)","min(ArrDel15)"],"columnDataTypes":["STRING","LONG","INT","DOUBLE","DOUBLE","DOUBLE"]},"rows":[["HA",19690,1,-809830.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]]},"exceptions":[],"numServersQueried":2,"numServersResponded":2,"numSegmentsQueried":12,"numSegmentsProcessed":12,"numSegmentsMatched":12,"numConsumingSegmentsQueried":0,"numConsumingSegmentsProcessed":0,"numConsumingSegmentsMatched":0,"numDocsScanned":14727,"numEntriesScannedInFilter":131387,"numEntriesScannedPostFilter":73635,"numGroupsLimitReached":false,"totalDocs":115545,"timeUsedMs":16,"offlineThreadCpuTimeNs":11989000,"realtimeThreadCpuTimeNs":0,"offlineSystemActivitiesCpuTimeNs":12899745,"realtimeSystemActivitiesCpuTimeNs":0,"offlineResponseSerializationCpuTimeNs":32800,"realtimeResponseSerializationCpuTimeNs":0,"offlineTotalCpuTimeNs":24921545,"realtimeTotalCpuTimeNs":0,"segmentStatistics":[],"traceInfo":{},"minConsumingFreshnessTimeMs":0,"numRowsResultSet":2,"numSegmentsPrunedByBroker":0,"numSegmentsPrunedByServer":0,"numSegmentsPrunedInvalid":0,"numSegmentsPrunedByLimit":0,"numSegmentsPrunedByValue":0,"explainPlanNumEmptyFilterSegments":0,"explainPlanNumMatchAllFilterSegments":0}: Iterators differ at element [1]: [["HA",19690,1,-809830.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]] != [["HA",19690,1,-749837.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]] expected [[["HA",19690,1,-809830.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]]] but found [[["HA",19690,1,-749837.0,0.0,-9999.0],["WN",19393,1,-1.840513E7,-9999.0,-9999.0]]]
at org.testng.Assert.fail(Assert.java:93)
at org.testng.Assert.failNotEquals(Assert.java:512)
at org.testng.Assert.assertEqualsImpl(Assert.java:134)
at org.testng.Assert.assertEquals(Assert.java:610)
at org.testng.Assert.assertEquals(Assert.java:661)
at org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest.testStarQuery(StarTreeClusterIntegrationTest.java:188)
at org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest.testGeneratedQueries(StarTreeClusterIntegrationTest.java:158)
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:108)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:661)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:869)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1193)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:126)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
at org.testng.TestRunner.privateRun(TestRunner.java:744)
at org.testng.TestRunner.run(TestRunner.java:602)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:380)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:375)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:340)
at org.testng.SuiteRunner.run(SuiteRunner.java:289)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1301)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1226)
at org.testng.TestNG.runSuites(TestNG.java:1144)
at org.testng.TestNG.run(TestNG.java:1115)
at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:136)
at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:112)
at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:99)
at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:145)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:428)
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:562)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:548)
Error: org.apache.pinot.integration.tests.StarTreeClusterIntegrationTest.testPredicateOnMetrics Time elapsed: 0.189 s
