lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_45) - Build # 9046 - Failure!
Date Sat, 11 Jan 2014 01:25:27 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9046/
Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([C8454DD6654A0A73:49A3C3CE12156A4F]: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:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 10519 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 751748 T3979 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vh/q
   [junit4]   2> 751751 T3979 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-1389402768209
   [junit4]   2> 751752 T3979 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 751752 T3980 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 751852 T3979 oasc.ZkTestServer.run start zk server on port:55635
   [junit4]   2> 751854 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 751906 T3986 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66335c6d name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 751907 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 751907 T3979 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 751913 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 751916 T3988 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c98e9c7 name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 751916 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 751917 T3979 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 751922 T3979 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 751927 T3979 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 751930 T3979 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 751934 T3979 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> 751935 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 751941 T3979 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> 751942 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 751947 T3979 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> 751948 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 751952 T3979 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> 751952 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 751956 T3979 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> 751957 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 751961 T3979 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> 751962 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 751966 T3979 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> 751967 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 751970 T3979 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> 751971 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 751976 T3979 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> 751976 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 751981 T3979 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> 751981 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 751987 T3979 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> 751988 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using new style solr.xml
   [junit4]   2> 751994 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 751996 T3990 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61803a11 name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 751997 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 751997 T3979 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 752001 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752003 T3992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28a9d3e6 name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752003 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752004 T3979 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> 752005 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 752010 T3979 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> 752011 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 752016 T3979 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> 752016 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 752021 T3979 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> 752021 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 752025 T3979 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> 752026 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 752030 T3979 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> 752030 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 752034 T3979 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> 752035 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 752038 T3979 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> 752039 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 752043 T3979 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> 752044 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 752049 T3979 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> 752049 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 752053 T3979 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> 752054 T3979 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 752126 T3979 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 752132 T3979 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43820
   [junit4]   2> 752133 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 752134 T3979 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 752134 T3979 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389402768516
   [junit4]   2> 752135 T3979 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389402768516/'
   [junit4]   2> 752146 T3979 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-controljetty-1389402768516/solr.xml
   [junit4]   2> 752187 T3979 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 752187 T3979 oasc.CoreContainer.<init> New CoreContainer 1837231158
   [junit4]   2> 752187 T3979 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389402768516/]
   [junit4]   2> 752188 T3979 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 752188 T3979 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 752188 T3979 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 752189 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 752189 T3979 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 752189 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 752189 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 752189 T3979 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 752190 T3979 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 752191 T3979 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 752192 T3979 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 752192 T3979 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 752192 T3979 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55635/solr
   [junit4]   2> 752192 T3979 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 752193 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752195 T4003 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6cbb0564 name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752195 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752198 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752200 T4005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@290413ec name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752200 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752202 T3979 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 752206 T3979 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 752209 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 752211 T3979 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43820_vh%2Fq
   [junit4]   2> 752212 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43820_vh%2Fq
   [junit4]   2> 752214 T3979 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 752217 T3979 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 752224 T3979 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 752226 T3979 oasc.Overseer.start Overseer (id=91055899817476101-127.0.0.1:43820_vh%2Fq-n_0000000000) starting
   [junit4]   2> 752228 T3979 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 752230 T4007 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 752230 T3979 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 752232 T3979 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 752234 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 752236 T4006 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 752238 T3979 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-controljetty-1389402768516
   [junit4]   2> 752239 T3979 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-controljetty-1389402768516/conf/
   [junit4]   2> 752259 T3979 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 752259 T3979 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 752260 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 752260 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752262 T4010 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e1f1f20 name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752262 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752263 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 752264 T3979 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 752324 T3979 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 752325 T3979 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33010
   [junit4]   2> 752326 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 752326 T3979 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 752326 T3979 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721
   [junit4]   2> 752326 T3979 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/'
   [junit4]   2> 752335 T3979 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-1389402768721/solr.xml
   [junit4]   2> 752371 T3979 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 752371 T3979 oasc.CoreContainer.<init> New CoreContainer 1248145359
   [junit4]   2> 752371 T3979 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/]
   [junit4]   2> 752372 T3979 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 752373 T3979 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 752373 T3979 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 752373 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 752373 T3979 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 752373 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 752374 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 752374 T3979 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 752374 T3979 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 752376 T3979 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 752376 T3979 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 752376 T3979 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 752376 T3979 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55635/solr
   [junit4]   2> 752377 T3979 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 752377 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752380 T4021 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3925e531 name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752380 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752383 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 752385 T4023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a48d7dd name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 752385 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 752391 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 753397 T3979 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33010_vh%2Fq
   [junit4]   2> 753398 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33010_vh%2Fq
   [junit4]   2> 753400 T4010 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 753400 T4023 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 753400 T4005 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 753404 T3979 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-1389402768721
   [junit4]   2> 753405 T3979 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-1389402768721/conf/
   [junit4]   2> 753425 T3979 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 753426 T3979 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 753426 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 753486 T3979 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 753488 T3979 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41041
   [junit4]   2> 753488 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 753488 T3979 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 753489 T3979 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-1389402769883
   [junit4]   2> 753489 T3979 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-1389402769883/'
   [junit4]   2> 753498 T3979 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-1389402769883/solr.xml
   [junit4]   2> 753527 T3979 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 753528 T3979 oasc.CoreContainer.<init> New CoreContainer 942030627
   [junit4]   2> 753528 T3979 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-1389402769883/]
   [junit4]   2> 753529 T3979 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 753529 T3979 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 753529 T3979 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 753529 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 753529 T3979 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 753530 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 753530 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 753530 T3979 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 753530 T3979 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 753532 T3979 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 753532 T3979 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 753533 T3979 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 753533 T3979 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55635/solr
   [junit4]   2> 753533 T3979 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 753534 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 753535 T4035 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56fb2fa1 name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 753535 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 753537 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 753538 T4037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@df752ec name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 753539 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 753541 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 754544 T3979 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41041_vh%2Fq
   [junit4]   2> 754546 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41041_vh%2Fq
   [junit4]   2> 754549 T4005 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 754549 T4037 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 754549 T4010 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 754549 T4023 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 754558 T3979 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-1389402769883
   [junit4]   2> 754560 T3979 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-1389402769883/conf/
   [junit4]   2> 754589 T3979 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 754590 T3979 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 754590 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 754650 T3979 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 754653 T3979 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46137
   [junit4]   2> 754654 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 754654 T3979 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 754654 T3979 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-jetty3-1389402771048
   [junit4]   2> 754654 T3979 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-jetty3-1389402771048/'
   [junit4]   2> 754664 T3979 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-jetty3-1389402771048/solr.xml
   [junit4]   2> 754702 T3979 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 754702 T3979 oasc.CoreContainer.<init> New CoreContainer 784712823
   [junit4]   2> 754702 T3979 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-jetty3-1389402771048/]
   [junit4]   2> 754703 T3979 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 754704 T3979 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 754704 T3979 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 754704 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 754704 T3979 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 754704 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 754705 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 754705 T3979 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 754705 T3979 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 754707 T3979 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 754707 T3979 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 754707 T3979 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 754708 T3979 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55635/solr
   [junit4]   2> 754708 T3979 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 754708 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 754710 T4049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39e5789e name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 754710 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 754712 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 754713 T4051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@238f00dd name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 754713 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 754718 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 755721 T3979 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46137_vh%2Fq
   [junit4]   2> 755722 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46137_vh%2Fq
   [junit4]   2> 755724 T4023 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 755724 T4037 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 755724 T4005 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 755724 T4010 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 755724 T4051 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 755729 T3979 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-jetty3-1389402771048
   [junit4]   2> 755730 T3979 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-jetty3-1389402771048/conf/
   [junit4]   2> 755760 T3979 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 755761 T3979 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 755761 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 755819 T3979 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 755821 T3979 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44200
   [junit4]   2> 755822 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 755822 T3979 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 755822 T3979 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-1389402772218
   [junit4]   2> 755822 T3979 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-1389402772218/'
   [junit4]   2> 755832 T3979 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-1389402772218/solr.xml
   [junit4]   2> 755860 T3979 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 755860 T3979 oasc.CoreContainer.<init> New CoreContainer 618174525
   [junit4]   2> 755861 T3979 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-1389402772218/]
   [junit4]   2> 755862 T3979 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 755862 T3979 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 755862 T3979 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 755862 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 755862 T3979 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 755863 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 755863 T3979 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 755863 T3979 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 755863 T3979 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 755865 T3979 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 755865 T3979 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 755865 T3979 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 755866 T3979 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55635/solr
   [junit4]   2> 755866 T3979 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 755867 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 755868 T4063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f2dfb1 name:ZooKeeperConnection Watcher:127.0.0.1:55635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 755868 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 755870 T3979 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 755871 T4065 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@191920c name:ZooKeeperConnection Watcher:127.0.0.1:55635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 755871 T3979 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 755873 T3979 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 756875 T3979 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44200_vh%2Fq
   [junit4]   2> 756877 T3979 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44200_vh%2Fq
   [junit4]   2> 756879 T4051 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756879 T4005 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756879 T4037 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756879 T4010 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756879 T4023 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756879 T4065 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 756883 T3979 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-1389402772218
   [junit4]   2> 756884 T3979 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-1389402772218/conf/
   [junit4]   2> 756921 T3979 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 756921 T3979 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 756921 T3979 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 756929 T4018 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&name=solrj_collection&action=CREATE&collection.configName=conf1&router.field=myOwnField&router.name=compositeId&wt=javabin&version=2&numShards=2
   [junit4]   2> 756930 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 756931 T4007 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> 756931 T4007 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> 756931 T4007 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 756932 T4007 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 756934 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 756935 T4006 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 756936 T4006 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 756936 T4006 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 756937 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 756938 T4051 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> 756938 T4010 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> 756938 T4005 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> 756938 T4023 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> 756938 T4037 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> 756938 T4065 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> 757035 T4007 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 757035 T4007 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:46137_vh%2Fq
   [junit4]   2> 757035 T4007 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:41041_vh%2Fq
   [junit4]   2> 757035 T4007 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:44200_vh%2Fq
   [junit4]   2> 757036 T4007 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:33010_vh%2Fq
   [junit4]   2> 757038 T4019 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 757038 T4032 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 757038 T4046 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 757039 T4059 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 757039 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 757039 T4019 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 758255 T3983 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1215ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 758256 T4032 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 758256 T4046 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 758258 T4059 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 758259 T4006 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 758259 T4006 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:33010/vh/q",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:33010_vh%2Fq",
   [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> 758297 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 758298 T4006 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:41041/vh/q",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:41041_vh%2Fq",
   [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> 758337 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 758338 T4006 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:46137/vh/q",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:46137_vh%2Fq",
   [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> 758359 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 758360 T4006 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:44200/vh/q",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:44200_vh%2Fq",
   [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> 758362 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 758464 T4010 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> 758464 T4005 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> 758464 T4023 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> 758464 T4065 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> 758464 T4051 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> 758464 T4037 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> 759040 T4019 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 759041 T4019 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2
   [junit4]   2> 759041 T4019 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 759042 T4019 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 759042 T4019 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 759043 T4019 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/'
   [junit4]   2> 759086 T4019 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 759125 T4019 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 759127 T4019 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 759135 T4019 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 759258 T4046 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 759258 T4032 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 759259 T4059 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 759259 T4046 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389402771048/solrj_collection_shard1_replica1
   [junit4]   2> 759259 T4046 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 759259 T4059 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-jetty4-1389402772218/solrj_collection_shard2_replica1
   [junit4]   2> 759260 T4059 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 759260 T4046 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 759259 T4032 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389402769883/solrj_collection_shard1_replica2
   [junit4]   2> 759260 T4032 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 759260 T4059 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 759260 T4046 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 759261 T4032 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 759261 T4032 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 759261 T4059 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 759262 T4046 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-jetty3-1389402771048/solrj_collection_shard1_replica1/'
   [junit4]   2> 759262 T4032 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-1389402769883/solrj_collection_shard1_replica2/'
   [junit4]   2> 759263 T4059 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-1389402772218/solrj_collection_shard2_replica1/'
   [junit4]   2> 759291 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 759316 T4059 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 759320 T4032 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 759355 T4059 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 759356 T4059 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 759357 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 759358 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 759362 T4059 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 759378 T4046 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 759384 T4032 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 759386 T4032 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 759396 T4032 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 759671 T4019 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 759679 T4019 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 759712 T4019 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 759724 T4019 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759728 T4019 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759732 T4019 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759734 T4019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759734 T4019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759734 T4019 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759735 T4019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759736 T4019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759736 T4019 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 759737 T4019 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/data/
   [junit4]   2> 759737 T4019 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@68a43495
   [junit4]   2> 759738 T4019 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/data
   [junit4]   2> 759738 T4019 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 759738 T4019 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 759739 T4019 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389402768721/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 759739 T4019 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=26.8671875, floorSegmentMB=0.28515625, forceMergeDeletesPctAllowed=8.344049943950871, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.517391777665399
   [junit4]   2> 759740 T4019 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3727d6ff lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7f2e98d6),segFN=segments_1,generation=1}
   [junit4]   2> 759741 T4019 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 759762 T4019 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 759762 T4019 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 759763 T4019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 759763 T4019 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759764 T4019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759764 T4019 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 759764 T4019 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759765 T4019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759765 T4019 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 759766 T4019 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 759766 T4019 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 759767 T4019 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 759767 T4019 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 759768 T4019 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 759768 T4019 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 759769 T4019 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 759769 T4019 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 759773 T4019 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 759790 T4019 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 759791 T4019 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 759791 T4019 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=54.3310546875, floorSegmentMB=1.119140625, forceMergeDeletesPctAllowed=1.9611134088535054, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 759794 T4019 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3727d6ff lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7f2e98d6),segFN=segments_1,generation=1}
   [junit4]   2> 759803 T4019 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 759804 T4019 oass.SolrIndexSearcher.<init> Opening Searcher@590c7357 main
   [junit4]   2> 759809 T4019 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 759810 T4019 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:33010/vh/q collection:solrj_collection shard:shard2
   [junit4]   2> 759811 T4071 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@590c7357 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 759811 T4019 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 759818 T4019 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 759820 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 759820 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 759820 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 759820 T4019 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=180000
   [junit4]   2> 759821 T4006 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 759824 T4005 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 759891 T4032 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 759906 T4032 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 759910 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 759910 T4032 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 759916 T4046 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 759919 T4046 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 759922 T4059 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 759923 T4032 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759925 T4065 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> 759925 T4037 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> 759926 T4051 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> 759926 T4023 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> 759931 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759932 T4059 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 759932 T4032 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759935 T4059 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 759935 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759936 T4010 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> 759936 T4032 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759937 T4032 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759938 T4032 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759938 T4032 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759939 T4032 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759939 T4032 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759939 T4032 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 759940 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759940 T4032 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389402769883/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389402769883/solrj_collection_shard1_replica2/data/
   [junit4]   2> 759940 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759941 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759940 T4005 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> 759941 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759941 T4032 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@68a43495
   [junit4]   2> 759943 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759943 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759943 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 759943 T4032 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-jetty2-1389402769883/solrj_collection_shard1_replica2/data
   [junit4]   2> 759944 T4046 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389402771048/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389402771048/solrj_collection_shard1_replica1/data/
   [junit4]   2> 759944 T4032 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-jetty2-1389402769883/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 759944 T4046 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@68a43495
   [junit4]   2> 759944 T4032 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389402769883/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 759945 T4046 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-jetty3-1389402771048/solrj_collection_shard1_replica1/data
   [junit4]   2> 759945 T4032 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-jetty2-1389402769883/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 759946 T4046 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-jetty3-1389402771048/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 759946 T4032 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=26.8671875, floorSegmentMB=0.28515625, forceMergeDeletesPctAllowed=8.344049943950871, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.517391777665399
   [junit4]   2> 759946 T4046 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389402771048/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 759947 T4046 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-jetty3-1389402771048/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 759947 T4032 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10c42a7f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1049889f),segFN=segments_1,generation=1}
   [junit4]   2> 759948 T4032 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 759947 T4046 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=26.8671875, floorSegmentMB=0.28515625, forceMergeDeletesPctAllowed=8.344049943950871, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.517391777665399
   [junit4]   2> 759948 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@253c1733 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73151763),segFN=segments_1,generation=1}
   [junit4]   2> 759949 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 759950 T4032 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 759951 T4032 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 759951 T4032 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 759951 T4032 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759951 T4032 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759952 T4032 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 759952 T4032 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759952 T4059 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759953 T4032 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759952 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 759953 T4032 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 759953 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 759954 T4032 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 759954 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 759954 T4032 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 759954 T4032 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 759954 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759955 T4032 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 759955 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 759955 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 759955 T4032 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 759956 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759956 T4032 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 759956 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 759957 T4046 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 759957 T4032 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 759957 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 759957 T4059 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 759958 T4032 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 759958 T4046 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 759959 T4046 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 759959 T4046 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 759960 T4046 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 759960 T4032 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 759960 T4046 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 759961 T4046 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 759961 T4059 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759961 T4046 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 759962 T4059 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759963 T4059 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759963 T4059 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 759963 T4046 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 759964 T4032 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 759964 T4032 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 759964 T4059 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 759965 T4032 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=54.3310546875, floorSegmentMB=1.119140625, forceMergeDeletesPctAllowed=1.9611134088535054, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 759965 T4059 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 759965 T4032 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@10c42a7f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1049889f),segFN=segments_1,generation=1}
   [junit4]   2> 759965 T4059 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 759966 T4032 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 759966 T4059 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-jetty4-1389402772218/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/solrj_collection_shard2_replica1/data/
   [junit4]   2> 759966 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 759966 T4032 oass.SolrIndexSearcher.<init> Opening Searcher@5e4987a8 main
   [junit4]   2> 759967 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 759966 T4059 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@68a43495
   [junit4]   2> 759967 T4046 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=54.3310546875, floorSegmentMB=1.119140625, forceMergeDeletesPctAllowed=1.9611134088535054, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 759968 T4059 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-1389402772218/solrj_collection_shard2_replica1/data
   [junit4]   2> 759968 T4046 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@253c1733 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73151763),segFN=segments_1,generation=1}
   [junit4]   2> 759968 T4059 oasc.SolrCore.getN

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

junit4]   2> 921085 T3979 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/awholynewcollection_2_shard1_replica1/data
   [junit4]   2> 921086 T3979 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/awholynewcollection_2_shard1_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/awholynewcollection_2_shard1_replica1/data/index;done=false>>]
   [junit4]   2> 921086 T3979 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/awholynewcollection_2_shard1_replica1/data/index
   [junit4]   2> 921086 T3979 oasc.SolrCore.close [halfdeletedcollection_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ad23857
   [junit4]   2> 921091 T3979 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 921091 T3979 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 921091 T3979 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 921091 T3979 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 921092 T3979 oasc.SolrCore.closeSearcher [halfdeletedcollection_shard1_replica1] Closing main searcher on request.
   [junit4]   2> 921092 T3979 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 921092 T3979 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data;done=false>>]
   [junit4]   2> 921092 T3979 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data
   [junit4]   2> 921093 T3979 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data/index;done=false>>]
   [junit4]   2> 921093 T3979 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389402772218/halfdeletedcollection_shard1_replica1/data/index
   [junit4]   2> 921115 T3979 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/vh/q,null}
   [junit4]   2> 921170 T3979 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 921174 T3979 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55635 55635
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   1> client port:0.0.0.0/0.0.0.0:55635
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=C8454DD6654A0A73 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP -Dtests.timezone=UTC -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE  170s J0 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C8454DD6654A0A73:49A3C3CE12156A4F]:0)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectionWithDownNodes(CollectionsAPIDistributedZkTest.java:390)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 921392 T3979 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 169650 T3978 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
   [junit4]   2> 922385 T4005 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 922494 T4051 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 922595 T4065 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=ja_JP, timezone=UTC
   [junit4]   2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=8,threads=2,free=30371920,total=241172480
   [junit4]   2> NOTE: All tests run in this JVM: [TestRandomDVFaceting, TestRealTimeGet, ResponseLogComponentTest, UpdateParamsTest, TestShardHandlerFactory, TestManagedSchema, StatelessScriptUpdateProcessorFactoryTest, TestDocumentBuilder, DateMathParserTest, DocumentBuilderTest, CoreAdminCreateDiscoverTest, DeleteShardTest, TestBadConfig, LukeRequestHandlerTest, TestReplicationHandler, SimpleFacetsTest, TestSolrXmlPersistor, SliceStateUpdateTest, SOLR749Test, TestTrie, SolrIndexSplitterTest, URLClassifyProcessorTest, SolrInfoMBeanTest, TestBM25SimilarityFactory, ScriptEngineTest, AutoCommitTest, TestLMDirichletSimilarityFactory, CursorPagingTest, SynonymTokenizerTest, TestPseudoReturnFields, HdfsUnloadDistributedZkTest, PeerSyncTest, HdfsChaosMonkeySafeLeaderTest, TestMergePolicyConfig, LegacyHTMLStripCharFilterTest, TestClassNameShortening, TestSolrXMLSerializer, TestDocSet, SpellPossibilityIteratorTest, TestAnalyzeInfixSuggestions, BJQParserTest, CoreMergeIndexesAdminHandlerTest, CircularListTest, SolrXmlInZkTest, HdfsDirectoryTest, UUIDFieldTest, ParsingFieldUpdateProcessorsTest, CopyFieldTest, TestSolrDeletionPolicy1, TestJmxMonitoredMap, BasicFunctionalityTest, TestSurroundQueryParser, TestCharFilters, DistributedQueryElevationComponentTest, ResourceLoaderTest, HdfsSyncSliceTest, TestStressVersions, TestPostingsSolrHighlighter, SampleTest, TestElisionMultitermQuery, HdfsBasicDistributedZk2Test, OverseerCollectionProcessorTest, PolyFieldTest, DistributedDebugComponentTest, HdfsLockFactoryTest, DistributedSpellCheckComponentTest, FastVectorHighlighterTest, DOMUtilTest, TestSolrXmlPersistence, TriLevelCompositeIdRoutingTest, TermsComponentTest, HdfsCollectionsAPIDistributedZkTest, CoreAdminHandlerTest, TestQueryUtils, ZkControllerTest, OverseerTest, SchemaVersionSpecificBehaviorTest, DistributedSuggestComponentTest, TestSort, TestRemoteStreaming, BlockCacheTest, SearchHandlerTest, EchoParamsTest, TestDynamicFieldCollectionResource, ShardRoutingTest, DirectUpdateHandlerOptimizeTest, TestLuceneMatchVersion, TestFunctionQuery, AddSchemaFieldsUpdateProcessorFactoryTest, BasicDistributedZkTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J0 in 170.94s, 1 test, 1 failure <<< FAILURES!

[...truncated 542 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: 47 minutes 20 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message