You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/01/12 07:19:59 UTC

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b121) - Build # 9060 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9060/
Java: 32bit/jdk1.8.0-ea-b121 -client -XX:+UseConcMarkSweepGC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([42760432F0D51BEF:C3908A2A878A7BD3]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertFalse(Assert.java:68)
	at org.junit.Assert.assertFalse(Assert.java:79)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectionWithDownNodes(CollectionsAPIDistributedZkTest.java:390)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	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:70)
	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:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	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 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:70)
	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:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10470 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 658035 T2619 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 658038 T2619 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1389506902108
   [junit4]   2> 658039 T2619 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 658039 T2620 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 658139 T2619 oasc.ZkTestServer.run start zk server on port:33548
   [junit4]   2> 658142 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658329 T2626 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c325c0 name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658329 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658330 T2619 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 658334 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658335 T2628 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16f5437 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658335 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658336 T2619 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 658338 T2619 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 658340 T2619 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 658342 T2619 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 658344 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 658345 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 658348 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 658349 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 658352 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 658352 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 658355 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 658355 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 658358 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 658358 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 658360 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 658361 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 658363 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 658364 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 658368 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 658368 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 658371 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 658371 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 658375 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 658375 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 658377 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 658377 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using new style solr.xml
   [junit4]   2> 658380 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658381 T2630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16eabe0 name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658382 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658382 T2619 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 658384 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658385 T2632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1425a2 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658385 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658386 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 658387 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 658390 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 658390 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 658393 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 658393 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 658396 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 658396 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 658398 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 658399 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 658401 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 658401 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 658403 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 658404 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 658406 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 658406 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 658409 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 658409 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 658411 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 658412 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 658414 T2619 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 658414 T2619 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 658494 T2619 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 658504 T2619 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๕๗๘๔๙
   [junit4]   2> 658505 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 658506 T2619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 658506 T2619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486
   [junit4]   2> 658506 T2619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/'
   [junit4]   2> 658520 T2619 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solr.xml
   [junit4]   2> 658530 T2619 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 658531 T2619 oasc.CoreContainer.<init> New CoreContainer 3618678
   [junit4]   2> 658531 T2619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/]
   [junit4]   2> 658532 T2619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 658532 T2619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 658533 T2619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 658533 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 658533 T2619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 658534 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 658534 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 658535 T2619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 658535 T2619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 658537 T2619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 658538 T2619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 658538 T2619 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 658539 T2619 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33548/solr
   [junit4]   2> 658539 T2619 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 658540 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658542 T2643 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11f585 name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658542 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658544 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658545 T2645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19cc45b name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658546 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658547 T2619 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 658550 T2619 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 658552 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 658554 T2619 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57849_
   [junit4]   2> 658555 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57849_
   [junit4]   2> 658557 T2619 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 658558 T2619 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 658561 T2619 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 658563 T2619 oasc.Overseer.start Overseer (id=91062724336680965-127.0.0.1:57849_-n_0000000000) starting
   [junit4]   2> 658566 T2619 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 658569 T2619 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 658569 T2647 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 658571 T2619 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 658572 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 658575 T2646 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 658576 T2619 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486
   [junit4]   2> 658577 T2619 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/conf/
   [junit4]   2> 658612 T2619 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 658612 T2619 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 658613 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 658614 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658615 T2650 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@300b3b name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658616 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658617 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 658618 T2619 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 658695 T2619 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 658697 T2619 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๕๔๙๓๐
   [junit4]   2> 658698 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 658698 T2619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 658698 T2619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688
   [junit4]   2> 658699 T2619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/'
   [junit4]   2> 658712 T2619 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solr.xml
   [junit4]   2> 658725 T2619 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 658725 T2619 oasc.CoreContainer.<init> New CoreContainer 23014009
   [junit4]   2> 658726 T2619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/]
   [junit4]   2> 658726 T2619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 658726 T2619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 658727 T2619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 658727 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 658727 T2619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 658728 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 658728 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 658728 T2619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 658728 T2619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 658730 T2619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 658731 T2619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 658731 T2619 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 658731 T2619 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33548/solr
   [junit4]   2> 658732 T2619 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 658732 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658734 T2661 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@edf866 name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658734 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658736 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 658737 T2663 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fd0b64 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 658737 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 658740 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 659743 T2619 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54930_
   [junit4]   2> 659744 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54930_
   [junit4]   2> 659746 T2645 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 659746 T2650 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 659747 T2663 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 659750 T2619 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688
   [junit4]   2> 659751 T2619 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/conf/
   [junit4]   2> 659777 T2619 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 659778 T2619 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 659778 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 659856 T2619 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 659863 T2619 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๔๗๐๓๔
   [junit4]   2> 659864 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 659864 T2619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 659865 T2619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848
   [junit4]   2> 659865 T2619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848/'
   [junit4]   2> 659879 T2619 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848/solr.xml
   [junit4]   2> 659888 T2619 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 659888 T2619 oasc.CoreContainer.<init> New CoreContainer 23620918
   [junit4]   2> 659888 T2619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848/]
   [junit4]   2> 659889 T2619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 659889 T2619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 659890 T2619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 659890 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 659890 T2619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 659890 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 659891 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 659891 T2619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 659891 T2619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 659893 T2619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 659894 T2619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 659894 T2619 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 659894 T2619 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33548/solr
   [junit4]   2> 659895 T2619 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 659895 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 659896 T2675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ef0cc name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 659897 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 659899 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 659900 T2677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@599a07 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 659900 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 659903 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 660906 T2619 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47034_
   [junit4]   2> 660907 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47034_
   [junit4]   2> 660910 T2645 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 660910 T2677 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 660910 T2663 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 660910 T2650 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 660913 T2619 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848
   [junit4]   2> 660914 T2619 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389506903848/conf/
   [junit4]   2> 660965 T2619 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 660966 T2619 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 660967 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 661039 T2619 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 661041 T2619 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๔๘๖๒๖
   [junit4]   2> 661042 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 661042 T2619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 661043 T2619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036
   [junit4]   2> 661043 T2619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/'
   [junit4]   2> 661057 T2619 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solr.xml
   [junit4]   2> 661071 T2619 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 661072 T2619 oasc.CoreContainer.<init> New CoreContainer 9270912
   [junit4]   2> 661072 T2619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/]
   [junit4]   2> 661073 T2619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 661073 T2619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 661073 T2619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 661074 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 661074 T2619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 661074 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 661075 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 661075 T2619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 661075 T2619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 661077 T2619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 661078 T2619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 661078 T2619 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 661078 T2619 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33548/solr
   [junit4]   2> 661079 T2619 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 661079 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 661081 T2689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d2e1ee name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 661081 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 661083 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 661084 T2691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1361d40 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 661084 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 661169 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 662173 T2619 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48626_
   [junit4]   2> 662175 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48626_
   [junit4]   2> 662179 T2650 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 662180 T2663 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 662180 T2645 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 662180 T2677 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 662180 T2691 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 662186 T2619 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036
   [junit4]   2> 662188 T2619 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/conf/
   [junit4]   2> 662223 T2619 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 662224 T2619 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 662224 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 662291 T2619 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 662294 T2619 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๔๕๕๒๗
   [junit4]   2> 662295 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 662295 T2619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 662296 T2619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293
   [junit4]   2> 662296 T2619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/'
   [junit4]   2> 662308 T2619 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solr.xml
   [junit4]   2> 662316 T2619 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 662316 T2619 oasc.CoreContainer.<init> New CoreContainer 24754752
   [junit4]   2> 662317 T2619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/]
   [junit4]   2> 662317 T2619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 662317 T2619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 662318 T2619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 662318 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 662318 T2619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 662319 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 662319 T2619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 662319 T2619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 662319 T2619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 662321 T2619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 662322 T2619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 662322 T2619 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 662322 T2619 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33548/solr
   [junit4]   2> 662322 T2619 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 662323 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 662325 T2703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@141f7bb name:ZooKeeperConnection Watcher:127.0.0.1:33548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 662325 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 662328 T2619 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 662330 T2705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@124e268 name:ZooKeeperConnection Watcher:127.0.0.1:33548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 662330 T2619 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 662338 T2619 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 663343 T2619 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45527_
   [junit4]   2> 663346 T2619 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45527_
   [junit4]   2> 663349 T2677 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663349 T2705 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663350 T2645 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663349 T2663 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663349 T2691 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663349 T2650 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 663353 T2619 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293
   [junit4]   2> 663354 T2619 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/conf/
   [junit4]   2> 663386 T2619 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 663387 T2619 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 663387 T2619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 663396 T2656 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&name=solrj_collection&router.name=compositeId&action=CREATE&numShards=2&wt=javabin&version=2
   [junit4]   2> 663397 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663399 T2647 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 663399 T2647 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 663399 T2647 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 663399 T2647 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 663403 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663405 T2646 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 663406 T2646 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 663406 T2646 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 663409 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663410 T2650 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663410 T2691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663410 T2705 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663410 T2663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663410 T2677 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663410 T2645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663504 T2647 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 663504 T2647 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:54930_
   [junit4]   2> 663505 T2647 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:48626_
   [junit4]   2> 663506 T2647 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:57849_
   [junit4]   2> 663507 T2647 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:45527_
   [junit4]   2> 663508 T2687 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 663508 T2658 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 663509 T2698 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 663508 T2639 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 663510 T2687 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 663510 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663510 T2698 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 663510 T2639 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 663510 T2658 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 663511 T2646 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 663512 T2646 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:48626",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:48626_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 663514 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663515 T2646 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:54930",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54930_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 663517 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663517 T2646 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:45527",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:45527_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 663519 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663520 T2646 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:57849",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57849_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 663522 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 663624 T2650 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663624 T2645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663624 T2705 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663624 T2663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663624 T2691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 663624 T2677 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 664510 T2687 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 664511 T2698 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 664511 T2658 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 664511 T2639 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 664512 T2698 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2
   [junit4]   2> 664513 T2698 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 664512 T2687 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2
   [junit4]   2> 664514 T2698 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 664513 T2639 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1
   [junit4]   2> 664515 T2639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 664513 T2658 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1
   [junit4]   2> 664516 T2639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 664516 T2639 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 664516 T2658 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 664514 T2698 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 664514 T2687 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 664518 T2658 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 664518 T2639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/'
   [junit4]   2> 664519 T2687 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 664521 T2687 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 664519 T2658 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 664519 T2698 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/'
   [junit4]   2> 664523 T2687 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/'
   [junit4]   2> 664523 T2658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/'
   [junit4]   2> 664554 T2639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 664561 T2687 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 664564 T2639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 664566 T2639 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 664575 T2658 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 664575 T2698 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 664579 T2687 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 664581 T2687 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 664583 T2639 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 664586 T2698 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 664587 T2698 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 664587 T2687 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 664588 T2658 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 664590 T2658 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 664601 T2698 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 664607 T2658 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 664751 T2687 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 664760 T2687 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 664762 T2687 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 664772 T2687 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664774 T2687 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664777 T2687 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664778 T2687 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664778 T2687 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664779 T2687 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664780 T2687 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664780 T2687 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664780 T2687 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 664781 T2687 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/data/
   [junit4]   2> 664781 T2687 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a667f
   [junit4]   2> 664782 T2687 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/data
   [junit4]   2> 664782 T2687 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 664782 T2687 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 664783 T2687 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389506905036/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 664783 T2687 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=43.6064453125, floorSegmentMB=2.181640625, forceMergeDeletesPctAllowed=28.45046719317403, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.16136069854613888
   [junit4]   2> 664784 T2687 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@129fa89 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fa16e1),segFN=segments_1,generation=1}
   [junit4]   2> 664784 T2687 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 664795 T2687 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 664795 T2687 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 664796 T2687 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 664796 T2687 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664796 T2658 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 664796 T2687 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664797 T2687 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 664798 T2687 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664798 T2687 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664798 T2687 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 664799 T2639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 664799 T2687 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 664800 T2687 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 664800 T2687 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 664800 T2687 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 664801 T2687 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 664801 T2687 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 664802 T2687 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 664802 T2687 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 664803 T2658 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 664803 T2639 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 664804 T2687 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 664805 T2698 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 664805 T2639 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 664805 T2658 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 664805 T2687 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 664806 T2687 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 664807 T2687 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=74.5380859375, floorSegmentMB=1.373046875, forceMergeDeletesPctAllowed=15.667210695932868, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 664808 T2687 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@129fa89 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fa16e1),segFN=segments_1,generation=1}
   [junit4]   2> 664808 T2687 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 664808 T2687 oass.SolrIndexSearcher.<init> Opening Searcher@18369eb main
   [junit4]   2> 664810 T2698 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 664812 T2711 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@18369eb main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 664812 T2698 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 664815 T2687 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 664816 T2687 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:48626 collection:solrj_collection shard:shard1
   [junit4]   2> 664817 T2687 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 664819 T2639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664820 T2658 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664823 T2658 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664823 T2687 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 664823 T2639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664826 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 664826 T2658 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664826 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 664826 T2687 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=180000
   [junit4]   2> 664826 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 664827 T2639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664827 T2698 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664827 T2658 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664829 T2658 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664829 T2646 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 664829 T2639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664830 T2639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664829 T2658 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664830 T2698 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 664830 T2639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664831 T2658 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664832 T2658 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664832 T2639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664833 T2639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664832 T2645 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 664832 T2658 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 664833 T2698 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664833 T2639 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 664834 T2658 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/data/
   [junit4]   2> 664834 T2639 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/data/
   [junit4]   2> 664834 T2658 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a667f
   [junit4]   2> 664834 T2698 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664835 T2639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a667f
   [junit4]   2> 664836 T2658 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/data
   [junit4]   2> 664836 T2658 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 664835 T2698 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664837 T2658 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 664836 T2639 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/data
   [junit4]   2> 664838 T2639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 664838 T2658 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389506902688/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 664837 T2698 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 664839 T2658 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=43.6064453125, floorSegmentMB=2.181640625, forceMergeDeletesPctAllowed=28.45046719317403, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.16136069854613888
   [junit4]   2> 664838 T2639 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 664840 T2658 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@106106c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c58166),segFN=segments_1,generation=1}
   [junit4]   2> 664841 T2658 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 664841 T2639 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389506902486/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 664840 T2698 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 664842 T2698 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 664842 T2639 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=43.6064453125, floorSegmentMB=2.181640625, forceMergeDeletesPctAllowed=28.45046719317403, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.16136069854613888
   [junit4]   2> 664843 T2698 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 664843 T2639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c39653 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1fc30a5),segFN=segments_1,generation=1}
   [junit4]   2> 664844 T2639 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 664844 T2698 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/data/
   [junit4]   2> 664845 T2698 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a667f
   [junit4]   2> 664845 T2658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 664845 T2658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 664845 T2698 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/data
   [junit4]   2> 664846 T2658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 664846 T2698 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 664847 T2658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664847 T2639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 664847 T2698 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 664848 T2639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 664847 T2658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664849 T2639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 664848 T2698 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389506906293/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 664849 T2639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664849 T2658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 664850 T2639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664850 T2698 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=43.6064453125, floorSegmentMB=2.181640625, forceMergeDeletesPctAllowed=28.45046719317403, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.16136069854613888
   [junit4]   2> 664851 T2639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 664851 T2698 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@154e982 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1abaf34),segFN=segments_1,generation=1}
   [junit4]   2> 664852 T2698 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 664851 T2658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664852 T2639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664852 T2658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664853 T2639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664853 T2639 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 664853 T2658 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 664854 T2639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 664854 T2658 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 664855 T2639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 664855 T2639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 664855 T2698 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 664855 T2639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 664855 T2658 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 664856 T2639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 664856 T2698 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 664857 T2639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 664856 T2658 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 664857 T2639 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 664857 T2698 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 664858 T2639 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 664858 T2698 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664858 T2658 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 664859 T2698 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 664859 T2639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 664860 T2698 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 664860 T2658 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 664860 T2698 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664861 T2658 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 664861 T2698 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 664861 T2698 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 664861 T2639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 664862 T2698 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 664861 T2658 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 664862 T2698 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 664863 T2698 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 664862 T2639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 664863 T2698 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 664864 T2639 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=74.5380859375, floorSegmentMB=1.373046875, forceMergeDeletesPctAllowed=15.667210695932868, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 664864 T2698 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 664863 T2658 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 664865 T2698 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 664864 T2639 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: nu

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

778465 T2705 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [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.exists(ZooKeeper.java:1041)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:273)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 	
   [junit4]   2> 778466 T2705 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/nodes_used_collection/leader_elect/shard2/election/91062724336680974-core_node3-n_0000000001
   [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.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:276)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 778466 T2705 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> 778467 T2705 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 778467 T2705 oasc.LeaderElector$1.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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:91)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 778467 T2705 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {other_tl1=PostingsFormat(name=Lucene41VarGapFixedInterval), _version_=PostingsFormat(name=Lucene41VarGapFixedInterval), multiDefault=PostingsFormat(name=Direct), a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), a_si=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), range_facet_sl=Pulsing41(freqCutoff=11 minBlockSize=63 maxBlockSize=163), range_facet_si=PostingsFormat(name=Direct), id=PostingsFormat(name=Memory doPackFST= false), text=Pulsing41(freqCutoff=11 minBlockSize=63 maxBlockSize=163), range_facet_l=PostingsFormat(name=Lucene41VarGapFixedInterval), timestamp=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=th_TH_TH_#u-nu-thai, timezone=Europe/Simferopol
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=120368080,total=240455680
   [junit4]   2> NOTE: All tests run in this JVM: [DeleteShardTest, ZkControllerTest, DistributedQueryElevationComponentTest, QueryFacetTest, StatelessScriptUpdateProcessorFactoryTest, ExternalFileFieldSortTest, OverseerTest, TestQueryUtils, TestMergePolicyConfig, TestPHPSerializedResponseWriter, TestBadConfig, HdfsRecoveryZkTest, RegexBoostProcessorTest, TestSearchPerf, TestRecoveryHdfs, SliceStateTest, TestLRUCache, TestSystemIdResolver, FunctionTest, DocValuesTest, TestElisionMultitermQuery, TestValueSourceCache, TestStressVersions, TestFieldTypeResource, TestClassNameShortening, TestGroupingSearch, UnloadDistributedZkTest, UpdateParamsTest, DocumentBuilderTest, HdfsSyncSliceTest, TestSolrQueryParserDefaultOperatorResource, ResponseLogComponentTest, BinaryUpdateRequestHandlerTest, TestPseudoReturnFields, TestSurroundQueryParser, TestPostingsSolrHighlighter, TestLuceneMatchVersion, TestSort, SolrTestCaseJ4Test, TestJoin, TestFieldTypeCollectionResource, TestRandomDVFaceting, SchemaVersionSpecificBehaviorTest, DistributedSpellCheckComponentTest, BadComponentTest, AnalysisAfterCoreReloadTest, ResourceLoaderTest, IndexSchemaTest, SimpleFacetsTest, SpellPossibilityIteratorTest, BJQParserTest, EchoParamsTest, QueryResultKeyTest, OverseerCollectionProcessorTest, DistributedDebugComponentTest, RangeFacetTest, SampleTest, TestReversedWildcardFilterFactory, TestManagedSchemaFieldResource, CursorMarkTest, QueryEqualityTest, TestShardHandlerFactory, TestRealTimeGet, TestInfoStreamLogging, RecoveryZkTest, TestSolrXMLSerializer, ScriptEngineTest, ClusterStateTest, TestDocumentBuilder, HdfsCollectionsAPIDistributedZkTest, BasicDistributedZkTest, TestSolrXmlPersistor, TestRemoteStreaming, FieldFacetTest, MoreLikeThisHandlerTest, LoggingHandlerTest, CircularListTest, DistributedQueryComponentCustomSortTest, TestDocBasedVersionConstraints, TestDefaultSearchFieldResource, JsonLoaderTest, TestFileDictionaryLookup, TestSuggestSpellingConverter, TestRandomMergePolicy, CacheHeaderTest, FastVectorHighlighterTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J0 in 120.56s, 1 test, 1 failure <<< FAILURES!

[...truncated 618 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: 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:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1304: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:937: There were test failures: 362 suites, 1592 tests, 1 failure, 34 ignored (6 assumptions)

Total time: 45 minutes 42 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b121 -client -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure