lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_55) - Build # 10335 - Failure!
Date Mon, 19 May 2014 15:28:54 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10335/
Java: 64bit/jdk1.7.0_55 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.HttpPartitionTest.testDistribSearch

Error Message:
Didn't see all replicas come up within 20000 ms! ClusterState: live nodes:[127.0.0.1:36955_, 127.0.0.1:43414_, 127.0.0.1:59339_] collections:{control_collection=DocCollection(control_collection)={   "router":{"name":"compositeId"},   "autoCreated":"true",   "maxShardsPerNode":"1",   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{"core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:59339",           "core":"collection1",           "node_name":"127.0.0.1:59339_",           "leader":"true"}}}},   "replicationFactor":"1"}, collection1=DocCollection(collection1)={   "router":{"name":"compositeId"},   "autoCreated":"true",   "maxShardsPerNode":"1",   "shards":{     "shard1":{       "range":"80000000-ffffffff",       "state":"active",       "replicas":{"core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:43414",           "core":"collection1",           "node_name":"127.0.0.1:43414_",           "leader":"true"}}},     "shard2":{       "range":"0-7fffffff",       "state":"active",       "replicas":{"core_node2":{           "state":"active",           "base_url":"http://127.0.0.1:36955",           "core":"collection1",           "node_name":"127.0.0.1:36955_",           "leader":"true"}}}},   "replicationFactor":"1"}, c8n_1x2=DocCollection(c8n_1x2)={   "router":{"name":"compositeId"},   "maxShardsPerNode":"1",   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{         "core_node1":{           "state":"active",           "base_url":"http://127.0.0.1:59339",           "core":"c8n_1x2_shard1_replica1",           "node_name":"127.0.0.1:59339_",           "leader":"true"},         "core_node2":{           "state":"active",           "base_url":"http://127.0.0.1:36955",           "core":"c8n_1x2_shard1_replica2",           "node_name":"127.0.0.1:36955_"}}}},   "replicationFactor":"2"}, c8n_1x3=DocCollection(c8n_1x3)={   "router":{"name":"compositeId"},   "maxShardsPerNode":"1",   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{         "core_node1":{           "state":"recovering",           "base_url":"http://127.0.0.1:43414",           "core":"c8n_1x3_shard1_replica2",           "node_name":"127.0.0.1:43414_"},         "core_node2":{           "state":"active",           "base_url":"http://127.0.0.1:36955",           "core":"c8n_1x3_shard1_replica1",           "node_name":"127.0.0.1:36955_",           "leader":"true"},         "core_node3":{           "state":"recovering",           "base_url":"http://127.0.0.1:59339",           "core":"c8n_1x3_shard1_replica3",           "node_name":"127.0.0.1:59339_"}}}},   "replicationFactor":"3"}}

Stack Trace:
java.lang.AssertionError: Didn't see all replicas come up within 20000 ms! ClusterState: live nodes:[127.0.0.1:36955_, 127.0.0.1:43414_, 127.0.0.1:59339_] collections:{control_collection=DocCollection(control_collection)={
  "router":{"name":"compositeId"},
  "autoCreated":"true",
  "maxShardsPerNode":"1",
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{"core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:59339",
          "core":"collection1",
          "node_name":"127.0.0.1:59339_",
          "leader":"true"}}}},
  "replicationFactor":"1"}, collection1=DocCollection(collection1)={
  "router":{"name":"compositeId"},
  "autoCreated":"true",
  "maxShardsPerNode":"1",
  "shards":{
    "shard1":{
      "range":"80000000-ffffffff",
      "state":"active",
      "replicas":{"core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:43414",
          "core":"collection1",
          "node_name":"127.0.0.1:43414_",
          "leader":"true"}}},
    "shard2":{
      "range":"0-7fffffff",
      "state":"active",
      "replicas":{"core_node2":{
          "state":"active",
          "base_url":"http://127.0.0.1:36955",
          "core":"collection1",
          "node_name":"127.0.0.1:36955_",
          "leader":"true"}}}},
  "replicationFactor":"1"}, c8n_1x2=DocCollection(c8n_1x2)={
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"1",
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{
        "core_node1":{
          "state":"active",
          "base_url":"http://127.0.0.1:59339",
          "core":"c8n_1x2_shard1_replica1",
          "node_name":"127.0.0.1:59339_",
          "leader":"true"},
        "core_node2":{
          "state":"active",
          "base_url":"http://127.0.0.1:36955",
          "core":"c8n_1x2_shard1_replica2",
          "node_name":"127.0.0.1:36955_"}}}},
  "replicationFactor":"2"}, c8n_1x3=DocCollection(c8n_1x3)={
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"1",
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{
        "core_node1":{
          "state":"recovering",
          "base_url":"http://127.0.0.1:43414",
          "core":"c8n_1x3_shard1_replica2",
          "node_name":"127.0.0.1:43414_"},
        "core_node2":{
          "state":"active",
          "base_url":"http://127.0.0.1:36955",
          "core":"c8n_1x3_shard1_replica1",
          "node_name":"127.0.0.1:36955_",
          "leader":"true"},
        "core_node3":{
          "state":"recovering",
          "base_url":"http://127.0.0.1:59339",
          "core":"c8n_1x3_shard1_replica3",
          "node_name":"127.0.0.1:59339_"}}}},
  "replicationFactor":"3"}}
	at __randomizedtesting.SeedInfo.seed([27BA048E48164993:A65C8A963F4929AF]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.HttpPartitionTest.ensureAllReplicasAreActive(HttpPartitionTest.java:495)
	at org.apache.solr.cloud.HttpPartitionTest.testRf3(HttpPartitionTest.java:259)
	at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:145)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
	at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	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:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	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:43)
	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:360)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11673 lines...]
   [junit4] Suite: org.apache.solr.cloud.HttpPartitionTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-27BA048E48164993-001/init-core-data-001
   [junit4]   2> 1381748 T5543 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1381751 T5543 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1381752 T5543 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1381753 T5544 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1381852 T5543 oasc.ZkTestServer.run start zk server on port:59412
   [junit4]   2> 1381853 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1387523 T5547 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 5669ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1387525 T5550 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@582946ef name:ZooKeeperConnection Watcher:127.0.0.1:59412 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1387525 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1387525 T5543 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1387552 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1387571 T5552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21a4e236 name:ZooKeeperConnection Watcher:127.0.0.1:59412/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1387571 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1387572 T5543 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1387612 T5543 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1387631 T5543 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1387654 T5543 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1387672 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1387673 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1390121 T5547 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 2408ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1390124 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1390125 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1390131 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1390131 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1390135 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1390135 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1390139 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1390140 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1390143 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1390143 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1390146 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1390147 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1390150 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1390151 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1390154 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1390155 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1390158 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1390159 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1390161 T5543 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1390162 T5543 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1390376 T5543 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1390379 T5543 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35033
   [junit4]   2> 1390380 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1390380 T5543 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1390381 T5543 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002
   [junit4]   2> 1390381 T5543 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/'
   [junit4]   2> 1390394 T5543 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/solr.xml
   [junit4]   2> 1390427 T5543 oasc.CoreContainer.<init> New CoreContainer 477800354
   [junit4]   2> 1390427 T5543 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/]
   [junit4]   2> 1390428 T5543 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1390428 T5543 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1390429 T5543 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1390429 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1390429 T5543 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1390429 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1390429 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1390430 T5543 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1390430 T5543 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1390430 T5543 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1390430 T5543 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1390431 T5543 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1390431 T5543 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59412/solr
   [junit4]   2> 1390431 T5543 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1390432 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1390434 T5563 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38938b49 name:ZooKeeperConnection Watcher:127.0.0.1:59412 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1390434 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1390436 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1390437 T5565 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@446158a8 name:ZooKeeperConnection Watcher:127.0.0.1:59412/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1390437 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1390439 T5543 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1390440 T5543 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1390442 T5543 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1390444 T5543 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1390445 T5543 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1390447 T5543 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1390448 T5543 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59339_
   [junit4]   2> 1390448 T5543 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59339_
   [junit4]   2> 1390450 T5543 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1390464 T5543 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1390467 T5543 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59339_
   [junit4]   2> 1390467 T5543 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1390468 T5543 oasc.Overseer.start Overseer (id=91784025184927747-127.0.0.1:59339_-n_0000000000) starting
   [junit4]   2> 1390472 T5543 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1390478 T5567 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1390478 T5543 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1390480 T5543 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1390481 T5543 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1390483 T5566 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1390486 T5568 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1390486 T5568 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1390487 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1390487 T5568 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1390488 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1390488 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59339",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:59339_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1390489 T5566 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1390489 T5566 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1390490 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1390491 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1391487 T5568 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1391488 T5568 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1391488 T5568 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1391488 T5568 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1391489 T5568 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1391490 T5568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/collection1/'
   [junit4]   2> 1391490 T5568 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 1391490 T5568 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 1391491 T5568 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 1391521 T5568 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1391555 T5568 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1391556 T5568 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1391569 T5568 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1391857 T5568 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1391862 T5568 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1391864 T5568 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1391872 T5568 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1391874 T5568 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1391877 T5568 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1391878 T5568 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1391878 T5568 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1391878 T5568 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1391879 T5568 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1391879 T5568 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1391879 T5568 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1391879 T5568 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1391880 T5568 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-002/collection1/, dataDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/control/data/
   [junit4]   2> 1391880 T5568 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3aa865cf
   [junit4]   2> 1391880 T5568 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/control/data
   [junit4]   2> 1391880 T5568 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/control/data/index/
   [junit4]   2> 1391881 T5568 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1391881 T5568 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/control/data/index
   [junit4]   2> 1391881 T5568 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=78.234375, floorSegmentMB=1.7265625, forceMergeDeletesPctAllowed=23.588817092619554, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1391882 T5568 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1e71eda6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12e91bf1),segFN=segments_1,generation=1}
   [junit4]   2> 1391882 T5568 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1391884 T5568 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1391884 T5568 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1391884 T5568 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1391885 T5568 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1391885 T5568 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1391885 T5568 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1391885 T5568 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1391885 T5568 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1391886 T5568 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1391886 T5568 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1391886 T5568 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1391886 T5568 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1391887 T5568 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1391887 T5568 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1391887 T5568 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1391887 T5568 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1391888 T5568 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1391890 T5568 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1391892 T5568 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1391892 T5568 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1391893 T5568 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.476493025439654]
   [junit4]   2> 1391893 T5568 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1e71eda6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12e91bf1),segFN=segments_1,generation=1}
   [junit4]   2> 1391893 T5568 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1391894 T5568 oass.SolrIndexSearcher.<init> Opening Searcher@5d4524a[collection1] main
   [junit4]   2> 1391894 T5568 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1391895 T5568 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1391895 T5568 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1391895 T5568 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1391895 T5568 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1391895 T5568 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1391896 T5568 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1391896 T5568 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1391896 T5568 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1391896 T5568 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1391898 T5569 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d4524a[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1391899 T5568 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1391899 T5572 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59339 collection:control_collection shard:shard1
   [junit4]   2> 1391900 T5543 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1391900 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1391901 T5572 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1391903 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1391904 T5575 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@787967dc name:ZooKeeperConnection Watcher:127.0.0.1:59412/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1391904 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1391905 T5543 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1391907 T5543 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1391907 T5572 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1391911 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1391911 T5572 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1391912 T5572 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1574 name=collection1 org.apache.solr.core.SolrCore@1f302620 url=http://127.0.0.1:59339/collection1 node=127.0.0.1:59339_ C1574_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:59339, core=collection1, node_name=127.0.0.1:59339_}
   [junit4]   2> 1391912 T5572 C1574 P59339 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59339/collection1/
   [junit4]   2> 1391912 T5572 C1574 P59339 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1391912 T5572 C1574 P59339 oasc.SyncStrategy.syncToMe http://127.0.0.1:59339/collection1/ has no replicas
   [junit4]   2> 1391913 T5572 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59339/collection1/ shard1
   [junit4]   2> 1391913 T5572 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1391913 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1391917 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1391918 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1391921 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1392022 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1392023 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1392070 T5572 oasc.ZkController.register We are http://127.0.0.1:59339/collection1/ and leader is http://127.0.0.1:59339/collection1/
   [junit4]   2> 1392070 T5572 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59339
   [junit4]   2> 1392070 T5572 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1392070 T5572 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1392070 T5572 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1392072 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1392072 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1392072 T5572 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1392072 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1392073 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1392074 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59339",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:59339_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1392075 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1392143 T5543 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1392143 T5543 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1392145 T5543 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40413
   [junit4]   2> 1392146 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1392146 T5543 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1392146 T5543 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003
   [junit4]   2> 1392147 T5543 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/'
   [junit4]   2> 1392157 T5543 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/solr.xml
   [junit4]   2> 1392177 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1392177 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1392191 T5543 oasc.CoreContainer.<init> New CoreContainer 117331818
   [junit4]   2> 1392191 T5543 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/]
   [junit4]   2> 1392192 T5543 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1392193 T5543 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1392193 T5543 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1392193 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1392193 T5543 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1392193 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1392194 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1392194 T5543 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1392194 T5543 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1392195 T5543 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1392195 T5543 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1392195 T5543 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1392195 T5543 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59412/solr
   [junit4]   2> 1392196 T5543 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1392196 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1392198 T5586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@241cf3bc name:ZooKeeperConnection Watcher:127.0.0.1:59412 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1392198 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1392201 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1392202 T5588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ab57073 name:ZooKeeperConnection Watcher:127.0.0.1:59412/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1392202 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1392207 T5543 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1393209 T5543 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43414_
   [junit4]   2> 1393210 T5543 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43414_
   [junit4]   2> 1393217 T5589 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1393218 T5589 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1393220 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1393220 T5589 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1393220 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1393220 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1393221 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1393222 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43414",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43414_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1393222 T5566 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1393222 T5566 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1393224 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1393326 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1393326 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1393326 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394220 T5589 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1394221 T5589 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1394221 T5589 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1394222 T5589 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1394223 T5589 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1394223 T5589 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/collection1/'
   [junit4]   2> 1394224 T5589 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 1394225 T5589 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 1394225 T5589 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 1394283 T5589 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1394316 T5589 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1394317 T5589 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1394322 T5589 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1394620 T5589 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1394625 T5589 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1394627 T5589 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1394634 T5589 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1394637 T5589 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1394639 T5589 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1394640 T5589 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1394640 T5589 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1394640 T5589 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1394641 T5589 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1394641 T5589 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1394641 T5589 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1394642 T5589 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1394642 T5589 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-003/collection1/, dataDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty1/
   [junit4]   2> 1394642 T5589 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3aa865cf
   [junit4]   2> 1394642 T5589 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty1
   [junit4]   2> 1394643 T5589 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty1/index/
   [junit4]   2> 1394643 T5589 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1394643 T5589 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty1/index
   [junit4]   2> 1394643 T5589 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=78.234375, floorSegmentMB=1.7265625, forceMergeDeletesPctAllowed=23.588817092619554, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1394644 T5589 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@67c503ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cdfcb42),segFN=segments_1,generation=1}
   [junit4]   2> 1394644 T5589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1394647 T5589 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1394647 T5589 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1394647 T5589 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1394647 T5589 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1394647 T5589 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1394648 T5589 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1394648 T5589 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1394648 T5589 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1394648 T5589 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1394649 T5589 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1394649 T5589 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1394649 T5589 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1394649 T5589 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1394650 T5589 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1394650 T5589 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1394650 T5589 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1394651 T5589 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1394653 T5589 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1394655 T5589 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1394655 T5589 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1394656 T5589 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.476493025439654]
   [junit4]   2> 1394656 T5589 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@67c503ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cdfcb42),segFN=segments_1,generation=1}
   [junit4]   2> 1394656 T5589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1394657 T5589 oass.SolrIndexSearcher.<init> Opening Searcher@59899de3[collection1] main
   [junit4]   2> 1394657 T5589 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1394657 T5589 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1394658 T5589 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1394658 T5589 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1394658 T5589 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1394658 T5589 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1394659 T5589 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1394659 T5589 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1394659 T5589 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1394659 T5589 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1394661 T5590 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59899de3[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1394663 T5589 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1394664 T5593 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43414 collection:collection1 shard:shard1
   [junit4]   2> 1394664 T5543 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1394665 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1394665 T5593 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1394669 T5593 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1394670 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394671 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394671 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394671 T5593 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1394671 T5593 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1575 name=collection1 org.apache.solr.core.SolrCore@83f61d url=http://127.0.0.1:43414/collection1 node=127.0.0.1:43414_ C1575_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:43414, core=collection1, node_name=127.0.0.1:43414_}
   [junit4]   2> 1394671 T5593 C1575 P43414 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43414/collection1/
   [junit4]   2> 1394672 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1394672 T5593 C1575 P43414 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1394672 T5593 C1575 P43414 oasc.SyncStrategy.syncToMe http://127.0.0.1:43414/collection1/ has no replicas
   [junit4]   2> 1394672 T5593 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43414/collection1/ shard1
   [junit4]   2> 1394673 T5593 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1394674 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394676 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394679 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394782 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394782 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394782 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394827 T5593 oasc.ZkController.register We are http://127.0.0.1:43414/collection1/ and leader is http://127.0.0.1:43414/collection1/
   [junit4]   2> 1394828 T5593 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43414
   [junit4]   2> 1394828 T5593 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1394828 T5593 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1394828 T5593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1394829 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394830 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394830 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394830 T5593 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1394831 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1394832 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43414",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43414_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1394833 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1394899 T5543 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1394900 T5543 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1394901 T5543 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34240
   [junit4]   2> 1394902 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1394902 T5543 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1394902 T5543 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004
   [junit4]   2> 1394902 T5543 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/'
   [junit4]   2> 1394912 T5543 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/solr.xml
   [junit4]   2> 1394935 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394935 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394935 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1394954 T5543 oasc.CoreContainer.<init> New CoreContainer 1060335041
   [junit4]   2> 1394954 T5543 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/]
   [junit4]   2> 1394955 T5543 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1394955 T5543 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1394955 T5543 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1394955 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1394956 T5543 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1394956 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1394956 T5543 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1394956 T5543 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1394957 T5543 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1394957 T5543 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1394957 T5543 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1394958 T5543 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1394958 T5543 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59412/solr
   [junit4]   2> 1394958 T5543 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1394959 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1394960 T5605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@496aba51 name:ZooKeeperConnection Watcher:127.0.0.1:59412 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1394961 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1394963 T5543 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1394964 T5607 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b7922f6 name:ZooKeeperConnection Watcher:127.0.0.1:59412/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1394964 T5543 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1394969 T5543 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1395972 T5543 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36955_
   [junit4]   2> 1395974 T5543 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36955_
   [junit4]   2> 1395982 T5608 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1395982 T5608 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1395983 T5608 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1395983 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1395983 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1395983 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1395984 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1395985 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36955",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36955_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1395985 T5566 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1395985 T5566 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1395987 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1396089 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1396089 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1396089 T5607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1396089 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1396983 T5608 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1396984 T5608 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1396984 T5608 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1396984 T5608 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1396985 T5608 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1396985 T5608 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/collection1/'
   [junit4]   2> 1396986 T5608 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 1396986 T5608 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 1396986 T5608 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 1397021 T5608 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1397054 T5608 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1397055 T5608 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1397061 T5608 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1397336 T5608 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1397341 T5608 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1397344 T5608 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1397352 T5608 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1397355 T5608 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1397358 T5608 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1397358 T5608 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1397359 T5608 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1397359 T5608 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1397360 T5608 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1397360 T5608 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1397360 T5608 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1397360 T5608 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1397360 T5608 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/collection1/, dataDir=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty2/
   [junit4]   2> 1397361 T5608 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3aa865cf
   [junit4]   2> 1397361 T5608 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty2
   [junit4]   2> 1397361 T5608 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty2/index/
   [junit4]   2> 1397361 T5608 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1397362 T5608 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-001/jetty2/index
   [junit4]   2> 1397362 T5608 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=78.234375, floorSegmentMB=1.7265625, forceMergeDeletesPctAllowed=23.588817092619554, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1397362 T5608 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@34d67595 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76397172),segFN=segments_1,generation=1}
   [junit4]   2> 1397363 T5608 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1397365 T5608 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1397365 T5608 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1397366 T5608 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1397366 T5608 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1397366 T5608 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1397366 T5608 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1397366 T5608 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1397367 T5608 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1397367 T5608 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1397367 T5608 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1397368 T5608 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1397368 T5608 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1397368 T5608 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1397368 T5608 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1397369 T5608 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1397369 T5608 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1397369 T5608 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1397371 T5608 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1397374 T5608 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1397374 T5608 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1397374 T5608 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.476493025439654]
   [junit4]   2> 1397375 T5608 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@34d67595 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76397172),segFN=segments_1,generation=1}
   [junit4]   2> 1397375 T5608 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1397375 T5608 oass.SolrIndexSearcher.<init> Opening Searcher@5e4f704c[collection1] main
   [junit4]   2> 1397375 T5608 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1397376 T5608 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1397376 T5608 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1397377 T5608 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1397377 T5608 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1397377 T5608 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1397377 T5608 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1397377 T5608 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1397378 T5608 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1397378 T5608 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1397380 T5609 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e4f704c[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1397382 T5608 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1397382 T5612 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36955 collection:collection1 shard:shard2
   [junit4]   2> 1397383 T5543 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1397383 T5543 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1397384 T5612 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1397384 T5543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1397385 T5543 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 30000 for each attempt
   [junit4]   2> 1397385 T5543 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30000
   [junit4]   2> 1397385 T5543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1397388 T5612 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1397389 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397389 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397390 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397390 T5612 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1397390 T5612 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1576 name=collection1 org.apache.solr.core.SolrCore@5832d49d url=http://127.0.0.1:36955/collection1 node=127.0.0.1:36955_ C1576_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:36955, core=collection1, node_name=127.0.0.1:36955_}
   [junit4]   2> 1397390 T5612 C1576 P36955 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36955/collection1/
   [junit4]   2> 1397390 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1397391 T5612 C1576 P36955 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1397391 T5612 C1576 P36955 oasc.SyncStrategy.syncToMe http://127.0.0.1:36955/collection1/ has no replicas
   [junit4]   2> 1397391 T5612 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36955/collection1/ shard2
   [junit4]   2> 1397391 T5612 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1397392 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397395 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397397 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397500 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397500 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397500 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397500 T5607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397545 T5612 oasc.ZkController.register We are http://127.0.0.1:36955/collection1/ and leader is http://127.0.0.1:36955/collection1/
   [junit4]   2> 1397546 T5612 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36955
   [junit4]   2> 1397546 T5612 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1397546 T5612 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1397546 T5612 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1397547 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397547 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397547 T5612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1397548 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397548 T5566 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1397549 T5566 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36955",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36955_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1397551 T5565 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1397653 T5607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397653 T5588 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397653 T5575 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1397653 T5565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1398387 T5543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1398387 T5543 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
   [junit4]   2> 1398389 T5573 oasc.SocketProxy$Acceptor.run accepted Socket[addr=/127.0.0.1,port=49749,localport=59339], receiveBufferSize:131015
   [junit4]   2> 1398391 T5573 oasc.SocketProxy$Bridge.<init> proxy connection Socket[addr=/127.0.0.1,port=35033,localport=44466], receiveBufferSize=131003
   [junit4]   2> ASYNC  NEW_CORE C1577 name=collection1 org.apache.solr.core.SolrCore@1f302620 url=http://127.0.0.1:59339/collection1 node=127.0.0.1:59339_ C1577_STATE=coll:control_collection core:collection1 props:{state=active, base_url=http://127.0.0.1:59339, core=collection1, node_name=127.0.0.1:59339_, leader=true}
   [junit4]   2> 1398392 T5559 C1577 P59339 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1398393 T5559 C1577 P59339 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1398393 T5559 C1577 P59339 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1398393 T5559 C1577 P59339 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 1398394 T5559 C15

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

ner is shutdown
   [junit4]   2> 1463724 T5607 oasc.SolrCore.close [c8n_1x2_shard1_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@44052644
   [junit4]   2> 1463730 T5607 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=148,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=6813,transaction_logs_total_number=1}
   [junit4]   2> 1463731 T5607 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 1463731 T5607 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 1463731 T5607 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 1463731 T5607 oasc.SolrCore.closeSearcher [c8n_1x2_shard1_replica2] Closing main searcher on request.
   [junit4]   2> 1463731 T5607 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1463732 T5607 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data/index [CachedDir<<refCount=0;path=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data/index;done=false>>]
   [junit4]   2> 1463732 T5607 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data/index
   [junit4]   2> 1463732 T5607 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data [CachedDir<<refCount=0;path=./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data;done=false>>]
   [junit4]   2> 1463732 T5607 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.HttpPartitionTest-27BA048E48164993-001/tempDir-004/c8n_1x2_shard1_replica2/data
   [junit4]   2> 1463732 T5607 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1463732 T5607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1463733 T5607 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1463733 T5607 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-27BA048E48164993-001
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=es_HN, timezone=America/Kentucky/Monticello
   [junit4]   2> NOTE: Linux 3.8.0-39-generic amd64/Oracle Corporation 1.7.0_55 (64-bit)/cpus=8,threads=1,free=199359640,total=519045120
   [junit4]   2> NOTE: All tests run in this JVM: [XmlUpdateRequestHandlerTest, ZkSolrClientTest, SolrPluginUtilsTest, TestManagedStopFilterFactory, TestNoOpRegenerator, TestDefaultSearchFieldResource, AnalysisErrorHandlingTest, PathHierarchyTokenizerFactoryTest, TestDistributedSearch, HdfsSyncSliceTest, TestSolrJ, BasicDistributedZk2Test, TestCollationFieldDocValues, TestLMDirichletSimilarityFactory, FieldAnalysisRequestHandlerTest, DistanceFunctionTest, TestBinaryField, InfoHandlerTest, TestFoldingMultitermQuery, TestFieldResource, TestSolrXMLSerializer, FunctionTest, TestRangeQuery, ChaosMonkeySafeLeaderTest, DeleteReplicaTest, AbstractAnalyticsStatsTest, SolrCoreCheckLockOnStartupTest, DistributedDebugComponentTest, TestQuerySenderNoQuery, TestHighFrequencyDictionaryFactory, SortByFunctionTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerTest, DateMathParserTest, TestAddFieldRealTimeGet, CurrencyFieldXmlFileTest, TestAnalyzedSuggestions, SolrCmdDistributorTest, ZkNodePropsTest, TestLRUCache, SystemInfoHandlerTest, TestFieldCollectionResource, TestCursorMarkWithoutUniqueKey, SolrXmlInZkTest, TestFastOutputStream, TestStressLucene, DefaultValueUpdateProcessorTest, TestSchemaNameResource, MultiTermTest, TestCoreDiscovery, TestUniqueKeyFieldResource, TestExceedMaxTermLength, NumericFieldsTest, HdfsRecoveryZkTest, AlternateDirectoryTest, TestOrdValues, HdfsCollectionsAPIDistributedZkTest, DirectSolrConnectionTest, TestReload, SignatureUpdateProcessorFactoryTest, HighlighterTest, TestRandomFaceting, TestSweetSpotSimilarityFactory, NoCacheHeaderTest, TestPhraseSuggestions, TestHashPartitioner, TestSchemaResource, TestDynamicFieldCollectionResource, BasicZkTest, ResourceLoaderTest, TestStressReorder, TestDocumentBuilder, CoreAdminRequestStatusTest, TermVectorComponentDistributedTest, TestRTGBase, SolrIndexConfigTest, BJQParserTest, TestIndexingPerformance, TestComponentsName, FullSolrCloudDistribCmdsTest, HdfsBasicDistributedZkTest, TestManagedResourceStorage, CoreMergeIndexesAdminHandlerTest, TestSerializedLuceneMatchVersion, CursorPagingTest, HdfsBasicDistributedZk2Test, OverseerRolesTest, DistributedExpandComponentTest, TestOverriddenPrefixQueryForCustomFieldType, TestRequestStatusCollectionAPI, TestSolrXmlPersistence, TestRecovery, TestCollationField, NotRequiredUniqueKeyTest, HighlighterConfigTest, TestCSVResponseWriter, ShardRoutingCustomTest, TestCollapseQParserPlugin, TestFiltering, CoreAdminCreateDiscoverTest, PrimUtilsTest, CollectionsAPIDistributedZkTest, LeaderElectionIntegrationTest, ShardRoutingTest, RecoveryZkTest, TestZkChroot, AutoCommitTest, TestDistributedGrouping, TestFaceting, DistributedSpellCheckComponentTest, TestRealTimeGet, TestJoin, StatsComponentTest, SpellCheckComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestLazyCores, OverseerCollectionProcessorTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SuggesterFSTTest, CoreAdminHandlerTest, SpatialFilterTest, TestCSVLoader, TestPseudoReturnFields, StatelessScriptUpdateProcessorFactoryTest, DocValuesMultiTest, XsltUpdateRequestHandlerTest, IndexBasedSpellCheckerTest, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest, RequestHandlersTest, TermVectorComponentTest, RequiredFieldsTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, IndexSchemaTest, JSONWriterTest, QueryParsingTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestBinaryResponseWriter, TestQuerySenderListener, TestSolrIndexConfig, ResponseLogComponentTest, TestStressRecovery, TestSystemIdResolver, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, TestUtils, FileUtilsTest, TestDistributedMissingSort, TestHighlightDedupGrouping, NoFacetTest, FieldFacetTest, RangeFacetTest, AliasIntegrationTest, DeleteInactiveReplicaTest, DistribCursorPagingTest, HttpPartitionTest]
   [junit4] Completed on J1 in 82.09s, 1 test, 1 failure <<< FAILURES!

[...truncated 182 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 404 suites, 1686 tests, 1 failure, 37 ignored (16 assumptions)

Total time: 57 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_55 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message