lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 734 - Still Failing
Date Thu, 09 Jul 2015 06:28:42 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/734/

5 tests failed.
REGRESSION:  org.apache.solr.cloud.HttpPartitionTest.test

Error Message:
Didn't see all replicas for shard shard1 in c8n_1x2 come up within 30000 ms! ClusterState: {   "collection1":{     "replicationFactor":"1",     "shards":{       "shard1":{         "range":"80000000-ffffffff",         "state":"active",         "replicas":{"core_node2":{             "core":"collection1",             "base_url":"http://127.0.0.1:52977",             "node_name":"127.0.0.1:52977_",             "state":"active",             "leader":"true"}}},       "shard2":{         "range":"0-7fffffff",         "state":"active",         "replicas":{           "core_node1":{             "core":"collection1",             "base_url":"http://127.0.0.1:48885",             "node_name":"127.0.0.1:48885_",             "state":"active",             "leader":"true"},           "core_node3":{             "core":"collection1",             "base_url":"http://127.0.0.1:56562",             "node_name":"127.0.0.1:56562_",             "state":"active"}}}},     "router":{"name":"compositeId"},     "maxShardsPerNode":"1",     "autoAddReplicas":"false",     "autoCreated":"true"},   "control_collection":{     "replicationFactor":"1",     "shards":{"shard1":{         "range":"80000000-7fffffff",         "state":"active",         "replicas":{"core_node1":{             "core":"collection1",             "base_url":"http://127.0.0.1:56797",             "node_name":"127.0.0.1:56797_",             "state":"active",             "leader":"true"}}}},     "router":{"name":"compositeId"},     "maxShardsPerNode":"1",     "autoAddReplicas":"false",     "autoCreated":"true"},   "c8n_1x2":{     "replicationFactor":"2",     "shards":{"shard1":{         "range":"80000000-7fffffff",         "state":"active",         "replicas":{           "core_node1":{             "core":"c8n_1x2_shard1_replica2",             "base_url":"http://127.0.0.1:48885",             "node_name":"127.0.0.1:48885_",             "state":"active",             "leader":"true"},           "core_node2":{             "core":"c8n_1x2_shard1_replica1",             "base_url":"http://127.0.0.1:56562",             "node_name":"127.0.0.1:56562_",             "state":"recovering"}}}},     "router":{"name":"compositeId"},     "maxShardsPerNode":"1",     "autoAddReplicas":"false"}}

Stack Trace:
java.lang.AssertionError: Didn't see all replicas for shard shard1 in c8n_1x2 come up within 30000 ms! ClusterState: {
  "collection1":{
    "replicationFactor":"1",
    "shards":{
      "shard1":{
        "range":"80000000-ffffffff",
        "state":"active",
        "replicas":{"core_node2":{
            "core":"collection1",
            "base_url":"http://127.0.0.1:52977",
            "node_name":"127.0.0.1:52977_",
            "state":"active",
            "leader":"true"}}},
      "shard2":{
        "range":"0-7fffffff",
        "state":"active",
        "replicas":{
          "core_node1":{
            "core":"collection1",
            "base_url":"http://127.0.0.1:48885",
            "node_name":"127.0.0.1:48885_",
            "state":"active",
            "leader":"true"},
          "core_node3":{
            "core":"collection1",
            "base_url":"http://127.0.0.1:56562",
            "node_name":"127.0.0.1:56562_",
            "state":"active"}}}},
    "router":{"name":"compositeId"},
    "maxShardsPerNode":"1",
    "autoAddReplicas":"false",
    "autoCreated":"true"},
  "control_collection":{
    "replicationFactor":"1",
    "shards":{"shard1":{
        "range":"80000000-7fffffff",
        "state":"active",
        "replicas":{"core_node1":{
            "core":"collection1",
            "base_url":"http://127.0.0.1:56797",
            "node_name":"127.0.0.1:56797_",
            "state":"active",
            "leader":"true"}}}},
    "router":{"name":"compositeId"},
    "maxShardsPerNode":"1",
    "autoAddReplicas":"false",
    "autoCreated":"true"},
  "c8n_1x2":{
    "replicationFactor":"2",
    "shards":{"shard1":{
        "range":"80000000-7fffffff",
        "state":"active",
        "replicas":{
          "core_node1":{
            "core":"c8n_1x2_shard1_replica2",
            "base_url":"http://127.0.0.1:48885",
            "node_name":"127.0.0.1:48885_",
            "state":"active",
            "leader":"true"},
          "core_node2":{
            "core":"c8n_1x2_shard1_replica1",
            "base_url":"http://127.0.0.1:56562",
            "node_name":"127.0.0.1:56562_",
            "state":"recovering"}}}},
    "router":{"name":"compositeId"},
    "maxShardsPerNode":"1",
    "autoAddReplicas":"false"}}
	at __randomizedtesting.SeedInfo.seed([20660CD84FFDF448:A8323302E10199B0]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.ensureAllReplicasAreActive(AbstractFullDistribZkTestBase.java:1842)
	at org.apache.solr.cloud.HttpPartitionTest.testRf2(HttpPartitionTest.java:248)
	at org.apache.solr.cloud.HttpPartitionTest.test(HttpPartitionTest.java:102)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
	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:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	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:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  junit.framework.TestSuite.org.apache.solr.update.SoftAutoCommitTest

Error Message:
1

Stack Trace:
java.lang.AssertionError: 1
	at __randomizedtesting.SeedInfo.seed([20660CD84FFDF448]:0)
	at org.apache.solr.core.CachingDirectoryFactory.close(CachingDirectoryFactory.java:201)
	at org.apache.solr.core.SolrCore.close(SolrCore.java:1247)
	at org.apache.solr.core.SolrCores.close(SolrCores.java:124)
	at org.apache.solr.core.CoreContainer.shutdown(CoreContainer.java:510)
	at org.apache.solr.util.TestHarness.close(TestHarness.java:359)
	at org.apache.solr.SolrTestCaseJ4.deleteCore(SolrTestCaseJ4.java:680)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:227)
	at sun.reflect.GeneratedMethodAccessor98.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:799)
	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:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	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:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  junit.framework.TestSuite.org.apache.solr.update.SoftAutoCommitTest

Error Message:
Clean up static fields (in @AfterClass?), your test seems to hang on to approximately 14,615,064 bytes (threshold is 10,485,760). Field reference sizes (counted individually):   - 15,106,160 bytes, protected static org.apache.solr.util.TestHarness$LocalRequestFactory org.apache.solr.SolrTestCaseJ4.lrf   - 15,105,920 bytes, protected static org.apache.solr.util.TestHarness org.apache.solr.SolrTestCaseJ4.h   - 9,311,272 bytes, protected static org.apache.solr.core.SolrConfig org.apache.solr.SolrTestCaseJ4.solrConfig   - 232 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.testSolrHome   - 192 bytes, public static org.junit.rules.TestRule org.apache.solr.SolrTestCaseJ4.solrClassRules   - 128 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.factoryProp   - 72 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.configString   - 64 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.coreName   - 64 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.schemaString

Stack Trace:
junit.framework.AssertionFailedError: Clean up static fields (in @AfterClass?), your test seems to hang on to approximately 14,615,064 bytes (threshold is 10,485,760). Field reference sizes (counted individually):
  - 15,106,160 bytes, protected static org.apache.solr.util.TestHarness$LocalRequestFactory org.apache.solr.SolrTestCaseJ4.lrf
  - 15,105,920 bytes, protected static org.apache.solr.util.TestHarness org.apache.solr.SolrTestCaseJ4.h
  - 9,311,272 bytes, protected static org.apache.solr.core.SolrConfig org.apache.solr.SolrTestCaseJ4.solrConfig
  - 232 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.testSolrHome
  - 192 bytes, public static org.junit.rules.TestRule org.apache.solr.SolrTestCaseJ4.solrClassRules
  - 128 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.factoryProp
  - 72 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.configString
  - 64 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.coreName
  - 64 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.schemaString
	at com.carrotsearch.randomizedtesting.rules.StaticFieldsInvariantRule$1.afterAlways(StaticFieldsInvariantRule.java:127)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
	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:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test

Error Message:
Captured an uncaught exception in thread: Thread[id=59028, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=59028, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:57225/vv_yz/bs: collection already exists: awholynewstresscollection_collection2_1
	at __randomizedtesting.SeedInfo.seed([20660CD84FFDF448]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1572)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1593)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:887)


FAILED:  org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test

Error Message:
Captured an uncaught exception in thread: Thread[id=48562, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=48562, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:56252: Could not find collection : awholynewstresscollection_collection4_0
	at __randomizedtesting.SeedInfo.seed([20660CD84FFDF448]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:894)




Build Log:
[...truncated 10717 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/init-core-data-001
   [junit4]   2> 1789281 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[20660CD84FFDF448]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1789282 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[20660CD84FFDF448]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /vv_yz/bs
   [junit4]   2> 1789284 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1789286 INFO  (Thread-55864) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1789286 INFO  (Thread-55864) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 1789385 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkTestServer start zk server on port:47430
   [junit4]   2> 1789386 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1789386 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1789389 INFO  (zkCallback-422-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@697e2d17 name:ZooKeeperConnection Watcher:127.0.0.1:47430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1789389 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1789389 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1789389 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /solr
   [junit4]   2> 1789395 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1789395 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1789396 INFO  (zkCallback-423-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b341588 name:ZooKeeperConnection Watcher:127.0.0.1:47430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1789397 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1789397 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1789397 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
   [junit4]   2> 1789398 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
   [junit4]   2> 1789400 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
   [junit4]   2> 1789401 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
   [junit4]   2> 1789403 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1789403 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1789405 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1789405 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
   [junit4]   2> 1789407 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1789407 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1789409 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1789409 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1789411 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1789411 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1789412 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1789413 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
   [junit4]   2> 1789414 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1789414 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1789416 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1789416 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1789418 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1789418 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1789419 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1789420 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1789421 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1789421 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1789715 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1
   [junit4]   2> 1789722 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.Server jetty-9.2.11.v20150529
   [junit4]   2> 1789724 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@13bd3072{/vv_yz/bs,null,AVAILABLE}
   [junit4]   2> 1789724 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.ServerConnector Started ServerConnector@6d99f4f7{HTTP/1.1}{127.0.0.1:57225}
   [junit4]   2> 1789725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.Server Started @1793122ms
   [junit4]   2> 1789725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/tempDir-001/control/data, hostContext=/vv_yz/bs, hostPort=57225, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores}
   [junit4]   2> 1789725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
   [junit4]   2> 1789725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/'
   [junit4]   2> 1789739 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/solr.xml
   [junit4]   2> 1789756 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores
   [junit4]   2> 1789757 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer New CoreContainer 1492773547
   [junit4]   2> 1789757 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/]
   [junit4]   2> 1789757 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/lib
   [junit4]   2> 1789757 WARN  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/lib).
   [junit4]   2> 1789763 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47430/solr
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 1789765 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1789766 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1789767 INFO  (zkCallback-425-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@71a1ce03 name:ZooKeeperConnection Watcher:127.0.0.1:47430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1789767 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1789768 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1789774 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1789775 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@a9b8003 name:ZooKeeperConnection Watcher:127.0.0.1:47430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1789775 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1789776 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
   [junit4]   2> 1789778 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
   [junit4]   2> 1789779 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
   [junit4]   2> 1789781 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
   [junit4]   2> 1789783 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
   [junit4]   2> 1789785 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
   [junit4]   2> 1789786 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
   [junit4]   2> 1789787 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
   [junit4]   2> 1789788 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57225_vv_yz%2Fbs
   [junit4]   2> 1789789 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:57225_vv_yz%2Fbs
   [junit4]   2> 1789791 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
   [junit4]   2> 1789792 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
   [junit4]   2> 1789793 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1789794 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000
   [junit4]   2> 1789794 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57225_vv_yz%2Fbs
   [junit4]   2> 1789794 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
   [junit4]   2> 1789796 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer Overseer (id=94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) starting
   [junit4]   2> 1789797 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
   [junit4]   2> 1789802 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 1789803 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer Starting to work on the main queue
   [junit4]   2> 1789806 INFO  (OverseerCollectionProcessor-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
   [junit4]   2> 1789811 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 1789814 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 1789814 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 1789815 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores
   [junit4]   2> 1789815 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 1789816 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/
   [junit4]   2> 1789816 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.CoresLocator Found 1 core definitions
   [junit4]   2> 1789817 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController publishing state=down
   [junit4]   2> 1789817 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
   [junit4]   2> 1789818 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController look for our core node name
   [junit4]   2> 1789819 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
   [junit4]   2> 1789819 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
   [junit4]   2> 1789818 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1789820 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:57225/vv_yz/bs",
   [junit4]   2>   "node_name":"127.0.0.1:57225_vv_yz%2Fbs",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1789820 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:57225/vv_yz/bs",
   [junit4]   2>   "node_name":"127.0.0.1:57225_vv_yz%2Fbs",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1789820 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
   [junit4]   2> 1789820 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 1789821 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1789822 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
   [junit4]   2> 1790819 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1790819 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
   [junit4]   2> 1790820 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.ZkController Collection zkNode exists
   [junit4]   2> 1790820 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
   [junit4]   2> 1790821 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1790821 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/'
   [junit4]   2> 1790836 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 
   [junit4]   2> 1790841 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 1790847 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1790855 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1790856 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1790863 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1790996 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1791001 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 1791002 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 1791011 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1791013 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1791015 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1791016 WARN  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1791016 WARN  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1791016 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1791017 WARN  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1791017 WARN  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1791017 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1791017 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1791018 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/], dataDir=[null]
   [junit4]   2> 1791018 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6d83c07f
   [junit4]   2> 1791018 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data
   [junit4]   2> 1791018 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data/index/
   [junit4]   2> 1791019 WARN  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1791019 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data/index
   [junit4]   2> 1791019 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=22.0341796875, floorSegmentMB=0.986328125, forceMergeDeletesPctAllowed=22.280415666565304, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1791020 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@6d8558e0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23e7b1a5),segFN=segments_1,generation=1}
   [junit4]   2> 1791020 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 1791025 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1791025 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1791025 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1791026 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1791028 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1791029 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1791030 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1791031 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1791033 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 1791034 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1791034 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data/
   [junit4]   2> 1791035 WARN  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
   [junit4]   2> 1791047 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1791047 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1791048 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
   [junit4]   2> 1791048 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
   [junit4]   2> 1791049 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=30, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=69.1650390625, floorSegmentMB=0.9775390625, forceMergeDeletesPctAllowed=18.351703465715044, segmentsPerTier=10.0, maxCFSSegmentSizeMB=1.9326171875, noCFSRatio=1.0
   [junit4]   2> 1791049 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@6d8558e0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23e7b1a5),segFN=segments_1,generation=1}
   [junit4]   2> 1791049 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 1791049 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@5613293d[collection1] main
   [junit4]   2> 1791049 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
   [junit4]   2> 1791050 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1791050 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1791051 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1791051 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
   [junit4]   2> 1791051 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1791051 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 1791052 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1506197143607574528
   [junit4]   2> 1791055 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 3 ms to seed version buckets with highest version 1506197143607574528
   [junit4]   2> 1791055 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
   [junit4]   2> 1791056 INFO  (coreLoadExecutor-2728-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 1791056 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:57225/vv_yz/bs collection:control_collection shard:shard1
   [junit4]   2> 1791057 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1791060 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/94137321359998979-core_node1-n_0000000000
   [junit4]   2> 1791060 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
   [junit4]   2> 1791061 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1791062 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection"} current state version: 1
   [junit4]   2> 1791064 INFO  (searcherExecutor-2729-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5613293d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57225/vv_yz/bs/collection1/
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:57225/vv_yz/bs/collection1/ has no replicas
   [junit4]   2> 1791064 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57225/vv_yz/bs/collection1/ shard1
   [junit4]   2> 1791065 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1791069 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1791069 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "base_url":"http://127.0.0.1:57225/vv_yz/bs",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active"} current state version: 1
   [junit4]   2> 1791171 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1791173 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
   [junit4]   2> 1791218 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:57225/vv_yz/bs/collection1/ and leader is http://127.0.0.1:57225/vv_yz/bs/collection1/
   [junit4]   2> 1791218 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57225/vv_yz/bs
   [junit4]   2> 1791218 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1791219 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
   [junit4]   2> 1791219 INFO  (coreZkRegister-2722-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:57225_vv_yz%2Fbs c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
   [junit4]   2> 1791220 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1791221 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:57225/vv_yz/bs",
   [junit4]   2>   "node_name":"127.0.0.1:57225_vv_yz%2Fbs",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"} current state version: 2
   [junit4]   2> 1791221 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:57225/vv_yz/bs",
   [junit4]   2>   "node_name":"127.0.0.1:57225_vv_yz%2Fbs",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 1791321 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1791321 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1791322 INFO  (zkCallback-428-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@39400b10 name:ZooKeeperConnection Watcher:127.0.0.1:47430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1791323 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1791323 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1791323 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 1791323 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1791325 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
   [junit4]   2> 1791326 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1791326 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
   [junit4]   2> 1791326 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1791327 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1791328 INFO  (zkCallback-429-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@40ddd8e3 name:ZooKeeperConnection Watcher:127.0.0.1:47430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1791328 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1791328 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1791330 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1791331 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"create",
   [junit4]   2>   "name":"collection1",
   [junit4]   2>   "numShards":"2",
   [junit4]   2>   "stateFormat":"2"} current state version: 3
   [junit4]   2> 1791331 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
   [junit4]   2> 1791433 INFO  (OverseerStateUpdate-94137321359998979-127.0.0.1:57225_vv_yz%2Fbs-n_0000000000) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
   [junit4]   2> 1791435 INFO  (zkCallback-428-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1791435 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1791438 INFO  (zkCallback-428-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
   [junit4]   2> 1791439 INFO  (zkCallback-426-thread-1-processing-n:127.0.0.1:57225_vv_yz%2Fbs) [n:127.0.0.1:57225_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
   [junit4]   2> 1791698 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/cores/collection1
   [junit4]   2> 1791699 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001
   [junit4]   2> 1791700 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.Server jetty-9.2.11.v20150529
   [junit4]   2> 1791702 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@59be5041{/vv_yz/bs,null,AVAILABLE}
   [junit4]   2> 1791702 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.ServerConnector Started ServerConnector@1753e5e8{HTTP/1.1}{127.0.0.1:40915}
   [junit4]   2> 1791702 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.e.j.s.Server Started @1795099ms
   [junit4]   2> 1791702 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/vv_yz/bs, hostPort=40915, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/cores}
   [junit4]   2> 1791703 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@c387f44
   [junit4]   2> 1791703 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/'
   [junit4]   2> 1791720 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/solr.xml
   [junit4]   2> 1791725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/cores
   [junit4]   2> 1791725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer New CoreContainer 355201688
   [junit4]   2> 1791725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/]
   [junit4]   2> 1791725 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/lib
   [junit4]   2> 1791725 WARN  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_20660CD84FFDF448-001/shard-1-001/lib).
   [junit4]   2> 1791732 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 1791733 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1791734 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1791734 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1791734 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47430/solr
   [junit4]   2> 1791734 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 1791734 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1791738 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1791739 INFO  (zkCallback-431-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7ca29fb4 name:ZooKeeperConnection Watcher:127.0.0.1:47430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1791739 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1791739 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1791742 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:40915_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1791745 INFO  (zkCallback-432-thread-1-processing-n:127.0.0.1:40915_vv_yz%2Fbs) [n:127.0.0.1:40915_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3b0e9804 name:ZooKeeperConnection Watcher:127.0.0.1:47430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1791746 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:40915_vv_yz%2Fbs    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1791749 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[20660CD84FFDF448]) [n:127.0.0.1:40915_vv_yz%2Fbs    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 1792753 INFO  (TEST-CollectionsAPIDistributedZkTest.tes

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

1)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:227)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:212)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:461)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:212)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:592)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:145)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:822)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1720)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1699)
   [junit4]   2> 	at org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:197)
   [junit4]   2> 	at org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.teardownClass(HdfsCollectionsAPIDistributedZkTest.java:50)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:483)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:799)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> Caused by: java.lang.NullPointerException
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:198)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223)
   [junit4]   2> 	... 53 more
   [junit4]   2> 3197768 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[20660CD84FFDF448]-worker) [n:127.0.0.1:36607_ c:addReplicaColl s:shard1 r:core_node5 x:addReplicaColl_shard1_replica3] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> Jul 09, 2015 2:22:18 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=es_UY, timezone=America/Guatemala
   [junit4]   2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_25 (64-bit)/cpus=4,threads=2,free=172484568,total=531628032
   [junit4]   2> NOTE: All tests run in this JVM: [RollingRestartTest, TestSolrJ, SynonymTokenizerTest, SimpleCollectionCreateDeleteTest, TestPartialUpdateDeduplication, BasicDistributedZk2Test, QueryParsingTest, TestPseudoReturnFields, StressHdfsTest, TestSolrXml, HardAutoCommitTest, TestRecovery, TestSolrDynamicMBean, TestQueryUtils, TestXIncludeConfig, TestSort, StatsComponentTest, TestRawResponseWriter, DistanceUnitsTest, TestUtils, TestAuthorizationFramework, SimpleFacetsTest, DirectUpdateHandlerOptimizeTest, TestReqParamsAPI, TestCursorMarkWithoutUniqueKey, SharedFSAutoReplicaFailoverTest, TestLuceneMatchVersion, DistribJoinFromCollectionTest, RegexBoostProcessorTest, TestSolrCloudWithKerberosAlt, OverseerCollectionProcessorTest, TestManagedStopFilterFactory, TestSchemaSimilarityResource, HdfsNNFailoverTest, TestCSVResponseWriter, DOMUtilTest, FileBasedSpellCheckerTest, DistributedQueryComponentCustomSortTest, TestCollationField, BinaryUpdateRequestHandlerTest, SampleTest, UnloadDistributedZkTest, TestSolrQueryParserDefaultOperatorResource, ResponseLogComponentTest, TestDocSet, TestCollectionAPI, TestSolr4Spatial2, ActionThrottleTest, TestReload, TestStressRecovery, CdcrVersionReplicationTest, TestShortCircuitedRequests, TestSearcherReuse, DirectSolrSpellCheckerTest, LeaderElectionTest, TestPerFieldSimilarity, HdfsBasicDistributedZk2Test, TestBinaryResponseWriter, TestNoOpRegenerator, TestRemoveLastDynamicCopyField, HdfsRecoveryZkTest, NumericFieldsTest, SearchHandlerTest, TestChildDocTransformer, CloudMLTQParserTest, LeaderInitiatedRecoveryOnCommitTest, PathHierarchyTokenizerFactoryTest, TestQueryTypes, TestStressReorder, TestExactStatsCache, VersionInfoTest, TermVectorComponentDistributedTest, TestReplicationHandlerBackup, CircularListTest, CursorPagingTest, DirectUpdateHandlerTest, MultiThreadedOCPTest, DistributedSuggestComponentTest, TestExtendedDismaxParser, AutoCommitTest, CloudExitableDirectoryReaderTest, TestMiniSolrCloudClusterSSL, OverseerTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestRandomFaceting, TestZkChroot, TestRandomDVFaceting, TestJoin, TestSolr4Spatial, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestBadConfig, SoftAutoCommitTest, DisMaxRequestHandlerTest, TermsComponentTest, TestIndexingPerformance, TestSolrQueryParser, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, TestQuerySenderNoQuery, SolrIndexConfigTest, MultiTermTest, TestElisionMultitermQuery, OutputWriterTest, DirectSolrConnectionTest, TestPhraseSuggestions, EchoParamsTest, TestLMJelinekMercerSimilarityFactory, TestFastOutputStream, ScriptEngineTest, PluginInfoTest, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, ClusterStateTest, TestLRUCache, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, UUIDFieldTest, DistributedMLTComponentTest, TestRTGBase, DistributedIntervalFacetingTest, CollectionReloadTest, DeleteInactiveReplicaTest, DistribCursorPagingTest, HttpPartitionTest, RecoveryAfterSoftCommitTest, ReplicationFactorTest, SharedFSAutoReplicaFailoverUtilsTest, SolrXmlInZkTest, TestCloudPivotFacet, TestReplicaProperties, TestRequestStatusCollectionAPI, HdfsCollectionsAPIDistributedZkTest]
   [junit4] Completed [443/514] on J2 in 313.99s, 1 test, 1 error <<< FAILURES!

[...truncated 228 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:533: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:474: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:61: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:39: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:230: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:513: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1426: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:981: There were test failures: 514 suites, 2022 tests, 2 suite-level errors, 2 errors, 1 failure, 20 ignored (10 assumptions)

Total time: 171 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message