Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Windows/473/
Java: 64bit/jdk1.8.0_102 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.RecoveryZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=10444,
name=updateExecutor-1725-thread-2, state=RUNNABLE, group=TGRP-RecoveryZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught
exception in thread: Thread[id=10444, name=updateExecutor-1725-thread-2,
state=RUNNABLE, group=TGRP-RecoveryZkTest]
at
__randomizedtesting.SeedInfo.seed([68A817BFFB88BCDF:E0FC28655574D127]:0)
Caused by: org.apache.solr.common.SolrException: Replica:
http://127.0.0.1:60276/collection1/ should have been marked under leader
initiated recovery in ZkController but wasn't.
at __randomizedtesting.SeedInfo.seed([68A817BFFB88BCDF]:0)
at
org.apache.solr.cloud.LeaderInitiatedRecoveryThread.run(LeaderInitiatedRecoveryThread.java:88)
at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11496 lines...]
[junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4] 2> Creating dataDir:
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\init-core-data-001
[junit4] 2> 1418066 INFO
(SUITE-RecoveryZkTest-seed#[68A817BFFB88BCDF]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 1418066 INFO
(SUITE-RecoveryZkTest-seed#[68A817BFFB88BCDF]-worker) [ ]
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 1418067 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkTestServer
STARTING ZK TEST SERVER
[junit4] 2> 1418068 INFO (Thread-2366) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1418068 INFO (Thread-2366) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1418169 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkTestServer
start zk server on port:60239
[junit4] 2> 1418173 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1418178 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1418184 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml
to /configs/conf1/solrconfig.xml
[junit4] 2> 1418186 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema15.xml
to /configs/conf1/schema.xml
[junit4] 2> 1418189 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml
to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1418191 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt
to /configs/conf1/stopwords.txt
[junit4] 2> 1418193 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt
to /configs/conf1/protwords.txt
[junit4] 2> 1418195 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml
to /configs/conf1/currency.xml
[junit4] 2> 1418197 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml
to /configs/conf1/enumsConfig.xml
[junit4] 2> 1418199 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json
to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1418201 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt
to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1418202 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt
to /configs/conf1/old_synonyms.txt
[junit4] 2> 1418205 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt
to /configs/conf1/synonyms.txt
[junit4] 2> 1418207 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x1575dec1b600001, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1418650 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.SolrTestCaseJ4
Writing core.properties file to
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1
[junit4] 2> 1418653 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
jetty-9.3.8.v20160314
[junit4] 2> 1418654 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@801e89a{/,null,AVAILABLE}
[junit4] 2> 1418658 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.ServerConnector Started
ServerConnector@4c9177{HTTP/1.1,[http/1.1]}{127.0.0.1:60246}
[junit4] 2> 1418658 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
Started @1424230ms
[junit4] 2> 1418658 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties:
{solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\tempDir-001/control/data,
hostContext=/, hostPort=60246,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores}
[junit4] 2> 1418661 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1418662 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 1418662 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.SolrXmlConfig
Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\solr.xml
[junit4] 2> 1418674 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1418675 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkContainer
Zookeeper client=127.0.0.1:60239/solr
[junit4] 2> 1418677 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1418681 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1418696 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1418698 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0)
[junit4] 2> 1418704 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:60246_
[junit4] 2> 1418705 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.Overseer Overseer (id=96649185664696324-127.0.0.1:60246_-n_0000000000)
starting
[junit4] 2> 1418715 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:60246_
[junit4] 2> 1418717 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1418717 INFO
(zkCallback-1718-thread-1-processing-n:127.0.0.1:60246_) [n:127.0.0.1:60246_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1)
[junit4] 2> 1418726 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores
[junit4] 2> 1418726 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60246_ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1418728 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard
shard=shard1
[junit4] 2> 1419733 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.c.Config loaded
config solrconfig.xml with version 0
[junit4] 2> 1419747 WARN
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.c.Config
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory>
instead.
[junit4] 2> 1419748 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 6.3.0
[junit4] 2> 1419757 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.c.SolrConfig
Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1419763 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.s.IndexSchema
[collection1] Schema name=test
[junit4] 2> 1419830 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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> 1419831 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.s.IndexSchema
[collection1] unique key field: id
[junit4] 2> 1419854 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection x:collection1] o.a.s.c.CoreContainer
Creating SolrCore 'collection1' using configuration from collection
control_collection
[junit4] 2> 1419854 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1\data\]
[junit4] 2> 1419854 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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@2311d6ad
[junit4] 2> 1419856 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore New index directory detected: old=null
new=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1\data\index/
[junit4] 2> 1419856 WARN
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore [collection1] Solr index directory
'C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1\data\index'
doesn't exist. Creating new index...
[junit4] 2> 1419856 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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=28, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=83.6923828125,
floorSegmentMB=0.685546875, forceMergeDeletesPctAllowed=26.134585952057705,
segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1419857 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1b4de09f
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1efa40fe),segFN=segments_1,generation=1}
[junit4] 2> 1419857 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1419857 WARN
(OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.DirectoryFactory
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\control-001\cores\collection1\data\
does not point to a valid data directory; skipping clean-up of old index
directories.
[junit4] 2> 1419858 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"nodistrib"
[junit4] 2> 1419858 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"dedupe"
[junit4] 2> 1419858 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1419858 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"stored_sig"
[junit4] 2> 1419858 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1419860 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-explicit"
[junit4] 2> 1419862 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1419862 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1419863 WARN
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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> 1419874 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.PluginBag [collection1] Initialized 25 plugins of type requestHandler:
[/update, /update/json, /update/csv, /update/json/docs, /config, /schema,
/replication, /get, /admin/ping, /admin/segments, /admin/luke, /admin/system,
/admin/mbeans, /admin/plugins, /admin/threads, /admin/properties,
/admin/logging, /admin/file, /export, /graph, /stream, /sql, /terms, standard,
/dump]
[junit4] 2> 1419874 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.RequestHandlers Registered paths:
/admin/mbeans,standard,/update/json/docs,/admin/luke,/export,/get,/admin/properties,/update/json,/admin/threads,/dump,/update/csv,/sql,/graph,/admin/segments,/admin/system,/replication,/config,/stream,/schema,/admin/plugins,/admin/logging,/admin/ping,/update,/admin/file,/terms
[junit4] 2> 1419875 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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> 1419875 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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> 1419876 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1419876 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1419876 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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=32, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=12.5205078125,
floorSegmentMB=0.33203125, forceMergeDeletesPctAllowed=16.747310080744324,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.285183366414781
[junit4] 2> 1419877 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1b4de09f
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1efa40fe),segFN=segments_1,generation=1}
[junit4] 2> 1419877 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1419877 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@5236af92[collection1] main]
[junit4] 2> 1419878 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the
RestManager with znodeBase: /configs/conf1
[junit4] 2> 1419879 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 1419879 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 1419879 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1419880 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage No data found for znode
/configs/conf1/_rest_managed.json
[junit4] 2> 1419880 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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> 1419880 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1419880 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1419880 INFO
(searcherExecutor-5401-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore
[collection1] Registered new searcher Searcher@5236af92[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1419881 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 1419881 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version
buckets from index
[junit4] 2> 1419881 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket
highest value from index
[junit4] 2> 1419881 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ 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 1546386972532015104
[junit4] 2> 1419882 INFO
(coreLoadExecutor-5400-thread-1-processing-n:127.0.0.1:60246_)
[n:127.0.0.1:60246_ c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version
1546386972532015104
[junit4] 2> 1419888 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard1
and weAreReplacement=false and leaderVoteWait=10000
[junit4] 2> 1419889 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1419889 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
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> 1419889 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy
Sync replicas to http://127.0.0.1:60246/collection1/
[junit4] 2> 1419889 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy
Sync Success - now sync replicas to me
[junit4] 2> 1419889 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy
http://127.0.0.1:60246/collection1/ has no replicas
[junit4] 2> 1419893 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
/collections/control_collection/leaders/shard1/leader after winning as
/collections/control_collection/leader_elect/shard1/election/96649185664696324-core_node1-n_0000000000
[junit4] 2> 1419894 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
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:60246/collection1/ shard1
[junit4] 2> 1420047 INFO
(coreZkRegister-5393-thread-1-processing-n:127.0.0.1:60246_ x:collection1
s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController
I am the leader, no recovery necessary
[junit4] 2> 1420229 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1420229 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1420231 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1420232 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ChaosMonkey
monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1420232 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 1420234 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1420705 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.SolrTestCaseJ4
Writing core.properties file to
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1
[junit4] 2> 1420708 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001
[junit4] 2> 1420708 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
jetty-9.3.8.v20160314
[junit4] 2> 1420709 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@34646c76{/,null,AVAILABLE}
[junit4] 2> 1420710 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.ServerConnector Started
ServerConnector@43d2dd39{HTTP/1.1,[http/1.1]}{127.0.0.1:60264}
[junit4] 2> 1420710 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
Started @1426283ms
[junit4] 2> 1420710 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties:
{solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\tempDir-001/jetty1,
solrconfig=solrconfig.xml, hostContext=/, hostPort=60264,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores}
[junit4] 2> 1420714 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1420715 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 1420715 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.SolrXmlConfig
Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\solr.xml
[junit4] 2> 1420738 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1420739 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkContainer
Zookeeper client=127.0.0.1:60239/solr
[junit4] 2> 1420740 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1420744 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1420750 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1420752 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1420756 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.ZkController Publish node=127.0.0.1:60264_ as DOWN
[junit4] 2> 1420758 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:60264_
[junit4] 2> 1420759 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.o.NodeMutator DownNode state invoked for node:
127.0.0.1:60264_
[junit4] 2> 1420760 INFO
(zkCallback-1718-thread-3-processing-n:127.0.0.1:60246_) [n:127.0.0.1:60246_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1420760 INFO (zkCallback-1722-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1420761 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1420778 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores
[junit4] 2> 1420779 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60264_ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1420781 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard
shard=shard1
[junit4] 2> 1420887 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [2])
[junit4] 2> 1421785 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.c.Config loaded config
solrconfig.xml with version 0
[junit4] 2> 1421795 WARN
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.c.Config Beginning
with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1421796 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 6.3.0
[junit4] 2> 1421823 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.c.SolrConfig Loaded
SolrConfig: solrconfig.xml
[junit4] 2> 1421828 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.s.IndexSchema
[collection1] Schema name=test
[junit4] 2> 1421899 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ 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> 1421900 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.s.IndexSchema
[collection1] unique key field: id
[junit4] 2> 1421927 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 x:collection1] o.a.s.c.CoreContainer
Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1421928 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1\data\]
[junit4] 2> 1421928 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 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@2311d6ad
[junit4] 2> 1421928 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore New index directory detected: old=null
new=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1\data\index/
[junit4] 2> 1421928 WARN
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrCore [collection1] Solr index directory
'C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1\data\index'
doesn't exist. Creating new index...
[junit4] 2> 1421929 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=28, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=83.6923828125,
floorSegmentMB=0.685546875, forceMergeDeletesPctAllowed=26.134585952057705,
segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1421929 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@4b0ebc1
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59f238f4),segFN=segments_1,generation=1}
[junit4] 2> 1421929 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1421930 WARN
(OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-1-001\cores\collection1\data\
does not point to a valid data directory; skipping clean-up of old index
directories.
[junit4] 2> 1421931 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"nodistrib"
[junit4] 2> 1421931 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"dedupe"
[junit4] 2> 1421931 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1421932 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"stored_sig"
[junit4] 2> 1421932 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1421932 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-explicit"
[junit4] 2> 1421932 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1421932 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1421932 WARN
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 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> 1421948 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.PluginBag [collection1] Initialized 25 plugins of type requestHandler:
[/update, /update/json, /update/csv, /update/json/docs, /config, /schema,
/replication, /get, /admin/ping, /admin/segments, /admin/luke, /admin/system,
/admin/mbeans, /admin/plugins, /admin/threads, /admin/properties,
/admin/logging, /admin/file, /export, /graph, /stream, /sql, /terms, standard,
/dump]
[junit4] 2> 1421948 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.RequestHandlers Registered paths:
/admin/mbeans,standard,/update/json/docs,/admin/luke,/export,/get,/admin/properties,/update/json,/admin/threads,/dump,/update/csv,/sql,/graph,/admin/segments,/admin/system,/replication,/config,/stream,/schema,/admin/plugins,/admin/logging,/admin/ping,/update,/admin/file,/terms
[junit4] 2> 1421950 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 1421950 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 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> 1421952 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1421952 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1421953 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=32, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=12.5205078125,
floorSegmentMB=0.33203125, forceMergeDeletesPctAllowed=16.747310080744324,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.285183366414781
[junit4] 2> 1421953 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@4b0ebc1
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59f238f4),segFN=segments_1,generation=1}
[junit4] 2> 1421953 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1421953 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@7f54284c[collection1] main]
[junit4] 2> 1421955 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the
RestManager with znodeBase: /configs/conf1
[junit4] 2> 1421955 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 1421955 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 1421955 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1421956 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.ManagedResourceStorage No data found for znode
/configs/conf1/_rest_managed.json
[junit4] 2> 1421956 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 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> 1421956 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1421956 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1421957 INFO
(searcherExecutor-5412-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new
searcher Searcher@7f54284c[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1421957 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 1421957 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version
buckets from index
[junit4] 2> 1421957 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket
highest value from index
[junit4] 2> 1421957 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 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 1546386974708858880
[junit4] 2> 1421959 INFO
(coreLoadExecutor-5411-thread-1-processing-n:127.0.0.1:60264_)
[n:127.0.0.1:60264_ c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version
1546386974708858880
[junit4] 2> 1421966 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the
leader process for shard=shard1 and weAreReplacement=false and
leaderVoteWait=10000
[junit4] 2> 1421968 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas
found to continue.
[junit4] 2> 1421968 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new
leader - try and sync
[junit4] 2> 1421968 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to
http://127.0.0.1:60264/collection1/
[junit4] 2> 1421968 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync
replicas to me
[junit4] 2> 1421968 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.SyncStrategy
http://127.0.0.1:60264/collection1/ has no replicas
[junit4] 2> 1421972 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating
leader registration node /collections/collection1/leaders/shard1/leader after
winning as
/collections/collection1/leader_elect/shard1/election/96649185664696329-core_node1-n_0000000000
[junit4] 2> 1421975 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new
leader: http://127.0.0.1:60264/collection1/ shard1
[junit4] 2> 1422079 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [2])
[junit4] 2> 1422128 INFO
(coreZkRegister-5406-thread-1-processing-n:127.0.0.1:60264_ x:collection1
s:shard1 c:collection1 r:core_node1) [n:127.0.0.1:60264_ c:collection1 s:shard1
r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery
necessary
[junit4] 2> 1422233 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [2])
[junit4] 2> 1422745 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.SolrTestCaseJ4
Writing core.properties file to
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1
[junit4] 2> 1422748 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001
[junit4] 2> 1422749 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
jetty-9.3.8.v20160314
[junit4] 2> 1422750 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1a47573d{/,null,AVAILABLE}
[junit4] 2> 1422751 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.ServerConnector Started
ServerConnector@b47397a{HTTP/1.1,[http/1.1]}{127.0.0.1:60276}
[junit4] 2> 1422751 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.e.j.s.Server
Started @1428324ms
[junit4] 2> 1422751 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties:
{solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\tempDir-001/jetty2,
solrconfig=solrconfig.xml, hostContext=/, hostPort=60276,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores}
[junit4] 2> 1422755 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1422756 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 1422756 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.SolrXmlConfig
Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\solr.xml
[junit4] 2> 1422770 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1422771 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkContainer
Zookeeper client=127.0.0.1:60239/solr
[junit4] 2> 1422783 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1422787 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1422794 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1422795 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1422800 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.ZkController Publish node=127.0.0.1:60276_ as DOWN
[junit4] 2> 1422801 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:60276_
[junit4] 2> 1422802 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.o.NodeMutator DownNode state invoked for node:
127.0.0.1:60276_
[junit4] 2> 1422802 INFO (zkCallback-1722-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1422802 INFO
(zkCallback-1734-thread-1-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1422802 INFO
(zkCallback-1718-thread-1-processing-n:127.0.0.1:60246_) [n:127.0.0.1:60246_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1422802 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1422817 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores
[junit4] 2> 1422817 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [n:127.0.0.1:60276_ ]
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1422820 INFO
(OverseerStateUpdate-96649185664696324-127.0.0.1:60246_-n_0000000000)
[n:127.0.0.1:60246_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard
shard=shard1
[junit4] 2> 1422923 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [3])
[junit4] 2> 1422923 INFO
(zkCallback-1734-thread-1-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [3])
[junit4] 2> 1423824 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.c.Config loaded config
solrconfig.xml with version 0
[junit4] 2> 1423833 WARN
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.c.Config Beginning
with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1423834 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 6.3.0
[junit4] 2> 1423851 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.c.SolrConfig Loaded
SolrConfig: solrconfig.xml
[junit4] 2> 1423856 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.s.IndexSchema
[collection1] Schema name=test
[junit4] 2> 1423937 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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> 1423938 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.s.IndexSchema
[collection1] unique key field: id
[junit4] 2> 1423965 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 x:collection1] o.a.s.c.CoreContainer
Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1423966 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1\data\]
[junit4] 2> 1423966 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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@2311d6ad
[junit4] 2> 1423967 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrCore New index directory detected: old=null
new=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1\data\index/
[junit4] 2> 1423967 WARN
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrCore [collection1] Solr index directory
'C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1\data\index'
doesn't exist. Creating new index...
[junit4] 2> 1423968 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=28, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=83.6923828125,
floorSegmentMB=0.685546875, forceMergeDeletesPctAllowed=26.134585952057705,
segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1423968 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@426b4a30
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49171931),segFN=segments_1,generation=1}
[junit4] 2> 1423968 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1423969 WARN
(OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.DirectoryFactory
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1\data\
does not point to a valid data directory; skipping clean-up of old index
directories.
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"nodistrib"
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"dedupe"
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"stored_sig"
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1423971 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-explicit"
[junit4] 2> 1423972 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1423972 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.UpdateRequestProcessorChain inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 1423972 WARN
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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> 1423986 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.PluginBag [collection1] Initialized 25 plugins of type requestHandler:
[/update, /update/json, /update/csv, /update/json/docs, /config, /schema,
/replication, /get, /admin/ping, /admin/segments, /admin/luke, /admin/system,
/admin/mbeans, /admin/plugins, /admin/threads, /admin/properties,
/admin/logging, /admin/file, /export, /graph, /stream, /sql, /terms, standard,
/dump]
[junit4] 2> 1423986 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.RequestHandlers Registered paths:
/admin/mbeans,standard,/update/json/docs,/admin/luke,/export,/get,/admin/properties,/update/json,/admin/threads,/dump,/update/csv,/sql,/graph,/admin/segments,/admin/system,/replication,/config,/stream,/schema,/admin/plugins,/admin/logging,/admin/ping,/update,/admin/file,/terms
[junit4] 2> 1423988 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 1423988 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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> 1423989 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1423989 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1423998 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=32, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=12.5205078125,
floorSegmentMB=0.33203125, forceMergeDeletesPctAllowed=16.747310080744324,
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.285183366414781
[junit4] 2> 1423998 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@426b4a30
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49171931),segFN=segments_1,generation=1}
[junit4] 2> 1423998 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1423998 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@2136e78d[collection1] main]
[junit4] 2> 1423999 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the
RestManager with znodeBase: /configs/conf1
[junit4] 2> 1424000 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 1424000 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 1424000 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1424000 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.ManagedResourceStorage No data found for znode
/configs/conf1/_rest_managed.json
[junit4] 2> 1424000 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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> 1424001 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1424001 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1424002 INFO
(searcherExecutor-5423-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.SolrCore [collection1] Registered new
searcher Searcher@2136e78d[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1424002 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 1424002 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version
buckets from index
[junit4] 2> 1424002 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket
highest value from index
[junit4] 2> 1424002 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ 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 1546386976853196800
[junit4] 2> 1424004 INFO
(coreLoadExecutor-5422-thread-1-processing-n:127.0.0.1:60276_)
[n:127.0.0.1:60276_ c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version
1546386976853196800
[junit4] 2> 1424010 INFO
(coreZkRegister-5417-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.ZkController Core needs to
recover:collection1
[junit4] 2> 1424010 INFO
(updateExecutor-1731-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 1424010 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process.
recoveringAfterStartup=true
[junit4] 2> 1424012 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 1424012 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates.
core=[collection1]
[junit4] 2> 1424012 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates.
FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1424012 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core
[collection1] as recovering, leader is [http://127.0.0.1:60264/collection1/]
and I am [http://127.0.0.1:60276/collection1/]
[junit4] 2> 1424014 INFO
(recoveryExecutor-1732-thread-1-processing-n:127.0.0.1:60276_ x:collection1
s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:60276_ c:collection1 s:shard1
r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery
command to [http://127.0.0.1:60264]; [WaitForState:
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:60276_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 1424019 INFO (qtp1765065468-10377) [n:127.0.0.1:60264_ ]
o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state:
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1424020 INFO (qtp1765065468-10377) [n:127.0.0.1:60264_ ]
o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1
(shard1 of collection1) have state: recovering
[junit4] 2> 1424020 INFO (qtp1765065468-10377) [n:127.0.0.1:60264_ ]
o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1,
shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader?
true, live=true, checkLive=true, currentState=down, localState=active,
nodeName=127.0.0.1:60276_, coreNodeName=core_node2,
onlyIfActiveCheckResult=false, nodeProps:
core_node2:{"core":"collection1","base_url":"http://127.0.0.1:60276","node_name":"127.0.0.1:60276_","state":"down"}
[junit4] 2> 1424120 INFO
(zkCallback-1734-thread-1-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [3])
[junit4] 2> 1424120 INFO
(zkCallback-1728-thread-1-processing-n:127.0.0.1:60264_) [n:127.0.0.1:60264_
] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/collection1/state.json] for collection [collection1] has
occurred - updating... (live nodes size: [3])
[junit4] 2> 1424323 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.SolrTestCaseJ4
###Starting test
[junit4] 2> 1424334 INFO (qtp1117641394-10340) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[2-0 (1546386977197129728)]} 0 3
[junit4] 2> 1424334 INFO (qtp1117641394-10341) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[1-0 (1546386977197129729)]} 0 3
[junit4] 2> 1424348 INFO (qtp1411436059-10407) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[1-0
(1546386977205518337)]} 0 1
[junit4] 2> 1424348 INFO (qtp1411436059-10408) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[2-0
(1546386977205518336)]} 0 1
[junit4] 2> 1424348 INFO (qtp1765065468-10380) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[1-0 (1546386977205518337)]} 0 10
[junit4] 2> 1424348 INFO (qtp1765065468-10378) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[2-0 (1546386977205518336)]} 0 11
[junit4] 2> 1424351 INFO (qtp1117641394-10342) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[2-1 (1546386977218101248)]} 0 0
[junit4] 2> 1424351 INFO (qtp1117641394-10343) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[1-1 (1546386977218101249)]} 0 0
[junit4] 2> 1424353 INFO (qtp1411436059-10409) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[2-1
(1546386977220198400)]} 0 0
[junit4] 2> 1424353 INFO (qtp1765065468-10382) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[2-1 (1546386977220198400)]} 0 1
[junit4] 2> 1424355 INFO (qtp1411436059-10410) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[1-1
(1546386977221246976)]} 0 0
[junit4] 2> 1424355 INFO (qtp1117641394-10344) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[2-1 (-1546386977223344128)]}
0 0
[junit4] 2> 1424355 INFO (qtp1765065468-10381) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[1-1 (1546386977221246976)]} 0 2
[junit4] 2> 1424356 INFO (qtp1117641394-10339) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{delete=[1-1 (-1546386977224392704)]}
0 0
[junit4] 2> 1424359 INFO (qtp1411436059-10411) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{delete=[2-1
(-1546386977225441280)]} 0 0
[junit4] 2> 1424361 INFO (qtp1765065468-10375) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[2-1 (-1546386977225441280)]} 0 3
[junit4] 2> 1424362 INFO (qtp1411436059-10404) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{delete=[1-1
(-1546386977227538432)]} 0 0
[junit4] 2> 1424364 INFO (qtp1765065468-10379) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{delete=[1-1 (-1546386977227538432)]} 0 3
[junit4] 2> 1424364 INFO (qtp1117641394-10337) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[2-2 (1546386977230684160)]} 0 0
[junit4] 2> 1424367 INFO (qtp1117641394-10341) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[1-2 (1546386977235927040)]} 0 0
[junit4] 2> 1424369 INFO (qtp1411436059-10406) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[2-2
(1546386977234878464)]} 0 0
[junit4] 2> 1424371 INFO (qtp1765065468-10380) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[2-2 (1546386977234878464)]} 0 4
[junit4] 2> 1424374 INFO (qtp1117641394-10340) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[2-3 (1546386977241169920)]} 0 1
[junit4] 2> 1424375 INFO (qtp1411436059-10407) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[1-2
(1546386977240121344)]} 0 0
[junit4] 2> 1424375 INFO (qtp1765065468-10378) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[1-2 (1546386977240121344)]} 0 4
[junit4] 2> 1424377 INFO (qtp1117641394-10342) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[1-3 (1546386977246412800)]} 0 0
[junit4] 2> 1424379 INFO (qtp1411436059-10408) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[2-3
(1546386977246412800)]} 0 0
[junit4] 2> 1424379 INFO (qtp1765065468-10380) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[2-3 (1546386977246412800)]} 0 2
[junit4] 2> 1424380 INFO (qtp1411436059-10409) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[1-3
(1546386977248509952)]} 0 0
[junit4] 2> 1424380 INFO (qtp1117641394-10343) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[2-4 (1546386977249558528)]} 0 0
[junit4] 2> 1424380 INFO (qtp1765065468-10381) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2}{add=[1-3 (1546386977248509952)]} 0 1
[junit4] 2> 1424382 INFO (qtp1117641394-10344) [n:127.0.0.1:60246_
c:control_collection s:shard1 r:core_node1 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={wt=javabin&version=2&CONTROL=TRUE}{add=[1-4 (1546386977251655680)]} 0 0
[junit4] 2> 1424384 INFO (qtp1411436059-10410) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:60264/collection1/&wt=javabin&version=2}{add=[2-4
(1546386977251655680)]} 0 0
[junit4] 2> 1424386 INFO (qtp1765065468-10375) [n:127.0.0.1:60264_
c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.Lo
[...truncated too long message...]
core_node2 x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory,
CoreContainer#isShutdown=true
[junit4] 2> 1456009 INFO
(zkCallback-1741-thread-2-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1]
o.a.s.c.CachingDirectoryFactory Closing directory:
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\..\..\..\..\..\..\..\..\..\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.RecoveryZkTest_68A817BFFB88BCDF-001\shard-2-001\cores\collection1\data\
[junit4] 2> 1456009 INFO
(zkCallback-1741-thread-2-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ElectionContext
Canceling election
/collections/collection1/leader_elect/shard1/election/96649185664696335-core_node2-n_0000000002
[junit4] 2> 1456511 WARN
(zkCallback-1741-thread-3-processing-n:127.0.0.1:60276_) [n:127.0.0.1:60276_
] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to
ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1456513 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.ServerConnector Stopped
ServerConnector@68f3c14c{HTTP/1.1,[http/1.1]}{127.0.0.1:60276}
[junit4] 2> 1456513 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@e391b8a{/,null,UNAVAILABLE}
[junit4] 2> 1456515 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x1575dec1b600005, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1456516 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ChaosMonkey
monkey: stop shard! 60246
[junit4] 2> 1456516 INFO
(TEST-RecoveryZkTest.test-seed#[68A817BFFB88BCDF]) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:60239 60239
[junit4] 2> 1456518 INFO (Thread-2366) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:60239 60239
[junit4] 2> 1456519 WARN (Thread-2366) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 4 /solr/security.json
[junit4] 2> 4 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 3 /solr/collections/collection1/state.json
[junit4] 2> 2
/solr/collections/collection1/leader_elect/shard1/election/96649185664696329-core_node1-n_0000000000
[junit4] 2> 2
/solr/overseer_elect/election/96649185664696329-127.0.0.1:60264_-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 117 /solr/overseer/queue
[junit4] 2> 36 /solr/overseer/collection-queue-work
[junit4] 2> 14 /solr/overseer/queue-work
[junit4] 2> 5 /solr/collections
[junit4] 2> 4 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest
-Dtests.method=test -Dtests.seed=68A817BFFB88BCDF -Dtests.slow=true
-Dtests.locale=sl-SI -Dtests.timezone=Antarctica/Vostok -Dtests.asserts=true
-Dtests.file.encoding=US-ASCII
[junit4] ERROR 38.5s J1 | RecoveryZkTest.test <<<
[junit4] > Throwable #1:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught
exception in thread: Thread[id=10444, name=updateExecutor-1725-thread-2,
state=RUNNABLE, group=TGRP-RecoveryZkTest]
[junit4] > at
__randomizedtesting.SeedInfo.seed([68A817BFFB88BCDF:E0FC28655574D127]:0)
[junit4] > Caused by: org.apache.solr.common.SolrException: Replica:
http://127.0.0.1:60276/collection1/ should have been marked under leader
initiated recovery in ZkController but wasn't.
[junit4] > at
__randomizedtesting.SeedInfo.seed([68A817BFFB88BCDF]:0)
[junit4] > at
org.apache.solr.cloud.LeaderInitiatedRecoveryThread.run(LeaderInitiatedRecoveryThread.java:88)
[junit4] > at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] > at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] > at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1456522 INFO
(SUITE-RecoveryZkTest-seed#[68A817BFFB88BCDF]-worker) [ ]
o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Sep 24, 2016 8:39:35 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62):
{rnd_b=PostingsFormat(name=LuceneFixedGap), _version_=FST50, a_t=FST50,
a_i=PostingsFormat(name=LuceneFixedGap),
id=PostingsFormat(name=LuceneFixedGap)}, docValues:{},
maxPointsInLeafNode=1129, maxMBSortInHeap=5.15123670544535,
sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=sl-SI,
timezone=Antarctica/Vostok
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 1.8.0_102
(64-bit)/cpus=3,threads=1,free=103784776,total=241717248
[junit4] 2> NOTE: All tests run in this JVM: [ResponseHeaderTest,
TestReload, BinaryUpdateRequestHandlerTest,
DistribDocExpirationUpdateProcessorTest, DeleteLastCustomShardedReplicaTest,
WordBreakSolrSpellCheckerTest, TestFieldCollectionResource,
TestSimpleTrackingShardHandler, PreAnalyzedFieldTest,
TestComplexPhraseQParserPlugin, UUIDUpdateProcessorFallbackTest,
SimpleMLTQParserTest, TestSchemaNameResource, SSLMigrationTest,
TestStressCloudBlindAtomicUpdates, TestSubQueryTransformer,
TestIntervalFaceting, TestDistributedGrouping,
CoreMergeIndexesAdminHandlerTest, TestQueryTypes, TestDistributedMissingSort,
TestMacros, AutoCommitTest, TestReversedWildcardFilterFactory,
TestHdfsCloudBackupRestore, SpellCheckComponentTest, TestQuerySenderListener,
TestUtils, TestCopyFieldCollectionResource,
TestLMJelinekMercerSimilarityFactory, StatsReloadRaceTest,
TestRandomRequestDistribution, TestLeaderInitiatedRecoveryThread,
URLClassifyProcessorTest, AddBlockUpdateTest, TestTrieFacet,
TestSolrDeletionPolicy2, TestPivotHelperCode, BasicFunctionalityTest,
CloudExitableDirectoryReaderTest, CSVRequestHandlerTest,
DefaultValueUpdateProcessorTest, SolrXmlInZkTest,
TestRandomCollapseQParserPlugin, CurrencyFieldOpenExchangeTest,
QueryParsingTest, ScriptEngineTest, TestDFISimilarityFactory,
TestDistributedStatsComponentCardinality, FieldAnalysisRequestHandlerTest,
DebugComponentTest, TestExactStatsCache, SolrIndexSplitterTest,
FileBasedSpellCheckerTest, ReturnFieldsTest, TestScoreJoinQPNoScore,
ParsingFieldUpdateProcessorsTest, CollectionStateFormat2Test,
TestLuceneMatchVersion, TestDocSet, TestRawTransformer,
TestSchemaSimilarityResource, SpellCheckCollatorTest, RAMDirectoryFactoryTest,
TestDocTermOrds, HLLUtilTest, AddSchemaFieldsUpdateProcessorFactoryTest,
SpatialRPTFieldTypeTest, TestBadConfig, CdcrRequestHandlerTest,
TestRandomFaceting, TestManagedResourceStorage, TestIndexSearcher,
JavabinLoaderTest, CoreAdminCreateDiscoverTest, TestFileDictionaryLookup,
CoreAdminHandlerTest, ZkSolrClientTest, TestIndexingPerformance,
TestFuzzyAnalyzedSuggestions, BlockJoinFacetDistribTest, CopyFieldTest,
DateMathParserTest, TestManagedStopFilterFactory, BlobRepositoryCloudTest,
TestLockTree, TestPHPSerializedResponseWriter, DeleteReplicaTest,
TestReloadAndDeleteDocs, TestDownShardTolerantSearch, TestConfigSets,
TestJmxMonitoredMap, TestConfigReload, HdfsNNFailoverTest,
FieldMutatingUpdateProcessorTest, TestImplicitCoreProperties,
TestOnReconnectListenerSupport, TestLegacyFieldCache, BadCopyFieldTest,
BitVectorTest, HdfsDirectoryFactoryTest, ChaosMonkeySafeLeaderTest,
TestFieldCacheReopen, ShowFileRequestHandlerTest,
SignatureUpdateProcessorFactoryTest, SuggestComponentContextFilterQueryTest,
TestRuleBasedAuthorizationPlugin, SuggesterWFSTTest,
TestBackupRepositoryFactory, LeaderInitiatedRecoveryOnCommitTest,
TestNumericTerms64, ClusterStateTest, SortSpecParsingTest,
TestGraphTermsQParserPlugin, TestFiltering, TestSchemaManager,
BigEndianAscendingWordDeserializerTest, TestLMDirichletSimilarityFactory,
TestRestoreCore, TestConfigSetsAPIExclusivity,
TestTolerantUpdateProcessorCloud, SolrIndexConfigTest, TestMissingGroups,
ConnectionReuseTest, SearchHandlerTest, TestSolr4Spatial2,
FullSolrCloudDistribCmdsTest, DocExpirationUpdateProcessorFactoryTest,
CachingDirectoryFactoryTest, TestInitQParser,
TestHighFrequencyDictionaryFactory, TestJoin, TestReloadDeadlock,
IndexSchemaTest, TestDynamicFieldCollectionResource, TestSimpleQParserPlugin,
TestRangeQuery, BlockJoinFacetSimpleTest, TestCoreDiscovery,
CollectionsAPIAsyncDistributedZkTest, TestManagedSchema, CheckHdfsIndexTest,
DirectUpdateHandlerOptimizeTest, BaseCdcrDistributedZkTest,
TestSolrCLIRunExample, HdfsBasicDistributedZkTest,
TestDocBasedVersionConstraints, ConvertedLegacyTest, OverseerRolesTest,
TestXmlQParserPlugin, RegexBoostProcessorTest, TestCloudManagedSchema,
TestSerializedLuceneMatchVersion, BasicDistributedZk2Test,
CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest,
LeaderElectionIntegrationTest, ShardRoutingTest, BasicZkTest, RecoveryZkTest]
[junit4] Completed [280/635 (1!)] on J1 in 39.11s, 1 test, 1 error <<<
FAILURES!
[...truncated 61488 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
