[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 3608 - Unstable!

Policeman Jenkins Server Sat, 15 Oct 2016 16:42:26 -0700

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3608/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC


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

Error Message:
Captured an uncaught exception in thread: Thread[id=42379, 
name=SocketProxy-Response-54359:54732, state=RUNNABLE, 
group=TGRP-HttpPartitionTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught 
exception in thread: Thread[id=42379, name=SocketProxy-Response-54359:54732, 
state=RUNNABLE, group=TGRP-HttpPartitionTest]
        at 
__randomizedtesting.SeedInfo.seed([39D9B932AF95744C:B18D86E8016919B4]:0)
Caused by: java.lang.RuntimeException: java.net.SocketException: Socket is 
closed
        at __randomizedtesting.SeedInfo.seed([39D9B932AF95744C]:0)
        at 
org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:347)
Caused by: java.net.SocketException: Socket is closed
        at java.net.Socket.setSoTimeout(Socket.java:1137)
        at 
org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:344)




Build Log:
[...truncated 12028 lines...]
   [junit4] Suite: org.apache.solr.cloud.HttpPartitionTest
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/init-core-data-001
   [junit4]   2> 2816854 INFO  
(SUITE-HttpPartitionTest-seed#[39D9B932AF95744C]-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)
 w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 2816855 INFO  
(SUITE-HttpPartitionTest-seed#[39D9B932AF95744C]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
   [junit4]   2> 2816857 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2816858 INFO  (Thread-3987) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2816858 INFO  (Thread-3987) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 2816861 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkTestServer start zk server on port:54355
   [junit4]   2> 2816942 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
 to /configs/conf1/solrconfig.xml
   [junit4]   2> 2816960 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml
 to /configs/conf1/schema.xml
   [junit4]   2> 2816977 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
 to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2816981 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
 to /configs/conf1/stopwords.txt
   [junit4]   2> 2816987 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt
 to /configs/conf1/protwords.txt
   [junit4]   2> 2816991 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml
 to /configs/conf1/currency.xml
   [junit4]   2> 2816996 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
 to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2817007 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
 to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2817023 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
 to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2817059 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
 to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2817070 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
 to /configs/conf1/synonyms.txt
   [junit4]   2> 2818507 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores/collection1
   [junit4]   2> 2818510 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 2818513 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@2a0e34af{/,null,AVAILABLE}
   [junit4]   2> 2818514 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@4d0700a2{HTTP/1.1,[http/1.1]}{127.0.0.1:54359}
   [junit4]   2> 2818514 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
Started @2823607ms
   [junit4]   2> 2818514 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/tempDir-001/control/data,
 hostContext=/, hostPort=54358, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores}
   [junit4]   2> 2818514 ERROR 
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2818514 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2818515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2818515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2818515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-10-15T22:50:43.053Z
   [junit4]   2> 2818523 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 2818523 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/solr.xml
   [junit4]   2> 2818539 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54355/solr
   [junit4]   2> 2818596 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54358_    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54358_
   [junit4]   2> 2818599 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54358_    ] 
o.a.s.c.Overseer Overseer (id=96768612197990404-127.0.0.1:54358_-n_0000000000) 
starting
   [junit4]   2> 2818619 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54358_    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54358_
   [junit4]   2> 2818622 INFO  
(OverseerStateUpdate-96768612197990404-127.0.0.1:54358_-n_0000000000) 
[n:127.0.0.1:54358_    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 2818645 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54358_    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores
   [junit4]   2> 2818645 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54358_    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2818652 INFO  
(OverseerStateUpdate-96768612197990404-127.0.0.1:54358_-n_0000000000) 
[n:127.0.0.1:54358_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard 
shard=shard1
   [junit4]   2> 2819679 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2819694 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 2819844 WARN  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 2819845 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2819870 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
control_collection
   [junit4]   2> 2819871 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores/collection1/data/]
   [junit4]   2> 2819871 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2819871 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2819876 WARN  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2819889 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2819889 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2819894 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2819894 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2819894 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2819895 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@17581ab[collection1] main]
   [junit4]   2> 2819896 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2819897 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2819897 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2819897 INFO  
(coreLoadExecutor-10187-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_ c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297798350274560
   [junit4]   2> 2819899 INFO  
(searcherExecutor-10188-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore 
[collection1] Registered new searcher Searcher@17581ab[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2819913 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2819913 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2819913 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
Sync replicas to http://127.0.0.1:54358/collection1/
   [junit4]   2> 2819922 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
Sync Success - now sync replicas to me
   [junit4]   2> 2819923 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:54358/collection1/ has no replicas
   [junit4]   2> 2819932 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:54358/collection1/ shard1
   [junit4]   2> 2820092 INFO  
(coreZkRegister-10180-thread-1-processing-n:127.0.0.1:54358_ x:collection1 
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController 
I am the leader, no recovery necessary
   [junit4]   2> 2820168 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2820172 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection 
loss:false
   [junit4]   2> 2820519 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores/collection1
   [junit4]   2> 2820521 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001
   [junit4]   2> 2820522 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 2820525 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7e5768cf{/,null,AVAILABLE}
   [junit4]   2> 2820525 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@6b5f7347{HTTP/1.1,[http/1.1]}{127.0.0.1:54365}
   [junit4]   2> 2820525 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
Started @2825619ms
   [junit4]   2> 2820525 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/tempDir-001/jetty1,
 solrconfig=solrconfig.xml, hostContext=/, hostPort=54364, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores}
   [junit4]   2> 2820526 ERROR 
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2820526 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2820526 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2820526 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2820526 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-10-15T22:50:45.064Z
   [junit4]   2> 2820532 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 2820532 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/solr.xml
   [junit4]   2> 2820549 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54355/solr
   [junit4]   2> 2820574 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54364_    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2820587 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54364_    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54364_
   [junit4]   2> 2820591 INFO  (zkCallback-9543-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2820591 INFO  
(zkCallback-9539-thread-1-processing-n:127.0.0.1:54358_) [n:127.0.0.1:54358_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2820592 INFO  
(zkCallback-9548-thread-1-processing-n:127.0.0.1:54364_) [n:127.0.0.1:54364_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2820633 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54364_    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores
   [junit4]   2> 2820633 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54364_    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2820640 INFO  
(OverseerStateUpdate-96768612197990404-127.0.0.1:54358_-n_0000000000) 
[n:127.0.0.1:54358_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard 
shard=shard2
   [junit4]   2> 2821720 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1   x:collection1] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 2821741 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 2821888 WARN  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 2821892 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded 
schema test/1.0 with uniqueid field id
   [junit4]   2> 2821917 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2821917 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores/collection1/data/]
   [junit4]   2> 2821917 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2821918 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2821922 WARN  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2821936 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2821936 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2821939 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2821940 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2821941 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2821941 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3b1b00c[collection1] main]
   [junit4]   2> 2821943 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2821944 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2821944 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2821945 INFO  
(searcherExecutor-10199-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new 
searcher Searcher@3b1b00c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2821946 INFO  
(coreLoadExecutor-10198-thread-1-processing-n:127.0.0.1:54364_) 
[n:127.0.0.1:54364_ c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297800498806784
   [junit4]   2> 2821961 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas 
found to continue.
   [junit4]   2> 2821961 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new 
leader - try and sync
   [junit4]   2> 2821961 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:54364/collection1/
   [junit4]   2> 2821961 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync 
replicas to me
   [junit4]   2> 2821961 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:54364/collection1/ has no replicas
   [junit4]   2> 2821971 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new 
leader: http://127.0.0.1:54364/collection1/ shard2
   [junit4]   2> 2822143 INFO  
(coreZkRegister-10193-thread-1-processing-n:127.0.0.1:54364_ x:collection1 
s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:54364_ c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery 
necessary
   [junit4]   2> 2822538 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/cores/collection1
   [junit4]   2> 2822540 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001
   [junit4]   2> 2822541 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 2822544 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@45eeda3a{/,null,AVAILABLE}
   [junit4]   2> 2822544 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@517b3e39{HTTP/1.1,[http/1.1]}{127.0.0.1:54370}
   [junit4]   2> 2822544 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
Started @2827638ms
   [junit4]   2> 2822545 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/tempDir-001/jetty2,
 solrconfig=solrconfig.xml, hostContext=/, hostPort=54369, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/cores}
   [junit4]   2> 2822545 ERROR 
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2822545 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2822545 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2822546 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2822546 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-10-15T22:50:47.084Z
   [junit4]   2> 2822552 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 2822552 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/solr.xml
   [junit4]   2> 2822582 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54355/solr
   [junit4]   2> 2822610 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54369_    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2822626 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54369_    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54369_
   [junit4]   2> 2822631 INFO  
(zkCallback-9554-thread-1-processing-n:127.0.0.1:54369_) [n:127.0.0.1:54369_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2822631 INFO  
(zkCallback-9539-thread-3-processing-n:127.0.0.1:54358_) [n:127.0.0.1:54358_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2822631 INFO  (zkCallback-9543-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2822631 INFO  
(zkCallback-9548-thread-1-processing-n:127.0.0.1:54364_) [n:127.0.0.1:54364_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2822645 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54369_    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/cores
   [junit4]   2> 2822646 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54369_    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2822649 INFO  
(OverseerStateUpdate-96768612197990404-127.0.0.1:54358_-n_0000000000) 
[n:127.0.0.1:54358_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard 
shard=shard1
   [junit4]   2> 2823667 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1   x:collection1] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 2823685 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 2823857 WARN  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 2823861 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded 
schema test/1.0 with uniqueid field id
   [junit4]   2> 2823893 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2823893 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-2-001/cores/collection1/data/]
   [junit4]   2> 2823893 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2823897 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2823905 WARN  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2823931 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2823931 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2823935 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2823935 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2823937 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2823937 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@f0d719b[collection1] main]
   [junit4]   2> 2823940 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2823941 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2823941 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2823943 INFO  
(searcherExecutor-10210-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SolrCore [collection1] Registered new 
searcher Searcher@f0d719b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2823943 INFO  
(coreLoadExecutor-10209-thread-1-processing-n:127.0.0.1:54369_) 
[n:127.0.0.1:54369_ c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297802592813056
   [junit4]   2> 2823959 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas 
found to continue.
   [junit4]   2> 2823959 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new 
leader - try and sync
   [junit4]   2> 2823959 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:54369/collection1/
   [junit4]   2> 2823959 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync 
replicas to me
   [junit4]   2> 2823959 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:54369/collection1/ has no replicas
   [junit4]   2> 2823969 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new 
leader: http://127.0.0.1:54369/collection1/ shard1
   [junit4]   2> 2824141 INFO  
(coreZkRegister-10204-thread-1-processing-n:127.0.0.1:54369_ x:collection1 
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:54369_ c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery 
necessary
   [junit4]   2> 2824509 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/cores/collection1
   [junit4]   2> 2824511 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001
   [junit4]   2> 2824512 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 2824514 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@4c9234a2{/,null,AVAILABLE}
   [junit4]   2> 2824515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@483e8db0{HTTP/1.1,[http/1.1]}{127.0.0.1:54375}
   [junit4]   2> 2824515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] o.e.j.s.Server 
Started @2829608ms
   [junit4]   2> 2824515 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/tempDir-001/jetty3,
 solrconfig=solrconfig.xml, hostContext=/, hostPort=54374, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/cores}
   [junit4]   2> 2824515 ERROR 
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2824516 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2824516 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2824516 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2824516 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-10-15T22:50:49.054Z
   [junit4]   2> 2824521 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 2824522 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/solr.xml
   [junit4]   2> 2824536 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54355/solr
   [junit4]   2> 2824562 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54374_    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 2824575 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54374_    ] 
o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54374_
   [junit4]   2> 2824585 INFO  
(zkCallback-9548-thread-1-processing-n:127.0.0.1:54364_) [n:127.0.0.1:54364_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2824585 INFO  (zkCallback-9543-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2824585 INFO  
(zkCallback-9539-thread-2-processing-n:127.0.0.1:54358_) [n:127.0.0.1:54358_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2824585 INFO  
(zkCallback-9554-thread-1-processing-n:127.0.0.1:54369_) [n:127.0.0.1:54369_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2824587 INFO  
(zkCallback-9560-thread-1-processing-n:127.0.0.1:54374_) [n:127.0.0.1:54374_    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2824603 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54374_    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/cores
   [junit4]   2> 2824604 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [n:127.0.0.1:54374_    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2824607 INFO  
(OverseerStateUpdate-96768612197990404-127.0.0.1:54358_-n_0000000000) 
[n:127.0.0.1:54358_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard 
shard=shard2
   [junit4]   2> 2825627 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1   x:collection1] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 7.0.0
   [junit4]   2> 2825649 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 2825790 WARN  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 2825793 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1   x:collection1] o.a.s.s.IndexSchema Loaded 
schema test/1.0 with uniqueid field id
   [junit4]   2> 2825821 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2825821 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-3-001/cores/collection1/data/]
   [junit4]   2> 2825821 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2825822 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2825828 WARN  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2825844 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2825844 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2825848 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2825848 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2825849 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2825849 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@5cc648e4[collection1] main]
   [junit4]   2> 2825852 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2825852 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2825853 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2825854 INFO  
(searcherExecutor-10221-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.SolrCore [collection1] Registered new 
searcher Searcher@5cc648e4[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2825854 INFO  
(coreLoadExecutor-10220-thread-1-processing-n:127.0.0.1:54374_) 
[n:127.0.0.1:54374_ c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297804596641792
   [junit4]   2> 2825863 INFO  
(coreZkRegister-10215-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.ZkController Core needs to 
recover:collection1
   [junit4]   2> 2825864 INFO  
(updateExecutor-9557-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 2825864 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. 
recoveringAfterStartup=true
   [junit4]   2> 2825865 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
   [junit4]   2> 2825865 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. 
core=[collection1]
   [junit4]   2> 2825865 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. 
FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 2825865 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core 
[collection1] as recovering, leader is [http://127.0.0.1:54364/collection1/] 
and I am [http://127.0.0.1:54374/collection1/]
   [junit4]   2> 2825868 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery 
command to [http://127.0.0.1:54364]; [WaitForState: 
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:54374_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 2825869 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54379,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2825870 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54380], receiveBufferSize=408300
   [junit4]   2> 2825873 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: 
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 2825875 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 
(shard2 of collection1) have state: recovering
   [junit4]   2> 2825875 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, 
shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? 
true, live=true, checkLive=true, currentState=down, localState=active, 
nodeName=127.0.0.1:54374_, coreNodeName=core_node3, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:54374","node_name":"127.0.0.1:54374_","state":"down"}
   [junit4]   2> 2826131 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 2826131 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 
30000 for each attempt
   [junit4]   2> 2826131 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: 
collection1 failOnTimeout:true timeout (sec):30000
   [junit4]   2> 2826878 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, 
shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? 
true, live=true, checkLive=true, currentState=recovering, localState=active, 
nodeName=127.0.0.1:54374_, coreNodeName=core_node3, 
onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:54374","node_name":"127.0.0.1:54374_","state":"recovering"}
   [junit4]   2> 2826878 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, 
checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 2826879 INFO  (qtp371361723-41860) [n:127.0.0.1:54364_    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={nodeName=127.0.0.1:54374_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
 status=0 QTime=1005
   [junit4]   2> 2833884 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Attempting to PeerSync 
from [http://127.0.0.1:54364/collection1/] - recoveringAfterStartup=[true]
   [junit4]   2> 2833884 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.PeerSync PeerSync: core=collection1 
url=http://127.0.0.1:54374 START replicas=[http://127.0.0.1:54364/collection1/] 
nUpdates=100
   [junit4]   2> 2833886 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54381,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2833887 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54382], receiveBufferSize=408300
   [junit4]   2> 2833888 INFO  (qtp371361723-41863) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] 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> 2833888 INFO  (qtp371361723-41863) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.S.Request 
[collection1]  webapp= path=/get 
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 2833889 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] 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> 2833889 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.PeerSync We are already in sync. No need to 
do a PeerSync 
   [junit4]   2> 2833889 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2833889 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted 
changes. Skipping IW.commit.
   [junit4]   2> 2833890 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2833890 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy PeerSync stage of recovery 
was successful.
   [junit4]   2> 2833890 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Replaying updates buffered 
during PeerSync.
   [junit4]   2> 2833890 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy No replay needed.
   [junit4]   2> 2833890 INFO  
(recoveryExecutor-9558-thread-1-processing-n:127.0.0.1:54374_ x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:54374_ c:collection1 s:shard2 
r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Registering as Active 
after recovery.
   [junit4]   2> 2834156 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
   [junit4]   2> 2834157 INFO  (SocketProxy-Acceptor-54358) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54383,localport=54358], receiveBufferSize:408300
   [junit4]   2> 2834158 INFO  (SocketProxy-Acceptor-54358) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54359,localport=54384], receiveBufferSize=408300
   [junit4]   2> 2834161 INFO  (qtp242504440-41822) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2834161 INFO  (qtp242504440-41822) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 2834162 INFO  (qtp242504440-41822) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2834162 INFO  (qtp242504440-41822) [n:127.0.0.1:54358_ 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp= path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 1
   [junit4]   2> 2834164 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54385,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2834164 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54386], receiveBufferSize=408300
   [junit4]   2> 2834167 INFO  (SocketProxy-Acceptor-54369) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54387,localport=54369], receiveBufferSize:408300
   [junit4]   2> 2834167 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54388,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2834168 INFO  (SocketProxy-Acceptor-54374) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54389,localport=54374], receiveBufferSize:408300
   [junit4]   2> 2834169 INFO  (SocketProxy-Acceptor-54369) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54370,localport=54390], receiveBufferSize=408300
   [junit4]   2> 2834169 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54392], receiveBufferSize=408300
   [junit4]   2> 2834172 INFO  (SocketProxy-Acceptor-54374) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54375,localport=54391], receiveBufferSize=408300
   [junit4]   2> 2834172 INFO  (qtp371361723-41865) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 
start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2834172 INFO  (qtp371361723-41865) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 
No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 2834173 INFO  (qtp371361723-41865) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 2834173 INFO  (qtp371361723-41865) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp= path=/update 
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:54364/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
 0 3
   [junit4]   2> 2834175 INFO  (qtp989645863-41889) [n:127.0.0.1:54369_ 
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 
start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2834175 INFO  (qtp1764659131-41918) [n:127.0.0.1:54374_ 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2834175 INFO  (qtp1764659131-41918) [n:127.0.0.1:54374_ 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 2834175 INFO  (qtp989645863-41889) [n:127.0.0.1:54369_ 
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 
No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 2834176 INFO  (qtp1764659131-41918) [n:127.0.0.1:54374_ 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 2834176 INFO  (qtp989645863-41889) [n:127.0.0.1:54369_ 
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 2834176 INFO  (qtp989645863-41889) [n:127.0.0.1:54369_ 
c:collection1 s:shard1 r:core_node2 x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp= path=/update 
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:54364/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
 0 1
   [junit4]   2> 2834176 INFO  (qtp1764659131-41918) [n:127.0.0.1:54374_ 
c:collection1 s:shard2 r:core_node3 x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp= path=/update 
params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:54364/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=}
 0 1
   [junit4]   2> 2834177 INFO  (qtp371361723-41864) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp= path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 11
   [junit4]   2> 2834179 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54393,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2834180 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54394], receiveBufferSize=408300
   [junit4]   2> 2834181 INFO  (qtp371361723-41862) [n:127.0.0.1:54364_ 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.S.Request 
[collection1]  webapp= path=/select 
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
 hits=0 status=0 QTime=0
   [junit4]   2> 2834182 INFO  (SocketProxy-Acceptor-54374) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54395,localport=54374], receiveBufferSize:408300
   [junit4]   2> 2834183 INFO  (SocketProxy-Acceptor-54374) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54375,localport=54396], receiveBufferSize=408300
   [junit4]   2> 2834183 INFO  (qtp1764659131-41920) [n:127.0.0.1:54374_ 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.S.Request 
[collection1]  webapp= path=/select 
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
 hits=0 status=0 QTime=0
   [junit4]   2> 2834184 INFO  (SocketProxy-Acceptor-54369) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54397,localport=54369], receiveBufferSize:408300
   [junit4]   2> 2834185 INFO  (SocketProxy-Acceptor-54369) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54370,localport=54398], receiveBufferSize=408300
   [junit4]   2> 2834186 INFO  (qtp989645863-41891) [n:127.0.0.1:54369_ 
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.S.Request 
[collection1]  webapp= path=/select 
params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2}
 hits=0 status=0 QTime=0
   [junit4]   2> 2836192 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase Creating collection with stateFormat=1: 
c8n_crud_1x2
   [junit4]   2> 2836195 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54399,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2836196 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54400], receiveBufferSize=408300
   [junit4]   2> 2836196 INFO  (qtp371361723-41863) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&maxShardsPerNode=1&name=c8n_crud_1x2&action=CREATE&numShards=1&stateFormat=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 2836202 INFO  
(OverseerThreadFactory-10185-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_    ] o.a.s.c.CreateCollectionCmd Create collection 
c8n_crud_1x2
   [junit4]   2> 2836203 INFO  
(OverseerThreadFactory-10185-thread-1-processing-n:127.0.0.1:54358_) 
[n:127.0.0.1:54358_    ] o.a.s.c.CreateCollectionCmd Only one config set found 
in zk - using it:conf1
   [junit4]   2> 2836322 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54401,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2836322 INFO  (SocketProxy-Acceptor-54358) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54402,localport=54358], receiveBufferSize:408300
   [junit4]   2> 2836323 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54403], receiveBufferSize=408300
   [junit4]   2> 2836324 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&name=c8n_crud_1x2_shard1_replica2&action=CREATE&numShards=1&collection=c8n_crud_1x2&shard=shard1&wt=javabin&version=2
   [junit4]   2> 2836324 INFO  (SocketProxy-Acceptor-54358) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54359,localport=54404], receiveBufferSize=408300
   [junit4]   2> 2836325 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&name=c8n_crud_1x2_shard1_replica1&action=CREATE&numShards=1&collection=c8n_crud_1x2&shard=shard1&wt=javabin&version=2
   [junit4]   2> 2837343 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2837344 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2837390 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica1] o.a.s.s.IndexSchema 
[c8n_crud_1x2_shard1_replica1] Schema name=test
   [junit4]   2> 2837394 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica2] o.a.s.s.IndexSchema 
[c8n_crud_1x2_shard1_replica2] Schema name=test
   [junit4]   2> 2837525 WARN  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica1] o.a.s.s.IndexSchema 
[c8n_crud_1x2_shard1_replica1] default search field in schema is text. WARNING: 
Deprecated, please use 'df' on request instead.
   [junit4]   2> 2837527 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica1] o.a.s.s.IndexSchema 
Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2837534 WARN  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica2] o.a.s.s.IndexSchema 
[c8n_crud_1x2_shard1_replica2] default search field in schema is text. WARNING: 
Deprecated, please use 'df' on request instead.
   [junit4]   2> 2837536 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica2] o.a.s.s.IndexSchema 
Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2837551 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica1] o.a.s.c.CoreContainer 
Creating SolrCore 'c8n_crud_1x2_shard1_replica1' using configuration from 
collection c8n_crud_1x2
   [junit4]   2> 2837551 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.SolrCore [[c8n_crud_1x2_shard1_replica1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores/c8n_crud_1x2_shard1_replica1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/control-001/cores/c8n_crud_1x2_shard1_replica1/data/]
   [junit4]   2> 2837551 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2837553 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2837558 WARN  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2837559 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1  x:c8n_crud_1x2_shard1_replica2] o.a.s.c.CoreContainer 
Creating SolrCore 'c8n_crud_1x2_shard1_replica2' using configuration from 
collection c8n_crud_1x2
   [junit4]   2> 2837560 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.c.SolrCore [[c8n_crud_1x2_shard1_replica2] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores/c8n_crud_1x2_shard1_replica2],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest_39D9B932AF95744C-001/shard-1-001/cores/c8n_crud_1x2_shard1_replica2/data/]
   [junit4]   2> 2837560 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43dbb9c6
   [junit4]   2> 2837561 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=8.419921875, 
floorSegmentMB=1.1416015625, forceMergeDeletesPctAllowed=27.485354005719422, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.23798825938989776
   [junit4]   2> 2837565 WARN  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 2837996 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2837996 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2837997 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2837997 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2838000 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2838000 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2838001 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2838001 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@4041da13[c8n_crud_1x2_shard1_replica1] main]
   [junit4]   2> 2838002 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2838002 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2838003 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4173341513514123]
   [junit4]   2> 2838003 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@4a2e3967[c8n_crud_1x2_shard1_replica2] main]
   [junit4]   2> 2838003 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2838004 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2838004 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2838005 INFO  
(searcherExecutor-10226-thread-1-processing-n:127.0.0.1:54358_ 
x:c8n_crud_1x2_shard1_replica1 s:shard1 c:c8n_crud_1x2 r:core_node2) 
[n:127.0.0.1:54358_ c:c8n_crud_1x2 s:shard1 r:core_node2 
x:c8n_crud_1x2_shard1_replica1] o.a.s.c.SolrCore [c8n_crud_1x2_shard1_replica1] 
Registered new searcher Searcher@4041da13[c8n_crud_1x2_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2838005 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297817337888768
   [junit4]   2> 2838005 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2838006 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2838006 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2838007 INFO  
(searcherExecutor-10227-thread-1-processing-n:127.0.0.1:54364_ 
x:c8n_crud_1x2_shard1_replica2 s:shard1 c:c8n_crud_1x2 r:core_node1) 
[n:127.0.0.1:54364_ c:c8n_crud_1x2 s:shard1 r:core_node1 
x:c8n_crud_1x2_shard1_replica2] o.a.s.c.SolrCore [c8n_crud_1x2_shard1_replica2] 
Registered new searcher Searcher@4a2e3967[c8n_crud_1x2_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2838007 INFO  (qtp371361723-41858) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1548297817339985920
   [junit4]   2> 2838018 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2838018 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2838018 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:54358/c8n_crud_1x2_shard1_replica1/
   [junit4]   2> 2838018 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.PeerSync PeerSync: core=c8n_crud_1x2_shard1_replica1 
url=http://127.0.0.1:54358 START 
replicas=[http://127.0.0.1:54364/c8n_crud_1x2_shard1_replica2/] nUpdates=100
   [junit4]   2> 2838019 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.u.PeerSync PeerSync: core=c8n_crud_1x2_shard1_replica1 
url=http://127.0.0.1:54358 DONE.  We have no versions.  sync failed.
   [junit4]   2> 2838020 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy accepted 
Socket[addr=/127.0.0.1,port=54405,localport=54364], receiveBufferSize:408300
   [junit4]   2> 2838021 INFO  (SocketProxy-Acceptor-54364) [    ] 
o.a.s.c.SocketProxy proxy connection 
Socket[addr=/127.0.0.1,port=54365,localport=54406], receiveBufferSize=408300
   [junit4]   2> 2838023 INFO  (qtp371361723-41864) [n:127.0.0.1:54364_ 
c:c8n_crud_1x2 s:shard1 r:core_node1 x:c8n_crud_1x2_shard1_replica2] 
o.a.s.c.S.Request [c8n_crud_1x2_shard1_replica2]  webapp= path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=1
   [junit4]   2> 2838023 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 2838024 INFO  (qtp242504440-41823) [n:127.0.0.1:54358_ 
c:c8n_crud_1x2 s:shard1 r:core_node2 x:c8n_crud_1x2_shard1_replica1] 
o.a.s.c.ShardL

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

rtitionTest.test-seed#[39D9B932AF95744C]) [    ] o.a.s.c.ChaosMonkey monkey: 
stop shard! 54358
   [junit4]   2> 2979795 INFO  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:54355 54355
   [junit4]   2> 2979812 INFO  (Thread-3987) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:54355 54355
   [junit4]   2> 2988082 WARN  (Thread-3987) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        6       /solr/clusterprops.json
   [junit4]   2>        6       /solr/aliases.json
   [junit4]   2>        5       /solr/security.json
   [junit4]   2>        5       /solr/configs/conf1
   [junit4]   2>        4       /solr/collections/collection1/state.json
   [junit4]   2>        3       /solr/collections/c8n_1x3/state.json
   [junit4]   2>        3       /solr/collections/collMinRf_1x3/state.json
   [junit4]   2>        3       
/solr/collections/c8n_1x2_leader_session_loss/state.json
   [junit4]   2>        2       /solr/collections/c8n_1x2/state.json
   [junit4]   2>        2       /solr/collections/c8n_crud_1x2/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        6       /solr/clusterstate.json
   [junit4]   2>        2       
/solr/collections/collection1/leader_elect/shard2/election/96768612197990408-core_node1-n_0000000000
   [junit4]   2>        2       
/solr/overseer_elect/election/96768612197990411-127.0.0.1:54369_-n_0000000002
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        141     /solr/overseer/collection-queue-work
   [junit4]   2>        129     /solr/overseer/queue
   [junit4]   2>        20      /solr/overseer/queue-work
   [junit4]   2>        7       /solr/live_nodes
   [junit4]   2>        6       /solr/collections
   [junit4]   2> 
   [junit4]   2> 2988082 WARN  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SocketProxy Closing 31 connections to: http://127.0.0.1:54358/, target: 
http://127.0.0.1:54359/
   [junit4]   2> 2988083 WARN  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SocketProxy Closing 7 connections to: http://127.0.0.1:54374/, target: 
http://127.0.0.1:54375/
   [junit4]   2> 2988083 WARN  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SocketProxy Closing 9 connections to: http://127.0.0.1:54364/, target: 
http://127.0.0.1:54365/
   [junit4]   2> 2988083 WARN  
(TEST-HttpPartitionTest.test-seed#[39D9B932AF95744C]) [    ] 
o.a.s.c.SocketProxy Closing 6 connections to: http://127.0.0.1:54369/, target: 
http://127.0.0.1:54370/
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HttpPartitionTest 
-Dtests.method=test -Dtests.seed=39D9B932AF95744C -Dtests.slow=true 
-Dtests.locale=ar-KW -Dtests.timezone=America/Moncton -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] ERROR    171s J0 | HttpPartitionTest.test <<<
   [junit4]    > Throwable #1: 
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught 
exception in thread: Thread[id=42379, name=SocketProxy-Response-54359:54732, 
state=RUNNABLE, group=TGRP-HttpPartitionTest]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([39D9B932AF95744C:B18D86E8016919B4]:0)
   [junit4]    > Caused by: java.lang.RuntimeException: 
java.net.SocketException: Socket is closed
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([39D9B932AF95744C]:0)
   [junit4]    >        at 
org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:347)
   [junit4]    > Caused by: java.net.SocketException: Socket is closed
   [junit4]    >        at java.net.Socket.setSoTimeout(Socket.java:1137)
   [junit4]    >        at 
org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:344)
   [junit4]   2> 2988128 INFO  
(SUITE-HttpPartitionTest-seed#[39D9B932AF95744C]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: test params are: codec=CheapBastard, 
sim=ClassicSimilarity, locale=ar-KW, timezone=America/Moncton
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_102 
(64-bit)/cpus=3,threads=1,free=359639920,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [TestRawTransformer, 
ChangedSchemaMergeTest, TestHdfsUpdateLog, TestManagedSchemaThreadSafety, 
HdfsThreadLeakTest, DirectUpdateHandlerTest, TestLeaderRecoverFromLogOnStartup, 
IndexSchemaRuntimeFieldTest, TestLegacyFieldCache, TestUpdate, ReplaceNodeTest, 
SolrPluginUtilsTest, QueryEqualityTest, TestStressLucene, ZkCLITest, 
LeaderInitiatedRecoveryOnCommitTest, CdcrReplicationDistributedZkTest, 
TestRTGBase, TestReRankQParserPlugin, LeaderElectionTest, 
TestPartialUpdateDeduplication, TestFastLRUCache, TestSchemaSimilarityResource, 
AnalyticsMergeStrategyTest, SpatialRPTFieldTypeTest, 
TestHighFrequencyDictionaryFactory, TestSolrCLIRunExample, 
TestCursorMarkWithoutUniqueKey, TestStressLiveNodes, TestCustomStream, 
TestExtendedDismaxParser, SyncSliceTest, TestStandardQParsers, 
TestTolerantSearch, TestAddFieldRealTimeGet, TestHashQParserPlugin, 
TestLegacyNumericRangeQueryBuilder, DistributedQueueTest, 
TestFieldTypeCollectionResource, TestCSVResponseWriter, 
TestSolrCloudWithDelegationTokens, CloudMLTQParserTest, 
DistributedSuggestComponentTest, TestSQLHandlerNonCloud, TestCloudPivotFacet, 
RulesTest, BigEndianAscendingWordDeserializerTest, TestCloudDeleteByQuery, 
TestFunctionQuery, TestRandomRequestDistribution, TestSolrQueryParserResource, 
LeaderFailoverAfterPartitionTest, MoreLikeThisHandlerTest, DeleteReplicaTest, 
RankQueryTest, TestJmxIntegration, TestGroupingSearch, 
DistributedMLTComponentTest, SampleTest, CurrencyFieldXmlFileTest, 
TestSchemaNameResource, TestFieldCacheReopen, 
CollectionsAPIAsyncDistributedZkTest, TestTrackingShardHandlerFactory, 
ResponseHeaderTest, DeleteLastCustomShardedReplicaTest, 
SpatialHeatmapFacetsTest, TestDocumentBuilder, TestSolr4Spatial2, 
XmlUpdateRequestHandlerTest, TestSolrCloudWithSecureImpersonation, 
HighlighterTest, SynonymTokenizerTest, TestNumericTerms64, RequiredFieldsTest, 
TestMergePolicyConfig, OutputWriterTest, SolrXmlInZkTest, TestCollationField, 
BinaryUpdateRequestHandlerTest, HdfsCollectionsAPIDistributedZkTest, 
TestImplicitCoreProperties, RecoveryZkTest, ShardRoutingTest, 
SpatialFilterTest, OverseerTaskQueueTest, HdfsDirectoryTest, NumericFieldsTest, 
AssignTest, TestDistribIDF, SolrIndexConfigTest, TestSubQueryTransformer, 
HdfsBasicDistributedZk2Test, TestSortingResponseWriter, ClusterStateUpdateTest, 
DateFieldTest, DOMUtilTest, StatelessScriptUpdateProcessorFactoryTest, 
TestCloudSchemaless, TestManagedSchema, SolrRequestParserTest, 
UniqFieldsUpdateProcessorFactoryTest, MultiTermTest, TestConfigOverlay, 
TestConfigSetProperties, TestObjectReleaseTracker, CdcrRequestHandlerTest, 
StressHdfsTest, TestLRUCache, TestLockTree, TestCustomSort, 
TestTolerantUpdateProcessorRandomCloud, TestDynamicFieldCollectionResource, 
FastVectorHighlighterTest, TestConfigReload, DistributedFacetExistsSmallTest, 
TestCharFilters, TestBM25SimilarityFactory, TestSolrJ, 
TestElisionMultitermQuery, DistributedQueryElevationComponentTest, 
MBeansHandlerTest, BlockDirectoryTest, TriLevelCompositeIdRoutingTest, 
TestOrdValues, TestRandomDVFaceting, TermsComponentTest, 
TestDocBasedVersionConstraints, TestWordDelimiterFilterFactory, 
TestNamedUpdateProcessors, TestFieldCacheVsDocValues, 
DistributedQueryComponentCustomSortTest, TestQuerySenderNoQuery, 
RequestLoggingTest, TestFilteredDocIdSet, TestXIncludeConfig, 
AddBlockUpdateTest, XsltUpdateRequestHandlerTest, BlockJoinFacetRandomTest, 
TestHashPartitioner, TestLeaderElectionZkExpiry, TestAnalyzeInfixSuggestions, 
TestFileDictionaryLookup, TestNonDefinedSimilarityFactory, 
TestCloudManagedSchema, QueryElevationComponentTest, 
TestSerializedLuceneMatchVersion, TestOverriddenPrefixQueryForCustomFieldType, 
DocExpirationUpdateProcessorFactoryTest, AlternateDirectoryTest, 
TestFieldCacheSort, TestConfigSetsAPIExclusivity, TestSolrConfigHandler, 
ParsingFieldUpdateProcessorsTest, SimplePostToolTest, DirectSolrConnectionTest, 
BasicDistributedZkTest, UnloadDistributedZkTest, FullSolrCloudDistribCmdsTest, 
TestReplicationHandler, ShardRoutingCustomTest, AutoCommitTest, TestFaceting, 
TestRecovery, DistributedSpellCheckComponentTest, 
TermVectorComponentDistributedTest, TestStressReorder, TestStressVersions, 
HardAutoCommitTest, TestRangeQuery, PeerSyncTest, TestLazyCores, 
ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, TestCoreDiscovery, 
AnalysisAfterCoreReloadTest, SpellCheckCollatorTest, CoreAdminHandlerTest, 
TestTrie, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, 
WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, 
SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, SortByFunctionTest, 
TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, 
IndexBasedSpellCheckerTest, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, 
DocumentAnalysisRequestHandlerTest, TestOmitPositions, DocumentBuilderTest, 
PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, 
IndexSchemaTest, PingRequestHandlerTest, TestLFUCache, TestFastWriter, 
TimeZoneUtilsTest, TestFastOutputStream, ScriptEngineTest, 
OpenExchangeRatesOrgProviderTest, DateMathParserTest, PreAnalyzedFieldTest, 
TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, 
RAMDirectoryFactoryTest, ZkNodePropsTest, SliceStateTest, 
SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, CircularListTest, 
CursorPagingTest, DistributedIntervalFacetingTest, SolrTestCaseJ4Test, 
TestDistributedMissingSort, TestHighlightDedupGrouping, 
TestEmbeddedSolrServerConstructors, TestJettySolrRunner, ConnectionReuseTest, 
ActionThrottleTest, AliasIntegrationTest, CleanupOldIndexTest, 
CollectionStateFormat2Test, CollectionsAPISolrJTest, 
ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, 
CreateCollectionCleanupTest, DeleteShardTest, DeleteStatusTest, 
DistribDocExpirationUpdateProcessorTest, HttpPartitionTest]
   [junit4] Completed [471/638 (1!)] on J0 in 171.81s, 1 test, 1 error <<< 
FAILURES!

[...truncated 60920 lines...]

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

[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 3608 - Unstable!

Reply via email to