Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/3469/
Java: 32bit/jdk-9-ea+168 -server -XX:+UseSerialGC
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([A77CD4947DE33092:2C5B07453CE59B16]: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:856)
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 12346 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_A77CD4947DE33092-001/init-core-data-001
[junit4] 2> 525669 INFO
(SUITE-ShardSplitTest-seed#[A77CD4947DE33092]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 525670 INFO
(SUITE-ShardSplitTest-seed#[A77CD4947DE33092]-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> 525670 INFO
(SUITE-ShardSplitTest-seed#[A77CD4947DE33092]-worker) [ ]
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 525671 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 525671 INFO (Thread-1296) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 525671 INFO (Thread-1296) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 525673 ERROR (Thread-1296) [ ] o.a.z.s.ZooKeeperServer
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action
on ERROR or SHUTDOWN server state changes
[junit4] 2> 525771 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkTestServer start zk server on port:42618
[junit4] 2> 525779 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525780 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525781 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525782 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525783 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525784 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525784 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525785 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525786 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525787 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525790 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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> 525906 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/control-001/cores/collection1
[junit4] 2> 525907 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 525909 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@16de0ea{/,null,AVAILABLE}
[junit4] 2> 525909 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1595188{HTTP/1.1,[http/1.1]}{127.0.0.1:42905}
[junit4] 2> 525909 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server Started @527933ms
[junit4] 2> 525910 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/tempDir-001/control/data,
hostPort=42905,
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_A77CD4947DE33092-001/control-001/cores}
[junit4] 2> 525910 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 525910 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.6.0
[junit4] 2> 525910 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 525910 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 525910 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-05-08T17:34:03.278871Z
[junit4] 2> 525913 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 525913 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/control-001/solr.xml
[junit4] 2> 525918 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 525919 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42618/solr
[junit4] 2> 525931 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 525933 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42905_
[junit4] 2> 525933 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=97928140753469444-127.0.0.1:42905_-n_0000000000)
starting
[junit4] 2> 525938 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42905_
[junit4] 2> 525940 INFO (zkCallback-1711-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 526091 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/control-001/cores
[junit4] 2> 526091 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 526092 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 526094 INFO
(OverseerStateUpdate-97928140753469444-127.0.0.1:42905_-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 527102 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 527113 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 527198 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 527211 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection control_collection, trusted=true
[junit4] 2> 527211 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 527211 INFO (coreLoadExecutor-3323-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_A77CD4947DE33092-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_A77CD4947DE33092-001/control-001/cores/collection1/data/]
[junit4] 2> 527211 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f369ea
[junit4] 2> 527214 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=11, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=46.6533203125,
floorSegmentMB=0.9384765625, forceMergeDeletesPctAllowed=6.519256676813555,
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 527237 WARN (coreLoadExecutor-3323-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> 527267 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 527267 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 527268 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 527268 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 527269 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=2.076171875, noCFSRatio=0.0]
[junit4] 2> 527269 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@d8699a[collection1] main]
[junit4] 2> 527270 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 527270 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 527270 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 527271 INFO (searcherExecutor-3324-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@d8699a[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 527272 INFO (coreLoadExecutor-3323-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1566850253733232640
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:42905/collection1/
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:42905/collection1/ has no replicas
[junit4] 2> 527277 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 527279 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:42905/collection1/ shard1
[junit4] 2> 527430 INFO (coreZkRegister-3316-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 527598 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 527599 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42618/solr ready
[junit4] 2> 527599 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection
loss:false
[junit4] 2> 527745 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-1-001/cores/collection1
[junit4] 2> 527746 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-1-001
[junit4] 2> 527746 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 527747 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7e684a{/,null,AVAILABLE}
[junit4] 2> 527748 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@260661{HTTP/1.1,[http/1.1]}{127.0.0.1:37824}
[junit4] 2> 527748 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server Started @529771ms
[junit4] 2> 527748 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/tempDir-001/jetty1,
hostPort=37824,
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_A77CD4947DE33092-001/shard-1-001/cores}
[junit4] 2> 527749 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 527749 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.6.0
[junit4] 2> 527749 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 527749 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 527749 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-05-08T17:34:05.117525Z
[junit4] 2> 527752 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 527752 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-1-001/solr.xml
[junit4] 2> 527756 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 527757 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42618/solr
[junit4] 2> 527762 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 527763 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 527764 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37824_
[junit4] 2> 527765 INFO (zkCallback-1711-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 527765 INFO (zkCallback-1720-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 527765 INFO (zkCallback-1715-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 527903 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-1-001/cores
[junit4] 2> 527903 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 527904 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 527905 INFO
(OverseerStateUpdate-97928140753469444-127.0.0.1:42905_-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 528913 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 528923 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 529018 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 529027 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 529028 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 529028 INFO (coreLoadExecutor-3334-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_A77CD4947DE33092-001/shard-1-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_A77CD4947DE33092-001/shard-1-001/cores/collection1/data/]
[junit4] 2> 529028 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f369ea
[junit4] 2> 529030 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=11, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=46.6533203125,
floorSegmentMB=0.9384765625, forceMergeDeletesPctAllowed=6.519256676813555,
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 529083 WARN (coreLoadExecutor-3334-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> 529131 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 529131 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 529133 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 529133 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 529134 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=2.076171875, noCFSRatio=0.0]
[junit4] 2> 529134 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@81807f[collection1] main]
[junit4] 2> 529135 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 529135 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 529135 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 529137 INFO (searcherExecutor-3335-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@81807f[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 529137 INFO (coreLoadExecutor-3334-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1566850255688826880
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37824/collection1/
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:37824/collection1/ has no replicas
[junit4] 2> 529142 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 529144 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:37824/collection1/ shard2
[junit4] 2> 529294 INFO (coreZkRegister-3329-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 529548 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-2-001/cores/collection1
[junit4] 2> 529548 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-2-001
[junit4] 2> 529549 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 529566 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1fea56d{/,null,AVAILABLE}
[junit4] 2> 529567 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1e12703{HTTP/1.1,[http/1.1]}{127.0.0.1:43223}
[junit4] 2> 529567 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server Started @531590ms
[junit4] 2> 529567 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/tempDir-001/jetty2,
hostPort=43223,
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/shard-2-001/cores}
[junit4] 2> 529568 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 529568 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.6.0
[junit4] 2> 529568 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 529568 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 529568 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-05-08T17:34:06.936803Z
[junit4] 2> 529570 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 529571 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-2-001/solr.xml
[junit4] 2> 529576 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 529577 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42618/solr
[junit4] 2> 529583 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 529584 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 529585 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:43223_
[junit4] 2> 529585 INFO (zkCallback-1715-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 529585 INFO (zkCallback-1720-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 529585 INFO (zkCallback-1726-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 529586 INFO (zkCallback-1711-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 529684 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-2-001/cores
[junit4] 2> 529684 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 529685 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 529685 INFO
(OverseerStateUpdate-97928140753469444-127.0.0.1:42905_-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 530692 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 530707 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 530796 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 530804 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 530804 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 530804 INFO (coreLoadExecutor-3345-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_A77CD4947DE33092-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_A77CD4947DE33092-001/shard-2-001/cores/collection1/data/]
[junit4] 2> 530805 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f369ea
[junit4] 2> 530806 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=11, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=46.6533203125,
floorSegmentMB=0.9384765625, forceMergeDeletesPctAllowed=6.519256676813555,
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 530839 WARN (coreLoadExecutor-3345-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> 530872 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 530872 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 530872 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 530872 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 530873 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=2.076171875, noCFSRatio=0.0]
[junit4] 2> 530874 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@54ec2[collection1] main]
[junit4] 2> 530874 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 530874 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 530875 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 530875 INFO (searcherExecutor-3346-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@54ec2[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 530876 INFO (coreLoadExecutor-3345-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1566850257512300544
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43223/collection1/
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.SyncStrategy http://127.0.0.1:43223/collection1/ has no replicas
[junit4] 2> 530880 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 530882 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:43223/collection1/ shard1
[junit4] 2> 531033 INFO (coreZkRegister-3340-thread-1) [ ]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 531306 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-3-001/cores/collection1
[junit4] 2> 531306 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-3-001
[junit4] 2> 531306 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 531307 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1039035{/,null,AVAILABLE}
[junit4] 2> 531307 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@14e0fe{HTTP/1.1,[http/1.1]}{127.0.0.1:38218}
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server Started @533332ms
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/tempDir-001/jetty3,
hostPort=38218,
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_A77CD4947DE33092-001/shard-3-001/cores}
[junit4] 2> 531309 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.6.0
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 531309 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-05-08T17:34:08.677913Z
[junit4] 2> 531311 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 531311 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-3-001/solr.xml
[junit4] 2> 531315 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 531316 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42618/solr
[junit4] 2> 531323 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 531324 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 531344 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38218_
[junit4] 2> 531345 INFO (zkCallback-1726-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 531345 INFO (zkCallback-1720-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 531345 INFO (zkCallback-1711-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 531348 INFO (zkCallback-1715-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 531348 INFO (zkCallback-1732-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 531466 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-3-001/cores
[junit4] 2> 531466 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 531466 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 531467 INFO
(OverseerStateUpdate-97928140753469444-127.0.0.1:42905_-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 532478 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 532493 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 532580 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 532589 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 532589 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 532589 INFO (coreLoadExecutor-3356-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_A77CD4947DE33092-001/shard-3-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_A77CD4947DE33092-001/shard-3-001/cores/collection1/data/]
[junit4] 2> 532590 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f369ea
[junit4] 2> 532593 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=11, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=46.6533203125,
floorSegmentMB=0.9384765625, forceMergeDeletesPctAllowed=6.519256676813555,
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 532607 WARN (coreLoadExecutor-3356-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> 532653 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 532653 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 532654 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 532654 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 532655 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=2.076171875, noCFSRatio=0.0]
[junit4] 2> 532655 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@10d92f0[collection1] main]
[junit4] 2> 532656 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 532656 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 532656 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 532657 INFO (searcherExecutor-3357-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@10d92f0[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 532657 INFO (coreLoadExecutor-3356-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1566850259379814400
[junit4] 2> 532660 INFO (coreZkRegister-3351-thread-1) [ ]
o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 532661 INFO (updateExecutor-1729-thread-1) [ ]
o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 532661 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 532661 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 532661 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 532661 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=null}
[junit4] 2> 532661 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering,
leader is [http://127.0.0.1:37824/collection1/] and I am
[http://127.0.0.1:38218/collection1/]
[junit4] 2> 532662 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Sending prep recovery command to
[http://127.0.0.1:37824]; [WaitForState:
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:38218_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 532665 INFO (qtp21118466-6941) [ ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 532666 INFO (qtp21118466-6941) [ ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1
(shard2 of collection1) have state: recovering
[junit4] 2> 532666 INFO (qtp21118466-6941) [ ]
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:38218_, coreNodeName=core_node3,
onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:38218","node_name":"127.0.0.1:38218_","state":"down"}
[junit4] 2> 533097 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-4-001/cores/collection1
[junit4] 2> 533097 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-4-001
[junit4] 2> 533099 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 533099 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2c9f99{/,null,AVAILABLE}
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1b691df{HTTP/1.1,[http/1.1]}{127.0.0.1:45448}
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.Server Started @535123ms
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/,
solrconfig=solrconfig.xml,
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_A77CD4947DE33092-001/tempDir-001/jetty4,
hostPort=45448,
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_A77CD4947DE33092-001/shard-4-001/cores}
[junit4] 2> 533100 ERROR
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
6.6.0
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 533100 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-05-08T17:34:10.468915Z
[junit4] 2> 533102 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 533102 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-4-001/solr.xml
[junit4] 2> 533106 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 533107 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42618/solr
[junit4] 2> 533113 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 533114 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 533115 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45448_
[junit4] 2> 533116 INFO (zkCallback-1726-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533116 INFO (zkCallback-1720-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533116 INFO (zkCallback-1715-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533116 INFO (zkCallback-1711-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533116 INFO (zkCallback-1739-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533117 INFO (zkCallback-1732-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 533281 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
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_A77CD4947DE33092-001/shard-4-001/cores
[junit4] 2> 533281 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 533281 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 533282 INFO
(OverseerStateUpdate-97928140753469444-127.0.0.1:42905_-n_0000000000) [ ]
o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 533666 INFO (qtp21118466-6941) [ ]
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:38218_, coreNodeName=core_node3,
onlyIfActiveCheckResult=false, nodeProps:
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:38218","node_name":"127.0.0.1:38218_","state":"recovering"}
[junit4] 2> 533666 INFO (qtp21118466-6941) [ ]
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering,
checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 533666 INFO (qtp21118466-6941) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:38218_&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> 534166 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Attempting to PeerSync from
[http://127.0.0.1:37824/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 534167 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:38218 START
replicas=[http://127.0.0.1:37824/collection1/] nUpdates=100
[junit4] 2> 534169 INFO (qtp21118466-6941) [ ]
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> 534169 INFO (qtp21118466-6941) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 534170 INFO (recoveryExecutor-1730-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> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 534170 INFO (recoveryExecutor-1730-thread-1) [ ]
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 534294 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
[junit4] 2> 534309 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 534424 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 534438 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from
collection collection1, trusted=true
[junit4] 2> 534439 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 534439 INFO (coreLoadExecutor-3367-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_A77CD4947DE33092-001/shard-4-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_A77CD4947DE33092-001/shard-4-001/cores/collection1/data/]
[junit4] 2> 534439 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f369ea
[junit4] 2> 534442 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=11, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=46.6533203125,
floorSegmentMB=0.9384765625, forceMergeDeletesPctAllowed=6.519256676813555,
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 534472 WARN (coreLoadExecutor-3367-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> 534532 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 534532 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 534533 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 534533 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 534534 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=2.076171875, noCFSRatio=0.0]
[junit4] 2> 534534 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.s.SolrIndexSearcher Opening [Searcher@dd93c1[collection1] main]
[junit4] 2> 534535 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 534535 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 534535 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 534536 INFO (searcherExecutor-3368-thread-1) [ ]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@dd93c1[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 534537 INFO (coreLoadExecutor-3367-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1566850261351137280
[junit4] 2> 534540 INFO (coreZkRegister-3362-thread-1) [ ]
o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 534540 INFO (updateExecutor-1736-thread-1) [ ]
o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 534540 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 534541 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 534541 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 534541 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=null}
[junit4] 2> 534541 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering,
leader is [http://127.0.0.1:43223/collection1/] and I am
[http://127.0.0.1:45448/collection1/]
[junit4] 2> 534542 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Sending prep recovery command to
[http://127.0.0.1:43223]; [WaitForState:
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:45448_&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 534543 INFO (qtp19728315-6969) [ ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 534544 INFO (qtp19728315-6969) [ ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1
(shard1 of collection1) have state: recovering
[junit4] 2> 534544 INFO (qtp19728315-6969) [ ]
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:45448_, coreNodeName=core_node4,
onlyIfActiveCheckResult=false, nodeProps:
core_node4:{"core":"collection1","base_url":"http://127.0.0.1:45448","node_name":"127.0.0.1:45448_","state":"down"}
[junit4] 2> 534785 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testSplitWithChaosMonkey
[junit4] 2> 534785 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 15
for each attempt
[junit4] 2> 534785 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection:
collection1 failOnTimeout:true timeout (sec):15
[junit4] 2> 535544 INFO (qtp19728315-6969) [ ]
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:45448_, coreNodeName=core_node4,
onlyIfActiveCheckResult=false, nodeProps:
core_node4:{"core":"collection1","base_url":"http://127.0.0.1:45448","node_name":"127.0.0.1:45448_","state":"recovering"}
[junit4] 2> 535544 INFO (qtp19728315-6969) [ ]
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node4, state: recovering,
checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 535544 INFO (qtp19728315-6969) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:45448_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node4&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1001
[junit4] 2> 536045 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Attempting to PeerSync from
[http://127.0.0.1:43223/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 536045 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:45448 START
replicas=[http://127.0.0.1:43223/collection1/] nUpdates=100
[junit4] 2> 536047 INFO (qtp19728315-6969) [ ]
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> 536047 INFO (qtp19728315-6969) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/get
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 536047 INFO (recoveryExecutor-1737-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> 536047 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 536047 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536047 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536048 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536048 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 536048 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 536048 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 536048 INFO (recoveryExecutor-1737-thread-1) [ ]
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 536786 INFO
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[A77CD4947DE33092]) [ ]
o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 536787 INFO (qtp18589169-6907) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536787 INFO (qtp18589169-6907) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536787 INFO (qtp18589169-6907) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536787 INFO (qtp18589169-6907) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 0
[junit4] 2> 536789 INFO (qtp19728315-6966) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536789 INFO (qtp19728315-6966) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536789 INFO (qtp19001918-7032) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536789 INFO (qtp21118466-6939) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536789 INFO (qtp19001918-7032) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536789 INFO (qtp19728315-6966) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536789 INFO (qtp21118466-6939) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536790 INFO (qtp19728315-6966) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:37824/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 0
[junit4] 2> 536790 INFO (qtp19001918-7032) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536790 INFO (qtp19001918-7032) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:37824/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 0
[junit4] 2> 536790 INFO (qtp21118466-6939) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536790 INFO (qtp31980512-6998) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 536790 INFO (qtp31980512-6998) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 536790 INFO (qtp21118466-6939) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:37824/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 0
[junit4] 2> 536790 INFO (qtp31980512-6998) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 536790 INFO (qtp31980512-6998) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:37824/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
0 0
[junit4] 2> 536790 INFO (qtp21118466-6938) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
0 2
[junit4] 2> 536792 INFO (qtp21118466-6943) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 536793 INFO (qtp31980512-6999) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 536796 INFO (qtp19728315-6969) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 536797 INFO (qtp19001918-7034) [ ] o.a.s.c.S.Request
[collection1] webapp= path=/select
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
hits=0 status=0 QTime=0
[junit4] 2> 538802 INFO (qtp18589169-6909) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-0 (1566850265822265344)]} 0 2
[junit4] 2> 538809 INFO (qtp19001918-7032) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-0
(1566850265824362496)]} 0 2
[junit4] 2> 538809 INFO (qtp19728315-6971) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-0 (1566850265824362496)]} 0 5
[junit4] 2> 538811 INFO (qtp18589169-6908) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-1 (1566850265832751104)]} 0 0
[junit4] 2> 538816 INFO (qtp19001918-7028) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-1
(1566850265834848256)]} 0 0
[junit4] 2> 538816 INFO (qtp19728315-6966) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-1 (1566850265834848256)]} 0 3
[junit4] 2> 538818 INFO (qtp18589169-6902) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-0 (-1566850265840091136)]}
0 0
[junit4] 2> 538822 INFO (qtp19001918-7028) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{delete=[0-0
(-1566850265843236864)]} 0 0
[junit4] 2> 538823 INFO (qtp19728315-6967) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[0-0 (-1566850265843236864)]} 0 2
[junit4] 2> 538825 INFO (qtp18589169-6907) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-2 (1566850265846382592)]} 0 1
[junit4] 2> 538829 INFO (qtp19001918-7028) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-2
(1566850265849528320)]} 0 0
[junit4] 2> 538830 INFO (qtp19728315-6969) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-2 (1566850265849528320)]} 0 2
[junit4] 2> 538831 INFO (qtp18589169-6909) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-1 (-1566850265853722624)]}
0 0
[junit4] 2> 538834 INFO (qtp19001918-7032) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{delete=[0-1
(-1566850265855819776)]} 0 0
[junit4] 2> 538834 INFO (qtp19728315-6971) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[0-1 (-1566850265855819776)]} 0 1
[junit4] 2> 538836 INFO (qtp18589169-6908) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-3 (1566850265858965504)]} 0 0
[junit4] 2> 538840 INFO (qtp19001918-7034) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-3
(1566850265861062656)]} 0 0
[junit4] 2> 538841 INFO (qtp19728315-6966) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-3 (1566850265861062656)]} 0 2
[junit4] 2> 538843 INFO (qtp18589169-6902) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-3 (-1566850265866305536)]}
0 0
[junit4] 2> 538847 INFO (qtp19001918-7029) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{delete=[0-3
(-1566850265868402688)]} 0 0
[junit4] 2> 538847 INFO (qtp19728315-6967) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[0-3 (-1566850265868402688)]} 0 2
[junit4] 2> 538849 INFO (qtp18589169-6907) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-4 (1566850265871548416)]} 0 0
[junit4] 2> 538853 INFO (qtp19001918-7028) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-4
(1566850265874694144)]} 0 0
[junit4] 2> 538853 INFO (qtp19728315-6969) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-4 (1566850265874694144)]} 0 2
[junit4] 2> 538855 INFO (qtp18589169-6909) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-4 (-1566850265878888448)]}
0 0
[junit4] 2> 538858 INFO (qtp19001918-7032) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{delete=[0-4
(-1566850265880985600)]} 0 0
[junit4] 2> 538859 INFO (qtp19728315-6971) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[0-4 (-1566850265880985600)]} 0 1
[junit4] 2> 538861 INFO (qtp18589169-6908) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-5 (1566850265884131328)]} 0 0
[junit4] 2> 538866 INFO (qtp31980512-6997) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37824/collection1/&wt=javabin&version=2}{add=[0-5
(1566850265886228480)]} 0 1
[junit4] 2> 538866 INFO (qtp21118466-6936) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-5 (1566850265886228480)]} 0 4
[junit4] 2> 538869 INFO (qtp18589169-6902) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-6 (1566850265892519936)]} 0 1
[junit4] 2> 538873 INFO (qtp31980512-6998) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37824/collection1/&wt=javabin&version=2}{add=[0-6
(1566850265895665664)]} 0 0
[junit4] 2> 538873 INFO (qtp21118466-6939) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-6 (1566850265895665664)]} 0 2
[junit4] 2> 538875 INFO (qtp18589169-6907) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-7 (1566850265899859968)]} 0 0
[junit4] 2> 538879 INFO (qtp31980512-6993) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37824/collection1/&wt=javabin&version=2}{add=[0-7
(1566850265901957120)]} 0 0
[junit4] 2> 538879 INFO (qtp21118466-6938) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-7 (1566850265901957120)]} 0 2
[junit4] 2> 538881 INFO (qtp18589169-6909) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-8 (1566850265906151424)]} 0 0
[junit4] 2> 538885 INFO (qtp31980512-6992) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37824/collection1/&wt=javabin&version=2}{add=[0-8
(1566850265908248576)]} 0 0
[junit4] 2> 538885 INFO (qtp21118466-6943) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-8 (1566850265908248576)]} 0 2
[junit4] 2> 538887 INFO (qtp18589169-6908) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-9 (1566850265912442880)]} 0 0
[junit4] 2> 538890 INFO (qtp31980512-6997) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37824/collection1/&wt=javabin&version=2}{add=[0-9
(1566850265913491456)]} 0 0
[junit4] 2> 538890 INFO (qtp21118466-6936) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[0-9 (1566850265913491456)]} 0 1
[junit4] 2> 538892 INFO (qtp18589169-6902) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-10 (1566850265917685760)]} 0 0
[junit4] 2> 538896 INFO (qtp19001918-7034) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:43223/collection1/&wt=javabin&version=2}{add=[0-10
(1566850265919782912)]} 0 0
[junit4] 2> 538896 INFO (qtp19728315-6966) [ ] o.a.s.u.p.LogUpdat
[...truncated too long message...]
litByRouteKeyTest_shard1_replica2] CLOSING SolrCore
org.apache.solr.core.SolrCore@14a139a
[junit4] 2> 1307443 INFO (coreCloseExecutor-3991-thread-8) [ ]
o.a.s.c.SolrCore [splitByRouteKeyTest_shard1_0_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@1c4fbdf
[junit4] 2> 1307443 INFO (coreCloseExecutor-3991-thread-5) [ ]
o.a.s.c.SolrCore [routeFieldColl_shard1_1_replica0] CLOSING SolrCore
org.apache.solr.core.SolrCore@2e626a
[junit4] 2> 1307446 INFO (zkCallback-1912-thread-2) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/splitByRouteKeyTest/state.json] for collection
[splitByRouteKeyTest] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1307446 INFO (zkCallback-1912-thread-4) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/splitByRouteKeyTest/state.json] for collection
[splitByRouteKeyTest] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1307448 INFO (coreCloseExecutor-3991-thread-11) [ ]
o.a.s.c.SolrCore [splitByRouteKeyTest_shard1_1_replica0] CLOSING SolrCore
org.apache.solr.core.SolrCore@11b7f30
[junit4] 2> 1307557 INFO (zkCallback-1912-thread-2) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/routeFieldColl/state.json] for collection [routeFieldColl]
has occurred - updating... (live nodes size: [1])
[junit4] 2> 1307557 INFO (zkCallback-1912-thread-4) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/routeFieldColl/state.json] for collection [routeFieldColl]
has occurred - updating... (live nodes size: [1])
[junit4] 2> 1307866 INFO (coreCloseExecutor-3991-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.collection1.shard1_1.replica0
[junit4] 2> 1308074 INFO (coreCloseExecutor-3991-thread-5) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.routeFieldColl.shard1_1.replica0
[junit4] 2> 1308251 INFO (coreCloseExecutor-3991-thread-3) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.routeFieldColl.shard4.replica1
[junit4] 2> 1308269 INFO (coreCloseExecutor-3991-thread-6) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard4.replica1
[junit4] 2> 1308274 INFO (coreCloseExecutor-3991-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1308294 INFO (coreCloseExecutor-3991-thread-8) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard1_0.replica1
[junit4] 2> 1308304 INFO (coreCloseExecutor-3991-thread-9) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard1_1.replica1
[junit4] 2> 1308310 INFO (coreCloseExecutor-3991-thread-7) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard1.replica2
[junit4] 2> 1308310 INFO (coreCloseExecutor-3991-thread-10) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard1_2.replica1
[junit4] 2> 1308311 INFO (coreCloseExecutor-3991-thread-4) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.routeFieldColl.shard1.replica2
[junit4] 2> 1308313 INFO (coreCloseExecutor-3991-thread-11) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for:
solr.core.splitByRouteKeyTest.shard1_1.replica0
[junit4] 2> 1308314 INFO
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ] o.a.s.c.Overseer
Overseer (id=97928179073941522-127.0.0.1:40737_-n_0000000004) closing
[junit4] 2> 1308315 INFO
(OverseerStateUpdate-97928179073941522-127.0.0.1:40737_-n_0000000004) [ ]
o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:40737_
[junit4] 2> 1308316 INFO (zkCallback-1920-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1308316 INFO (zkCallback-1887-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1309816 WARN (zkCallback-1912-thread-2) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1309817 INFO
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@176f089{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1309818 INFO
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4e1085{/,null,UNAVAILABLE}
[junit4] 2> 1309821 INFO
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ] o.a.s.c.ChaosMonkey
monkey: stop shard! 42166
[junit4] 2> 1309821 ERROR
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ]
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper
server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1309821 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15be928f7340005, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1309822 INFO
(TEST-ShardSplitTest.test-seed#[A77CD4947DE33092]) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:33403 33403
[junit4] 2> 1309828 INFO (Thread-1568) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:33403 33403
[junit4] 2> 1309829 WARN (Thread-1568) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 9 /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> 160 /solr/collections/splitByRouteKeyTest/state.json
[junit4] 2> 142 /solr/collections/routeFieldColl/state.json
[junit4] 2> 9 /solr/clusterprops.json
[junit4] 2> 9 /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> 9 /solr/live_nodes
[junit4] 2> 9 /solr/collections
[junit4] 2> 5 /solr/overseer/queue
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2> 4 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 1309831 INFO
(SUITE-ShardSplitTest-seed#[A77CD4947DE33092]-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_A77CD4947DE33092-001
[junit4] 2> May 08, 2017 5:47:07 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 3 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62),
sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=fr-ML,
timezone=Pacific/Pitcairn
[junit4] 2> NOTE: Linux 4.4.0-75-generic i386/Oracle Corporation 9-ea
(32-bit)/cpus=12,threads=1,free=131776264,total=333389824
[junit4] 2> NOTE: All tests run in this JVM: [OverseerTest,
TestFileDictionaryLookup, HdfsRestartWhileUpdatingTest, StatsReloadRaceTest,
TestBinaryField, BigEndianAscendingWordSerializerTest, NoCacheHeaderTest,
TestDistributedMissingSort, TestRecoveryHdfs, BinaryUpdateRequestHandlerTest,
TestDynamicFieldResource, CollectionTooManyReplicasTest,
HdfsTlogReplayBufferedWhileIndexingTest, ReplicaListTransformerTest,
TestSolrQueryResponse, FieldAnalysisRequestHandlerTest,
TestHdfsCloudBackupRestore, TestTolerantUpdateProcessorRandomCloud,
ResponseLogComponentTest, TestMacros, AnalyticsQueryTest,
SolrCoreCheckLockOnStartupTest, TestExceedMaxTermLength, BadComponentTest,
MigrateRouteKeyTest, DistribDocExpirationUpdateProcessorTest, SuggesterTest,
StatsComponentTest, TestBinaryResponseWriter, DistributedSuggestComponentTest,
TestClassNameShortening, SuggestComponentContextFilterQueryTest,
TestUniqueKeyFieldResource, DateRangeFieldTest, CircularListTest,
SolrTestCaseJ4Test, TestCollectionAPI, TestExactStatsCache,
XmlUpdateRequestHandlerTest, CurrencyFieldXmlFileTest, TestNRTOpen,
ZkStateWriterTest, AddSchemaFieldsUpdateProcessorFactoryTest, AutoCommitTest,
BadIndexSchemaTest, PluginInfoTest, TestWriterPerf, ActionThrottleTest,
TestCorePropertiesReload, TestMultiWordSynonyms, TestSolrConfigHandlerCloud,
SolrSlf4jReporterTest, JSONWriterTest, TestSort, TestRecovery,
BlockJoinFacetSimpleTest, TestSubQueryTransformerCrossCore,
CreateCollectionCleanupTest, TestDistribDocBasedVersion, UpdateParamsTest,
TestSimpleTextCodec, TestNumericTerms64, OverseerRolesTest, TestRestoreCore,
DistributedVersionInfoTest, TestDFRSimilarityFactory, TestManagedSchema,
SimpleFacetsTest, TestSolrQueryParser, TestSolrDeletionPolicy1,
CoreAdminHandlerTest, TestRequestStatusCollectionAPI,
TestHdfsBackupRestoreCore, RulesTest, DeleteLastCustomShardedReplicaTest,
PreAnalyzedFieldTest, TestFieldCacheWithThreads, TestConfigSetsAPIZkFailure,
ShardSplitTest]
[junit4] Completed [432/711 (1!)] on J2 in 785.20s, 5 tests, 1 failure <<<
FAILURES!
[...truncated 37280 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
