You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/03/09 14:06:27 UTC
[JENKINS-EA] Lucene-Solr-6.x-Linux (32bit/jdk-9-ea+159) - Build #
3022 - Unstable!
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...]
Re: [JENKINS-EA] Lucene-Solr-6.x-Linux (32bit/jdk-9-ea+159) - Build #
3022 - Unstable!
Posted by Joel Bernstein <jo...@gmail.com>.
Looks like we have another locale related failure. This time AZERBAIJAN (AZ
).
I'll investigate.
Joel Bernstein
http://joelsolr.blogspot.com/
On Thu, Mar 9, 2017 at 9:06 AM, Policeman Jenkins Server <
jenkins@thetaphi.de> wrote:
> 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-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>