Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/3285/ Java: 64bit/jdk1.8.0_121 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed. FAILED: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.test Error Message: shard2 is not consistent. Got 204 from https://127.0.0.1:33191/tm_/i/collection1 (previous client) and got 185 from https://127.0.0.1:40121/tm_/i/collection1 Stack Trace: java.lang.AssertionError: shard2 is not consistent. Got 204 from https://127.0.0.1:33191/tm_/i/collection1 (previous client) and got 185 from https://127.0.0.1:40121/tm_/i/collection1 at __randomizedtesting.SeedInfo.seed([3E012BEF8449A0DB:B65514352AB5CD23]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1280) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1259) at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.test(ChaosMonkeySafeLeaderTest.java:162) 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 11735 lines...] [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/init-core-data-001 [junit4] 2> 545232 WARN (SUITE-ChaosMonkeySafeLeaderTest-seed#[3E012BEF8449A0DB]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=945 numCloses=945 [junit4] 2> 545232 INFO (SUITE-ChaosMonkeySafeLeaderTest-seed#[3E012BEF8449A0DB]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 545233 INFO (SUITE-ChaosMonkeySafeLeaderTest-seed#[3E012BEF8449A0DB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 545234 INFO (SUITE-ChaosMonkeySafeLeaderTest-seed#[3E012BEF8449A0DB]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /tm_/i [junit4] 2> 545235 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 545235 INFO (Thread-1695) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 545235 INFO (Thread-1695) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 545335 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkTestServer start zk server on port:46072 [junit4] 2> 545341 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545342 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 545342 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545343 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545343 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545344 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545344 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545346 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545346 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545347 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545347 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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> 545422 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/cores/collection1 [junit4] 2> 545424 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 545425 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@33361185{/tm_/i,null,AVAILABLE} [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6ab128bd{SSL,[ssl, http/1.1]}{127.0.0.1:45660} [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server Started @547126ms [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/tempDir-001/control/data, hostContext=/tm_/i, hostPort=45660, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/cores} [junit4] 2> 545426 ERROR (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.0 [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 545426 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-15T12:19:33.626Z [junit4] 2> 545428 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 545428 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/solr.xml [junit4] 2> 545433 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 545434 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46072/solr [junit4] 2> 545443 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 545444 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45660_tm_%2Fi [junit4] 2> 545444 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) starting [junit4] 2> 545447 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45660_tm_%2Fi [junit4] 2> 545448 INFO (zkCallback-1912-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 545527 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/cores [junit4] 2> 545527 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 545528 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 545529 INFO (OverseerStateUpdate-97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 546538 WARN (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 546538 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 546548 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 546614 WARN (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi 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> 546615 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 546623 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection, trusted=true [junit4] 2> 546623 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 546624 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/control-001/cores/collection1/data/] [junit4] 2> 546624 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi 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@2be0734f [junit4] 2> 546634 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=58.0224609375, floorSegmentMB=0.615234375, forceMergeDeletesPctAllowed=10.961656460699079, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 546659 WARN (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi 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> 546683 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 546684 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 546684 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; [junit4] 2> 546684 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 546685 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@1d180c34 [junit4] 2> 546685 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4ee165f5[collection1] main] [junit4] 2> 546686 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 546686 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 546686 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 546687 INFO (searcherExecutor-4322-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4ee165f5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 546687 INFO (coreLoadExecutor-4321-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi c:control_collection x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1564746737135910912 [junit4] 2> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi 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> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45660/tm_/i/collection1/ [junit4] 2> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:45660/tm_/i/collection1/ has no replicas [junit4] 2> 546691 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 546692 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi 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:45660/tm_/i/collection1/ shard1 [junit4] 2> 546843 INFO (coreZkRegister-4314-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi x:collection1 c:control_collection) [n:127.0.0.1:45660_tm_%2Fi c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 547059 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 547059 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46072/solr ready [junit4] 2> 547059 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 547059 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2 [junit4] 2> 547128 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/cores/collection1 [junit4] 2> 547129 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001 [junit4] 2> 547130 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 547131 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@348cdbbc{/tm_/i,null,AVAILABLE} [junit4] 2> 547131 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@49f1b9a5{SSL,[ssl, http/1.1]}{127.0.0.1:33191} [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server Started @548832ms [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/tm_/i, hostPort=33191, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/cores} [junit4] 2> 547132 ERROR (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.0 [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 547132 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-15T12:19:35.332Z [junit4] 2> 547134 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 547134 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/solr.xml [junit4] 2> 547139 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 547139 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46072/solr [junit4] 2> 547143 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 547144 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 547146 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33191_tm_%2Fi [junit4] 2> 547147 INFO (zkCallback-1916-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 547147 INFO (zkCallback-1912-thread-1-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 547147 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 547200 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/cores [junit4] 2> 547200 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 547201 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 547201 INFO (OverseerStateUpdate-97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 547303 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 548210 WARN (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 548210 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 548220 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 548288 WARN (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi 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> 548289 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 548298 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true [junit4] 2> 548298 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 548299 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-1-001/cores/collection1/data/] [junit4] 2> 548299 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2be0734f [junit4] 2> 548300 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=58.0224609375, floorSegmentMB=0.615234375, forceMergeDeletesPctAllowed=10.961656460699079, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 548472 WARN (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi 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> 548499 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 548499 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 548499 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; [junit4] 2> 548499 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 548500 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@26196ae8 [junit4] 2> 548501 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5529f366[collection1] main] [junit4] 2> 548502 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 548502 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 548502 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 548503 INFO (searcherExecutor-4333-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5529f366[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 548503 INFO (coreLoadExecutor-4332-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1564746739040124928 [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33191/tm_/i/collection1/ [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:33191/tm_/i/collection1/ has no replicas [junit4] 2> 548508 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 548509 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33191/tm_/i/collection1/ shard2 [junit4] 2> 548611 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 548660 INFO (coreZkRegister-4327-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:33191_tm_%2Fi c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 548762 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 548789 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/cores/collection1 [junit4] 2> 548789 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001 [junit4] 2> 548790 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 548791 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@517d61c8{/tm_/i,null,AVAILABLE} [junit4] 2> 548792 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6f0779c5{SSL,[ssl, http/1.1]}{127.0.0.1:46748} [junit4] 2> 548792 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server Started @550493ms [junit4] 2> 548792 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/tm_/i, hostPort=46748, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/cores} [junit4] 2> 548792 ERROR (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 548793 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.0 [junit4] 2> 548793 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 548793 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 548793 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-15T12:19:36.993Z [junit4] 2> 548794 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 548795 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/solr.xml [junit4] 2> 548799 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 548799 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46072/solr [junit4] 2> 548804 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 548805 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 548806 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46748_tm_%2Fi [junit4] 2> 548806 INFO (zkCallback-1916-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 548806 INFO (zkCallback-1912-thread-2-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 548807 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 548807 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 548863 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/cores [junit4] 2> 548864 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 548864 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 548865 INFO (OverseerStateUpdate-97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 548966 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 548966 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 549873 WARN (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 549873 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 549883 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 549941 WARN (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi 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> 549942 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 549958 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true [junit4] 2> 549959 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 549959 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-2-001/cores/collection1/data/] [junit4] 2> 549959 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2be0734f [junit4] 2> 549960 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=58.0224609375, floorSegmentMB=0.615234375, forceMergeDeletesPctAllowed=10.961656460699079, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 549984 WARN (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi 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> 550010 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 550010 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 550011 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; [junit4] 2> 550011 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 550012 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@25e361d4 [junit4] 2> 550012 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@d7a43d0[collection1] main] [junit4] 2> 550014 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 550014 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 550014 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 550015 INFO (searcherExecutor-4344-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@d7a43d0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 550015 INFO (coreLoadExecutor-4343-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1564746740625571840 [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46748/tm_/i/collection1/ [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:46748/tm_/i/collection1/ has no replicas [junit4] 2> 550019 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 550020 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46748/tm_/i/collection1/ shard3 [junit4] 2> 550122 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 550122 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 550171 INFO (coreZkRegister-4338-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:46748_tm_%2Fi c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 550273 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 550273 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 550460 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/cores/collection1 [junit4] 2> 550460 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001 [junit4] 2> 550461 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 550462 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@74658aca{/tm_/i,null,AVAILABLE} [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d41aa44{SSL,[ssl, http/1.1]}{127.0.0.1:37535} [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server Started @552164ms [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/tm_/i, hostPort=37535, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/cores} [junit4] 2> 550463 ERROR (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.0 [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 550463 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 550464 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-15T12:19:38.664Z [junit4] 2> 550465 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 550465 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/solr.xml [junit4] 2> 550470 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 550471 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46072/solr [junit4] 2> 550475 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 550476 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 550476 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37535_tm_%2Fi [junit4] 2> 550477 INFO (zkCallback-1916-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 550477 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 550477 INFO (zkCallback-1912-thread-2-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 550477 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 550477 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 550548 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/cores [junit4] 2> 550548 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 550549 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 550550 INFO (OverseerStateUpdate-97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 550651 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 550651 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] 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> 550651 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 551558 WARN (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 551558 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 551568 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 551626 WARN (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi 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> 551627 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 551634 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true [junit4] 2> 551635 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 551635 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-3-001/cores/collection1/data/] [junit4] 2> 551635 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2be0734f [junit4] 2> 551636 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=58.0224609375, floorSegmentMB=0.615234375, forceMergeDeletesPctAllowed=10.961656460699079, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 551672 WARN (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi 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> 551697 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 551697 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 551698 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; [junit4] 2> 551698 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 551699 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@59bd12fe [junit4] 2> 551699 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@36708b8a[collection1] main] [junit4] 2> 551699 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 551700 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 551700 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 551701 INFO (searcherExecutor-4355-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@36708b8a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 551701 INFO (coreLoadExecutor-4354-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1564746742393470976 [junit4] 2> 551704 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 551704 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 551704 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37535/tm_/i/collection1/ [junit4] 2> 551704 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 551705 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy https://127.0.0.1:37535/tm_/i/collection1/ has no replicas [junit4] 2> 551705 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 551706 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37535/tm_/i/collection1/ shard1 [junit4] 2> 551808 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] 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> 551808 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 551808 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 551857 INFO (coreZkRegister-4349-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:37535_tm_%2Fi c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 551959 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] 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> 551959 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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> 551959 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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> 552138 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/cores/collection1 [junit4] 2> 552139 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001 [junit4] 2> 552140 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 552141 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6d5407bd{/tm_/i,null,AVAILABLE} [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1ea574{SSL,[ssl, http/1.1]}{127.0.0.1:40121} [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.Server Started @553842ms [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/tempDir-001/jetty4, solrconfig=solrconfig.xml, hostContext=/tm_/i, hostPort=40121, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/cores} [junit4] 2> 552142 ERROR (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.0 [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 552142 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-15T12:19:40.342Z [junit4] 2> 552144 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 552144 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/solr.xml [junit4] 2> 552150 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 552150 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46072/solr [junit4] 2> 552155 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 552156 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 552156 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40121_tm_%2Fi [junit4] 2> 552157 INFO (zkCallback-1916-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552157 INFO (zkCallback-1912-thread-2-processing-n:127.0.0.1:45660_tm_%2Fi) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552157 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552158 INFO (zkCallback-1940-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552157 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552158 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 552232 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/cores [junit4] 2> 552232 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 552232 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 552233 INFO (OverseerStateUpdate-97796670975901701-127.0.0.1:45660_tm_%2Fi-n_0000000000) [n:127.0.0.1:45660_tm_%2Fi ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 552335 INFO (zkCallback-1934-thread-1-processing-n:127.0.0.1:37535_tm_%2Fi) [n:127.0.0.1:37535_tm_%2Fi ] 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: [5]) [junit4] 2> 552335 INFO (zkCallback-1940-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi ] 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: [5]) [junit4] 2> 552335 INFO (zkCallback-1928-thread-1-processing-n:127.0.0.1:46748_tm_%2Fi) [n:127.0.0.1:46748_tm_%2Fi ] 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: [5]) [junit4] 2> 552335 INFO (zkCallback-1922-thread-1-processing-n:127.0.0.1:33191_tm_%2Fi) [n:127.0.0.1:33191_tm_%2Fi ] 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: [5]) [junit4] 2> 553253 WARN (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 553253 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 553263 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 553322 WARN (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi 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> 553323 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 553330 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true [junit4] 2> 553330 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 553330 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi 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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001/shard-4-001/cores/collection1/data/] [junit4] 2> 553331 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2be0734f [junit4] 2> 553332 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=58.0224609375, floorSegmentMB=0.615234375, forceMergeDeletesPctAllowed=10.961656460699079, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 553370 WARN (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi 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> 553399 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 553399 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 553400 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; [junit4] 2> 553400 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 553402 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7e9e26e7 [junit4] 2> 553402 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@751e44aa[collection1] main] [junit4] 2> 553412 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 553412 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 553412 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 553413 INFO (searcherExecutor-4366-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@751e44aa[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 553413 INFO (coreLoadExecutor-4365-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1564746744188633088 [junit4] 2> 553416 INFO (coreZkRegister-4360-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi x:collection1 c:collection1) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 553417 INFO (updateExecutor-1937-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 553417 INFO (recoveryExecutor-1938-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 553417 IN [...truncated too long message...] figSetProcessor-97796670975901718-127.0.0.1:40121_tm_%2Fi-n_0000000005) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.OverseerTaskProcessor According to ZK I (id=97796670975901718-127.0.0.1:40121_tm_%2Fi-n_0000000005) am no longer a leader. [junit4] 2> 572226 ERROR (OverseerCollectionConfigSetProcessor-97796670975901718-127.0.0.1:40121_tm_%2Fi-n_0000000005) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.OverseerTaskProcessor Unable to prioritize overseer [junit4] 2> java.lang.InterruptedException [junit4] 2> at java.lang.Object.wait(Native Method) [junit4] 2> at java.lang.Object.wait(Object.java:502) [junit4] 2> at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1342) [junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1040) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:322) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:319) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:319) [junit4] 2> at org.apache.solr.cloud.OverseerNodePrioritizer.prioritizeOverseerNodes(OverseerNodePrioritizer.java:61) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:178) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 572227 WARN (zkCallback-1947-thread-1-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 572981 WARN (zkCallback-1947-thread-2-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.SyncStrategy Closed, skipping sync up. [junit4] 2> 572981 INFO (zkCallback-1947-thread-2-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@16594a29 [junit4] 2> 573007 INFO (zkCallback-1947-thread-2-processing-n:127.0.0.1:40121_tm_%2Fi) [n:127.0.0.1:40121_tm_%2Fi c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1 [junit4] 2> 573007 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 573008 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@126651ee{SSL,[ssl, http/1.1]}{127.0.0.1:40121} [junit4] 2> 573009 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@407b7eff{/tm_/i,null,UNAVAILABLE} [junit4] 2> 573010 INFO (TEST-ChaosMonkeySafeLeaderTest.test-seed#[3E012BEF8449A0DB]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46072 46072 [junit4] 2> 573037 INFO (Thread-1695) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46072 46072 [junit4] 2> 573038 WARN (Thread-1695) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 7 /solr/aliases.json [junit4] 2> 6 /solr/security.json [junit4] 2> 6 /solr/configs/conf1 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 7 /solr/clusterstate.json [junit4] 2> 7 /solr/clusterprops.json [junit4] 2> 5 /solr/collections/collection1/state.json [junit4] 2> 2 /solr/overseer_elect/election/97796670975901712-127.0.0.1:37535_tm_%2Fi-n_0000000003 [junit4] 2> 2 /solr/collections/collection1/leader_elect/shard2/election/97796670975901706-core_node1-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 36 /solr/overseer/queue [junit4] 2> 26 /solr/overseer/collection-queue-work [junit4] 2> 11 /solr/overseer/queue-work [junit4] 2> 7 /solr/collections [junit4] 2> 6 /solr/live_nodes [junit4] 2> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.method=test -Dtests.seed=3E012BEF8449A0DB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar-IQ -Dtests.timezone=Pacific/Ponape -Dtests.asserts=true -Dtests.file.encoding=US-ASCII [junit4] FAILURE 27.8s J0 | ChaosMonkeySafeLeaderTest.test <<< [junit4] > Throwable #1: java.lang.AssertionError: shard2 is not consistent. Got 204 from https://127.0.0.1:33191/tm_/i/collection1 (previous client) and got 185 from https://127.0.0.1:40121/tm_/i/collection1 [junit4] > at __randomizedtesting.SeedInfo.seed([3E012BEF8449A0DB:B65514352AB5CD23]:0) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1280) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1259) [junit4] > at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.test(ChaosMonkeySafeLeaderTest.java:162) [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> 573040 INFO (SUITE-ChaosMonkeySafeLeaderTest-seed#[3E012BEF8449A0DB]-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/J0/temp/solr.cloud.ChaosMonkeySafeLeaderTest_3E012BEF8449A0DB-001 [junit4] 2> Apr 15, 2017 12:20:01 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): {rnd_b=PostingsFormat(name=LuceneVarGapFixedInterval), a_t=FSTOrd50, a_i=PostingsFormat(name=LuceneVarGapFixedInterval), id=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{rnd_b=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Lucene54), a_t=DocValuesFormat(name=Lucene54), a_i=DocValuesFormat(name=Asserting), id=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1942, maxMBSortInHeap=7.175873553808039, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=ar-IQ, timezone=Pacific/Ponape [junit4] 2> NOTE: Linux 4.4.0-72-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=12,threads=1,free=221834872,total=536870912 [junit4] 2> NOTE: All tests run in this JVM: [AnalyticsQueryTest, TestFreeTextSuggestions, TestManagedSynonymFilterFactory, CdcrReplicationHandlerTest, TestHdfsUpdateLog, TestPushWriter, TestAddFieldRealTimeGet, RequiredFieldsTest, TestTolerantUpdateProcessorCloud, TestSolrConfigHandlerCloud, TestPerFieldSimilarity, TestDocSet, TestDeleteCollectionOnDownNodes, TestManagedSchema, TestDynamicFieldCollectionResource, QueryEqualityTest, TestImpersonationWithHadoopAuth, TestScoreJoinQPNoScore, ZkNodePropsTest, CollectionsAPIAsyncDistributedZkTest, QueryElevationComponentTest, SolrCLIZkUtilsTest, LeaderInitiatedRecoveryOnCommitTest, SuggestComponentContextFilterQueryTest, ReplicaListTransformerTest, StandardRequestHandlerTest, TestMacros, TestFieldResource, AlternateDirectoryTest, HdfsBasicDistributedZkTest, TestComplexPhraseQParserPlugin, MissingSegmentRecoveryTest, HLLUtilTest, TestIBSimilarityFactory, TestSchemaVersionResource, SolrRequestParserTest, TestSlowCompositeReaderWrapper, EnumFieldTest, JsonValidatorTest, CloudMLTQParserTest, TestMiniSolrCloudClusterSSL, TestPointFields, TestInitQParser, LeaderElectionContextKeyTest, TestAnalyzeInfixSuggestions, TestPHPSerializedResponseWriter, TestHdfsBackupRestoreCore, TestQueryWrapperFilter, TestFastWriter, SSLMigrationTest, TestRemoteStreaming, TestJettySolrRunner, TestPerFieldSimilarityWithDefaultOverride, TestClusterProperties, DeleteStatusTest, DistributedFacetPivotLongTailTest, TestPseudoReturnFields, TestDocumentBuilder, TestSolrQueryResponse, TestDFISimilarityFactory, TestFaceting, TestAuthenticationFramework, SpatialRPTFieldTypeTest, ExplicitHLLTest, SynonymTokenizerTest, PropertiesRequestHandlerTest, OutputWriterTest, TolerantUpdateProcessorTest, TestClassNameShortening, HdfsRecoveryZkTest, PathHierarchyTokenizerFactoryTest, CacheHeaderTest, PKIAuthenticationIntegrationTest, TestConfigSets, TestSolrQueryParserResource, TestConfigSetsAPIExclusivity, ClassificationUpdateProcessorTest, ConfigSetsAPITest, FastVectorHighlighterTest, ZkStateReaderTest, BaseCdcrDistributedZkTest, StatsReloadRaceTest, DistributedSpellCheckComponentTest, TestBinaryResponseWriter, TestXmlQParser, DistributedSuggestComponentTest, TestSolrCloudWithDelegationTokens, TestCrossCoreJoin, HighlighterConfigTest, DistributedExpandComponentTest, TestCSVLoader, TestLRUStatsCache, AtomicUpdatesTest, BigEndianAscendingWordDeserializerTest, TestRangeQuery, TestSolrXml, TestCloudPivotFacet, CursorPagingTest, ReplicationFactorTest, DistributedQueryElevationComponentTest, SolrMetricManagerTest, TestSolr4Spatial2, AliasIntegrationTest, TestAtomicUpdateErrorCases, ClusterStateTest, TestStressRecovery, TestLazyCores, TestManagedResourceStorage, MBeansHandlerTest, TestFilteredDocIdSet, TestStressLucene, TestCodecSupport, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest] [junit4] Completed [229/704 (1!)] on J0 in 28.83s, 1 test, 1 failure <<< FAILURES! [...truncated 44931 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
