Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/3252/
Java: 32bit/jdk-9-ea+164 -client -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.ShardSplitTest.testSplitWithChaosMonkey
Error Message:
There are still nodes recoverying - waited for 330 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330
seconds
at
__randomizedtesting.SeedInfo.seed([9B29EFE5EA28CDFA:100E3C34AB2E667E]:0)
at org.junit.Assert.fail(Assert.java:93)
at
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:187)
at
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:144)
at
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:139)
at
org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:865)
at
org.apache.solr.cloud.ShardSplitTest.testSplitWithChaosMonkey(ShardSplitTest.java:437)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:563)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 11822 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/init-core-data-001
[junit4] 2> 381618 WARN
(SUITE-ShardSplitTest-seed#[9B29EFE5EA28CDFA]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=17 numCloses=17
[junit4] 2> 381619 INFO
(SUITE-ShardSplitTest-seed#[9B29EFE5EA28CDFA]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 381620 INFO
(SUITE-ShardSplitTest-seed#[9B29EFE5EA28CDFA]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="https://issues.apache.org/jira/browse/SOLR-5776";)
[junit4] 2> 381620 INFO
(SUITE-ShardSplitTest-seed#[9B29EFE5EA28CDFA]-worker) [ ]
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /y/
[junit4] 2> 381622 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 381622 INFO (Thread-646) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 381622 INFO (Thread-646) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 381722 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkTestServer start zk server on port:36282
[junit4] 2> 381728 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381731 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381733 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381736 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381738 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381740 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381743 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381746 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381748 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381750 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 381752 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
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> 382423 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 Writing core.properties file to
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/cores/collection1
[junit4] 2> 382424 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 382425 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@a60147{/y,null,AVAILABLE}
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@4dada1{HTTP/1.1,[http/1.1]}{127.0.0.1:38064}
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server Started @384258ms
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/y,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/tempDir-001/control/data,
hostPort=38064,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/cores}
[junit4] 2> 382426 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
6.6.0
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 382426 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-04-11T09:26:08.309781Z
[junit4] 2> 382428 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 382428 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.SolrXmlConfig Loading container configuration from
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/solr.xml
[junit4] 2> 382434 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 382436 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36282/solr
[junit4] 2> 382447 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 382447 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38064_y
[junit4] 2> 382448 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=97773339771338756-127.0.0.1:38064_y-n_0000000000)
starting
[junit4] 2> 382452 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38064_y
[junit4] 2> 382453 INFO (zkCallback-2359-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 382698 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/cores
[junit4] 2> 382698 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 382699 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 382703 INFO
(OverseerStateUpdate-97773339771338756-127.0.0.1:38064_y-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 383711 WARN (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use
<mergePolicyFactory> instead.
[junit4] 2> 383711 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 383741 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 383791 WARN (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] default search field in schema is text.
WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 383792 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 383830 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection control_collection, trusted=true
[junit4] 2> 383831 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 383831 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/cores/collection1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/control-001/cores/collection1/data/]
[junit4] 2> 383831 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@dc1416
[junit4] 2> 383847 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=18.9453125,
floorSegmentMB=1.779296875, forceMergeDeletesPctAllowed=22.086593230756897,
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 383911 WARN (coreLoadExecutor-1716-thread-1) [ ]
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> 384088 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 384088 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 384089 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 384089 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 384090 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.8664814653166723]
[junit4] 2> 384090 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@146c9cd[collection1] main]
[junit4] 2> 384091 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 384091 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 384091 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 384092 INFO (searcherExecutor-1717-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@146c9cd[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 384093 INFO (coreLoadExecutor-1716-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1564373438930354176
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:38064/y/collection1/
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:38064/y/collection1/ has no replicas
[junit4] 2> 384097 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 384100 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:38064/y/collection1/ shard1
[junit4] 2> 384250 INFO (coreZkRegister-1709-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 384386 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 384387 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:36282/solr ready
[junit4] 2> 384387 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection
loss:false
[junit4] 2> 385368 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 Writing core.properties file to
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/cores/collection1
[junit4] 2> 385369 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001
[junit4] 2> 385369 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 385370 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@620279{/y,null,AVAILABLE}
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@173f1db{HTTP/1.1,[http/1.1]}{127.0.0.1:40785}
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server Started @387203ms
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/y,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/tempDir-001/jetty1,
hostPort=40785,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/cores}
[junit4] 2> 385371 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
6.6.0
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 385371 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-04-11T09:26:11.254777Z
[junit4] 2> 385374 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 385374 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.SolrXmlConfig Loading container configuration from
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/solr.xml
[junit4] 2> 385380 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 385382 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36282/solr
[junit4] 2> 385387 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 385388 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 385389 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:40785_y
[junit4] 2> 385393 INFO (zkCallback-2359-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 385394 INFO (zkCallback-2368-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 385394 INFO (zkCallback-2363-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 385575 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/cores
[junit4] 2> 385575 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 385575 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 385576 INFO
(OverseerStateUpdate-97773339771338756-127.0.0.1:38064_y-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 386588 WARN (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use
<mergePolicyFactory> instead.
[junit4] 2> 386588 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 386598 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 386654 WARN (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] default search field in schema is text.
WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 386656 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 386665 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 386665 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 386665 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/cores/collection1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-1-001/cores/collection1/data/]
[junit4] 2> 386666 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@dc1416
[junit4] 2> 386668 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=18.9453125,
floorSegmentMB=1.779296875, forceMergeDeletesPctAllowed=22.086593230756897,
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 386707 WARN (coreLoadExecutor-1727-thread-1) [ ]
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> 386886 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 386886 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 386886 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 386887 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 386887 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.8664814653166723]
[junit4] 2> 386888 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1022d85[collection1] main]
[junit4] 2> 386889 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 386889 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 386889 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 386890 INFO (searcherExecutor-1728-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@1022d85[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 386891 INFO (coreLoadExecutor-1727-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1564373441864269824
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40785/y/collection1/
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:40785/y/collection1/ has no replicas
[junit4] 2> 386896 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 386897 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:40785/y/collection1/ shard2
[junit4] 2> 387048 INFO (coreZkRegister-1722-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 387911 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 Writing core.properties file to
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/cores/collection1
[junit4] 2> 387911 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001
[junit4] 2> 387912 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 387913 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@25d926{/y,null,AVAILABLE}
[junit4] 2> 387914 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@abae30{HTTP/1.1,[http/1.1]}{127.0.0.1:34826}
[junit4] 2> 387914 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server Started @389746ms
[junit4] 2> 387914 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/y,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/tempDir-001/jetty2,
hostPort=34826,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/cores}
[junit4] 2> 387914 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 387914 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
6.6.0
[junit4] 2> 387915 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 387915 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 387915 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-04-11T09:26:13.798145Z
[junit4] 2> 387917 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 387917 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.SolrXmlConfig Loading container configuration from
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/solr.xml
[junit4] 2> 387928 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 387931 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36282/solr
[junit4] 2> 387950 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 387951 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 387953 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:34826_y
[junit4] 2> 387954 INFO (zkCallback-2368-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 387954 INFO (zkCallback-2363-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 387955 INFO (zkCallback-2359-thread-3) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 387958 INFO (zkCallback-2374-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 388373 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/cores
[junit4] 2> 388374 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 388374 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 388375 INFO
(OverseerStateUpdate-97773339771338756-127.0.0.1:38064_y-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 389382 WARN (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use
<mergePolicyFactory> instead.
[junit4] 2> 389383 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 389394 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 389496 WARN (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] default search field in schema is text.
WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 389498 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 389513 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 389513 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 389514 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/cores/collection1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-2-001/cores/collection1/data/]
[junit4] 2> 389514 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@dc1416
[junit4] 2> 389517 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=18.9453125,
floorSegmentMB=1.779296875, forceMergeDeletesPctAllowed=22.086593230756897,
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 389574 WARN (coreLoadExecutor-1738-thread-1) [ ]
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> 389814 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 389814 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 389816 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 389816 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 389817 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.8664814653166723]
[junit4] 2> 389820 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@bab07b[collection1] main]
[junit4] 2> 389821 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 389821 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 389821 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 389824 INFO (coreLoadExecutor-1738-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1564373444939743232
[junit4] 2> 389828 INFO (searcherExecutor-1739-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@bab07b[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:34826/y/collection1/
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:34826/y/collection1/ has no replicas
[junit4] 2> 389833 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 389835 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:34826/y/collection1/ shard1
[junit4] 2> 389987 INFO (coreZkRegister-1733-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 390654 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 Writing core.properties file to
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/cores/collection1
[junit4] 2> 390655 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001
[junit4] 2> 390655 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 390659 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@a9ce16{/y,null,AVAILABLE}
[junit4] 2> 390659 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@786790{HTTP/1.1,[http/1.1]}{127.0.0.1:34347}
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server Started @392492ms
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/y,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/tempDir-001/jetty3,
hostPort=34347,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/cores}
[junit4] 2> 390660 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
6.6.0
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 390660 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-04-11T09:26:16.543698Z
[junit4] 2> 390663 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 390663 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.SolrXmlConfig Loading container configuration from
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/solr.xml
[junit4] 2> 390669 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 390672 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36282/solr
[junit4] 2> 390677 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 390678 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 390679 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:34347_y
[junit4] 2> 390680 INFO (zkCallback-2359-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 390680 INFO (zkCallback-2368-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 390680 INFO (zkCallback-2374-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 390681 INFO (zkCallback-2380-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 390681 INFO (zkCallback-2363-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 390875 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/cores
[junit4] 2> 390875 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 390876 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 390882 INFO
(OverseerStateUpdate-97773339771338756-127.0.0.1:38064_y-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 391898 WARN (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use
<mergePolicyFactory> instead.
[junit4] 2> 391898 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 391908 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 392007 WARN (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] default search field in schema is text.
WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 392008 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 392018 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 392018 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 392018 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/cores/collection1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-3-001/cores/collection1/data/]
[junit4] 2> 392019 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@dc1416
[junit4] 2> 392021 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=18.9453125,
floorSegmentMB=1.779296875, forceMergeDeletesPctAllowed=22.086593230756897,
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 392038 WARN (coreLoadExecutor-1749-thread-1) [ ]
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> 392270 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 392270 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 392271 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 392271 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 392273 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.8664814653166723]
[junit4] 2> 392273 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1fcc2ca[collection1] main]
[junit4] 2> 392274 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 392275 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 392275 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 392276 INFO (searcherExecutor-1750-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@1fcc2ca[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 392277 INFO (coreLoadExecutor-1749-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1564373447511900160
[junit4] 2> 392280 INFO (coreZkRegister-1744-thread-1) [ ]
o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 392280 INFO (updateExecutor-2377-thread-1) [ ]
o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 392280 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 392281 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 392281 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 392281 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=null}
[junit4] 2> 392281 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering,
leader is [http://127.0.0.1:40785/y/collection1/] and I am
[http://127.0.0.1:34347/y/collection1/]
[junit4] 2> 392283 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Sending prep recovery command to
[http://127.0.0.1:40785/y]; [WaitForState:
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:34347_y&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 392287 INFO (qtp392089-9652) [ ] o.a.s.h.a.PrepRecoveryOp
Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true,
onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 392287 INFO (qtp392089-9652) [ ] o.a.s.h.a.PrepRecoveryOp
Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have
state: recovering
[junit4] 2> 392287 INFO (qtp392089-9652) [ ] o.a.s.h.a.PrepRecoveryOp
In WaitForState(recovering): collection=collection1, shard=shard2,
thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true,
live=true, checkLive=true, currentState=down, localState=active,
nodeName=127.0.0.1:34347_y, coreNodeName=core_node3,
onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:34347/y","node_name":"127.0.0.1:34347_y","state":"down"}
[junit4] 2> 393132 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 Writing core.properties file to
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/cores/collection1
[junit4] 2> 393133 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001
[junit4] 2> 393134 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 393135 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@17eab69{/y,null,AVAILABLE}
[junit4] 2> 393135 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@9b21fd{HTTP/1.1,[http/1.1]}{127.0.0.1:45557}
[junit4] 2> 393136 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.Server Started @394968ms
[junit4] 2> 393136 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/y,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/tempDir-001/jetty4,
hostPort=45557,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/cores}
[junit4] 2> 393136 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 393136 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
6.6.0
[junit4] 2> 393136 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 393137 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 393137 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-04-11T09:26:19.020053Z
[junit4] 2> 393139 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 393139 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.SolrXmlConfig Loading container configuration from
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/solr.xml
[junit4] 2> 393149 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 393152 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36282/solr
[junit4] 2> 393159 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 393160 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 393161 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45557_y
[junit4] 2> 393162 INFO (zkCallback-2374-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393162 INFO (zkCallback-2368-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393174 INFO (zkCallback-2363-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393174 INFO (zkCallback-2380-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393176 INFO (zkCallback-2359-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393177 INFO (zkCallback-2387-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 393287 INFO (qtp392089-9652) [ ] o.a.s.h.a.PrepRecoveryOp
In WaitForState(recovering): collection=collection1, shard=shard2,
thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true,
live=true, checkLive=true, currentState=recovering, localState=active,
nodeName=127.0.0.1:34347_y, coreNodeName=core_node3,
onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:34347/y","node_name":"127.0.0.1:34347_y","state":"recovering"}
[junit4] 2> 393287 INFO (qtp392089-9652) [ ] o.a.s.h.a.PrepRecoveryOp
Waited coreNodeName: core_node3, state: recovering, checkLive: true,
onlyIfLeader: true for: 1 seconds.
[junit4] 2> 393287 INFO (qtp392089-9652) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:34347_y&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1000
[junit4] 2> 393375 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/cores
[junit4] 2> 393375 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 393387 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 393388 INFO
(OverseerStateUpdate-97773339771338756-127.0.0.1:38064_y-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 393788 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Attempting to PeerSync from
[http://127.0.0.1:40785/y/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 393788 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:34347/y START
replicas=[http://127.0.0.1:40785/y/collection1/] nUpdates=100
[junit4] 2> 393793 INFO (qtp392089-9652) [ ] o.a.s.u.IndexFingerprint
IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807,
maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0,
maxDoc=0}
[junit4] 2> 393793 INFO (qtp392089-9652) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=1
[junit4] 2> 393795 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0
result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0,
maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 393795 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 393795 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 393795 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 393796 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 393798 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 393798 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 393798 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 393798 INFO (recoveryExecutor-2378-thread-1) [ ]
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 394399 WARN (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use
<mergePolicyFactory> instead.
[junit4] 2> 394399 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 394411 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 394485 WARN (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] default search field in schema is text.
WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 394486 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 394495 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 394495 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 394495 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/cores/collection1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001/shard-4-001/cores/collection1/data/]
[junit4] 2> 394495 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@dc1416
[junit4] 2> 394498 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=18.9453125,
floorSegmentMB=1.779296875, forceMergeDeletesPctAllowed=22.086593230756897,
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 394531 WARN (coreLoadExecutor-1760-thread-1) [ ]
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> 394735 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 394735 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 394736 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 394736 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 394737 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.8664814653166723]
[junit4] 2> 394738 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@16a2ac5[collection1] main]
[junit4] 2> 394739 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 394739 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 394739 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 394740 INFO (searcherExecutor-1761-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@16a2ac5[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 394741 INFO (coreLoadExecutor-1760-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1564373450095591424
[junit4] 2> 394745 INFO (coreZkRegister-1755-thread-1) [ ]
o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 394746 INFO (updateExecutor-2384-thread-1) [ ]
o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 394746 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 394746 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 394746 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 394746 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=null}
[junit4] 2> 394746 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering,
leader is [http://127.0.0.1:34826/y/collection1/] and I am
[http://127.0.0.1:45557/y/collection1/]
[junit4] 2> 394748 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Sending prep recovery command to
[http://127.0.0.1:34826/y]; [WaitForState:
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:45557_y&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 394751 INFO (qtp15849838-9678) [ ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 394751 INFO (qtp15849838-9678) [ ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1
(shard1 of collection1) have state: recovering
[junit4] 2> 394751 INFO (qtp15849838-9678) [ ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1,
shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader?
true, live=true, checkLive=true, currentState=down, localState=active,
nodeName=127.0.0.1:45557_y, coreNodeName=core_node4,
onlyIfActiveCheckResult=false, nodeProps:
core_node4:{"core":"collection1","base_url":"http://127.0.0.1:45557/y","node_name":"127.0.0.1:45557_y","state":"down"}
[junit4] 2> 395092 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testSplitWithChaosMonkey
[junit4] 2> 395092 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 15
for each attempt
[junit4] 2> 395092 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection:
collection1 failOnTimeout:true timeout (sec):15
[junit4] 2> 395751 INFO (qtp15849838-9678) [ ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1,
shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader?
true, live=true, checkLive=true, currentState=recovering, localState=active,
nodeName=127.0.0.1:45557_y, coreNodeName=core_node4,
onlyIfActiveCheckResult=false, nodeProps:
core_node4:{"core":"collection1","base_url":"http://127.0.0.1:45557/y","node_name":"127.0.0.1:45557_y","state":"recovering"}
[junit4] 2> 395751 INFO (qtp15849838-9678) [ ]
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node4, state: recovering,
checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 395751 INFO (qtp15849838-9678) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:45557_y&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node4&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1000
[junit4] 2> 396252 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Attempting to PeerSync from
[http://127.0.0.1:34826/y/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 396252 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:45557/y START
replicas=[http://127.0.0.1:34826/y/collection1/] nUpdates=100
[junit4] 2> 396256 INFO (qtp15849838-9678) [ ]
o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0
result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0,
maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 396256 INFO (qtp15849838-9678) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0
result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0,
maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 396257 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 396258 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 396258 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 396258 INFO (recoveryExecutor-2385-thread-1) [ ]
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 397094 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 397096 INFO (qtp25336719-9616) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 397097 INFO (qtp25336719-9616) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 397098 INFO (qtp25336719-9616) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 397098 INFO (qtp25336719-9616) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 1
[junit4] 2> 397103 INFO (qtp6695910-9736) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 397107 INFO (qtp15849838-9676) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 397107 INFO (qtp15849838-9676) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 397108 INFO (qtp6695910-9736) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 397108 INFO (qtp15849838-9676) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 397108 INFO (qtp6695910-9736) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 397108 INFO (qtp6695910-9736) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:34826/y/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 5
[junit4] 2> 397109 INFO (qtp15849838-9676) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:34826/y/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 1
[junit4] 2> 397109 INFO (qtp16016238-9709) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 397109 INFO (qtp392089-9645) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 397109 INFO (qtp392089-9645) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 397113 INFO (qtp16016238-9709) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 397115 INFO (qtp392089-9645) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 397115 INFO (qtp16016238-9709) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 397115 INFO (qtp392089-9645) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:34826/y/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 5
[junit4] 2> 397115 INFO (qtp16016238-9709) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:34826/y/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 6
[junit4] 2> 397118 INFO (qtp15849838-9680) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 18
[junit4] 2> 397134 INFO (qtp392089-9652) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 397137 INFO (qtp16016238-9708) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 397140 INFO (qtp15849838-9673) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 397151 INFO (qtp6695910-9737) [ ] o.a.s.c.S.Request
[collection1] webapp=/y path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=1
[junit4] 2> 399160 INFO (qtp25336719-9617) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-0 (1564373454726103040)]} 0 3
[junit4] 2> 399169 INFO (qtp6695910-9741) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{add=[0-0
(1564373454732394496)]} 0 2
[junit4] 2> 399169 INFO (qtp15849838-9674) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-0 (1564373454732394496)]} 0 6
[junit4] 2> 399172 INFO (qtp25336719-9610) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-0 (-1564373454740783104)]}
0 1
[junit4] 2> 399177 INFO (qtp6695910-9736) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{delete=[0-0
(-1564373454743928832)]} 0 1
[junit4] 2> 399177 INFO (qtp15849838-9676) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{delete=[0-0 (-1564373454743928832)]} 0 3
[junit4] 2> 399180 INFO (qtp25336719-9616) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-1 (1564373454749171712)]} 0 1
[junit4] 2> 399185 INFO (qtp6695910-9742) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{add=[0-1
(1564373454752317440)]} 0 0
[junit4] 2> 399185 INFO (qtp15849838-9680) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-1 (1564373454752317440)]} 0 3
[junit4] 2> 399188 INFO (qtp25336719-9615) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-2 (1564373454757560320)]} 0 1
[junit4] 2> 399194 INFO (qtp6695910-9737) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{add=[0-2
(1564373454761754624)]} 0 1
[junit4] 2> 399195 INFO (qtp15849838-9678) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-2 (1564373454761754624)]} 0 3
[junit4] 2> 399197 INFO (qtp25336719-9617) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-2 (-1564373454766997504)]}
0 0
[junit4] 2> 399200 INFO (qtp6695910-9741) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{delete=[0-2
(-1564373454769094656)]} 0 0
[junit4] 2> 399201 INFO (qtp15849838-9674) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{delete=[0-2 (-1564373454769094656)]} 0 2
[junit4] 2> 399204 INFO (qtp25336719-9610) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-3 (1564373454774337536)]} 0 1
[junit4] 2> 399209 INFO (qtp6695910-9736) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{add=[0-3
(1564373454777483264)]} 0 0
[junit4] 2> 399209 INFO (qtp15849838-9676) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-3 (1564373454777483264)]} 0 3
[junit4] 2> 399211 INFO (qtp25336719-9616) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-4 (1564373454782726144)]} 0 0
[junit4] 2> 399215 INFO (qtp6695910-9742) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{add=[0-4
(1564373454784823296)]} 0 0
[junit4] 2> 399216 INFO (qtp15849838-9680) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-4 (1564373454784823296)]} 0 2
[junit4] 2> 399218 INFO (qtp25336719-9615) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-5 (1564373454789017600)]} 0 0
[junit4] 2> 399229 INFO (qtp16016238-9704) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40785/y/collection1/&wt=javabin&version=2}{add=[0-5
(1564373454791114752)]} 0 4
[junit4] 2> 399229 INFO (qtp392089-9645) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-5 (1564373454791114752)]} 0 10
[junit4] 2> 399231 INFO (qtp25336719-9617) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-6 (1564373454803697664)]} 0 0
[junit4] 2> 399237 INFO (qtp16016238-9703) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40785/y/collection1/&wt=javabin&version=2}{add=[0-6
(1564373454805794816)]} 0 1
[junit4] 2> 399237 INFO (qtp392089-9648) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-6 (1564373454805794816)]} 0 4
[junit4] 2> 399239 INFO (qtp25336719-9610) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-4 (-1564373454812086272)]}
0 0
[junit4] 2> 399243 INFO (qtp6695910-9737) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:34826/y/collection1/&wt=javabin&version=2}{delete=[0-4
(-1564373454814183424)]} 0 0
[junit4] 2> 399243 INFO (qtp15849838-9678) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{delete=[0-4 (-1564373454814183424)]} 0 2
[junit4] 2> 399245 INFO (qtp25336719-9616) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-7 (1564373454818377728)]} 0 0
[junit4] 2> 399250 INFO (qtp16016238-9708) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40785/y/collection1/&wt=javabin&version=2}{add=[0-7
(1564373454820474880)]} 0 0
[junit4] 2> 399250 INFO (qtp392089-9652) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-7 (1564373454820474880)]} 0 3
[junit4] 2> 399253 INFO (qtp25336719-9615) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-8 (1564373454826766336)]} 0 0
[junit4] 2> 399259 INFO (qtp16016238-9709) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40785/y/collection1/&wt=javabin&version=2}{add=[0-8
(1564373454828863488)]} 0 1
[junit4] 2> 399259 INFO (qtp392089-9650) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-8 (1564373454828863488)]} 0 4
[junit4] 2> 399261 INFO (qtp25336719-9617) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-9 (1564373454835154944)]} 0 0
[junit4] 2> 399265 INFO (qtp16016238-9704) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40785/y/collection1/&wt=javabin&version=2}{add=[0-9
(1564373454837252096)]} 0 0
[junit4] 2> 399265 INFO (qtp392089-9645) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/y path=/update
params={wt=javabin&version=2}{add=[0-9 (1564373454837252096)]} 0 2
[junit4] 2> 399267 INFO (qtp25336719-9610) [
[...truncated too long message...]
.1]}{127.0.0.1:0}
[junit4] 2> 1209027 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@dee268{/y,null,UNAVAILABLE}
[junit4] 2> 1209027 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ChaosMonkey monkey: stop shard! 33907
[junit4] 2> 1209027 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=22673989
[junit4] 2> 1209028 INFO (coreCloseExecutor-2382-thread-1) [ ]
o.a.s.c.SolrCore [collection1] CLOSING SolrCore
org.apache.solr.core.SolrCore@4166ae
[junit4] 2> 1209064 INFO (coreCloseExecutor-2382-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1209064 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=97773391205564431-127.0.0.1:33907_y-n_0000000003)
closing
[junit4] 2> 1209064 INFO
(OverseerStateUpdate-97773391205564431-127.0.0.1:33907_y-n_0000000003) [ ]
o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:33907_y
[junit4] 2> 1209065 INFO (zkCallback-2551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1209065 INFO (zkCallback-2576-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1209065 INFO (zkCallback-2576-thread-4) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41543_y
[junit4] 2> 1209066 INFO (zkCallback-2576-thread-4) [ ]
o.a.s.c.Overseer Overseer (id=97773391205564434-127.0.0.1:41543_y-n_0000000004)
starting
[junit4] 2> 1209070 INFO (zkCallback-2576-thread-4) [ ]
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: [1])
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41543/y/collection1/
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-3) [ ]
o.a.s.c.SyncStrategy Sync replicas to
http://127.0.0.1:41543/y/collection1_shard1_1_replica0/
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-3) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:41543/y/collection1/ has no replicas
[junit4] 2> 1210027 INFO (zkCallback-2576-thread-3) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:41543/y/collection1_shard1_1_replica0/
has no replicas
[junit4] 2> 1210029 INFO (zkCallback-2576-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:41543/y/collection1/ shard1
[junit4] 2> 1210029 INFO (zkCallback-2576-thread-3) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:41543/y/collection1_shard1_1_replica0/ shard1_1
[junit4] 2> 1210131 INFO (zkCallback-2576-thread-3) [ ]
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: [1])
[junit4] 2> 1210565 WARN (zkCallback-2569-thread-1) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1210565 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1210566 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@bc022e{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1210566 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1f0d563{/y,null,UNAVAILABLE}
[junit4] 2> 1210567 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ChaosMonkey monkey: stop shard! 41543
[junit4] 2> 1210567 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=8931498
[junit4] 2> 1210568 INFO (coreCloseExecutor-2386-thread-1) [ ]
o.a.s.c.SolrCore [collection1] CLOSING SolrCore
org.apache.solr.core.SolrCore@cdac33
[junit4] 2> 1210568 INFO (coreCloseExecutor-2386-thread-2) [ ]
o.a.s.c.SolrCore [collection1_shard1_1_replica0] CLOSING SolrCore
org.apache.solr.core.SolrCore@1a3ca6c
[junit4] 2> 1210604 INFO (coreCloseExecutor-2386-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1210620 INFO (coreCloseExecutor-2386-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.collection1.shard1_1.replica0
[junit4] 2> 1210621 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.Overseer Overseer (id=97773391205564434-127.0.0.1:41543_y-n_0000000004)
closing
[junit4] 2> 1210621 INFO
(OverseerStateUpdate-97773391205564434-127.0.0.1:41543_y-n_0000000004) [ ]
o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:41543_y
[junit4] 2> 1210622 INFO (zkCallback-2551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1212121 WARN (zkCallback-2576-thread-3) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1212122 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1212122 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@ff8784{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1212123 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1ba315e{/y,null,UNAVAILABLE}
[junit4] 2> 1212123 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ChaosMonkey monkey: stop shard! 41764
[junit4] 2> 1212123 INFO
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[9B29EFE5EA28CDFA]) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:39131 39131
[junit4] 2> 1212140 INFO (Thread-959) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:39131 39131
[junit4] 2> 1212141 WARN (Thread-959) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/aliases.json
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 5 /solr/security.json
[junit4] 2> 5 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/clusterstate.json
[junit4] 2> 4 /solr/collections/collection1/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 56 /solr/overseer/queue
[junit4] 2> 19 /solr/overseer/collection-queue-work
[junit4] 2> 10 /solr/overseer/queue-work
[junit4] 2> 6 /solr/live_nodes
[junit4] 2> 6 /solr/collections
[junit4] 2>
[junit4] 2> 1212144 INFO
(SUITE-ShardSplitTest-seed#[9B29EFE5EA28CDFA]-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/J2/temp/solr.cloud.ShardSplitTest_9B29EFE5EA28CDFA-001
[junit4] 2> Apr 11, 2017 9:39:58 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=en-AS,
timezone=Asia/Manila
[junit4] 2> NOTE: Linux 4.4.0-72-generic i386/Oracle Corporation 9-ea
(32-bit)/cpus=12,threads=1,free=133047000,total=450887680
[junit4] 2> NOTE: All tests run in this JVM:
[TestSolrQueryParserDefaultOperatorResource, HdfsChaosMonkeySafeLeaderTest,
TestSQLHandlerNonCloud, TestCloudManagedSchema, TestSolrDynamicMBean,
InfixSuggestersTest, HdfsBasicDistributedZk2Test, TestBulkSchemaAPI,
TestRawTransformer, TestExceedMaxTermLength, ResponseLogComponentTest,
TestReqParamsAPI, DistributedFacetPivotLargeTest, SmileWriterTest,
TestStressLiveNodes, TestFieldCollectionResource, TestGroupingSearch,
TestCoreDiscovery, TestSchemaSimilarityResource, TestSolrFieldCacheMBean,
SubstringBytesRefFilterTest, TestDistributedMissingSort,
CdcrReplicationDistributedZkTest, PrimUtilsTest, TestRTimerTree,
TestDistributedStatsComponentCardinality, TestIndexingPerformance,
SolrJmxReporterTest, StatsComponentTest, MetricsHandlerTest, SOLR749Test,
StatelessScriptUpdateProcessorFactoryTest, TestZkChroot, RollingRestartTest,
TestIndexSearcher, TestCustomStream, TestSystemCollAutoCreate,
HdfsDirectoryTest, ClassificationUpdateProcessorIntegrationTest,
ConcurrentDeleteAndCreateCollectionTest, TestLeaderElectionWithEmptyReplica,
SolrMetricsIntegrationTest, AutoCommitTest, ShardSplitTest]
[junit4] Completed [283/704 (1!)] on J2 in 831.54s, 5 tests, 1 failure <<<
FAILURES!
[...truncated 37625 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
