Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/3022/ Java: 32bit/jdk-9-ea+159 -client -XX:+UseParallelGC
1 tests failed. FAILED: org.apache.solr.handler.TestSQLHandler.doTest Error Message: --> http://127.0.0.1:41686/pk_/sx/collection1:Failed to execute sqlQuery 'select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2' against JDBC connection 'jdbc:calcitesolr:'. Error while executing SQL "select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2": From line 1, column 39 to line 1, column 50: No match found for function signature min(<NUMERIC>) Stack Trace: java.io.IOException: --> http://127.0.0.1:41686/pk_/sx/collection1:Failed to execute sqlQuery 'select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2' against JDBC connection 'jdbc:calcitesolr:'. Error while executing SQL "select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2": From line 1, column 39 to line 1, column 50: No match found for function signature min(<NUMERIC>) at __randomizedtesting.SeedInfo.seed([7D628A7DB31B3E9A:DA2632D9DEA02D23]:0) at org.apache.solr.client.solrj.io.stream.SolrStream.read(SolrStream.java:235) at org.apache.solr.handler.TestSQLHandler.getTuples(TestSQLHandler.java:2337) at org.apache.solr.handler.TestSQLHandler.testBasicGrouping(TestSQLHandler.java:663) at org.apache.solr.handler.TestSQLHandler.doTest(TestSQLHandler.java:81) 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:547) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 11781 lines...] [junit4] Suite: org.apache.solr.handler.TestSQLHandler [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/init-core-data-001 [junit4] 2> 968030 WARN (SUITE-TestSQLHandler-seed#[7D628A7DB31B3E9A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2 [junit4] 2> 968030 INFO (SUITE-TestSQLHandler-seed#[7D628A7DB31B3E9A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields [junit4] 2> 968032 INFO (SUITE-TestSQLHandler-seed#[7D628A7DB31B3E9A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0) [junit4] 2> 968032 INFO (SUITE-TestSQLHandler-seed#[7D628A7DB31B3E9A]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /pk_/sx [junit4] 2> 968033 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 968033 INFO (Thread-1669) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 968033 INFO (Thread-1669) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 968133 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkTestServer start zk server on port:42921 [junit4] 2> 968140 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-sql.xml to /configs/conf1/solrconfig.xml [junit4] 2> 968142 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema-sql.xml to /configs/conf1/schema.xml [junit4] 2> 968145 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 968147 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 968152 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 968155 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 968158 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 968163 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 968166 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 968170 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 968173 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 968772 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/cores/collection1 [junit4] 2> 968775 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 968776 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@f0aa16{/pk_/sx,null,AVAILABLE} [junit4] 2> 968776 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7fc74a{HTTP/1.1,[http/1.1]}{127.0.0.1:33597} [junit4] 2> 968776 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server Started @970571ms [junit4] 2> 968776 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pk_/sx, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/tempDir-001/control/data, hostPort=33597, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/cores} [junit4] 2> 968776 ERROR (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 968777 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 968777 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 968777 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 968777 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-09T13:32:40.963199Z [junit4] 2> 968779 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 968779 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/solr.xml [junit4] 2> 968784 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 968786 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42921/solr [junit4] 2> 968796 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 968796 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33597_pk_%2Fsx [junit4] 2> 968797 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) starting [junit4] 2> 968801 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33597_pk_%2Fsx [junit4] 2> 968802 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 968980 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/cores [junit4] 2> 968980 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 968983 INFO (OverseerStateUpdate-97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 969988 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 970001 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 970050 WARN (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 970051 WARN (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 970051 WARN (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 970052 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 970052 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 970053 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/control-001/cores/collection1/data/] [junit4] 2> 970268 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 970269 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 970271 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 970271 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 970271 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1c41586[collection1] main] [junit4] 2> 970272 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 970273 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 970273 INFO (searcherExecutor-3182-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1c41586[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 970273 INFO (coreLoadExecutor-3181-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561399250081808384 [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:33597/pk_/sx/collection1/ [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:33597/pk_/sx/collection1/ has no replicas [junit4] 2> 970278 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 970286 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:33597/pk_/sx/collection1/ shard1 [junit4] 2> 970437 INFO (coreZkRegister-3174-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 970750 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 970751 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 970751 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 971356 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/cores/collection1 [junit4] 2> 971357 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001 [junit4] 2> 971358 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 971358 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@14a21af{/pk_/sx,null,AVAILABLE} [junit4] 2> 971359 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@36cfbf{HTTP/1.1,[http/1.1]}{127.0.0.1:41686} [junit4] 2> 971359 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server Started @973154ms [junit4] 2> 971359 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pk_/sx, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/tempDir-001/jetty1, hostPort=41686, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/cores} [junit4] 2> 971359 ERROR (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 971360 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 971360 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 971360 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 971360 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-09T13:32:43.546220Z [junit4] 2> 971362 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 971362 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/solr.xml [junit4] 2> 971367 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 971369 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42921/solr [junit4] 2> 971373 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 971374 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 971375 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41686_pk_%2Fsx [junit4] 2> 971376 INFO (zkCallback-1080-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 971376 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 971376 INFO (zkCallback-1085-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 971625 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/cores [junit4] 2> 971625 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 971626 INFO (OverseerStateUpdate-97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 972631 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 972637 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 972673 WARN (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 972675 WARN (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 972675 WARN (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 972675 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 972676 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 972676 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-1-001/cores/collection1/data/] [junit4] 2> 972824 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 972824 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 972826 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 972826 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 972826 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ff53c9[collection1] main] [junit4] 2> 972827 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 972827 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 972827 INFO (searcherExecutor-3192-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1ff53c9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 972827 INFO (coreLoadExecutor-3191-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561399252759871488 [junit4] 2> 972831 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 972831 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 972832 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41686/pk_/sx/collection1/ [junit4] 2> 972832 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 972832 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:41686/pk_/sx/collection1/ has no replicas [junit4] 2> 972832 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 972833 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41686/pk_/sx/collection1/ shard2 [junit4] 2> 972984 INFO (coreZkRegister-3186-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 973447 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/cores/collection1 [junit4] 2> 973448 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001 [junit4] 2> 973448 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 973449 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ef9e14{/pk_/sx,null,AVAILABLE} [junit4] 2> 973449 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@169e5bd{HTTP/1.1,[http/1.1]}{127.0.0.1:37054} [junit4] 2> 973449 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server Started @975245ms [junit4] 2> 973449 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pk_/sx, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/tempDir-001/jetty2, hostPort=37054, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/cores} [junit4] 2> 973450 ERROR (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 973450 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 973450 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 973450 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 973450 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-09T13:32:45.636541Z [junit4] 2> 973452 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 973452 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/solr.xml [junit4] 2> 973457 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 973459 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42921/solr [junit4] 2> 973464 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 973465 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 973467 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37054_pk_%2Fsx [junit4] 2> 973468 INFO (zkCallback-1085-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 973468 INFO (zkCallback-1091-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 973468 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 973468 INFO (zkCallback-1080-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 973639 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/cores [junit4] 2> 973639 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 973640 INFO (OverseerStateUpdate-97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 974644 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 974650 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 974685 WARN (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 974686 WARN (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 974686 WARN (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 974686 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 974687 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 974687 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-2-001/cores/collection1/data/] [junit4] 2> 974823 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 974823 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 974825 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 974825 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 974825 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@17bc30f[collection1] main] [junit4] 2> 974826 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 974826 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 974826 INFO (searcherExecutor-3202-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@17bc30f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 974826 INFO (coreLoadExecutor-3201-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561399254855974912 [junit4] 2> 974829 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 974829 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 974829 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37054/pk_/sx/collection1/ [junit4] 2> 974830 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 974830 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:37054/pk_/sx/collection1/ has no replicas [junit4] 2> 974830 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 974831 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:37054/pk_/sx/collection1/ shard1 [junit4] 2> 974981 INFO (coreZkRegister-3196-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 975564 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/cores/collection1 [junit4] 2> 975565 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001 [junit4] 2> 975565 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 975566 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@607b69{/pk_/sx,null,AVAILABLE} [junit4] 2> 975566 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1ecef20{HTTP/1.1,[http/1.1]}{127.0.0.1:46261} [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server Started @977362ms [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pk_/sx, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/tempDir-001/jetty3, hostPort=46261, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/cores} [junit4] 2> 975567 ERROR (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 975567 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-09T13:32:47.753839Z [junit4] 2> 975570 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 975570 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/solr.xml [junit4] 2> 975574 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 975576 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42921/solr [junit4] 2> 975582 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 975582 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 975583 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46261_pk_%2Fsx [junit4] 2> 975584 INFO (zkCallback-1097-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 975584 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 975585 INFO (zkCallback-1091-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 975585 INFO (zkCallback-1080-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 975585 INFO (zkCallback-1085-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 975770 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/cores [junit4] 2> 975770 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 975771 INFO (OverseerStateUpdate-97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 976776 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 976782 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 976816 WARN (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 976817 WARN (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 976817 WARN (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 976817 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 976818 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 976818 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-3-001/cores/collection1/data/] [junit4] 2> 976978 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 976978 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 976979 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 976979 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 976980 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@bd8442[collection1] main] [junit4] 2> 976980 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 976980 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 976981 INFO (searcherExecutor-3212-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@bd8442[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 976981 INFO (coreLoadExecutor-3211-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561399257115656192 [junit4] 2> 976984 INFO (coreZkRegister-3206-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 976984 INFO (updateExecutor-1094-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 976984 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 976984 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 976984 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1] [junit4] 2> 976984 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 976984 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:41686/pk_/sx/collection1/] and I am [http://127.0.0.1:46261/pk_/sx/collection1/] [junit4] 2> 976986 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:41686/pk_/sx]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:46261_pk_%252Fsx&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 976988 INFO (qtp14674883-6748) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 976989 INFO (qtp14674883-6748) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have state: recovering [junit4] 2> 976989 INFO (qtp14674883-6748) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:46261_pk_%2Fsx, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:46261/pk_/sx","node_name":"127.0.0.1:46261_pk_%2Fsx","state":"down"} [junit4] 2> 977778 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/cores/collection1 [junit4] 2> 977778 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001 [junit4] 2> 977779 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 977780 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@bb2f99{/pk_/sx,null,AVAILABLE} [junit4] 2> 977780 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1331610{HTTP/1.1,[http/1.1]}{127.0.0.1:44432} [junit4] 2> 977780 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.Server Started @979575ms [junit4] 2> 977780 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pk_/sx, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/tempDir-001/jetty4, hostPort=44432, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/cores} [junit4] 2> 977780 ERROR (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 977781 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 977781 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 977781 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 977781 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-09T13:32:49.967339Z [junit4] 2> 977783 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 977783 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/solr.xml [junit4] 2> 977789 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 977790 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42921/solr [junit4] 2> 977795 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 977796 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 977797 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44432_pk_%2Fsx [junit4] 2> 977797 INFO (zkCallback-1097-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977797 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977799 INFO (zkCallback-1085-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977799 INFO (zkCallback-1080-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977799 INFO (zkCallback-1091-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977799 INFO (zkCallback-1104-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 977989 INFO (qtp14674883-6748) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:46261_pk_%2Fsx, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:46261/pk_/sx","node_name":"127.0.0.1:46261_pk_%2Fsx","state":"recovering"} [junit4] 2> 977989 INFO (qtp14674883-6748) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4] 2> 977989 INFO (qtp14674883-6748) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:46261_pk_%252Fsx&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000 [junit4] 2> 978053 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/cores [junit4] 2> 978053 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 978054 INFO (OverseerStateUpdate-97587452983443460-127.0.0.1:33597_pk_%2Fsx-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 978490 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:41686/pk_/sx/collection1/] - recoveringAfterStartup=[true] [junit4] 2> 978490 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:46261/pk_/sx START replicas=[http://127.0.0.1:41686/pk_/sx/collection1/] nUpdates=100 [junit4] 2> 978492 INFO (qtp14674883-6744) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0} [junit4] 2> 978492 INFO (qtp14674883-6744) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 978493 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0} [junit4] 2> 978493 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync [junit4] 2> 978493 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 978493 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 978494 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 978494 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful. [junit4] 2> 978494 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync. [junit4] 2> 978494 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed. [junit4] 2> 978494 INFO (recoveryExecutor-1095-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 979059 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 979065 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 979123 WARN (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 979124 WARN (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 979124 WARN (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 979125 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 979125 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 979126 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001/shard-4-001/cores/collection1/data/] [junit4] 2> 979332 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 979332 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 979334 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 979334 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 979334 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a5ba0[collection1] main] [junit4] 2> 979335 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 979335 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 979336 INFO (searcherExecutor-3222-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7a5ba0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 979336 INFO (coreLoadExecutor-3221-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561399259585052672 [junit4] 2> 979338 INFO (coreZkRegister-3216-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 979339 INFO (updateExecutor-1101-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 979339 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 979339 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 979339 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1] [junit4] 2> 979339 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 979339 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:37054/pk_/sx/collection1/] and I am [http://127.0.0.1:44432/pk_/sx/collection1/] [junit4] 2> 979341 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:37054/pk_/sx]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:44432_pk_%252Fsx&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 979342 INFO (qtp13082927-6776) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 979342 INFO (qtp13082927-6776) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering [junit4] 2> 979342 INFO (qtp13082927-6776) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:44432_pk_%2Fsx, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:44432/pk_/sx","node_name":"127.0.0.1:44432_pk_%2Fsx","state":"down"} [junit4] 2> 979380 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTest [junit4] 2> 979381 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):330 [junit4] 2> 980342 INFO (qtp13082927-6776) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:44432_pk_%2Fsx, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:44432/pk_/sx","node_name":"127.0.0.1:44432_pk_%2Fsx","state":"recovering"} [junit4] 2> 980342 INFO (qtp13082927-6776) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4] 2> 980342 INFO (qtp13082927-6776) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:44432_pk_%252Fsx&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node4&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000 [junit4] 2> 980843 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:37054/pk_/sx/collection1/] - recoveringAfterStartup=[true] [junit4] 2> 980843 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:44432/pk_/sx START replicas=[http://127.0.0.1:37054/pk_/sx/collection1/] nUpdates=100 [junit4] 2> 980845 INFO (qtp13082927-6776) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0} [junit4] 2> 980845 INFO (qtp13082927-6776) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0} [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful. [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync. [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed. [junit4] 2> 980846 INFO (recoveryExecutor-1102-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 981381 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1 [junit4] 2> 981385 INFO (qtp18559244-6714) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1561399261730439168)} 0 3 [junit4] 2> 981393 INFO (qtp15147743-6838) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&_version_=-1561399261734633472&distrib.from=http://127.0.0.1:37054/pk_/sx/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561399261734633472)} 0 2 [junit4] 2> 981394 INFO (qtp25938166-6804) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&_version_=-1561399261735682048&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561399261735682048)} 0 2 [junit4] 2> 981394 INFO (qtp14674883-6749) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:37054/pk_/sx/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1561399261735682048)} 0 6 [junit4] 2> 981394 INFO (qtp13082927-6771) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1561399261734633472)} 0 8 [junit4] 2> 981396 INFO (qtp18559244-6715) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981396 INFO (qtp18559244-6715) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 981396 INFO (qtp18559244-6715) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981396 INFO (qtp18559244-6715) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 0 [junit4] 2> 981397 INFO (qtp13082927-6776) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981398 INFO (qtp13082927-6776) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 981398 INFO (qtp15147743-6840) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981398 INFO (qtp15147743-6840) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 981398 INFO (qtp13082927-6776) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981399 INFO (qtp15147743-6840) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981399 INFO (qtp13082927-6776) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1 [junit4] 2> 981399 INFO (qtp15147743-6840) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 981399 INFO (qtp14674883-6749) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981399 INFO (qtp14674883-6749) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 981399 INFO (qtp14674883-6749) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981399 INFO (qtp14674883-6749) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 981400 INFO (qtp25938166-6805) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981400 INFO (qtp25938166-6805) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 981400 INFO (qtp25938166-6805) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981400 INFO (qtp25938166-6805) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 981400 INFO (qtp14674883-6744) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 4 [junit4] 2> 981405 INFO (qtp18559244-6713) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[1 (1561399261751410688)]} 0 2 [junit4] 2> 981413 INFO (qtp15147743-6839) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37054/pk_/sx/collection1/&wt=javabin&version=2}{add=[1 (1561399261755604992)]} 0 2 [junit4] 2> 981413 INFO (qtp13082927-6772) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[1 (1561399261755604992)]} 0 6 [junit4] 2> 981415 INFO (qtp18559244-6708) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[2 (1561399261763993600)]} 0 0 [junit4] 2> 981420 INFO (qtp25938166-6806) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{add=[2 (1561399261766090752)]} 0 0 [junit4] 2> 981420 INFO (qtp14674883-6745) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[2 (1561399261766090752)]} 0 3 [junit4] 2> 981423 INFO (qtp18559244-6714) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[3 (1561399261773430784)]} 0 0 [junit4] 2> 981426 INFO (qtp25938166-6799) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{add=[3 (1561399261774479360)]} 0 0 [junit4] 2> 981427 INFO (qtp14674883-6743) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[3 (1561399261774479360)]} 0 2 [junit4] 2> 981428 INFO (qtp18559244-6715) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[4 (1561399261778673664)]} 0 0 [junit4] 2> 981432 INFO (qtp15147743-6838) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37054/pk_/sx/collection1/&wt=javabin&version=2}{add=[4 (1561399261780770816)]} 0 0 [junit4] 2> 981432 INFO (qtp13082927-6771) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[4 (1561399261780770816)]} 0 2 [junit4] 2> 981434 INFO (qtp18559244-6713) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[5 (1561399261783916544)]} 0 1 [junit4] 2> 981437 INFO (qtp25938166-6804) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{add=[5 (1561399261787062272)]} 0 0 [junit4] 2> 981438 INFO (qtp14674883-6749) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[5 (1561399261787062272)]} 0 1 [junit4] 2> 981439 INFO (qtp18559244-6708) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[6 (1561399261790208000)]} 0 0 [junit4] 2> 981442 INFO (qtp25938166-6805) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{add=[6 (1561399261792305152)]} 0 0 [junit4] 2> 981442 INFO (qtp14674883-6744) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[6 (1561399261792305152)]} 0 1 [junit4] 2> 981444 INFO (qtp18559244-6714) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[7 (1561399261795450880)]} 0 0 [junit4] 2> 981448 INFO (qtp25938166-6806) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&wt=javabin&version=2}{add=[7 (1561399261797548032)]} 0 0 [junit4] 2> 981448 INFO (qtp14674883-6745) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[7 (1561399261797548032)]} 0 1 [junit4] 2> 981450 INFO (qtp18559244-6715) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[8 (1561399261801742336)]} 0 0 [junit4] 2> 981453 INFO (qtp15147743-6834) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37054/pk_/sx/collection1/&wt=javabin&version=2}{add=[8 (1561399261802790912)]} 0 0 [junit4] 2> 981453 INFO (qtp13082927-6774) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={wt=javabin&version=2}{add=[8 (1561399261802790912)]} 0 1 [junit4] 2> 981455 INFO (qtp18559244-6713) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981455 INFO (qtp18559244-6713) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@fe675a [junit4] 2> 981459 INFO (qtp18559244-6713) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dd051d[collection1] main] [junit4] 2> 981460 INFO (qtp18559244-6713) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981460 INFO (searcherExecutor-3182-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1dd051d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C8)))} [junit4] 2> 981460 INFO (qtp18559244-6713) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 5 [junit4] 2> 981463 INFO (qtp14674883-6746) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981463 INFO (qtp13082927-6773) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981463 INFO (qtp15147743-6833) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981463 INFO (qtp14674883-6746) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1c2f4bf [junit4] 2> 981463 INFO (qtp15147743-6833) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@166a8b8 [junit4] 2> 981463 INFO (qtp25938166-6799) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 981463 INFO (qtp13082927-6773) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1ebccfe [junit4] 2> 981464 INFO (qtp25938166-6799) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@53a821 [junit4] 2> 981468 INFO (qtp25938166-6799) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@70be74[collection1] main] [junit4] 2> 981468 INFO (qtp15147743-6833) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@520321[collection1] main] [junit4] 2> 981468 INFO (qtp13082927-6773) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@510e3e[collection1] main] [junit4] 2> 981468 INFO (qtp14674883-6746) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@14dcd24[collection1] main] [junit4] 2> 981468 INFO (qtp15147743-6833) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981468 INFO (qtp25938166-6799) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981468 INFO (searcherExecutor-3202-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@510e3e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C3)))} [junit4] 2> 981468 INFO (searcherExecutor-3212-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@70be74[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C5)))} [junit4] 2> 981468 INFO (searcherExecutor-3222-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@520321[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C3)))} [junit4] 2> 981468 INFO (qtp25938166-6799) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5 [junit4] 2> 981468 INFO (qtp13082927-6773) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981468 INFO (qtp14674883-6746) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 981468 INFO (qtp13082927-6773) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5 [junit4] 2> 981468 INFO (searcherExecutor-3192-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@14dcd24[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C5)))} [junit4] 2> 981468 INFO (qtp15147743-6833) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5 [junit4] 2> 981469 INFO (qtp14674883-6746) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41686/pk_/sx/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5 [junit4] 2> 981469 INFO (qtp14674883-6743) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/pk_/sx path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7 [junit4] 1> ############# testBasicSelect() ############ [junit4] 2> 981480 INFO (qtp14674883-6745) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/sql params={wt=json&version=2.2&stmt=select+id,+field_i,+str_s+from+collection1+where+(text%3D'(XXXX)'+OR+text%3D'XXXX')+AND+text%3D'XXXX'+order+by+field_i+desc} status=0 QTime=5 [junit4] 2> 982203 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 982204 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 982212 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 982212 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 982217 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 982217 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 982222 INFO (qtp15147743-6838) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/admin/luke params={numTerms=0&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 983039 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983039 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983043 INFO (qtp25938166-6805) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/export params={q=((text:(XXXX)+OR+text:"XXXX")+AND+text:"XXXX")&distrib=false&fl=id,field_i,str_s&sort=field_i+desc&wt=json&version=2.2} hits=5 status=0 QTime=0 [junit4] 2> 983045 INFO (qtp15147743-6835) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/export params={q=((text:(XXXX)+OR+text:"XXXX")+AND+text:"XXXX")&distrib=false&fl=id,field_i,str_s&sort=field_i+desc&wt=json&version=2.2} hits=3 status=0 QTime=0 [junit4] 2> 983059 INFO (qtp14674883-6745) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/sql params={wt=json&version=2.2&stmt=select+id,+field_i,+str_s+from+collection1+where+text%3D'XXXX'} status=0 QTime=0 [junit4] 2> 983064 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983064 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983067 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983067 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983069 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983070 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983073 INFO (qtp14674883-6748) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/admin/luke params={numTerms=0&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 983118 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983119 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983121 INFO (qtp14674883-6743) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/export params={q=text:"XXXX"&distrib=false&fl=id,field_i,str_s,_version_&sort=_version_+desc&wt=json&version=2.2} hits=5 status=0 QTime=0 [junit4] 2> 983123 INFO (qtp15147743-6835) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/export params={q=text:"XXXX"&distrib=false&fl=id,field_i,str_s,_version_&sort=_version_+desc&wt=json&version=2.2} hits=3 status=0 QTime=0 [junit4] 2> 983137 INFO (qtp14674883-6745) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/sql params={wt=json&version=2.2&stmt=select+id,+field_i,+str_s+from+collection1+where+text%3D'XXXX'+order+by+field_i+desc+limit+1} status=0 QTime=0 [junit4] 2> 983143 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983143 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983145 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983146 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983148 INFO (qtp14674883-6745) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 983148 INFO (qtp14674883-6745) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42921/solr ready [junit4] 2> 983152 INFO (qtp13082927-6771) [ ] o.a.s.c.S.Request [collection1] webapp=/pk_/sx path=/admin/luke params={numTerms=0&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 983305 INFO (qtp1 [...truncated too long message...] 7.0.0.1:46261_pk_%2Fsx [junit4] 2> 993175 INFO (zkCallback-1104-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 993175 INFO (zkCallback-1104-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44432_pk_%2Fsx [junit4] 2> 993176 INFO (zkCallback-1104-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97587452983443473-127.0.0.1:44432_pk_%2Fsx-n_0000000004) starting [junit4] 2> 994171 INFO (zkCallback-1104-thread-2) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44432/pk_/sx/collection1/ [junit4] 2> 994171 INFO (zkCallback-1104-thread-2) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 994171 INFO (zkCallback-1104-thread-2) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:44432/pk_/sx/collection1/ has no replicas [junit4] 2> 994173 INFO (zkCallback-1104-thread-2) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44432/pk_/sx/collection1/ shard1 [junit4] 2> 994675 WARN (zkCallback-1097-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 994676 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 994676 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1ecef20{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 994676 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@607b69{/pk_/sx,null,UNAVAILABLE} [junit4] 2> 994676 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 44432 [junit4] 2> 994676 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=26144321 [junit4] 2> 994677 INFO (coreCloseExecutor-3254-thread-1) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1db1149 [junit4] 2> 994679 INFO (coreCloseExecutor-3254-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1 [junit4] 2> 994679 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.Overseer Overseer (id=97587452983443473-127.0.0.1:44432_pk_%2Fsx-n_0000000004) closing [junit4] 2> 994679 INFO (OverseerStateUpdate-97587452983443473-127.0.0.1:44432_pk_%2Fsx-n_0000000004) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44432_pk_%2Fsx [junit4] 2> 996180 WARN (zkCallback-1104-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 996180 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 996180 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1331610{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 996181 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@bb2f99{/pk_/sx,null,UNAVAILABLE} [junit4] 2> 996181 INFO (TEST-TestSQLHandler.doTest-seed#[7D628A7DB31B3E9A]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42921 42921 [junit4] 2> 1001193 INFO (Thread-1669) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42921 42921 [junit4] 2> 1001194 WARN (Thread-1669) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 76 /solr/aliases.json [junit4] 2> 76 /solr/clusterprops.json [junit4] 2> 5 /solr/security.json [junit4] 2> 5 /solr/configs/conf1 [junit4] 2> 4 /solr/collections/collection1/state.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 76 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 76 /solr/live_nodes [junit4] 2> 76 /solr/collections [junit4] 2> 28 /solr/overseer/queue [junit4] 2> 23 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/overseer/queue-work [junit4] 2> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSQLHandler -Dtests.method=doTest -Dtests.seed=7D628A7DB31B3E9A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=az -Dtests.timezone=Asia/Bangkok -Dtests.asserts=true -Dtests.file.encoding=US-ASCII [junit4] ERROR 33.2s J1 | TestSQLHandler.doTest <<< [junit4] > Throwable #1: java.io.IOException: --> http://127.0.0.1:41686/pk_/sx/collection1:Failed to execute sqlQuery 'select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2' against JDBC connection 'jdbc:calcitesolr:'. [junit4] > Error while executing SQL "select str_s, count(*), sum(field_i), min(field_i), max(field_i), cast(avg(1.0 * field_i) as float) from collection1 where text='XXXX' group by str_s order by sum(field_i) asc limit 2": From line 1, column 39 to line 1, column 50: No match found for function signature min(<NUMERIC>) [junit4] > at __randomizedtesting.SeedInfo.seed([7D628A7DB31B3E9A:DA2632D9DEA02D23]:0) [junit4] > at org.apache.solr.client.solrj.io.stream.SolrStream.read(SolrStream.java:235) [junit4] > at org.apache.solr.handler.TestSQLHandler.getTuples(TestSQLHandler.java:2337) [junit4] > at org.apache.solr.handler.TestSQLHandler.testBasicGrouping(TestSQLHandler.java:663) [junit4] > at org.apache.solr.handler.TestSQLHandler.doTest(TestSQLHandler.java:81) [junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:547) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967) [junit4] > at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 1001196 INFO (SUITE-TestSQLHandler-seed#[7D628A7DB31B3E9A]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_7D628A7DB31B3E9A-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene62), sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=az, timezone=Asia/Bangkok [junit4] 2> NOTE: Linux 4.4.0-53-generic i386/Oracle Corporation 9-ea (32-bit)/cpus=12,threads=1,free=147211648,total=325582848 [junit4] 2> NOTE: All tests run in this JVM: [SliceStateTest, TestFileDictionaryLookup, TestExportWriter, CollectionsAPIDistributedZkTest, TestNumericTerms64, SpellCheckComponentTest, CoreAdminCreateDiscoverTest, ZkControllerTest, BlockJoinFacetSimpleTest, TestFieldCollectionResource, ConvertedLegacyTest, InfixSuggestersTest, BasicAuthIntegrationTest, SharedFSAutoReplicaFailoverTest, OpenCloseCoreStressTest, SpatialHeatmapFacetsTest, TestSolrCloudSnapshots, TestQuerySenderListener, DistribCursorPagingTest, LeaderFailoverAfterPartitionTest, TestTrie, IndexSchemaTest, OverseerCollectionConfigSetProcessorTest, PeerSyncWithIndexFingerprintCachingTest, TestCollectionAPIs, TestBM25SimilarityFactory, RecoveryAfterSoftCommitTest, TestRandomCollapseQParserPlugin, TestCollationFieldDocValues, MultiThreadedOCPTest, TestQueryUtils, TestSolrConfigHandler, TestFieldCacheWithThreads, TestManagedStopFilterFactory, ConnectionManagerTest, SolrMetricsIntegrationTest, WordBreakSolrSpellCheckerTest, MergeStrategyTest, OverseerStatusTest, SolrIndexConfigTest, ClusterStateUpdateTest, PreAnalyzedUpdateProcessorTest, TestWordDelimiterFilterFactory, DirectSolrConnectionTest, TestAddFieldRealTimeGet, BlockCacheTest, QueryResultKeyTest, TestQueryTypes, HdfsThreadLeakTest, TestJavabinTupleStreamParser, TestTrackingShardHandlerFactory, RuleEngineTest, TestPartialUpdateDeduplication, DocValuesMissingTest, BasicFunctionalityTest, ClassificationUpdateProcessorIntegrationTest, TestHashPartitioner, MetricUtilsTest, SmileWriterTest, TestSolrCoreParser, TestExclusionRuleCollectionAccess, FileUtilsTest, TestClusterProperties, TestComplexPhraseQParserPlugin, TestRecoveryHdfs, TestSolrQueryParserDefaultOperatorResource, TestFastOutputStream, AnalysisErrorHandlingTest, TestSolrConfigHandlerConcurrent, TestExactSharedStatsCache, SampleTest, HdfsWriteToMultipleCollectionsTest, AddSchemaFieldsUpdateProcessorFactoryTest, ShardRoutingTest, TestDefaultSearchFieldResource, TestLuceneMatchVersion, SpellingQueryConverterTest, TestMinMaxOnMultiValuedField, TestSearchPerf, SolrJmxReporterTest, TestNamedUpdateProcessors, TestTolerantUpdateProcessorCloud, DistanceUnitsTest, TestCloudPivotFacet, TestSimpleQParserPlugin, TestInPlaceUpdatesStandalone, DistributedQueueTest, DocValuesTest, TestUpdate, SpellCheckCollatorTest, TestSystemIdResolver, TestCursorMarkWithoutUniqueKey, TestSQLHandler] [junit4] Completed [274/697 (1!)] on J1 in 33.18s, 1 test, 1 error <<< FAILURES! [...truncated 53092 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
