Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18792/
Java: 32bit/jdk-9-ea+152 -client -XX:+UseParallelGC

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

Error Message:
document count mismatch.  control=1096 sum(shards)=1095 cloudClient=1095

Stack Trace:
java.lang.AssertionError: document count mismatch.  control=1096 
sum(shards)=1095 cloudClient=1095
        at 
__randomizedtesting.SeedInfo.seed([2FA2D4BC69650D1:8AAE1291686A3D29]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1323)
        at 
org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:231)
        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:543)
        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:985)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
        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:367)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
        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:367)
        at java.base/java.lang.Thread.run(Thread.java:844)




Build Log:
[...truncated 11516 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/init-core-data-001
   [junit4]   2> 761920 INFO  
(SUITE-ChaosMonkeyNothingIsSafeTest-seed#[2FA2D4BC69650D1]-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> 761920 INFO  
(SUITE-ChaosMonkeyNothingIsSafeTest-seed#[2FA2D4BC69650D1]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: 
/pp_x/xw
   [junit4]   2> 761922 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 761922 INFO  (Thread-1484) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 761922 INFO  (Thread-1484) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 762022 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkTestServer start zk server on port:36358
   [junit4]   2> 762033 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
 to /configs/conf1/solrconfig.xml
   [junit4]   2> 762035 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml
 to /configs/conf1/schema.xml
   [junit4]   2> 762037 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
 to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 762039 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
 to /configs/conf1/stopwords.txt
   [junit4]   2> 762041 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt
 to /configs/conf1/protwords.txt
   [junit4]   2> 762044 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml
 to /configs/conf1/currency.xml
   [junit4]   2> 762046 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
 to /configs/conf1/enumsConfig.xml
   [junit4]   2> 762048 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
 to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 762050 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
 to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 762052 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
 to /configs/conf1/old_synonyms.txt
   [junit4]   2> 762054 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
 to /configs/conf1/synonyms.txt
   [junit4]   2> 762780 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/cores/collection1
   [junit4]   2> 762783 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 762784 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@104666b{/pp_x/xw,null,AVAILABLE}
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@c9f28e{HTTP/1.1,[http/1.1]}{127.0.0.1:40777}
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server Started @764670ms
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pp_x/xw, 
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/tempDir-001/control/data,
 hostPort=40777, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/cores}
   [junit4]   2> 762787 ERROR 
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 762787 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 762788 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-01-17T14:12:58.326005Z
   [junit4]   2> 762790 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 762790 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 0x159acc60bf80002, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 762790 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/solr.xml
   [junit4]   2> 762799 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36358/solr
   [junit4]   2> 762812 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 
127.0.0.1:40777_pp_x%2Fxw
   [junit4]   2> 762812 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.Overseer Overseer 
(id=97298833569480708-127.0.0.1:40777_pp_x%2Fxw-n_0000000000) starting
   [junit4]   2> 762816 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:40777_pp_x%2Fxw
   [junit4]   2> 762817 INFO  (zkCallback-1040-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 762871 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/cores
   [junit4]   2> 762871 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 762872 INFO  
(OverseerStateUpdate-97298833569480708-127.0.0.1:40777_pp_x%2Fxw-n_0000000000) 
[    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 763880 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 763888 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 763936 WARN  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 763938 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 763946 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection control_collection
   [junit4]   2> 763947 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/cores/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/control-001/cores/collection1/data/]
   [junit4]   2> 763947 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be9e7
   [junit4]   2> 763954 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=28, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=1.271484375, 
floorSegmentMB=1.2265625, forceMergeDeletesPctAllowed=4.2043185634495694, 
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.6433978480181348
   [junit4]   2> 764016 WARN  (coreLoadExecutor-2982-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> 764025 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 764026 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 764027 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 764027 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 764028 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=38, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=1.1494140625, 
floorSegmentMB=0.8681640625, forceMergeDeletesPctAllowed=17.77665134906585, 
segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4696360937862849
   [junit4]   2> 764030 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1bd334f[collection1] main]
   [junit4]   2> 764031 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 764031 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 764031 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 764033 INFO  (searcherExecutor-2983-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1bd334f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 764034 INFO  (coreLoadExecutor-2982-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1556781339322089472
   [junit4]   2> 764038 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 764038 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 764038 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:40777/pp_x/xw/collection1/
   [junit4]   2> 764039 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 764039 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.SyncStrategy http://127.0.0.1:40777/pp_x/xw/collection1/ has no replicas
   [junit4]   2> 764041 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:40777/pp_x/xw/collection1/ shard1
   [junit4]   2> 764191 INFO  (coreZkRegister-2975-thread-1) [    ] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 764342 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 764343 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:36358/solr ready
   [junit4]   2> 764343 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection 
loss:false
   [junit4]   2> 765095 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/cores/collection1
   [junit4]   2> 765096 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001
   [junit4]   2> 765097 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 765097 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@12b6ad3{/pp_x/xw,null,AVAILABLE}
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1c7d6dc{HTTP/1.1,[http/1.1]}{127.0.0.1:33203}
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server Started @766981ms
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pp_x/xw, 
solrconfig=solrconfig.xml, 
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/tempDir-001/jetty1,
 hostPort=33203, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/cores}
   [junit4]   2> 765098 ERROR 
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 765098 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-01-17T14:13:00.636824Z
   [junit4]   2> 765101 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 765101 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/solr.xml
   [junit4]   2> 765109 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36358/solr
   [junit4]   2> 765114 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 765116 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33203_pp_x%2Fxw
   [junit4]   2> 765117 INFO  (zkCallback-1040-thread-2) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 765117 INFO  (zkCallback-1044-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 765117 INFO  (zkCallback-1049-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 765189 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/cores
   [junit4]   2> 765190 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 765191 INFO  
(OverseerStateUpdate-97298833569480708-127.0.0.1:40777_pp_x%2Fxw-n_0000000000) 
[    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 766202 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 766216 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 766289 WARN  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 766291 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 766309 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection collection1
   [junit4]   2> 766309 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/cores/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-1-001/cores/collection1/data/]
   [junit4]   2> 766309 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be9e7
   [junit4]   2> 766316 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=28, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=1.271484375, 
floorSegmentMB=1.2265625, forceMergeDeletesPctAllowed=4.2043185634495694, 
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.6433978480181348
   [junit4]   2> 766406 WARN  (coreLoadExecutor-2993-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> 766418 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 766418 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 766420 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 766420 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 766422 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=38, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=1.1494140625, 
floorSegmentMB=0.8681640625, forceMergeDeletesPctAllowed=17.77665134906585, 
segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4696360937862849
   [junit4]   2> 766424 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@cce10d[collection1] main]
   [junit4]   2> 766424 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 766425 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 766425 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 766426 INFO  (searcherExecutor-2994-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@cce10d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 766428 INFO  (coreLoadExecutor-2993-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1556781341832380416
   [junit4]   2> 766432 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 766432 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 766432 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:33203/pp_x/xw/collection1/
   [junit4]   2> 766432 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 766432 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.SyncStrategy http://127.0.0.1:33203/pp_x/xw/collection1/ has no replicas
   [junit4]   2> 766435 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:33203/pp_x/xw/collection1/ shard1
   [junit4]   2> 766586 INFO  (coreZkRegister-2988-thread-1) [    ] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 767520 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/cores/collection1
   [junit4]   2> 767522 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001
   [junit4]   2> 767522 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 767524 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1a0e0ec{/pp_x/xw,null,AVAILABLE}
   [junit4]   2> 767524 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@793ae9{HTTP/1.1,[http/1.1]}{127.0.0.1:39185}
   [junit4]   2> 767524 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server Started @769408ms
   [junit4]   2> 767525 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pp_x/xw, 
solrconfig=solrconfig.xml, 
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/tempDir-001/jetty2,
 hostPort=39185, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/cores}
   [junit4]   2> 767525 ERROR 
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 767525 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 767525 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 767525 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 767525 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-01-17T14:13:03.063606Z
   [junit4]   2> 767528 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 767528 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/solr.xml
   [junit4]   2> 767535 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36358/solr
   [junit4]   2> 767541 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 767544 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:39185_pp_x%2Fxw
   [junit4]   2> 767544 INFO  (zkCallback-1055-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 767544 INFO  (zkCallback-1040-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 767544 INFO  (zkCallback-1044-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 767544 INFO  (zkCallback-1049-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 767640 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/cores
   [junit4]   2> 767640 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 767642 INFO  
(OverseerStateUpdate-97298833569480708-127.0.0.1:40777_pp_x%2Fxw-n_0000000000) 
[    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 768656 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 768665 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 768709 WARN  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 768710 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 768719 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection collection1
   [junit4]   2> 768720 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/cores/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-2-001/cores/collection1/data/]
   [junit4]   2> 768720 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be9e7
   [junit4]   2> 768726 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=28, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=1.271484375, 
floorSegmentMB=1.2265625, forceMergeDeletesPctAllowed=4.2043185634495694, 
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.6433978480181348
   [junit4]   2> 768802 WARN  (coreLoadExecutor-3004-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> 768820 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 768820 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 768822 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 768822 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 768823 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=38, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=1.1494140625, 
floorSegmentMB=0.8681640625, forceMergeDeletesPctAllowed=17.77665134906585, 
segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4696360937862849
   [junit4]   2> 768825 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@5f6111[collection1] main]
   [junit4]   2> 768826 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 768826 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 768826 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 768827 INFO  (searcherExecutor-3005-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@5f6111[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 768829 INFO  (coreLoadExecutor-3004-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1556781344350011392
   [junit4]   2> 768832 INFO  (coreZkRegister-2999-thread-1) [    ] 
o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 768832 INFO  (updateExecutor-1052-thread-1) [    ] 
o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 768832 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 768832 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
   [junit4]   2> 768832 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
   [junit4]   2> 768832 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, 
tlog=null}
   [junit4]   2> 768832 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, 
leader is [http://127.0.0.1:33203/pp_x/xw/collection1/] and I am 
[http://127.0.0.1:39185/pp_x/xw/collection1/]
   [junit4]   2> 768835 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Sending prep recovery command to 
[http://127.0.0.1:33203/pp_x/xw]; [WaitForState: 
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:39185_pp_x%252Fxw&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 768849 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state: 
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 768849 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 
(shard1 of collection1) have state: recovering
   [junit4]   2> 768849 INFO  (qtp13663910-6153) [    ] 
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:39185_pp_x%2Fxw, coreNodeName=core_node2, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node2:{"core":"collection1","base_url":"http://127.0.0.1:39185/pp_x/xw","node_name":"127.0.0.1:39185_pp_x%2Fxw","state":"down"}
   [junit4]   2> 769849 INFO  (qtp13663910-6153) [    ] 
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:39185_pp_x%2Fxw, coreNodeName=core_node2, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node2:{"core":"collection1","base_url":"http://127.0.0.1:39185/pp_x/xw","node_name":"127.0.0.1:39185_pp_x%2Fxw","state":"recovering"}
   [junit4]   2> 769849 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node2, state: recovering, 
checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 769850 INFO  (qtp13663910-6153) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={nodeName=127.0.0.1:39185_pp_x%252Fxw&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
 status=0 QTime=1000
   [junit4]   2> 769903 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/cores/collection1
   [junit4]   2> 769904 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001
   [junit4]   2> 769905 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 769906 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@15e5212{/pp_x/xw,null,AVAILABLE}
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@15728ec{HTTP/1.1,[http/1.1]}{127.0.0.1:39436}
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.Server Started @771790ms
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pp_x/xw, 
solrconfig=solrconfig.xml, 
solr.data.dir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/tempDir-001/jetty3,
 hostPort=39436, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/cores}
   [junit4]   2> 769907 ERROR 
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 769907 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-01-17T14:13:05.445852Z
   [junit4]   2> 769910 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 769910 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/solr.xml
   [junit4]   2> 769918 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36358/solr
   [junit4]   2> 769923 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 769928 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:39436_pp_x%2Fxw
   [junit4]   2> 769928 INFO  (zkCallback-1055-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 769928 INFO  (zkCallback-1040-thread-2) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 769928 INFO  (zkCallback-1044-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 769928 INFO  (zkCallback-1049-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 769929 INFO  (zkCallback-1062-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 770028 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/cores
   [junit4]   2> 770028 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 770029 INFO  
(OverseerStateUpdate-97298833569480708-127.0.0.1:40777_pp_x%2Fxw-n_0000000000) 
[    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 771038 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 771056 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 771099 WARN  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 771101 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 771109 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection collection1
   [junit4]   2> 771109 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/cores/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001/shard-3-001/cores/collection1/data/]
   [junit4]   2> 771109 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be9e7
   [junit4]   2> 771117 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=28, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=1.271484375, 
floorSegmentMB=1.2265625, forceMergeDeletesPctAllowed=4.2043185634495694, 
segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.6433978480181348
   [junit4]   2> 771185 WARN  (coreLoadExecutor-3015-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> 771197 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 771197 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 771199 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 771199 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 771200 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=38, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=1.1494140625, 
floorSegmentMB=0.8681640625, forceMergeDeletesPctAllowed=17.77665134906585, 
segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4696360937862849
   [junit4]   2> 771202 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1e2e7a0[collection1] main]
   [junit4]   2> 771203 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 771203 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 771203 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 771204 INFO  (searcherExecutor-3016-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1e2e7a0[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 771206 INFO  (coreLoadExecutor-3015-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1556781346842476544
   [junit4]   2> 771208 INFO  (coreZkRegister-3010-thread-1) [    ] 
o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 771209 INFO  (updateExecutor-1059-thread-1) [    ] 
o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 771209 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 771209 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
   [junit4]   2> 771209 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
   [junit4]   2> 771209 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, 
tlog=null}
   [junit4]   2> 771210 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, 
leader is [http://127.0.0.1:33203/pp_x/xw/collection1/] and I am 
[http://127.0.0.1:39436/pp_x/xw/collection1/]
   [junit4]   2> 771211 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Sending prep recovery command to 
[http://127.0.0.1:33203/pp_x/xw]; [WaitForState: 
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:39436_pp_x%252Fxw&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 771212 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: 
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 771212 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 
(shard1 of collection1) have state: recovering
   [junit4]   2> 771212 INFO  (qtp13663910-6153) [    ] 
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:39436_pp_x%2Fxw, coreNodeName=core_node3, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:39436/pp_x/xw","node_name":"127.0.0.1:39436_pp_x%2Fxw","state":"down"}
   [junit4]   2> 771504 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 771504 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: 
collection1 failOnTimeout:true timeout (sec):330
   [junit4]   2> 772212 INFO  (qtp13663910-6153) [    ] 
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:39436_pp_x%2Fxw, coreNodeName=core_node3, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:39436/pp_x/xw","node_name":"127.0.0.1:39436_pp_x%2Fxw","state":"recovering"}
   [junit4]   2> 772212 INFO  (qtp13663910-6153) [    ] 
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, 
checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 772213 INFO  (qtp13663910-6153) [    ] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={nodeName=127.0.0.1:39436_pp_x%252Fxw&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> 776850 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Attempting to PeerSync from 
[http://127.0.0.1:33203/pp_x/xw/collection1/] - recoveringAfterStartup=[true]
   [junit4]   2> 776850 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:39185/pp_x/xw 
START replicas=[http://127.0.0.1:33203/pp_x/xw/collection1/] nUpdates=100
   [junit4]   2> 776852 INFO  (qtp13663910-6153) [    ] 
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> 776852 INFO  (qtp13663910-6153) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/pp_x/xw path=/get 
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
 status=0 QTime=1
   [junit4]   2> 776853 INFO  (recoveryExecutor-1053-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> 776853 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync 
   [junit4]   2> 776853 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 776853 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 776854 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 776854 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
   [junit4]   2> 776854 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
   [junit4]   2> 776854 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy No replay needed.
   [junit4]   2> 776854 INFO  (recoveryExecutor-1053-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
   [junit4]   2> 779213 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Attempting to PeerSync from 
[http://127.0.0.1:33203/pp_x/xw/collection1/] - recoveringAfterStartup=[true]
   [junit4]   2> 779213 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:39436/pp_x/xw 
START replicas=[http://127.0.0.1:33203/pp_x/xw/collection1/] nUpdates=100
   [junit4]   2> 779215 INFO  (qtp13663910-6149) [    ] 
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> 779215 INFO  (qtp13663910-6149) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/pp_x/xw path=/get 
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 779216 INFO  (recoveryExecutor-1060-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> 779216 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync 
   [junit4]   2> 779216 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 779216 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 779217 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 779218 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
   [junit4]   2> 779218 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
   [junit4]   2> 779218 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy No replay needed.
   [junit4]   2> 779218 INFO  (recoveryExecutor-1060-thread-1) [    ] 
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
   [junit4]   2> 779505 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
   [junit4]   2> 779510 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1556781355546705920)} 0 3
   [junit4]   2> 779520 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&_version_=-1556781355550900224&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{deleteByQuery=*:*
 (-1556781355550900224)} 0 4
   [junit4]   2> 779520 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&_version_=-1556781355550900224&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{deleteByQuery=*:*
 (-1556781355550900224)} 0 4
   [junit4]   2> 779520 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1556781355550900224)} 0 9
   [junit4]   2> 779522 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ChaosMonkey monkey: starting
   [junit4]   2> 779523 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ChaosMonkey monkey: Jetty will not commit on close
   [junit4]   2> 779524 INFO  (qtp12706066-6183) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/pp_x/xw path=/select params={q=aid&wt=javabin&version=2} 
hits=0 status=0 QTime=0
   [junit4]   2> 779526 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-0 (1556781355562434560)]} 0 4
   [junit4]   2> 779533 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-0
 (1556781355567677440)]} 0 3
   [junit4]   2> 779533 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-0
 (1556781355567677440)]} 0 3
   [junit4]   2> 779533 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-0 (1556781355567677440)]} 0 6
   [junit4]   2> 779534 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-1 (1556781355575017472)]} 0 0
   [junit4]   2> 779536 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-1
 (1556781355576066048)]} 0 0
   [junit4]   2> 779536 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-1
 (1556781355576066048)]} 0 0
   [junit4]   2> 779536 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-1 (1556781355576066048)]} 0 1
   [junit4]   2> 779536 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-0 (-1556781355577114624)]} 
0 0
   [junit4]   2> 779539 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-0
 (-1556781355578163200)]} 0 1
   [junit4]   2> 779539 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-0
 (-1556781355578163200)]} 0 1
   [junit4]   2> 779539 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-0 (-1556781355578163200)]} 0 2
   [junit4]   2> 779540 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-2 (1556781355580260352)]} 0 0
   [junit4]   2> 779541 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-2
 (1556781355581308928)]} 0 0
   [junit4]   2> 779541 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-2
 (1556781355581308928)]} 0 0
   [junit4]   2> 779541 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-2 (1556781355581308928)]} 0 1
   [junit4]   2> 779541 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-3 (1556781355582357504)]} 0 0
   [junit4]   2> 779542 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-3
 (1556781355583406080)]} 0 0
   [junit4]   2> 779542 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-3
 (1556781355583406080)]} 0 0
   [junit4]   2> 779542 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-3 (1556781355583406080)]} 0 0
   [junit4]   2> 779543 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-2 (-1556781355584454656)]} 
0 0
   [junit4]   2> 779543 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-2
 (-1556781355584454656)]} 0 0
   [junit4]   2> 779543 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-2
 (-1556781355584454656)]} 0 0
   [junit4]   2> 779544 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-2 (-1556781355584454656)]} 0 0
   [junit4]   2> 779544 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-4 (1556781355585503232)]} 0 0
   [junit4]   2> 779546 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-4
 (1556781355586551808)]} 0 0
   [junit4]   2> 779546 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-4
 (1556781355586551808)]} 0 0
   [junit4]   2> 779546 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-4 (1556781355586551808)]} 0 1
   [junit4]   2> 779546 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-4 (-1556781355587600384)]} 
0 0
   [junit4]   2> 779547 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-4
 (-1556781355588648960)]} 0 0
   [junit4]   2> 779547 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-4
 (-1556781355588648960)]} 0 0
   [junit4]   2> 779547 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-4 (-1556781355588648960)]} 0 0
   [junit4]   2> 779548 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-5 (1556781355589697536)]} 0 0
   [junit4]   2> 779549 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-5
 (1556781355589697536)]} 0 0
   [junit4]   2> 779549 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-5
 (1556781355589697536)]} 0 0
   [junit4]   2> 779549 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-5 (1556781355589697536)]} 0 0
   [junit4]   2> 779549 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-6 (1556781355590746112)]} 0 0
   [junit4]   2> 779551 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-6
 (1556781355592843264)]} 0 0
   [junit4]   2> 779551 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-6
 (1556781355592843264)]} 0 0
   [junit4]   2> 779551 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-6 (1556781355592843264)]} 0 0
   [junit4]   2> 779552 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-7 (1556781355593891840)]} 0 0
   [junit4]   2> 779553 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-7
 (1556781355593891840)]} 0 0
   [junit4]   2> 779553 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-7
 (1556781355593891840)]} 0 0
   [junit4]   2> 779553 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-7 (1556781355593891840)]} 0 0
   [junit4]   2> 779553 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-5 (-1556781355594940416)]} 
0 0
   [junit4]   2> 779554 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-5
 (-1556781355594940416)]} 0 0
   [junit4]   2> 779554 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-5
 (-1556781355594940416)]} 0 0
   [junit4]   2> 779554 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-5 (-1556781355594940416)]} 0 0
   [junit4]   2> 779554 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-8 (1556781355595988992)]} 0 0
   [junit4]   2> 779555 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-8
 (1556781355597037568)]} 0 0
   [junit4]   2> 779555 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-8
 (1556781355597037568)]} 0 0
   [junit4]   2> 779555 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-8 (1556781355597037568)]} 0 0
   [junit4]   2> 779556 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-7 (-1556781355598086144)]} 
0 0
   [junit4]   2> 779556 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-7
 (-1556781355598086144)]} 0 0
   [junit4]   2> 779556 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-7
 (-1556781355598086144)]} 0 0
   [junit4]   2> 779556 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-7 (-1556781355598086144)]} 0 0
   [junit4]   2> 779557 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-9 (1556781355599134720)]} 0 0
   [junit4]   2> 779558 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-9
 (1556781355599134720)]} 0 0
   [junit4]   2> 779558 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-9
 (1556781355599134720)]} 0 0
   [junit4]   2> 779558 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-9 (1556781355599134720)]} 0 0
   [junit4]   2> 779559 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-8 (-1556781355601231872)]} 
0 0
   [junit4]   2> 779560 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-8
 (-1556781355601231872)]} 0 0
   [junit4]   2> 779560 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-8
 (-1556781355601231872)]} 0 0
   [junit4]   2> 779560 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-8 (-1556781355601231872)]} 0 0
   [junit4]   2> 779560 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-10 (1556781355602280448)]} 0 0
   [junit4]   2> 779562 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-10
 (1556781355603329024)]} 0 1
   [junit4]   2> 779562 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-10
 (1556781355603329024)]} 0 1
   [junit4]   2> 779563 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-10 (1556781355603329024)]} 0 2
   [junit4]   2> 779563 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-10 
(-1556781355605426176)]} 0 0
   [junit4]   2> 779564 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-10
 (-1556781355605426176)]} 0 0
   [junit4]   2> 779564 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-10
 (-1556781355605426176)]} 0 0
   [junit4]   2> 779564 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-10 (-1556781355605426176)]} 0 0
   [junit4]   2> 779564 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-11 (1556781355606474752)]} 0 0
   [junit4]   2> 779565 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-11
 (1556781355607523328)]} 0 0
   [junit4]   2> 779565 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-11
 (1556781355607523328)]} 0 0
   [junit4]   2> 779565 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-11 (1556781355607523328)]} 0 0
   [junit4]   2> 779566 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-12 (1556781355608571904)]} 0 0
   [junit4]   2> 779566 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-12
 (1556781355608571904)]} 0 0
   [junit4]   2> 779566 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-12
 (1556781355608571904)]} 0 0
   [junit4]   2> 779567 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-12 (1556781355608571904)]} 0 0
   [junit4]   2> 779567 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-12 
(-1556781355609620480)]} 0 0
   [junit4]   2> 779568 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-12
 (-1556781355609620480)]} 0 0
   [junit4]   2> 779568 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-12
 (-1556781355609620480)]} 0 0
   [junit4]   2> 779568 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-12 (-1556781355609620480)]} 0 0
   [junit4]   2> 779568 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-13 (1556781355610669056)]} 0 0
   [junit4]   2> 779569 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-13
 (1556781355610669056)]} 0 0
   [junit4]   2> 779569 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-13
 (1556781355610669056)]} 0 0
   [junit4]   2> 779569 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-13 (1556781355610669056)]} 0 0
   [junit4]   2> 779569 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-13 
(-1556781355611717632)]} 0 0
   [junit4]   2> 779570 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-13
 (-1556781355612766208)]} 0 0
   [junit4]   2> 779570 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{delete=[0-13
 (-1556781355612766208)]} 0 0
   [junit4]   2> 779570 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{delete=[0-13 (-1556781355612766208)]} 0 0
   [junit4]   2> 779570 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-14 (1556781355612766208)]} 0 0
   [junit4]   2> 779571 INFO  (qtp12706066-6181) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-14
 (1556781355613814784)]} 0 0
   [junit4]   2> 779571 INFO  (qtp9912071-6211) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-14
 (1556781355613814784)]} 0 0
   [junit4]   2> 779571 INFO  (qtp13663910-6153) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-14 (1556781355613814784)]} 0 0
   [junit4]   2> 779572 INFO  (qtp30674373-6118) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-15 (1556781355614863360)]} 0 0
   [junit4]   2> 779573 INFO  (qtp12706066-6177) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-15
 (1556781355614863360)]} 0 0
   [junit4]   2> 779573 INFO  (qtp9912071-6217) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-15
 (1556781355614863360)]} 0 0
   [junit4]   2> 779573 INFO  (qtp13663910-6151) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-15 (1556781355614863360)]} 0 0
   [junit4]   2> 779573 INFO  (qtp30674373-6119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-16 (1556781355615911936)]} 0 0
   [junit4]   2> 779575 INFO  (qtp9912071-6218) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-16
 (1556781355618009088)]} 0 0
   [junit4]   2> 779575 INFO  (qtp12706066-6182) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-16
 (1556781355618009088)]} 0 0
   [junit4]   2> 779575 INFO  (qtp13663910-6149) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-16 (1556781355618009088)]} 0 0
   [junit4]   2> 779576 INFO  (qtp30674373-6112) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-17 (1556781355618009088)]} 0 0
   [junit4]   2> 779576 INFO  (qtp12706066-6183) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-17
 (1556781355619057664)]} 0 0
   [junit4]   2> 779576 INFO  (qtp9912071-6216) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:33203/pp_x/xw/collection1/&wt=javabin&version=2}{add=[0-17
 (1556781355619057664)]} 0 0
   [junit4]   2> 779576 INFO  (qtp13663910-6155) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/pp_x/xw path=/update 
params={wt=javabin&version=2}{add=[0-17 (1556781355619057664)]} 0 0
   [junit4]   2> 779577 INFO  (qtp30674373-6117) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/p

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

 [junit4]   2> 830303 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=29861562
   [junit4]   2> 830313 INFO  (coreCloseExecutor-3041-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@1571c53
   [junit4]   2> 831835 INFO  (coreCloseExecutor-3041-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
   [junit4]   2> 831835 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.Overseer Overseer 
(id=97298833569480715-127.0.0.1:39185_pp_x%2Fxw-n_0000000002) closing
   [junit4]   2> 831836 INFO  
(OverseerStateUpdate-97298833569480715-127.0.0.1:39185_pp_x%2Fxw-n_0000000002) 
[    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39185_pp_x%2Fxw
   [junit4]   2> 831841 WARN  (zkCallback-1055-thread-1) [    ] 
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: 
[KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 831841 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 831841 INFO  (zkCallback-1062-thread-5) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 831842 INFO  (zkCallback-1062-thread-3) [    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 
127.0.0.1:39436_pp_x%2Fxw
   [junit4]   2> 831842 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@793ae9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 831842 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1a0e0ec{/pp_x/xw,null,UNAVAILABLE}
   [junit4]   2> 831843 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ChaosMonkey monkey: stop shard! 39436
   [junit4]   2> 831843 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=9623981
   [junit4]   2> 831848 INFO  (zkCallback-1062-thread-3) [    ] 
o.a.s.c.Overseer Overseer 
(id=97298833569480718-127.0.0.1:39436_pp_x%2Fxw-n_0000000003) starting
   [junit4]   2> 831850 INFO  (coreCloseExecutor-3043-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@e5244c
   [junit4]   2> 832577 INFO  (coreCloseExecutor-3043-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
   [junit4]   2> 832578 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.Overseer Overseer 
(id=97298833569480718-127.0.0.1:39436_pp_x%2Fxw-n_0000000003) closing
   [junit4]   2> 832578 INFO  
(OverseerStateUpdate-97298833569480718-127.0.0.1:39436_pp_x%2Fxw-n_0000000003) 
[    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39436_pp_x%2Fxw
   [junit4]   2> 832583 WARN  (zkCallback-1062-thread-3) [    ] 
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: 
[KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 832583 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 832584 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@15728ec{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 832584 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@15e5212{/pp_x/xw,null,UNAVAILABLE}
   [junit4]   2> 832584 INFO  
(TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[2FA2D4BC69650D1]) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:36358 36358
   [junit4]   2> 832586 INFO  (Thread-1541) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:36358 36358
   [junit4]   2> 832586 WARN  (Thread-1541) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        38      /solr/overseer/collection-queue-work
   [junit4]   2>        8       /solr/overseer/queue
   [junit4]   2>        4       /solr/overseer/queue-work
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=test 
-Dtests.seed=2FA2D4BC69650D1 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=ta-LK -Dtests.timezone=Etc/GMT+6 -Dtests.asserts=true 
-Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 70.7s J1 | ChaosMonkeyNothingIsSafeTest.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: document count 
mismatch.  control=1096 sum(shards)=1095 cloudClient=1095
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([2FA2D4BC69650D1:8AAE1291686A3D29]:0)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1323)
   [junit4]    >        at 
org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:231)
   [junit4]    >        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    >        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    >        at 
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    >        at 
java.base/java.lang.reflect.Method.invoke(Method.java:543)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
   [junit4]    >        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 832588 INFO  
(SUITE-ChaosMonkeyNothingIsSafeTest-seed#[2FA2D4BC69650D1]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_2FA2D4BC69650D1-001
   [junit4]   2> Jan 17, 2017 2:14:08 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{rnd_b=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
 _version_=FST50, a_t=PostingsFormat(name=Memory), 
a_i=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
 
id=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128)))},
 docValues:{}, maxPointsInLeafNode=343, maxMBSortInHeap=7.037741930068005, 
sim=RandomSimilarity(queryNorm=false): {}, locale=ta-LK, timezone=Etc/GMT+6
   [junit4]   2> NOTE: Linux 4.4.0-53-generic i386/Oracle Corporation 9-ea 
(32-bit)/cpus=12,threads=1,free=218524976,total=473432064
   [junit4]   2> NOTE: All tests run in this JVM: [SpellCheckComponentTest, 
SolrIndexMetricsTest, SimplePostToolTest, TestSolrCloudWithDelegationTokens, 
ShardRoutingCustomTest, TestCustomSort, DirectSolrConnectionTest, 
LeaderElectionContextKeyTest, OverseerCollectionConfigSetProcessorTest, 
TestExactStatsCache, CoreAdminCreateDiscoverTest, ShardRoutingTest, 
TestHashPartitioner, SampleTest, TestUninvertingReader, ZkStateWriterTest, 
SolrGraphiteReporterTest, TestSegmentSorting, 
TestExclusionRuleCollectionAccess, ChangedSchemaMergeTest, 
HdfsTlogReplayBufferedWhileIndexingTest, SolrCLIZkUtilsTest, 
TestGeoJSONResponseWriter, TestFieldCacheReopen, TestUseDocValuesAsStored2, 
TestNoOpRegenerator, QueryParsingTest, TestReloadAndDeleteDocs, 
HighlighterMaxOffsetTest, TestPerFieldSimilarity, TestStressRecovery, 
IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestRecoveryHdfs, 
TestSweetSpotSimilarityFactory, ClusterStateUpdateTest, 
ChaosMonkeySafeLeaderTest, TestManagedSchema, SoftAutoCommitTest, 
TestScoreJoinQPScore, TestCloudPivotFacet, InfoHandlerTest, 
TestSolrQueryParserResource, ConvertedLegacyTest, SSLMigrationTest, 
CollectionsAPIAsyncDistributedZkTest, DOMUtilTest, TestInfoStreamLogging, 
DistributedFacetPivotWhiteBoxTest, SolrIndexSplitterTest, 
TestStressCloudBlindAtomicUpdates, TestDefaultStatsCache, 
IndexBasedSpellCheckerTest, TestPKIAuthenticationPlugin, SortSpecParsingTest, 
TestJettySolrRunner, BJQParserTest, RulesTest, TestFastLRUCache, 
TimeZoneUtilsTest, IndexSchemaRuntimeFieldTest, TestStressVersions, 
ClassificationUpdateProcessorTest, BigEndianAscendingWordSerializerTest, 
BlockDirectoryTest, DocValuesNotIndexedTest, TestSolrCoreSnapshots, 
SparseHLLTest, HighlighterTest, CursorMarkTest, TestSystemIdResolver, 
TestMinMaxOnMultiValuedField, DistributedIntervalFacetingTest, 
SuggesterFSTTest, TestDelegationWithHadoopAuth, 
SchemaVersionSpecificBehaviorTest, LeaderInitiatedRecoveryOnCommitTest, 
TestLegacyFieldCache, TolerantUpdateProcessorTest, 
HdfsRestartWhileUpdatingTest, HdfsNNFailoverTest, SpellCheckCollatorTest, 
TestPushWriter, TestQueryUtils, SegmentsInfoRequestHandlerTest, 
TestDistributedGrouping, TestSolrIndexConfig, TestSearchPerf, 
HttpSolrCallGetCoreTest, TestCursorMarkWithoutUniqueKey, 
DistributedExpandComponentTest, TestCustomStream, TestAuthenticationFramework, 
TestRandomRequestDistribution, StressHdfsTest, TestNonDefinedSimilarityFactory, 
BasicAuthStandaloneTest, TestPostingsSolrHighlighter, FullHLLTest, 
ExitableDirectoryReaderTest, TestXmlQParserPlugin, TestPivotHelperCode, 
ZkSolrClientTest, ReplicationFactorTest, DistributedMLTComponentTest, 
ChaosMonkeyNothingIsSafeTest]
   [junit4] Completed [248/678 (1!)] on J1 in 71.70s, 1 test, 1 failure <<< 
FAILURES!

[...truncated 52908 lines...]

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to