You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/01/13 21:42:09 UTC
[JENKINS-EA] Lucene-Solr-6.x-Linux (64bit/jdk-9-ea+147) - Build #
2661 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2661/
Java: 64bit/jdk-9-ea+147 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.PeerSyncReplicationTest.test
Error Message:
expected:<152> but was:<140>
Stack Trace:
java.lang.AssertionError: expected:<152> but was:<140>
at __randomizedtesting.SeedInfo.seed([5428A2DE548F879D:DC7C9D04FA73EA65]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.PeerSyncReplicationTest.bringUpDeadNodeAndEnsureNoReplication(PeerSyncReplicationTest.java:286)
at org.apache.solr.cloud.PeerSyncReplicationTest.forceNodeFailureAndDoPeerSync(PeerSyncReplicationTest.java:259)
at org.apache.solr.cloud.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:138)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:538)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12639 lines...]
[junit4] Suite: org.apache.solr.cloud.PeerSyncReplicationTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/init-core-data-001
[junit4] 2> 1702874 INFO (SUITE-PeerSyncReplicationTest-seed#[5428A2DE548F879D]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1702875 INFO (SUITE-PeerSyncReplicationTest-seed#[5428A2DE548F879D]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 1702876 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1702877 INFO (Thread-2672) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1702877 INFO (Thread-2672) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1702977 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkTestServer start zk server on port:37512
[junit4] 2> 1702982 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1702984 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1702986 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1702988 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1702991 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1702993 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1702995 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1702997 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1702999 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1703002 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1703004 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1703651 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/cores/collection1
[junit4] 2> 1703654 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1703655 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5fc29520{/,null,AVAILABLE}
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3fa95d19{SSL,[ssl, http/1.1]}{127.0.0.1:37250}
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server Started @1706042ms
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/tempDir-001/control/data, hostPort=37250, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/cores}
[junit4] 2> 1703657 ERROR (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1703657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T21:24:52.271695Z
[junit4] 2> 1703659 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1703659 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/solr.xml
[junit4] 2> 1703665 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1703666 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37512/solr
[junit4] 2> 1703676 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37250_
[junit4] 2> 1703676 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.Overseer Overseer (id=97277882629619717-127.0.0.1:37250_-n_0000000000) starting
[junit4] 2> 1703679 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37250_
[junit4] 2> 1703680 INFO (OverseerStateUpdate-97277882629619717-127.0.0.1:37250_-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1703710 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/cores
[junit4] 2> 1703710 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1703712 INFO (OverseerStateUpdate-97277882629619717-127.0.0.1:37250_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1704720 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 1704731 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1704806 WARN (coreLoadExecutor-5334-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 1704808 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 1704812 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1704813 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/control-001/cores/collection1/data/]
[junit4] 2> 1704813 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ab669bd
[junit4] 2> 1704816 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=32, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.15916767601744575]
[junit4] 2> 1704855 WARN (coreLoadExecutor-5334-thread-1) [ ] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1704863 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1704863 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1704869 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1704870 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1704870 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1704871 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f2bea9[collection1] main]
[junit4] 2> 1704872 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1704872 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1704872 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1704873 INFO (searcherExecutor-5335-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5f2bea9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1704874 INFO (coreLoadExecutor-5334-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556446124166873088
[junit4] 2> 1704905 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1704905 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1704905 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37250/collection1/
[junit4] 2> 1704905 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1704905 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:37250/collection1/ has no replicas
[junit4] 2> 1704907 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37250/collection1/ shard1
[junit4] 2> 1705058 INFO (coreZkRegister-5327-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1705161 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1705162 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37512/solr ready
[junit4] 2> 1705162 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1705162 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 1705657 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/cores/collection1
[junit4] 2> 1705658 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001
[junit4] 2> 1705660 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1705661 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7d7328a7{/,null,AVAILABLE}
[junit4] 2> 1705661 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5db3ecb8{SSL,[ssl, http/1.1]}{127.0.0.1:34358}
[junit4] 2> 1705661 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server Started @1708047ms
[junit4] 2> 1705661 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/tempDir-001/jetty1, hostPort=34358, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/cores}
[junit4] 2> 1705662 ERROR (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1705662 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1705662 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1705662 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1705662 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T21:24:54.276418Z
[junit4] 2> 1705664 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1705664 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/solr.xml
[junit4] 2> 1705669 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1705671 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37512/solr
[junit4] 2> 1705675 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1705676 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34358_
[junit4] 2> 1705677 INFO (zkCallback-1874-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1705678 INFO (zkCallback-1864-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1705678 INFO (zkCallback-1868-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1705693 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/cores
[junit4] 2> 1705693 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1705694 INFO (OverseerStateUpdate-97277882629619717-127.0.0.1:37250_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1705795 INFO (zkCallback-1874-thread-1) [ ] 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> 1706702 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 1706712 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1706787 WARN (coreLoadExecutor-5345-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 1706789 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 1706793 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1706794 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-1-001/cores/collection1/data/]
[junit4] 2> 1706794 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ab669bd
[junit4] 2> 1706797 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=32, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.15916767601744575]
[junit4] 2> 1706849 WARN (coreLoadExecutor-5345-thread-1) [ ] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1706859 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1706859 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1706865 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1706865 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1706866 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1706867 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@354f9bac[collection1] main]
[junit4] 2> 1706868 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1706868 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1706868 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1706869 INFO (searcherExecutor-5346-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@354f9bac[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1706870 INFO (coreLoadExecutor-5345-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556446126259830784
[junit4] 2> 1706874 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1706875 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1706875 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34358/collection1/
[junit4] 2> 1706875 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1706875 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34358/collection1/ has no replicas
[junit4] 2> 1706876 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34358/collection1/ shard1
[junit4] 2> 1706978 INFO (zkCallback-1874-thread-1) [ ] 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> 1707002 INFO (coreZkRegister-5340-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1707104 INFO (zkCallback-1874-thread-1) [ ] 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> 1707612 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/cores/collection1
[junit4] 2> 1707612 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001
[junit4] 2> 1707615 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1707616 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@323c6bfd{/,null,AVAILABLE}
[junit4] 2> 1707616 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6e74d2b9{SSL,[ssl, http/1.1]}{127.0.0.1:44087}
[junit4] 2> 1707616 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server Started @1710002ms
[junit4] 2> 1707616 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/tempDir-001/jetty2, hostPort=44087, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/cores}
[junit4] 2> 1707617 ERROR (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1707617 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1707617 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1707617 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1707617 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T21:24:56.231313Z
[junit4] 2> 1707619 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1707619 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/solr.xml
[junit4] 2> 1707624 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1707625 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37512/solr
[junit4] 2> 1707630 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1707632 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44087_
[junit4] 2> 1707632 INFO (zkCallback-1880-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1707632 INFO (zkCallback-1864-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1707632 INFO (zkCallback-1874-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1707632 INFO (zkCallback-1868-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1707681 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/cores
[junit4] 2> 1707681 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1707683 INFO (OverseerStateUpdate-97277882629619717-127.0.0.1:37250_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1707785 INFO (zkCallback-1874-thread-1) [ ] 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> 1707785 INFO (zkCallback-1880-thread-1) [ ] 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> 1708691 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 1708702 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1708785 WARN (coreLoadExecutor-5356-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 1708787 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 1708792 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1708793 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-2-001/cores/collection1/data/]
[junit4] 2> 1708793 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ab669bd
[junit4] 2> 1708795 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=32, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.15916767601744575]
[junit4] 2> 1708835 WARN (coreLoadExecutor-5356-thread-1) [ ] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1708844 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1708844 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1708851 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1708851 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1708852 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1708853 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@653f9b3c[collection1] main]
[junit4] 2> 1708853 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1708854 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1708854 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1708855 INFO (searcherExecutor-5357-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@653f9b3c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1708856 INFO (coreLoadExecutor-5356-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556446128342302720
[junit4] 2> 1708860 INFO (coreZkRegister-5351-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 1708860 INFO (updateExecutor-1877-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 1708860 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 1708860 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 1708860 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 1708860 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1708860 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [https://127.0.0.1:34358/collection1/] and I am [https://127.0.0.1:44087/collection1/]
[junit4] 2> 1708862 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:34358]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:44087_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 1708933 INFO (qtp80619096-11141) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1708934 INFO (qtp80619096-11141) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 1708934 INFO (qtp80619096-11141) [ ] 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:44087_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"https://127.0.0.1:44087","node_name":"127.0.0.1:44087_","state":"down"}
[junit4] 2> 1708962 INFO (zkCallback-1874-thread-1) [ ] 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> 1708962 INFO (zkCallback-1880-thread-1) [ ] 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> 1709603 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/cores/collection1
[junit4] 2> 1709603 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001
[junit4] 2> 1709606 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1709607 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5455b886{/,null,AVAILABLE}
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6d2bce0d{SSL,[ssl, http/1.1]}{127.0.0.1:36350}
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.Server Started @1711993ms
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/tempDir-001/jetty3, hostPort=36350, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/cores}
[junit4] 2> 1709608 ERROR (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1709608 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T21:24:58.222881Z
[junit4] 2> 1709611 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1709611 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/solr.xml
[junit4] 2> 1709616 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1709618 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37512/solr
[junit4] 2> 1709623 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1709624 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36350_
[junit4] 2> 1709625 INFO (zkCallback-1868-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1709625 INFO (zkCallback-1874-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1709625 INFO (zkCallback-1864-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1709625 INFO (zkCallback-1880-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1709625 INFO (zkCallback-1887-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1709658 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/cores
[junit4] 2> 1709658 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1709660 INFO (OverseerStateUpdate-97277882629619717-127.0.0.1:37250_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1709761 INFO (zkCallback-1880-thread-1) [ ] 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: [4])
[junit4] 2> 1709761 INFO (zkCallback-1887-thread-1) [ ] 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: [4])
[junit4] 2> 1709761 INFO (zkCallback-1874-thread-1) [ ] 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: [4])
[junit4] 2> 1709934 INFO (qtp80619096-11141) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:44087_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"https://127.0.0.1:44087","node_name":"127.0.0.1:44087_","state":"recovering"}
[junit4] 2> 1709934 INFO (qtp80619096-11141) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1709934 INFO (qtp80619096-11141) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:44087_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1001
[junit4] 2> 1710435 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [https://127.0.0.1:34358/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 1710435 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=https://127.0.0.1:44087 START replicas=[https://127.0.0.1:34358/collection1/] nUpdates=1000
[junit4] 2> 1710439 INFO (qtp80619096-11148) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1710439 INFO (qtp80619096-11148) [ ] o.a.s.c.S.Request [collection1] webapp= path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1710439 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1710439 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 1710439 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1710439 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1710440 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1710440 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 1710440 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 1710440 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 1710440 INFO (recoveryExecutor-1878-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 1710542 INFO (zkCallback-1880-thread-1) [ ] 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: [4])
[junit4] 2> 1710542 INFO (zkCallback-1874-thread-1) [ ] 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: [4])
[junit4] 2> 1710542 INFO (zkCallback-1887-thread-1) [ ] 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: [4])
[junit4] 2> 1710669 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 1710681 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1710762 WARN (coreLoadExecutor-5367-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 1710764 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 1710770 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1710770 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001/shard-3-001/cores/collection1/data/]
[junit4] 2> 1710770 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ab669bd
[junit4] 2> 1710773 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=32, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.15916767601744575]
[junit4] 2> 1710812 WARN (coreLoadExecutor-5367-thread-1) [ ] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1710821 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1710821 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1710825 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1710825 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1710826 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1710827 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5932c9bf[collection1] main]
[junit4] 2> 1710828 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1710828 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1710828 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1710829 INFO (searcherExecutor-5368-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5932c9bf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1710830 INFO (coreLoadExecutor-5367-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556446130412191744
[junit4] 2> 1710833 INFO (coreZkRegister-5362-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 1710833 INFO (updateExecutor-1884-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 1710834 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 1710834 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 1710834 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 1710834 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1710834 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [https://127.0.0.1:34358/collection1/] and I am [https://127.0.0.1:36350/collection1/]
[junit4] 2> 1710836 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:34358]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:36350_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 1710839 INFO (qtp80619096-11148) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1710840 INFO (qtp80619096-11148) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 1710840 INFO (qtp80619096-11148) [ ] 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:36350_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"https://127.0.0.1:36350","node_name":"127.0.0.1:36350_","state":"down"}
[junit4] 2> 1710936 INFO (zkCallback-1874-thread-1) [ ] 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: [4])
[junit4] 2> 1710936 INFO (zkCallback-1887-thread-1) [ ] 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: [4])
[junit4] 2> 1710936 INFO (zkCallback-1880-thread-1) [ ] 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: [4])
[junit4] 2> 1711072 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 1711072 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 30 for each attempt
[junit4] 2> 1711072 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30
[junit4] 2> 1711840 INFO (qtp80619096-11148) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:36350_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"https://127.0.0.1:36350","node_name":"127.0.0.1:36350_","state":"recovering"}
[junit4] 2> 1711840 INFO (qtp80619096-11148) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1711840 INFO (qtp80619096-11148) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:36350_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
[junit4] 2> 1712341 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [https://127.0.0.1:34358/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 1712341 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=https://127.0.0.1:36350 START replicas=[https://127.0.0.1:34358/collection1/] nUpdates=1000
[junit4] 2> 1712344 INFO (qtp80619096-11146) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1712344 INFO (qtp80619096-11146) [ ] o.a.s.c.S.Request [collection1] webapp= path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 1712345 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 1712346 INFO (recoveryExecutor-1885-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 1712447 INFO (zkCallback-1874-thread-1) [ ] 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: [4])
[junit4] 2> 1712447 INFO (zkCallback-1880-thread-1) [ ] 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: [4])
[junit4] 2> 1712447 INFO (zkCallback-1887-thread-1) [ ] 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: [4])
[junit4] 2> 1713074 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 1713137 INFO (qtp763621270-11110) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1713137 INFO (qtp763621270-11110) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1713138 INFO (qtp763621270-11110) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1713138 INFO (qtp763621270-11110) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 0
[junit4] 2> 1713170 INFO (qtp80619096-11147) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1713170 INFO (qtp80619096-11147) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1713170 INFO (qtp80619096-11147) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1713171 INFO (qtp80619096-11147) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:34358/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 1713208 INFO (qtp1077238789-11170) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1713208 INFO (qtp1077238789-11170) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1713208 INFO (qtp1077238789-11170) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1713208 INFO (qtp1077238789-11170) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:34358/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 1713231 INFO (qtp1856479103-11204) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1713231 INFO (qtp1856479103-11204) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1713232 INFO (qtp1856479103-11204) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1713233 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:34358/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1713233 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 88
[junit4] 2> 1713242 INFO (qtp80619096-11141) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 1713245 INFO (qtp1077238789-11177) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 1713254 INFO (qtp1856479103-11205) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 1715263 INFO (qtp763621270-11103) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556446135057383424)} 0 3
[junit4] 2> 1715278 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1556446135064723456&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556446135064723456)} 0 3
[junit4] 2> 1715279 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1556446135064723456&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556446135064723456)} 0 4
[junit4] 2> 1715279 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556446135064723456)} 0 12
[junit4] 2> 1715304 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[0 (1556446135087792128)]} 0 1
[junit4] 2> 1715304 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[0 (1556446135087792128)]} 0 1
[junit4] 2> 1715304 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[0 (1556446135087792128)]} 0 15
[junit4] 2> 1715310 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[1 (1556446135106666496)]} 0 0
[junit4] 2> 1715310 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[1 (1556446135106666496)]} 0 0
[junit4] 2> 1715310 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[1 (1556446135106666496)]} 0 3
[junit4] 2> 1715344 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[2 (1556446135136026624)]} 0 6
[junit4] 2> 1715344 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[2 (1556446135136026624)]} 0 6
[junit4] 2> 1715344 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[2 (1556446135136026624)]} 0 9
[junit4] 2> 1715352 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[3 (1556446135150706688)]} 0 0
[junit4] 2> 1715352 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[3 (1556446135150706688)]} 0 0
[junit4] 2> 1715353 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[3 (1556446135150706688)]} 0 3
[junit4] 2> 1715357 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[4 (1556446135156998144)]} 0 0
[junit4] 2> 1715363 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[4 (1556446135156998144)]} 0 1
[junit4] 2> 1715365 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[4 (1556446135156998144)]} 0 11
[junit4] 2> 1715371 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[5 (1556446135171678208)]} 0 0
[junit4] 2> 1715371 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[5 (1556446135171678208)]} 0 0
[junit4] 2> 1715375 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[5 (1556446135171678208)]} 0 5
[junit4] 2> 1715389 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[6 (1556446135190552576)]} 0 0
[junit4] 2> 1715389 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[6 (1556446135190552576)]} 0 0
[junit4] 2> 1715390 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[6 (1556446135190552576)]} 0 3
[junit4] 2> 1715400 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[7 (1556446135195795456)]} 0 1
[junit4] 2> 1715401 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[7 (1556446135195795456)]} 0 1
[junit4] 2> 1715401 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[7 (1556446135195795456)]} 0 8
[junit4] 2> 1715411 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[8 (1556446135207329792)]} 0 2
[junit4] 2> 1715411 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[8 (1556446135207329792)]} 0 0
[junit4] 2> 1715411 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[8 (1556446135207329792)]} 0 8
[junit4] 2> 1715430 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[9 (1556446135218864128)]} 0 13
[junit4] 2> 1715430 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[9 (1556446135218864128)]} 0 13
[junit4] 2> 1715431 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[9 (1556446135218864128)]} 0 17
[junit4] 2> 1715436 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[10 (1556446135238787072)]} 0 0
[junit4] 2> 1715437 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[10 (1556446135238787072)]} 0 1
[junit4] 2> 1715437 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[10 (1556446135238787072)]} 0 4
[junit4] 2> 1715451 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[11 (1556446135246127104)]} 0 8
[junit4] 2> 1715451 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[11 (1556446135246127104)]} 0 8
[junit4] 2> 1715452 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[11 (1556446135246127104)]} 0 11
[junit4] 2> 1715462 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[12 (1556446135263952896)]} 0 0
[junit4] 2> 1715463 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[12 (1556446135263952896)]} 0 0
[junit4] 2> 1715463 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[12 (1556446135263952896)]} 0 6
[junit4] 2> 1715468 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[13 (1556446135272341504)]} 0 0
[junit4] 2> 1715468 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[13 (1556446135272341504)]} 0 0
[junit4] 2> 1715468 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[13 (1556446135272341504)]} 0 3
[junit4] 2> 1715473 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[14 (1556446135278632960)]} 0 0
[junit4] 2> 1715473 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[14 (1556446135278632960)]} 0 0
[junit4] 2> 1715474 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[14 (1556446135278632960)]} 0 3
[junit4] 2> 1715480 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[15 (1556446135284924416)]} 0 0
[junit4] 2> 1715480 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[15 (1556446135284924416)]} 0 0
[junit4] 2> 1715480 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[15 (1556446135284924416)]} 0 3
[junit4] 2> 1715489 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[16 (1556446135290167296)]} 0 4
[junit4] 2> 1715489 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[16 (1556446135290167296)]} 0 4
[junit4] 2> 1715489 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[16 (1556446135290167296)]} 0 7
[junit4] 2> 1715502 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[17 (1556446135304847360)]} 0 1
[junit4] 2> 1715504 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[17 (1556446135304847360)]} 0 0
[junit4] 2> 1715504 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[17 (1556446135304847360)]} 0 9
[junit4] 2> 1715509 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[18 (1556446135316381696)]} 0 0
[junit4] 2> 1715509 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[18 (1556446135316381696)]} 0 0
[junit4] 2> 1715510 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[18 (1556446135316381696)]} 0 3
[junit4] 2> 1715515 INFO (qtp1856479103-11204) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[19 (1556446135321624576)]} 0 0
[junit4] 2> 1715515 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[19 (1556446135321624576)]} 0 0
[junit4] 2> 1715515 INFO (qtp80619096-11143) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[19 (1556446135321624576)]} 0 3
[junit4] 2> 1715521 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[20 (1556446135328964608)]} 0 0
[junit4] 2> 1715526 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[20 (1556446135328964608)]} 0 5
[junit4] 2> 1715527 INFO (qtp80619096-11148) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[20 (1556446135328964608)]} 0 8
[junit4] 2> 1715535 INFO (qtp1856479103-11211) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[21 (1556446135342596096)]} 0 0
[junit4] 2> 1715535 INFO (qtp1077238789-11171) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[21 (1556446135342596096)]} 0 0
[junit4] 2> 1715535 INFO (qtp80619096-11146) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[21 (1556446135342596096)]} 0 3
[junit4] 2> 1715541 INFO (qtp1077238789-11177) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[22 (1556446135347838976)]} 0 0
[junit4] 2> 1715541 INFO (qtp1856479103-11205) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[22 (1556446135347838976)]} 0 1
[junit4] 2> 1715542 INFO (qtp80619096-11141) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={_stateVer_=collection1:9&wt=javabin&version=2}{add=[22 (1556446135347838976)]} 0 5
[junit4] 2> 1715547 INFO (qtp1856479103-11209) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[23 (1556446135355179008)]} 0 0
[junit4] 2> 1715547 INFO (qtp1077238789-11176) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34358/collection1/&wt=javabin&version=2}{add=[23 (1556446135355179008)]} 0 0
[junit4] 2> 1715547 INFO (qtp80619096-11143) [ ] o.a.s.u.p.Log
[...truncated too long message...]
[junit4] 2> 1728830 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.Overseer Overseer (id=97277882629619731-127.0.0.1:44087_-n_0000000004) closing
[junit4] 2> 1728830 INFO (OverseerStateUpdate-97277882629619731-127.0.0.1:44087_-n_0000000004) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44087_
[junit4] 2> 1729845 WARN (zkCallback-1894-thread-3) [ ] o.a.s.c.SyncStrategy Closed, skipping sync up.
[junit4] 2> 1729845 INFO (zkCallback-1894-thread-3) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@54b628d9
[junit4] 2> 1729846 INFO (zkCallback-1894-thread-3) [ ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter close.
[junit4] 2> 1729846 INFO (zkCallback-1894-thread-3) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68c703a7
[junit4] 2> 1730003 INFO (zkCallback-1894-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1730330 WARN (zkCallback-1894-thread-4) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1730331 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1730331 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5394f9b2{SSL,[ssl, http/1.1]}{127.0.0.1:44087}
[junit4] 2> 1730331 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@129b81ff{/,null,UNAVAILABLE}
[junit4] 2> 1730332 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 36350
[junit4] 2> 1730332 INFO (TEST-PeerSyncReplicationTest.test-seed#[5428A2DE548F879D]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37512 37512
[junit4] 2> 1730386 INFO (Thread-2672) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37512 37512
[junit4] 2> 1730387 WARN (Thread-2672) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/aliases.json
[junit4] 2> 5 /solr/security.json
[junit4] 2> 5 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/clusterstate.json
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 4 /solr/collections/collection1/state.json
[junit4] 2> 2 /solr/overseer_elect/election/97277882629619722-127.0.0.1:34358_-n_0000000001
[junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/97277882629619722-core_node1-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/overseer/queue
[junit4] 2> 25 /solr/overseer/collection-queue-work
[junit4] 2> 18 /solr/overseer/queue-work
[junit4] 2> 6 /solr/collections
[junit4] 2> 5 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=PeerSyncReplicationTest -Dtests.method=test -Dtests.seed=5428A2DE548F879D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=to -Dtests.timezone=SST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 27.5s J1 | PeerSyncReplicationTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<152> but was:<140>
[junit4] > at __randomizedtesting.SeedInfo.seed([5428A2DE548F879D:DC7C9D04FA73EA65]:0)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.bringUpDeadNodeAndEnsureNoReplication(PeerSyncReplicationTest.java:286)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.forceNodeFailureAndDoPeerSync(PeerSyncReplicationTest.java:259)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:138)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:538)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1730389 INFO (SUITE-PeerSyncReplicationTest-seed#[5428A2DE548F879D]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_5428A2DE548F879D-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62), sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=to, timezone=SST
[junit4] 2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=220793088,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestReloadAndDeleteDocs, LoggingHandlerTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, SpellCheckCollatorTest, TestCursorMarkWithoutUniqueKey, TestCSVResponseWriter, SmileWriterTest, TestConfigSetsAPIExclusivity, CdcrUpdateLogTest, TolerantUpdateProcessorTest, TestFiltering, DistanceFunctionTest, IndexSchemaTest, SolrIndexSplitterTest, TestManagedResource, TestManagedStopFilterFactory, HighlighterMaxOffsetTest, TestSolrQueryParserDefaultOperatorResource, TestSQLHandlerNonCloud, TestMiniSolrCloudClusterSSL, SolrIndexConfigTest, TestInfoStreamLogging, TestJavabinTupleStreamParser, TestObjectReleaseTracker, SpellCheckComponentTest, FullHLLTest, ConvertedLegacyTest, SolrIndexMetricsTest, TestScoreJoinQPScore, TestMinMaxOnMultiValuedField, DistributedTermsComponentTest, FileUtilsTest, AliasIntegrationTest, TestTolerantUpdateProcessorRandomCloud, TestNonDefinedSimilarityFactory, SpellingQueryConverterTest, SimpleMLTQParserTest, TestFieldCacheSortRandom, TestReqParamsAPI, DistributedIntervalFacetingTest, SoftAutoCommitTest, TestConfigSetProperties, TestRawTransformer, TestDelegationWithHadoopAuth, CachingDirectoryFactoryTest, SolrCLIZkUtilsTest, ZkCLITest, UpdateRequestProcessorFactoryTest, SampleTest, BasicAuthIntegrationTest, DistributedSuggestComponentTest, TestLeaderElectionZkExpiry, CoreAdminCreateDiscoverTest, TestMacroExpander, TestStressUserVersions, TestRecoveryHdfs, SchemaVersionSpecificBehaviorTest, OverseerStatusTest, SparseHLLTest, SystemInfoHandlerTest, TermVectorComponentTest, SolrCmdDistributorTest, ClusterStateUpdateTest, TestCollationFieldDocValues, TestLuceneMatchVersion, TestSolrCoreParser, TestJettySolrRunner, SSLMigrationTest, TestClusterProperties, DateMathParserTest, RecoveryAfterSoftCommitTest, TestRTGBase, TestTrie, BJQParserTest, SpatialFilterTest, HdfsNNFailoverTest, BaseCdcrDistributedZkTest, ChaosMonkeySafeLeaderTest, TestSegmentSorting, DistribJoinFromCollectionTest, TestDistributedGrouping, TestCustomStream, AnalyticsQueryTest, DirectSolrSpellCheckerTest, TestConfigReload, TestFieldCacheReopen, ShufflingReplicaListTransformerTest, AtomicUpdatesTest, ShardRoutingCustomTest, TestBulkSchemaAPI, DocValuesMissingTest, TestPartialUpdateDeduplication, DeleteStatusTest, CollectionsAPIAsyncDistributedZkTest, TestManagedSchemaThreadSafety, ZkControllerTest, TestDefaultSearchFieldResource, DocValuesTest, TestCloudPivotFacet, PreAnalyzedFieldManagedSchemaCloudTest, TestBM25SimilarityFactory, TestRandomRequestDistribution, SearchHandlerTest, DistributedExpandComponentTest, TestUninvertingReader, TestFieldCollectionResource, CopyFieldTest, MultiThreadedOCPTest, TestStressCloudBlindAtomicUpdates, TestSchemaSimilarityResource, TestStressVersions, InfoHandlerTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest, ZkSolrClientTest, TestHashPartitioner, PeerSyncTest, TestSort, BasicFunctionalityTest, DirectUpdateHandlerTest, TestIndexSearcher, HighlighterTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, CoreAdminHandlerTest, SuggesterWFSTTest, TestCSVLoader, WordBreakSolrSpellCheckerTest, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, QueryEqualityTest, TestRemoteStreaming, XsltUpdateRequestHandlerTest, DebugComponentTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestQueryUtils, StandardRequestHandlerTest, DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, DocumentBuilderTest, TestIndexingPerformance, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestCollationField, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, TestBinaryResponseWriter, TestLFUCache, TestHighlightDedupGrouping, TestTolerantSearch, TestEmbeddedSolrServerConstructors, ConnectionReuseTest, CollectionsAPISolrJTest, DeleteInactiveReplicaTest, DeleteNodeTest, DistribDocExpirationUpdateProcessorTest, DocValuesNotIndexedTest, LeaderElectionContextKeyTest, LeaderInitiatedRecoveryOnCommitTest, OverriddenZkACLAndCredentialsProvidersTest, PeerSyncReplicationTest]
[junit4] Completed [502/680 (1!)] on J1 in 27.53s, 1 test, 1 failure <<< FAILURES!
[...truncated 52098 lines...]
[JENKINS-EA] Lucene-Solr-6.x-Linux (64bit/jdk-9-ea+147) - Build #
2662 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2662/
Java: 64bit/jdk-9-ea+147 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.search.join.BlockJoinFacetDistribTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest: 1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.] at java.base/java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139) at java.base/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
at java.base/java.lang.Thread.sleep(Native Method)
at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
at java.base/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([60F981BE3E6F147D]:0)
Build Log:
[...truncated 13008 lines...]
[junit4] Suite: org.apache.solr.search.join.BlockJoinFacetDistribTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/init-core-data-001
[junit4] 2> 2160453 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 2160454 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 6 servers in /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001
[junit4] 2> 2160454 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2160455 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2160455 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2160555 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41471
[junit4] 2> 2160564 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160566 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160568 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160575 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5147246{/solr,null,AVAILABLE}
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@16208f6e{SSL,[ssl, http/1.1]}{127.0.0.1:46464}
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.e.j.s.Server Started @2163327ms
[junit4] 2> 2160576 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46464}
[junit4] 2> 2160576 ERROR (jetty-launcher-5785-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160577 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.344334Z
[junit4] 2> 2160585 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160586 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160586 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160619 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2160620 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ef7b8b3{/solr,null,AVAILABLE}
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@fade67f{SSL,[ssl, http/1.1]}{127.0.0.1:36207}
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.e.j.s.Server Started @2163372ms
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36207}
[junit4] 2> 2160621 ERROR (jetty-launcher-5785-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160621 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.389129Z
[junit4] 2> 2160622 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@631cc431{/solr,null,AVAILABLE}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7ede4b9d{SSL,[ssl, http/1.1]}{127.0.0.1:46671}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.e.j.s.Server Started @2163374ms
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46671}
[junit4] 2> 2160623 ERROR (jetty-launcher-5785-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@16e32066{/solr,null,AVAILABLE}
[junit4] 2> 2160623 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.391120Z
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@761303b0{SSL,[ssl, http/1.1]}{127.0.0.1:44650}
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.e.j.s.Server Started @2163375ms
[junit4] 2> 2160624 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44650}
[junit4] 2> 2160624 ERROR (jetty-launcher-5785-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160625 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.392239Z
[junit4] 2> 2160626 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160626 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7c3eaebe{/solr,null,AVAILABLE}
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6655ae55{SSL,[ssl, http/1.1]}{127.0.0.1:35023}
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.e.j.s.Server Started @2163378ms
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35023}
[junit4] 2> 2160627 ERROR (jetty-launcher-5785-thread-5) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160627 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.394649Z
[junit4] 2> 2160630 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160632 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160634 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160634 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160635 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160639 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 0x1599a72c2470002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160640 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 0x1599a72c2470006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160640 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 0x1599a72c2470005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160655 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@28a48d73{/solr,null,AVAILABLE}
[junit4] 2> 2160656 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.AbstractConnector Started ServerConnector@60f31866{SSL,[ssl, http/1.1]}{127.0.0.1:34681}
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.e.j.s.Server Started @2163408ms
[junit4] 2> 2160657 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34681}
[junit4] 2> 2160657 ERROR (jetty-launcher-5785-thread-6) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2160659 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2160659 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2160660 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-14T00:48:49.427174Z
[junit4] 2> 2160665 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160666 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160669 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160673 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160673 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160677 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160679 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2160679 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 0x1599a72c247000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160680 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46464_solr
[junit4] 2> 2160681 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97278684641558535-127.0.0.1:46464_solr-n_0000000000) starting
[junit4] 2> 2160688 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2160691 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46464_solr
[junit4] 2> 2160693 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160695 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36207_solr
[junit4] 2> 2160695 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160697 INFO (zkCallback-5795-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2160698 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41471/solr
[junit4] 2> 2160699 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160700 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 0x1599a72c2470010, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 2160702 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2160705 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2160708 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160709 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34681_solr
[junit4] 2> 2160709 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46671_solr
[junit4] 2> 2160711 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160711 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160711 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160713 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2160713 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160714 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44650_solr
[junit4] 2> 2160716 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 2160717 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160717 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160718 INFO (jetty-launcher-5785-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/.
[junit4] 2> 2160720 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160721 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 2160723 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35023_solr
[junit4] 2> 2160724 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5795-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160724 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
[junit4] 2> 2160725 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 2160729 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (6)
[junit4] 2> 2160731 INFO (jetty-launcher-5785-thread-3) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/.
[junit4] 2> 2160738 INFO (jetty-launcher-5785-thread-4) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/.
[junit4] 2> 2160739 INFO (jetty-launcher-5785-thread-6) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/.
[junit4] 2> 2160740 INFO (jetty-launcher-5785-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/.
[junit4] 2> 2160743 INFO (jetty-launcher-5785-thread-5) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/.
[junit4] 2> 2161105 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (6)
[junit4] 2> 2161106 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41471/solr ready
[junit4] 2> 2161927 INFO (qtp2144423356-24992) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2161928 INFO (OverseerThreadFactory-8684-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection facetcollection
[junit4] 2> 2162042 INFO (qtp2144423356-24993) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 2162087 INFO (qtp1663415689-24976) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2
[junit4] 2> 2162087 INFO (qtp351607826-24963) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2
[junit4] 2> 2162087 INFO (qtp673341061-25001) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 2162090 INFO (qtp1516197574-24997) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 2162100 INFO (qtp1331257531-24996) [ ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 2162203 INFO (zkCallback-5795-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2162203 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2162203 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2162203 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2162203 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2162203 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163052 INFO (qtp2144423356-24993) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163058 INFO (qtp2144423356-24993) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] Schema name=test
[junit4] 2> 2163060 WARN (qtp2144423356-24993) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163061 INFO (qtp2144423356-24993) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163061 INFO (qtp2144423356-24993) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica1' using configuration from collection facetcollection
[junit4] 2> 2163062 INFO (qtp2144423356-24993) [ ] o.a.s.c.SolrCore [[facetcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/facetcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node2/./facetcollection_shard2_replica1/data/]
[junit4] 2> 2163072 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163072 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163074 INFO (qtp2144423356-24993) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163074 INFO (qtp2144423356-24993) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1282e43b[facetcollection_shard2_replica1] main]
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163075 INFO (qtp2144423356-24993) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163075 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@1282e43b[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163076 INFO (qtp2144423356-24993) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957012205568
[junit4] 2> 2163080 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163099 INFO (qtp1516197574-24997) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163137 INFO (qtp673341061-25001) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163137 INFO (qtp1663415689-24976) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163140 INFO (qtp1331257531-24996) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163140 INFO (qtp1516197574-24997) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] Schema name=test
[junit4] 2> 2163144 WARN (qtp1516197574-24997) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163145 INFO (qtp1516197574-24997) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163146 INFO (qtp1516197574-24997) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica1' using configuration from collection facetcollection
[junit4] 2> 2163148 INFO (qtp673341061-25001) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] Schema name=test
[junit4] 2> 2163149 INFO (qtp1516197574-24997) [ ] o.a.s.c.SolrCore [[facetcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/facetcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node5/./facetcollection_shard1_replica1/data/]
[junit4] 2> 2163149 INFO (qtp351607826-24963) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2163150 INFO (qtp1331257531-24996) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] Schema name=test
[junit4] 2> 2163587 INFO (qtp1663415689-24976) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] Schema name=test
[junit4] 2> 2163589 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163589 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163589 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163589 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163589 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163589 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163591 WARN (qtp1663415689-24976) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163591 INFO (qtp1663415689-24976) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163593 WARN (qtp1331257531-24996) [ ] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163594 INFO (qtp1331257531-24996) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163596 WARN (qtp673341061-25001) [ ] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163596 INFO (qtp673341061-25001) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163597 INFO (qtp1663415689-24976) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica1' using configuration from collection facetcollection
[junit4] 2> 2163598 INFO (qtp1663415689-24976) [ ] o.a.s.c.SolrCore [[facetcollection_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/facetcollection_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node3/./facetcollection_shard3_replica1/data/]
[junit4] 2> 2163601 INFO (qtp1331257531-24996) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica2' using configuration from collection facetcollection
[junit4] 2> 2163602 INFO (qtp1331257531-24996) [ ] o.a.s.c.SolrCore [[facetcollection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/facetcollection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node4/./facetcollection_shard2_replica2/data/]
[junit4] 2> 2163605 INFO (qtp351607826-24963) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] Schema name=test
[junit4] 2> 2163608 WARN (qtp351607826-24963) [ ] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 2163609 INFO (qtp351607826-24963) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2163609 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163609 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163609 INFO (qtp351607826-24963) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica2' using configuration from collection facetcollection
[junit4] 2> 2163610 INFO (qtp351607826-24963) [ ] o.a.s.c.SolrCore [[facetcollection_shard3_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/facetcollection_shard3_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node1/./facetcollection_shard3_replica2/data/]
[junit4] 2> 2163610 INFO (qtp673341061-25001) [ ] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica2' using configuration from collection facetcollection
[junit4] 2> 2163611 INFO (qtp673341061-25001) [ ] o.a.s.c.SolrCore [[facetcollection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/facetcollection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.search.join.BlockJoinFacetDistribTest_60F981BE3E6F147D-001/tempDir-001/node6/./facetcollection_shard1_replica2/data/]
[junit4] 2> 2163611 INFO (qtp1516197574-24997) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163611 INFO (qtp1516197574-24997) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163612 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163612 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163613 INFO (qtp1516197574-24997) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@361185b7[facetcollection_shard1_replica1] main]
[junit4] 2> 2163614 INFO (qtp1663415689-24976) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163614 INFO (qtp1516197574-24997) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163614 INFO (qtp1663415689-24976) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163615 INFO (qtp1663415689-24976) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@24e07190[facetcollection_shard3_replica1] main]
[junit4] 2> 2163617 INFO (qtp1516197574-24997) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163617 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@361185b7[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163617 INFO (qtp1516197574-24997) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957579485184
[junit4] 2> 2163623 INFO (qtp1663415689-24976) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163624 INFO (qtp1663415689-24976) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163625 INFO (qtp1663415689-24976) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957587873792
[junit4] 2> 2163627 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@24e07190[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163629 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163631 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard3: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2163632 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163633 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163635 INFO (qtp1331257531-24996) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163635 INFO (qtp1331257531-24996) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163636 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163636 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163636 INFO (qtp1331257531-24996) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@291afb78[facetcollection_shard2_replica2] main]
[junit4] 2> 2163637 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2163637 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2163638 INFO (qtp351607826-24963) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163638 INFO (qtp351607826-24963) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp673341061-25001) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp673341061-25001) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2163639 INFO (qtp1331257531-24996) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163639 INFO (qtp351607826-24963) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@39cd79ac[facetcollection_shard3_replica2] main]
[junit4] 2> 2163640 INFO (qtp1331257531-24996) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163640 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4213350d[facetcollection_shard1_replica2] main]
[junit4] 2> 2163641 INFO (qtp1331257531-24996) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957604651008
[junit4] 2> 2163641 INFO (qtp351607826-24963) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp673341061-25001) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp351607826-24963) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (qtp351607826-24963) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957605699584
[junit4] 2> 2163642 INFO (qtp673341061-25001) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig
[junit4] 2> 2163642 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@4213350d[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163643 INFO (qtp673341061-25001) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556458957606748160
[junit4] 2> 2163645 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@291afb78[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163646 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@39cd79ac[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2163733 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163733 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163733 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163733 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163733 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2163733 INFO (zkCallback-5795-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164090 INFO (qtp2144423356-24993) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/
[junit4] 2> 2164091 INFO (qtp2144423356-24993) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:36207/solr START replicas=[https://127.0.0.1:44650/solr/facetcollection_shard2_replica2/] nUpdates=100
[junit4] 2> 2164091 INFO (qtp2144423356-24993) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=https://127.0.0.1:36207/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164097 INFO (qtp1331257531-25013) [ ] o.a.s.c.S.Request [facetcollection_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2164098 INFO (qtp2144423356-24993) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164098 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2164102 INFO (qtp2144423356-24993) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/ shard2
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/
[junit4] 2> 2164130 INFO (qtp1516197574-24997) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:35023/solr START replicas=[https://127.0.0.1:34681/solr/facetcollection_shard1_replica2/] nUpdates=100
[junit4] 2> 2164131 INFO (qtp1516197574-24997) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=https://127.0.0.1:35023/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2164131 INFO (qtp1663415689-24976) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/
[junit4] 2> 2164132 INFO (qtp1663415689-24976) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica1 url=https://127.0.0.1:46671/solr START replicas=[https://127.0.0.1:46464/solr/facetcollection_shard3_replica2/] nUpdates=100
[junit4] 2> 2164133 INFO (qtp1663415689-24976) [ ] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica1 url=https://127.0.0.1:46671/solr DONE. We have no versions. sync failed.
[junit4] 2> 2164144 INFO (qtp673341061-25032) [ ] o.a.s.c.S.Request [facetcollection_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2164145 INFO (qtp1516197574-24997) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164145 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2164153 INFO (qtp351607826-24971) [ ] o.a.s.c.S.Request [facetcollection_shard3_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 2164154 INFO (qtp1663415689-24976) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2164154 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2164155 INFO (qtp1516197574-24997) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/ shard1
[junit4] 2> 2164159 INFO (qtp1663415689-24976) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/ shard3
[junit4] 2> 2164261 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164261 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164261 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164261 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164261 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164262 INFO (zkCallback-5795-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164304 INFO (qtp2144423356-24993) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164307 INFO (qtp1516197574-24997) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164309 INFO (qtp2144423356-24993) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2266
[junit4] 2> 2164310 INFO (qtp1663415689-24976) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2164310 INFO (qtp1516197574-24997) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2220
[junit4] 2> 2164313 INFO (qtp1663415689-24976) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2226
[junit4] 2> 2164422 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164422 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164422 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164422 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164422 INFO (zkCallback-5795-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164422 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164654 INFO (qtp1331257531-24996) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2553
[junit4] 2> 2164654 INFO (qtp351607826-24963) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2567
[junit4] 2> 2164654 INFO (qtp673341061-25001) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&newCollection=true&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2567
[junit4] 2> 2164657 INFO (qtp2144423356-24992) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2164758 INFO (zkCallback-5795-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164758 INFO (zkCallback-5812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164758 INFO (zkCallback-5819-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164758 INFO (zkCallback-5810-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164758 INFO (zkCallback-5811-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2164758 INFO (zkCallback-5821-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6])
[junit4] 2> 2165657 INFO (qtp2144423356-24992) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2} status=0 QTime=3730
[junit4] 2> 2165705 INFO (TEST-BlockJoinFacetDistribTest.testBJQFacetComponent-seed#[60F981BE3E6F147D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBJQFacetComponent
[junit4] 2> 2165722 INFO (qtp1331257531-24999) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959779397632&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959779397632)} 0 2
[junit4] 2> 2165723 INFO (qtp351607826-24965) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959776251904&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959776251904)} 0 2
[junit4] 2> 2165723 INFO (qtp673341061-25008) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1556458959782543360&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959782543360)} 0 1
[junit4] 2> 2165723 INFO (qtp2144423356-24992) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959779397632)} 0 8
[junit4] 2> 2165723 INFO (qtp1516197574-25027) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556458959782543360)} 0 5
[junit4] 2> 2165723 INFO (qtp1663415689-24979) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556458959776251904)} 0 12
[junit4] 2> 2165737 INFO (qtp673341061-25003) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[0 (1556458959799320576), 1 (1556458959800369152)]} 0 1
[junit4] 2> 2165738 INFO (qtp1516197574-25027) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1556458959799320576), 1 (1556458959800369152)]} 0 4
[junit4] 2> 2165739 INFO (qtp351607826-24970) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[5 (1556458959798272000)]} 0 0
[junit4] 2> 2165739 INFO (qtp1663415689-24987) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1556458959798272000)]} 0 6
[junit4] 2> 2165742 INFO (qtp1331257531-25012) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[2 (1556458959798272000), 3 (1556458959802466304), 4 (1556458959802466305), 6 (1556458959802466306)]} 0 2
[junit4] 2> 2165742 INFO (qtp2144423356-24994) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1556458959798272000), 3 (1556458959802466304), 4 (1556458959802466305), 6 (1556458959802466306)]} 0 9
[junit4] 2> 2165748 INFO (qtp1516197574-24997) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp351607826-24971) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165750 INFO (qtp2144423356-24991) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165751 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165752 INFO (qtp1663415689-24987) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165762 INFO (qtp351607826-24971) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@44a703b2[facetcollection_shard3_replica2] main]
[junit4] 2> 2165762 INFO (qtp1663415689-24987) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@edceb6[facetcollection_shard3_replica1] main]
[junit4] 2> 2165762 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5c0d4381[facetcollection_shard1_replica2] main]
[junit4] 2> 2165762 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@44a703b2[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30)))}
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a2ba120[facetcollection_shard1_replica1] main]
[junit4] 2> 2165762 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@edceb6[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30)))}
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@7a2ba120[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66)))}
[junit4] 2> 2165762 INFO (qtp2144423356-24991) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@594c9253[facetcollection_shard2_replica1] main]
[junit4] 2> 2165762 INFO (qtp1331257531-25012) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1105332a[facetcollection_shard2_replica2] main]
[junit4] 2> 2165762 INFO (qtp1516197574-24997) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 14
[junit4] 2> 2165763 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@1105332a[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133)))}
[junit4] 2> 2165762 INFO (qtp1663415689-24987) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@5c0d4381[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66)))}
[junit4] 2> 2165762 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165762 INFO (qtp351607826-24971) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165763 INFO (qtp673341061-25001) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 13
[junit4] 2> 2165763 INFO (qtp351607826-24971) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 13
[junit4] 2> 2165763 INFO (qtp1663415689-24987) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 10
[junit4] 2> 2165763 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165763 INFO (qtp1331257531-25012) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 12
[junit4] 2> 2165763 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@594c9253[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133)))}
[junit4] 2> 2165763 INFO (qtp2144423356-24991) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165765 INFO (qtp2144423356-24991) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 15
[junit4] 2> 2165765 INFO (qtp1663415689-24986) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={_stateVer_=facetcollection:6&waitSearcher=false&commit=true&softCommit=true&wt=javabin&version=2}{commit=} 0 19
[junit4] 2> 2165778 INFO (qtp351607826-24965) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[17 (1556458959837069312), 18 (1556458959838117888), 19 (1556458959839166464), 21 (1556458959839166465), 23 (1556458959839166466), 25 (1556458959839166467)]} 0 4
[junit4] 2> 2165778 INFO (qtp1663415689-24976) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17 (1556458959837069312), 18 (1556458959838117888), 19 (1556458959839166464), 21 (1556458959839166465), 23 (1556458959839166466), 25 (1556458959839166467)]} 0 8
[junit4] 2> 2165779 INFO (qtp673341061-25032) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[8 (1556458959838117888), 10 (1556458959839166464), 11 (1556458959839166465), 13 (1556458959839166466), 14 (1556458959840215040), 16 (1556458959840215041), 24 (1556458959840215042)]} 0 4
[junit4] 2> 2165779 INFO (qtp1331257531-25013) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[7 (1556458959836020736), 9 (1556458959838117888), 12 (1556458959839166464), 15 (1556458959839166465), 20 (1556458959839166466), 22 (1556458959840215040), 26 (1556458959840215041)]} 0 4
[junit4] 2> 2165779 INFO (qtp1516197574-25026) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8 (1556458959838117888), 10 (1556458959839166464), 11 (1556458959839166465), 13 (1556458959839166466), 14 (1556458959840215040), 16 (1556458959840215041), 24 (1556458959840215042)]} 0 8
[junit4] 2> 2165779 INFO (qtp2144423356-24990) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7 (1556458959836020736), 9 (1556458959838117888), 12 (1556458959839166464), 15 (1556458959839166465), 20 (1556458959839166466), 22 (1556458959840215040), 26 (1556458959840215041)]} 0 10
[junit4] 2> 2165783 INFO (qtp673341061-25005) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165783 INFO (qtp1516197574-25022) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165783 INFO (qtp351607826-24963) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165784 INFO (qtp2144423356-24993) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165784 INFO (qtp1663415689-24979) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165785 INFO (qtp1331257531-24999) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165788 INFO (qtp2144423356-24993) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@18df0645[facetcollection_shard2_replica1] main]
[junit4] 2> 2165788 INFO (qtp1331257531-24999) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1579fcca[facetcollection_shard2_replica2] main]
[junit4] 2> 2165789 INFO (qtp1331257531-24999) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165789 INFO (qtp1331257531-24999) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 4
[junit4] 2> 2165790 INFO (searcherExecutor-8703-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@1579fcca[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133) Uninverting(_1(6.4.0):C221)))}
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@36b0ed73[facetcollection_shard1_replica1] main]
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165790 INFO (searcherExecutor-8697-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@18df0645[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C133) Uninverting(_1(6.4.0):C221)))}
[junit4] 2> 2165790 INFO (qtp673341061-25005) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@254c58be[facetcollection_shard1_replica2] main]
[junit4] 2> 2165790 INFO (qtp2144423356-24993) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165790 INFO (qtp2144423356-24993) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 2165790 INFO (searcherExecutor-8706-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@254c58be[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66) Uninverting(_1(6.4.0):C219)))}
[junit4] 2> 2165790 INFO (qtp1516197574-25022) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 2165790 INFO (searcherExecutor-8701-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@36b0ed73[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C66) Uninverting(_1(6.4.0):C219)))}
[junit4] 2> 2165790 INFO (qtp673341061-25005) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2e47276f[facetcollection_shard3_replica2] main]
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (qtp673341061-25005) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165791 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@2e47276f[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192)))}
[junit4] 2> 2165791 INFO (qtp351607826-24963) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6f193abe[facetcollection_shard3_replica1] main]
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165791 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@6f193abe[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192)))}
[junit4] 2> 2165791 INFO (qtp1663415689-24979) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 7
[junit4] 2> 2165792 INFO (qtp1663415689-24982) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={_stateVer_=facetcollection:6&waitSearcher=false&commit=true&softCommit=true&wt=javabin&version=2}{commit=} 0 10
[junit4] 2> 2165798 INFO (qtp351607826-24971) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&wt=javabin&version=2}{add=[29 (1556458959863283712), 30 (1556458959863283713)]} 0 0
[junit4] 2> 2165798 INFO (qtp673341061-25008) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:35023/solr/facetcollection_shard1_replica1/&wt=javabin&version=2}{add=[27 (1556458959862235136), 28 (1556458959863283712)]} 0 1
[junit4] 2> 2165799 INFO (qtp1663415689-24976) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29 (1556458959863283712), 30 (1556458959863283713)]} 0 4
[junit4] 2> 2165799 INFO (qtp1516197574-25021) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27 (1556458959862235136), 28 (1556458959863283712)]} 0 4
[junit4] 2> 2165799 INFO (qtp1331257531-24996) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:36207/solr/facetcollection_shard2_replica1/&wt=javabin&version=2}{add=[31 (1556458959864332288)]} 0 0
[junit4] 2> 2165800 INFO (qtp2144423356-24992) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31 (1556458959864332288)]} 0 4
[junit4] 2> 2165804 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1663415689-24986) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp351607826-24970) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1331257531-25012) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165804 INFO (qtp1516197574-25027) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=false,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@190057f8[facetcollection_shard3_replica1] main]
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@186cd8f9[facetcollection_shard1_replica2] main]
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (searcherExecutor-8702-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@190057f8[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192) Uninverting(_2(6.4.0):C60)))}
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (qtp1663415689-24986) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2165807 INFO (qtp673341061-25001) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=false&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:46671/solr/facetcollection_shard3_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5de0d4b4[facetcollection_shard3_replica2] main]
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2165807 INFO (searcherExecutor-8705-thread-1) [ ] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@5de0d4b4[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.4.0):C30) Uninverting(_1(6.4.0):C192) Uninverting(_2(6.4.0):C60)))}
[junit4] 2> 2165807 INFO (qtp351607826-24970) [ ] o.a.s.u.p.LogUpdateProcessorFactory [facetcollection_shard3_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&wait
[...truncated too long message...]
7278684641558541-127.0.0.1:46671_solr-n_0000000002) [ ] o.a.s.c.Overseer According to ZK I (id=97278684641558541-127.0.0.1:46671_solr-n_0000000002) am no longer a leader.
[junit4] 2> 2167429 INFO (OverseerStateUpdate-97278684641558541-127.0.0.1:46671_solr-n_0000000002) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:46671_solr
[junit4] 2> 2167430 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41471 41471
[junit4] 2> 2172493 INFO (Thread-3294) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41471 41471
[junit4] 2> 2172493 WARN (Thread-3294) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 6 /solr/security.json
[junit4] 2> 6 /solr/configs/solrCloudCollectionConfig
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 6 /solr/collections/facetcollection/state.json
[junit4] 2> 2 /solr/overseer_elect/election/97278684641558541-127.0.0.1:46671_solr-n_0000000002
[junit4] 2> 2 /solr/overseer_elect/election/97278684641558535-127.0.0.1:46464_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/overseer/queue
[junit4] 2> 7 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 2172494 INFO (SUITE-BlockJoinFacetDistribTest-seed#[60F981BE3E6F147D]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Jan 14, 2017 12:49:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Jan 14, 2017 12:49:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
[junit4] 2> 1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> at java.base/java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Jan 14, 2017 12:49:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> Jan 14, 2017 12:49:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {type_s=FSTOrd50, COLOR_s=PostingsFormat(name=MockRandom), SIZE_s=FST50, _version_=FSTOrd50, _root_=FSTOrd50, BRAND_s=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=377, maxMBSortInHeap=6.104498380038031, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=en-TK, timezone=Etc/GMT-3
[junit4] 2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=290822048,total=501743616
[junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, TestPerFieldSimilarityClassic, SolrCoreCheckLockOnStartupTest, SolrMetricsIntegrationTest, CdcrRequestHandlerTest, CloneFieldUpdateProcessorFactoryTest, TestXIncludeConfig, TestSubQueryTransformerCrossCore, TestCloudPseudoReturnFields, TestSchemaNameResource, TestSchemaManager, TestMacros, HdfsSyncSliceTest, TestSolrQueryResponse, LeaderFailoverAfterPartitionTest, TestSchemaVersionResource, CleanupOldIndexTest, BlobRepositoryCloudTest, OpenExchangeRatesOrgProviderTest, DataDrivenBlockJoinTest, TestLMJelinekMercerSimilarityFactory, EnumFieldTest, PKIAuthenticationIntegrationTest, TestMaxScoreQueryParser, LukeRequestHandlerTest, TestMiniSolrCloudCluster, TestCloudDeleteByQuery, TestTrieFacet, TestSort, PrimitiveFieldTypeTest, TestShardHandlerFactory, OverseerTaskQueueTest, TestZkChroot, DistributedFacetPivotSmallAdvancedTest, OverseerTest, ChangedSchemaMergeTest, TestSolrCloudWithKerberosAlt, TestConfigSetsAPIZkFailure, HdfsBasicDistributedZk2Test, TestIndexingPerformance, UtilsToolTest, TestRecovery, TestConfigOverlay, TestGraphTermsQParserPlugin, TestReversedWildcardFilterFactory, SolrCoreMetricManagerTest, DistributedQueryComponentCustomSortTest, TestBlendedInfixSuggestions, StatsReloadRaceTest, DistributedQueueTest, TestTrackingShardHandlerFactory, SpatialRPTFieldTypeTest, FieldMutatingUpdateProcessorTest, CoreAdminRequestStatusTest, TestOnReconnectListenerSupport, ResponseHeaderTest, AutoCommitTest, TestNumericTerms32, TestConfigSets, PluginInfoTest, SharedFSAutoReplicaFailoverUtilsTest, UpdateParamsTest, HdfsChaosMonkeySafeLeaderTest, TestDistributedMissingSort, DebugComponentTest, TestHdfsCloudBackupRestore, TlogReplayBufferedWhileIndexingTest, TestImpersonationWithHadoopAuth, TestCustomSort, TestSmileRequest, CdcrBootstrapTest, DOMUtilTest, AssignTest, TestUtils, TestRestoreCore, FullSolrCloudDistribCmdsTest, TestPostingsSolrHighlighter, TestDistributedStatsComponentCardinality, QueryParsingTest, TestCoreDiscovery, MetricUtilsTest, TestDFRSimilarityFactory, TestFieldCacheVsDocValues, TemplateUpdateProcessorTest, TestDynamicLoading, UnloadDistributedZkTest, TestSolrDeletionPolicy1, GraphQueryTest, CurrencyFieldXmlFileTest, TestCollapseQParserPlugin, CoreSorterTest, TestPhraseSuggestions, SolrTestCaseJ4Test, SortSpecParsingTest, RequestLoggingTest, HdfsDirectoryFactoryTest, TestStressLiveNodes, TestCollationField, ShowFileRequestHandlerTest, ResponseLogComponentTest, SaslZkACLProviderTest, SolrCloudExampleTest, TestGeoJSONResponseWriter, HardAutoCommitTest, MetricsHandlerTest, DeleteReplicaTest, TestRuleBasedAuthorizationPlugin, LeaderElectionTest, ZkCLITest, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestRealTimeGet, TestReload, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, SpellCheckComponentTest, TestLazyCores, HighlighterTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, CoreAdminHandlerTest, TestFoldingMultitermQuery, SuggesterTest, PolyFieldTest, SchemaVersionSpecificBehaviorTest, QueryEqualityTest, TestRemoteStreaming, DocValuesMultiTest, DistanceFunctionTest, CacheHeaderTest, TestWriterPerf, TermsComponentTest, RequestHandlersTest, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, JSONWriterTest, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, PingRequestHandlerTest, TestLFUCache, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, ActionThrottleTest, AsyncCallRequestStatusResponseTest, CdcrReplicationHandlerTest, CdcrVersionReplicationTest, CollectionsAPIAsyncDistributedZkTest, ConcurrentDeleteAndCreateCollectionTest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteInactiveReplicaTest, DeleteStatusTest, DistribCursorPagingTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderInitiatedRecoveryOnCommitTest, PeerSyncReplicationTest, SharedFSAutoReplicaFailoverTest, SimpleCollectionCreateDeleteTest, SolrCLIZkUtilsTest, TestCloudInspectUtil, TestCloudPivotFacet, TestCollectionAPI, TestLeaderElectionZkExpiry, TestLockTree, TestMiniSolrCloudClusterSSL, TestSolrCloudWithSecureImpersonation, TriLevelCompositeIdRoutingTest, TestInfoStreamLogging, TestInitParams, TestNRTOpen, TestSolrConfigHandler, TestConfigReload, TestSQLHandlerNonCloud, TestSolrConfigHandlerCloud, FacetPivotSmallTest, TestExpandComponent, JavabinLoaderTest, TestUnifiedSolrHighlighter, CheckHdfsIndexTest, SolrMetricManagerTest, SolrJmxReporterTest, SmileWriterTest, SmileWriterTest, TestBinaryResponseWriter, TestGraphMLResponseWriter, TestJavabinTupleStreamParser, TestPushWriter, TestRawResponseWriter, TestSubQueryTransformer, TestBulkSchemaAPI, ManagedSchemaRoundRobinCloudTest, TestBulkSchemaConcurrent, TestReloadDeadlock, TestSearcherReuse, TestSolrCoreParser, TestSolrFieldCacheMBean, TestJsonFacetRefinement, TestOrdValues, BJQParserTest, BlockJoinFacetDistribTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BlockJoinFacetDistribTest -Dtests.seed=60F981BE3E6F147D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-TK -Dtests.timezone=Etc/GMT-3 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J2 | BlockJoinFacetDistribTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest:
[junit4] > 1) Thread[id=25184, name=OverseerHdfsCoreFailoverThread-97278684641558541-127.0.0.1:46671_solr-n_0000000002, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] > at java.base/java.lang.Thread.sleep(Native Method)
[junit4] > at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([60F981BE3E6F147D]:0)
[junit4] Completed [632/680 (1!)] on J2 in 32.11s, 1 test, 1 error <<< FAILURES!
[...truncated 51696 lines...]