lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-6.x-Linux (64bit/jdk1.8.0_121) - Build # 2893 - Still Unstable!
Date Sun, 19 Feb 2017 15:24:46 GMT
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2893/
Java: 64bit/jdk1.8.0_121 -XX:-UseCompressedOops -XX:+UseSerialGC

1 tests failed.
FAILED:  org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.test

Error Message:
timeout waiting to see all nodes active

Stack Trace:
java.lang.AssertionError: timeout waiting to see all nodes active
	at __randomizedtesting.SeedInfo.seed([5BB34B1F6DD7462:8DEF0B6B5821199A]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.waitTillNodesActive(LeaderFailureAfterFreshStartTest.java:233)
	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.restartNodes(LeaderFailureAfterFreshStartTest.java:173)
	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.test(LeaderFailureAfterFreshStartTest.java:148)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	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 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.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 12629 lines...]
   [junit4] Suite: org.apache.solr.cloud.LeaderFailureAfterFreshStartTest
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/init-core-data-001
   [junit4]   2> 1444313 INFO  (SUITE-LeaderFailureAfterFreshStartTest-seed#[5BB34B1F6DD7462]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 1444314 INFO  (SUITE-LeaderFailureAfterFreshStartTest-seed#[5BB34B1F6DD7462]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1444315 INFO  (SUITE-LeaderFailureAfterFreshStartTest-seed#[5BB34B1F6DD7462]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /jv_f/v
   [junit4]   2> 1444317 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1444317 INFO  (Thread-2450) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1444317 INFO  (Thread-2450) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 1444417 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkTestServer start zk server on port:45850
   [junit4]   2> 1444422 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1444423 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1444424 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444425 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444425 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444426 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444426 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444427 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444427 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444428 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444428 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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> 1444491 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/cores/collection1
   [junit4]   2> 1444492 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1444493 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6d52335c{/jv_f/v,null,AVAILABLE}
   [junit4]   2> 1444494 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@6bce4929{SSL,[ssl, http/1.1]}{127.0.0.1:43506}
   [junit4]   2> 1444494 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server Started @1446624ms
   [junit4]   2> 1444494 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/tempDir-001/control/data, hostContext=/jv_f/v, hostPort=43506, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/cores}
   [junit4]   2> 1444494 ERROR (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1444495 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.5.0
   [junit4]   2> 1444495 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1444495 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1444495 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-02-19T14:59:10.395Z
   [junit4]   2> 1444497 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 1444497 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/solr.xml
   [junit4]   2> 1444525 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1444526 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45850/solr
   [junit4]   2> 1444535 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1444536 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43506_jv_f%2Fv
   [junit4]   2> 1444536 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.Overseer Overseer (id=97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) starting
   [junit4]   2> 1444539 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43506_jv_f%2Fv
   [junit4]   2> 1444540 INFO  (zkCallback-1835-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1444629 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/cores
   [junit4]   2> 1444629 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1444631 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1445638 WARN  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 1445639 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
   [junit4]   2> 1445650 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1445729 WARN  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1445731 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1445737 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1445737 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/control-001/cores/collection1/data/]
   [junit4]   2> 1445737 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5197f4c9
   [junit4]   2> 1445739 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=63.8974609375, floorSegmentMB=1.9150390625, forceMergeDeletesPctAllowed=26.36014600709151, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7800203775232898
   [junit4]   2> 1445752 WARN  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 1445778 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1445778 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1445778 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1445778 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1445779 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7524767408330313]
   [junit4]   2> 1445779 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74a20e56[collection1] main]
   [junit4]   2> 1445780 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1445780 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1445780 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1445781 INFO  (searcherExecutor-5699-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@74a20e56[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1445782 INFO  (coreLoadExecutor-5698-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection   x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559773945981304832
   [junit4]   2> 1445785 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1445785 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1445785 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43506/jv_f/v/collection1/
   [junit4]   2> 1445785 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1445785 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:43506/jv_f/v/collection1/ has no replicas
   [junit4]   2> 1445787 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43506/jv_f/v/collection1/ shard1
   [junit4]   2> 1445938 INFO  (coreZkRegister-5691-thread-1-processing-n:127.0.0.1:43506_jv_f%2Fv x:collection1 c:control_collection) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1446012 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1446012 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45850/solr ready
   [junit4]   2> 1446012 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1446012 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
   [junit4]   2> 1446075 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/cores/collection1
   [junit4]   2> 1446075 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001
   [junit4]   2> 1446076 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1446077 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7c41c2f4{/jv_f/v,null,AVAILABLE}
   [junit4]   2> 1446078 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@6c0037a4{SSL,[ssl, http/1.1]}{127.0.0.1:38154}
   [junit4]   2> 1446078 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server Started @1448208ms
   [junit4]   2> 1446078 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/jv_f/v, hostPort=38154, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/cores}
   [junit4]   2> 1446078 ERROR (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1446079 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.5.0
   [junit4]   2> 1446079 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1446079 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1446079 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-02-19T14:59:11.979Z
   [junit4]   2> 1446081 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 1446081 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/solr.xml
   [junit4]   2> 1446085 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1446086 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45850/solr
   [junit4]   2> 1446089 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1446090 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1446091 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38154_jv_f%2Fv
   [junit4]   2> 1446093 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1446093 INFO  (zkCallback-1839-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1446093 INFO  (zkCallback-1835-thread-3-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1446146 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:38154_jv_f%2Fv    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/cores
   [junit4]   2> 1446146 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1446148 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1446249 WARN  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.Overseer Bad version writing to ZK using compare-and-set, will force refresh cluster state: KeeperErrorCode = BadVersion for /collections/collection1/state.json
   [junit4]   2> 1446250 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1446251 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1446251 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1447155 WARN  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 1447155 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
   [junit4]   2> 1447166 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1447248 WARN  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1447250 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1447256 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1447256 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-1-001/cores/collection1/data/]
   [junit4]   2> 1447256 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5197f4c9
   [junit4]   2> 1447257 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=63.8974609375, floorSegmentMB=1.9150390625, forceMergeDeletesPctAllowed=26.36014600709151, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7800203775232898
   [junit4]   2> 1447304 WARN  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 1447329 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1447329 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1447330 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1447330 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1447330 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7524767408330313]
   [junit4]   2> 1447331 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@135af876[collection1] main]
   [junit4]   2> 1447331 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1447331 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1447331 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1447332 INFO  (searcherExecutor-5710-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@135af876[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1447333 INFO  (coreLoadExecutor-5709-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559773947607646208
   [junit4]   2> 1447336 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1447336 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1447336 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:38154/jv_f/v/collection1/
   [junit4]   2> 1447336 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1447336 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:38154/jv_f/v/collection1/ has no replicas
   [junit4]   2> 1447337 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:38154/jv_f/v/collection1/ shard1
   [junit4]   2> 1447439 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1447488 INFO  (coreZkRegister-5704-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1447562 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/cores/collection1
   [junit4]   2> 1447563 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001
   [junit4]   2> 1447564 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1447565 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7ecb5ac{/jv_f/v,null,AVAILABLE}
   [junit4]   2> 1447565 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@69dc7533{SSL,[ssl, http/1.1]}{127.0.0.1:34747}
   [junit4]   2> 1447565 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server Started @1449696ms
   [junit4]   2> 1447565 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/jv_f/v, hostPort=34747, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/cores}
   [junit4]   2> 1447566 ERROR (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1447566 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.5.0
   [junit4]   2> 1447566 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1447566 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1447566 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-02-19T14:59:13.466Z
   [junit4]   2> 1447568 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 1447568 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/solr.xml
   [junit4]   2> 1447572 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1447573 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45850/solr
   [junit4]   2> 1447577 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1447577 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1447578 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34747_jv_f%2Fv
   [junit4]   2> 1447578 INFO  (zkCallback-1835-thread-3-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1447579 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1447579 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1447579 INFO  (zkCallback-1839-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1447579 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1447646 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:34747_jv_f%2Fv    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/cores
   [junit4]   2> 1447646 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1447648 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1447749 WARN  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.Overseer Bad version writing to ZK using compare-and-set, will force refresh cluster state: KeeperErrorCode = BadVersion for /collections/collection1/state.json
   [junit4]   2> 1447750 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1447750 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1447751 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1447751 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1447751 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1448655 WARN  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 1448656 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
   [junit4]   2> 1448667 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1448750 WARN  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1448751 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1448757 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1448757 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-2-001/cores/collection1/data/]
   [junit4]   2> 1448757 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5197f4c9
   [junit4]   2> 1448758 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=63.8974609375, floorSegmentMB=1.9150390625, forceMergeDeletesPctAllowed=26.36014600709151, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7800203775232898
   [junit4]   2> 1448795 WARN  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 1448822 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1448823 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1448823 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1448823 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1448824 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7524767408330313]
   [junit4]   2> 1448824 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@50b04a49[collection1] main]
   [junit4]   2> 1448824 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1448825 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1448825 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1448826 INFO  (searcherExecutor-5721-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@50b04a49[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1448826 INFO  (coreLoadExecutor-5720-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559773949173170176
   [junit4]   2> 1448829 INFO  (coreZkRegister-5715-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 1448829 INFO  (updateExecutor-1848-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 1448829 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 1448829 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
   [junit4]   2> 1448830 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
   [junit4]   2> 1448830 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 1448830 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [https://127.0.0.1:38154/jv_f/v/collection1/] and I am [https://127.0.0.1:34747/jv_f/v/collection1/]
   [junit4]   2> 1448831 INFO  (recoveryExecutor-1849-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:38154/jv_f/v]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:34747_jv_f%252Fv&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 1448886 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 1448886 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> 1448886 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] 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:34747_jv_f%2Fv, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"https://127.0.0.1:34747/jv_f/v","node_name":"127.0.0.1:34747_jv_f%2Fv","state":"down"}
   [junit4]   2> 1448932 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1448932 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1449078 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/cores/collection1
   [junit4]   2> 1449078 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001
   [junit4]   2> 1449080 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1449080 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@23f7cc6e{/jv_f/v,null,AVAILABLE}
   [junit4]   2> 1449081 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@643d2473{SSL,[ssl, http/1.1]}{127.0.0.1:39272}
   [junit4]   2> 1449081 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.Server Started @1451211ms
   [junit4]   2> 1449081 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/jv_f/v, hostPort=39272, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/cores}
   [junit4]   2> 1449082 ERROR (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 1449082 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.5.0
   [junit4]   2> 1449082 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1449082 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1449082 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-02-19T14:59:14.982Z
   [junit4]   2> 1449084 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 1449084 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/solr.xml
   [junit4]   2> 1449088 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1449088 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45850/solr
   [junit4]   2> 1449094 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 1449094 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1449095 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39272_jv_f%2Fv
   [junit4]   2> 1449096 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 1449096 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 1449096 INFO  (zkCallback-1839-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 1449096 INFO  (zkCallback-1858-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 1449096 INFO  (zkCallback-1835-thread-3-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 1449133 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:39272_jv_f%2Fv    ] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/cores
   [junit4]   2> 1449133 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1449134 INFO  (OverseerStateUpdate-97485871527886853-127.0.0.1:43506_jv_f%2Fv-n_0000000000) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1449236 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1449236 INFO  (zkCallback-1858-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1449236 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1449886 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] 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:34747_jv_f%2Fv, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"https://127.0.0.1:34747/jv_f/v","node_name":"127.0.0.1:34747_jv_f%2Fv","state":"recovering"}
   [junit4]   2> 1449887 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 1449887 INFO  (qtp153843608-11015) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:34747_jv_f%252Fv&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
   [junit4]   2> 1450142 WARN  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 1450143 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
   [junit4]   2> 1450160 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1450279 WARN  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1450282 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1450302 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1450302 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] 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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001/shard-3-001/cores/collection1/data/]
   [junit4]   2> 1450302 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5197f4c9
   [junit4]   2> 1450305 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=63.8974609375, floorSegmentMB=1.9150390625, forceMergeDeletesPctAllowed=26.36014600709151, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7800203775232898
   [junit4]   2> 1450330 WARN  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 1450357 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1450357 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1450358 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1450358 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1450358 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7524767408330313]
   [junit4]   2> 1450358 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@396b78db[collection1] main]
   [junit4]   2> 1450359 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1450359 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1450359 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1450360 INFO  (searcherExecutor-5732-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@396b78db[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1450360 INFO  (coreLoadExecutor-5731-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv c:collection1   x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559773950781685760
   [junit4]   2> 1450363 INFO  (coreZkRegister-5726-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 c:collection1) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 1450364 INFO  (updateExecutor-1855-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 1450364 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 1450364 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
   [junit4]   2> 1450364 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
   [junit4]   2> 1450364 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 1450364 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [https://127.0.0.1:38154/jv_f/v/collection1/] and I am [https://127.0.0.1:39272/jv_f/v/collection1/]
   [junit4]   2> 1450366 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:38154/jv_f/v]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:39272_jv_f%252Fv&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 1450368 INFO  (qtp153843608-11016) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 1450368 INFO  (qtp153843608-11016) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> 1450368 INFO  (qtp153843608-11016) [n:127.0.0.1:38154_jv_f%2Fv    ] 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:39272_jv_f%2Fv, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"https://127.0.0.1:39272/jv_f/v","node_name":"127.0.0.1:39272_jv_f%2Fv","state":"down"}
   [junit4]   2> 1450466 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1450466 INFO  (zkCallback-1858-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1450466 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 1450508 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.LeaderFailureAfterFreshStartTest Leader node_name: core_node1,  url: https://127.0.0.1:38154/jv_f/v/collection1
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.LeaderFailureAfterFreshStartTest Nonleader node_name: core_node2,  url: https://127.0.0.1:34747/jv_f/v/collection1
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.LeaderFailureAfterFreshStartTest Nonleader node_name: core_node3,  url: https://127.0.0.1:39272/jv_f/v/collection1
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ChaosMonkey monkey: kill shard! 39272
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@643d2473{SSL,[ssl, http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1450509 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1783636152
   [junit4]   2> 1450510 WARN  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.RecoveryStrategy Stopping recovery for core=[collection1] coreNodeName=[core_node3]
   [junit4]   2> 1450511 ERROR (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Error while trying to recover. core=collection1:java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:38154/jv_f/v
   [junit4]   2> 	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
   [junit4]   2> 	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
   [junit4]   2> 	at org.apache.solr.cloud.RecoveryStrategy.sendPrepRecoveryCmd(RecoveryStrategy.java:614)
   [junit4]   2> 	at org.apache.solr.cloud.RecoveryStrategy.sendPrepRecoveryCmd(RecoveryStrategy.java:591)
   [junit4]   2> 	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:351)
   [junit4]   2> 	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:222)
   [junit4]   2> 	at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:38154/jv_f/v
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:624)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.lambda$httpUriRequest$0(HttpSolrClient.java:319)
   [junit4]   2> 	... 5 more
   [junit4]   2> Caused by: java.net.SocketException: Socket closed
   [junit4]   2> 	at java.net.SocketInputStream.read(SocketInputStream.java:204)
   [junit4]   2> 	at java.net.SocketInputStream.read(SocketInputStream.java:141)
   [junit4]   2> 	at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   [junit4]   2> 	at sun.security.ssl.InputRecord.read(InputRecord.java:503)
   [junit4]   2> 	at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
   [junit4]   2> 	at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
   [junit4]   2> 	at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
   [junit4]   2> 	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
   [junit4]   2> 	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
   [junit4]   2> 	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
   [junit4]   2> 	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
   [junit4]   2> 	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
   [junit4]   2> 	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
   [junit4]   2> 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
   [junit4]   2> 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
   [junit4]   2> 	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
   [junit4]   2> 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
   [junit4]   2> 	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:515)
   [junit4]   2> 	... 6 more
   [junit4]   2> 
   [junit4]   2> 1450511 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Replay not started, or was not successful... still buffering updates.
   [junit4]   2> 1450511 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy RecoveryStrategy has been closed
   [junit4]   2> 1450511 INFO  (recoveryExecutor-1856-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Finished recovery process, successful=[false]
   [junit4]   2> 1450512 INFO  (coreCloseExecutor-5737-thread-1) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@77da682f
   [junit4]   2> 1450512 WARN  (coreCloseExecutor-5737-thread-1) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Stopping recovery for core=[collection1] coreNodeName=[core_node3]
   [junit4]   2> 1450547 INFO  (coreCloseExecutor-5737-thread-1) [n:127.0.0.1:39272_jv_f%2Fv c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
   [junit4]   2> 1450548 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 1450548 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 1450548 INFO  (zkCallback-1835-thread-3-processing-n:127.0.0.1:43506_jv_f%2Fv) [n:127.0.0.1:43506_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 1450548 INFO  (zkCallback-1839-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 1450615 INFO  (zkCallback-1851-thread-1-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1450615 INFO  (zkCallback-1845-thread-1-processing-n:127.0.0.1:38154_jv_f%2Fv) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 1451369 INFO  (qtp153843608-11016) [n:127.0.0.1:38154_jv_f%2Fv    ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=false, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:39272_jv_f%2Fv, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"https://127.0.0.1:39272/jv_f/v","node_name":"127.0.0.1:39272_jv_f%2Fv","state":"down"}
   [junit4]   2> 1452048 WARN  (zkCallback-1858-thread-1-processing-n:127.0.0.1:39272_jv_f%2Fv) [n:127.0.0.1:39272_jv_f%2Fv    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1452048 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 1452048 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@23f7cc6e{/jv_f/v,null,UNAVAILABLE}
   [junit4]   2> 1452049 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ChaosMonkey monkey: stop shard! 39272
   [junit4]   2> 1452102 INFO  (qtp1840585938-10976) [n:127.0.0.1:43506_jv_f%2Fv c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/jv_f/v path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1559773952607256576)} 0 1
   [junit4]   2> 1452214 INFO  (qtp1960868147-11043) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/jv_f/v path=/update params={update.distrib=FROMLEADER&_version_=-1559773952662831104&distrib.from=https://127.0.0.1:38154/jv_f/v/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1559773952662831104)} 0 0
   [junit4]   2> 1452215 INFO  (qtp153843608-11020) [n:127.0.0.1:38154_jv_f%2Fv c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/jv_f/v path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1559773952662831104)} 0 61
   [junit4]   2> 1452215 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 30 for each attempt
   [junit4]   2> 1452215 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30
   [junit4]   2> 1452369

[...truncated too long message...]

ack-1865-thread-4-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4b4ff40d
   [junit4]   2> 1699102 INFO  (zkCallback-1865-thread-4-processing-n:127.0.0.1:34747_jv_f%2Fv) [n:127.0.0.1:34747_jv_f%2Fv c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
   [junit4]   2> 1699102 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 1699103 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@845b2af{SSL,[ssl, http/1.1]}{127.0.0.1:34747}
   [junit4]   2> 1699103 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@454fab3b{/jv_f/v,null,UNAVAILABLE}
   [junit4]   2> 1699103 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ChaosMonkey monkey: stop shard! 39272
   [junit4]   2> 1699104 INFO  (TEST-LeaderFailureAfterFreshStartTest.test-seed#[5BB34B1F6DD7462]) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45850 45850
   [junit4]   2> 1699115 INFO  (Thread-2450) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45850 45850
   [junit4]   2> 1699115 WARN  (Thread-2450) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	6	/solr/aliases.json
   [junit4]   2> 	5	/solr/security.json
   [junit4]   2> 	5	/solr/configs/conf1
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	6	/solr/clusterstate.json
   [junit4]   2> 	6	/solr/clusterprops.json
   [junit4]   2> 	4	/solr/collections/collection1/state.json
   [junit4]   2> 	2	/solr/overseer_elect/election/97485871527886858-127.0.0.1:38154_jv_f%2Fv-n_0000000001
   [junit4]   2> 	2	/solr/collections/collection1/leader_elect/shard1/election/97485871527886858-core_node1-n_0000000000
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	252	/solr/overseer/collection-queue-work
   [junit4]   2> 	18	/solr/overseer/queue
   [junit4]   2> 	13	/solr/overseer/queue-work
   [junit4]   2> 	6	/solr/collections
   [junit4]   2> 	5	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=LeaderFailureAfterFreshStartTest -Dtests.method=test -Dtests.seed=5BB34B1F6DD7462 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=el-GR -Dtests.timezone=Pacific/Noumea -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE  255s J1 | LeaderFailureAfterFreshStartTest.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: timeout waiting to see all nodes active
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([5BB34B1F6DD7462:8DEF0B6B5821199A]:0)
   [junit4]    > 	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.waitTillNodesActive(LeaderFailureAfterFreshStartTest.java:233)
   [junit4]    > 	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.restartNodes(LeaderFailureAfterFreshStartTest.java:173)
   [junit4]    > 	at org.apache.solr.cloud.LeaderFailureAfterFreshStartTest.test(LeaderFailureAfterFreshStartTest.java:148)
   [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.lang.Thread.run(Thread.java:745)
   [junit4]   2> 1699118 INFO  (SUITE-LeaderFailureAfterFreshStartTest-seed#[5BB34B1F6DD7462]-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.cloud.LeaderFailureAfterFreshStartTest_5BB34B1F6DD7462-001
   [junit4]   2> Feb 19, 2017 3:03:25 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): {other_tl1=PostingsFormat(name=Memory doPackFST= false), rnd_s=PostingsFormat(name=Memory doPackFST= false), multiDefault=FSTOrd50, a_t=FSTOrd50, a_i1=FSTOrd50, id=Lucene50(blocksize=128), text=PostingsFormat(name=Direct), timestamp=FSTOrd50}, docValues:{range_facet_l_dv=DocValuesFormat(name=Memory), _version_=DocValuesFormat(name=Lucene54), intDefault=DocValuesFormat(name=Lucene54), range_facet_i_dv=DocValuesFormat(name=Direct), intDvoDefault=DocValuesFormat(name=Memory), range_facet_l=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=1595, maxMBSortInHeap=7.550076415712336, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=el-GR, timezone=Pacific/Noumea
   [junit4]   2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=12,threads=1,free=199731992,total=514445312
   [junit4]   2> NOTE: All tests run in this JVM: [TestDynamicFieldCollectionResource, URLClassifyProcessorTest, TestPartialUpdateDeduplication, MetricsHandlerTest, IndexSchemaTest, CollectionTooManyReplicasTest, TestCloudPseudoReturnFields, TestWordDelimiterFilterFactory, TestUninvertingReader, DirectSolrSpellCheckerTest, TestFilteredDocIdSet, MigrateRouteKeyTest, ActionThrottleTest, SimplePostToolTest, TestPointFields, TestQueryUtils, TestSlowCompositeReaderWrapper, SpellCheckCollatorTest, TestManagedSchema, ExplicitHLLTest, TestInfoStreamLogging, TestLegacyFieldCache, TestConfigsApi, DistributedIntervalFacetingTest, TestXmlQParserPlugin, CollectionsAPIDistributedZkTest, TestRequestStatusCollectionAPI, DistributedFacetPivotWhiteBoxTest, TermVectorComponentTest, BlockDirectoryTest, SolrGangliaReporterTest, CSVRequestHandlerTest, ChangedSchemaMergeTest, TestEmbeddedSolrServerConstructors, TestSurroundQueryParser, UpdateRequestProcessorFactoryTest, SchemaVersionSpecificBehaviorTest, TestNoOpRegenerator, TestFuzzyAnalyzedSuggestions, DocValuesTest, DistributedMLTComponentTest, TestSubQueryTransformerCrossCore, TestComplexPhraseQParserPlugin, StatsReloadRaceTest, TestMacros, DocumentBuilderTest, TestDistributedGrouping, TestSchemaVersionResource, SuggesterFSTTest, AsyncCallRequestStatusResponseTest, TestLRUCache, TestReloadAndDeleteDocs, TestRandomCollapseQParserPlugin, ExitableDirectoryReaderTest, SolrMetricManagerTest, HttpPartitionTest, TestAnalyzeInfixSuggestions, EnumFieldTest, FileUtilsTest, TestSweetSpotSimilarityFactory, TestStressVersions, TestSchemaNameResource, CdcrUpdateLogTest, TestFastOutputStream, TestSolrQueryParserResource, RestartWhileUpdatingTest, TestFieldCacheReopen, SliceStateTest, ZkCLITest, ShardRoutingTest, BasicAuthIntegrationTest, JsonLoaderTest, TestRTGBase, TestManagedResourceStorage, TestExpandComponent, RankQueryTest, DateMathParserTest, HighlighterTest, TestSQLHandlerNonCloud, TestLeaderInitiatedRecoveryThread, TestCharFilters, HLLUtilTest, HdfsChaosMonkeyNothingIsSafeTest, DirectSolrConnectionTest, IndexBasedSpellCheckerTest, DeleteLastCustomShardedReplicaTest, TestConfigReload, TestSimpleQParserPlugin, SharedFSAutoReplicaFailoverUtilsTest, JsonValidatorTest, DistributedTermsComponentTest, TestPushWriter, MultiTermTest, RemoteQueryErrorTest, DistanceFunctionTest, HdfsTlogReplayBufferedWhileIndexingTest, TestInitQParser, SortByFunctionTest, AnalyticsQueryTest, ClusterStateUpdateTest, TestStressInPlaceUpdates, DistributedSuggestComponentTest, TestLMDirichletSimilarityFactory, DistributedVersionInfoTest, TestGeoJSONResponseWriter, OverseerTaskQueueTest, SaslZkACLProviderTest, BasicFunctionalityTest, BigEndianAscendingWordDeserializerTest, TestBinaryResponseWriter, TolerantUpdateProcessorTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, SyncSliceTest, TestRandomFaceting, LeaderElectionTest, TestZkChroot, ShardRoutingCustomTest, TestRecovery, TestHashPartitioner, TestStressReorder, TestReload, HardAutoCommitTest, StatsComponentTest, SolrCmdDistributorTest, TestFiltering, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, TestCoreDiscovery, TestExtendedDismaxParser, SolrRequestParserTest, TestTrie, SpatialFilterTest, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, QueryEqualityTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrDeletionPolicy1, CacheHeaderTest, StandardRequestHandlerTest, TestWriterPerf, TestQueryTypes, TestOmitPositions, TermsComponentTest, TestValueSourceCache, MoreLikeThisHandlerTest, TestSolrQueryParser, LoggingHandlerTest, JSONWriterTest, QueryParsingTest, BinaryUpdateRequestHandlerTest, TestQuerySenderListener, AlternateDirectoryTest, TestSolrIndexConfig, CopyFieldTest, BadComponentTest, TestMergePolicyConfig, TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestSolrCoreProperties, TestLuceneMatchVersion, EchoParamsTest, TestDFRSimilarityFactory, TestBM25SimilarityFactory, ResourceLoaderTest, TestFastLRUCache, PreAnalyzedFieldTest, TestSystemIdResolver, TestSuggestSpellingConverter, SpellingQueryConverterTest, ClusterStateTest, ZkNodePropsTest, CursorPagingTest, TestPathTrie, AliasIntegrationTest, CdcrReplicationDistributedZkTest, CdcrReplicationHandlerTest, CdcrVersionReplicationTest, CloudExitableDirectoryReaderTest, CollectionReloadTest, CollectionStateFormat2Test, DeleteNodeTest, DeleteShardTest, DistribJoinFromCollectionTest, DistributedQueueTest, DocValuesNotIndexedTest, LeaderElectionContextKeyTest, LeaderFailureAfterFreshStartTest]
   [junit4] Completed [531/696 (1!)] on J1 in 255.82s, 1 test, 1 failure <<< FAILURES!

[...truncated 63230 lines...]


Mime
View raw message