You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/10 22:05:20 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_40) - Build #
7828 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7828/
Java: 32bit/jdk1.7.0_40 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 330 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
at __randomizedtesting.SeedInfo.seed([9E6D286B31AA6909:1F8BA67346F50935]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:172)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:610)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:194)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:724)
Build Log:
[...truncated 10257 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 574976 T2607 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 574979 T2607 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1381434574553
[junit4] 2> 574980 T2607 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 574980 T2608 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 575080 T2607 oasc.ZkTestServer.run start zk server on port:38246
[junit4] 2> 575081 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575264 T2614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c8954 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575264 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575264 T2607 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 575269 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575270 T2616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f36d6e name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575270 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575270 T2607 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 575272 T2607 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 575274 T2607 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 575275 T2607 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 575277 T2607 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> 575277 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 575280 T2607 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> 575280 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 575283 T2607 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> 575283 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 575285 T2607 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> 575285 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 575287 T2607 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> 575287 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 575289 T2607 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> 575289 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 575291 T2607 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> 575291 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 575294 T2607 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> 575294 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 575296 T2607 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> 575297 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 575298 T2607 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> 575299 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using old style solr.xml
[junit4] 2> 575364 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 575367 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40316
[junit4] 2> 575375 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 575376 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 575376 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874
[junit4] 2> 575377 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/'
[junit4] 2> 575386 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/solr.xml
[junit4] 2> 575416 T2607 oasc.CoreContainer.<init> New CoreContainer 17983889
[junit4] 2> 575416 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/]
[junit4] 2> 575417 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 575417 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 575419 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 575421 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 575421 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 575421 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
[junit4] 2> 575422 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 575422 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575424 T2627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@991529 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575424 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575426 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 575427 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575428 T2629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15d9902 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575428 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575430 T2607 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 575432 T2607 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 575434 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 575435 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40316_
[junit4] 2> 575436 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40316_
[junit4] 2> 575438 T2607 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 575441 T2607 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 575443 T2607 oasc.Overseer.start Overseer (id=90533696278036483-127.0.0.1:40316_-n_0000000000) starting
[junit4] 2> 575446 T2607 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 575449 T2631 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 575449 T2607 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 575451 T2607 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 575452 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 575454 T2630 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 575456 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 575456 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 575456 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 575457 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 575458 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575459 T2634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e2660a name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575459 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575460 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 575462 T2607 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 575525 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 575527 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47161
[junit4] 2> 575528 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 575528 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 575528 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035
[junit4] 2> 575529 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/'
[junit4] 2> 575538 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/solr.xml
[junit4] 2> 575575 T2607 oasc.CoreContainer.<init> New CoreContainer 17617877
[junit4] 2> 575576 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/]
[junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 575579 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 575579 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 575580 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 575580 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 575581 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
[junit4] 2> 575581 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 575582 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575583 T2645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3aae2 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575584 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575585 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 575587 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 575588 T2647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@165826a name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 575588 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 575591 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 576593 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47161_
[junit4] 2> 576595 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47161_
[junit4] 2> 576597 T2634 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 576597 T2629 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 576598 T2647 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 576601 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 576601 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 576602 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 576665 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 576667 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59452
[junit4] 2> 576667 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 576667 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 576668 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175
[junit4] 2> 576668 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/'
[junit4] 2> 576678 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/solr.xml
[junit4] 2> 576706 T2607 oasc.CoreContainer.<init> New CoreContainer 2682644
[junit4] 2> 576706 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/]
[junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 576709 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 576710 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 576711 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 576711 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
[junit4] 2> 576711 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 576712 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 576714 T2659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e97b5 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 576714 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 576716 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 576717 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 576718 T2661 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e851a2 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 576718 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 576722 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 577724 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59452_
[junit4] 2> 577725 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59452_
[junit4] 2> 577727 T2629 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 577727 T2634 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 577727 T2647 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 577728 T2661 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 577732 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 577732 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 577732 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 577797 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 577799 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55534
[junit4] 2> 577799 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 577800 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 577800 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306
[junit4] 2> 577800 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/'
[junit4] 2> 577810 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/solr.xml
[junit4] 2> 577849 T2607 oasc.CoreContainer.<init> New CoreContainer 15165292
[junit4] 2> 577849 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/]
[junit4] 2> 577850 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 577850 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 577853 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 577854 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 577854 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 577854 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
[junit4] 2> 577855 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 577856 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 577893 T2673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10eb045 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 577894 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 577896 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 577898 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 577899 T2675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15387e1 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 577900 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 577904 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 578906 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55534_
[junit4] 2> 578907 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55534_
[junit4] 2> 578911 T2634 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 578911 T2629 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 578911 T2661 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 578911 T2647 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 578911 T2675 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 578915 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 578915 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 578915 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 578980 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 578982 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59314
[junit4] 2> 578982 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 578982 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 578983 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489
[junit4] 2> 578983 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/'
[junit4] 2> 578993 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/solr.xml
[junit4] 2> 579021 T2607 oasc.CoreContainer.<init> New CoreContainer 6201038
[junit4] 2> 579021 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/]
[junit4] 2> 579022 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 579022 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 579025 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 579026 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 579026 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 579026 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
[junit4] 2> 579027 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 579027 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 579029 T2687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dd9220 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 579029 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 579031 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 579032 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 579033 T2689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd8586 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 579033 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 579037 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 580039 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59314_
[junit4] 2> 580041 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59314_
[junit4] 2> 580044 T2647 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580044 T2634 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580045 T2689 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580044 T2629 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580045 T2661 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580045 T2675 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 580049 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 580049 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 580050 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 580050 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 580052 T2642 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4] 2> 580053 T2629 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580064 T2631 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "numShards":"2",
[junit4] 2> "name":"nodes_used_collection",
[junit4] 2> "replicationFactor":"2"}
[junit4] 2> 580064 T2631 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "numShards":"2",
[junit4] 2> "name":"nodes_used_collection",
[junit4] 2> "replicationFactor":"2"}
[junit4] 2> 581461 T2630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 581462 T2630 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: nodes_used_collection
[junit4] 2> 581462 T2630 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with shards [shard1, shard2]
[junit4] 2> 581464 T2629 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> 581465 T2661 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> 581465 T2634 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> 581465 T2675 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> 581465 T2689 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> 581465 T2647 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> 581468 T2631 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 581468 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:59452_
[junit4] 2> 581469 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:40316_
[junit4] 2> 581469 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:59314_
[junit4] 2> 581470 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:47161_
[junit4] 2> 581471 T2654 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4] 2> 581471 T2682 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4] 2> 581471 T2623 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4] 2> 581472 T2640 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4] 2> 581473 T2623 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 581474 T2682 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 581474 T2640 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 581474 T2654 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 582969 T2630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 582970 T2630 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:40316",
[junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40316_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 582974 T2630 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:59452",
[junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59452_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 582976 T2630 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:59314",
[junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59314_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 582979 T2630 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:47161",
[junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47161_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"nodes_used_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node4"}
[junit4] 2> 582981 T2647 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> 582981 T2675 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> 582981 T2634 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> 582981 T2661 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> 582981 T2629 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> 582981 T2689 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> 583473 T2623 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica2
[junit4] 2> 583474 T2682 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica1
[junit4] 2> 583474 T2640 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica2
[junit4] 2> 583475 T2682 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/solr.xml
[junit4] 2> 583475 T2654 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica1
[junit4] 2> 583475 T2623 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/solr.xml
[junit4] 2> 583476 T2654 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/solr.xml
[junit4] 2> 583476 T2623 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2
[junit4] 2> 583477 T2623 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4] 2> 583476 T2640 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/solr.xml
[junit4] 2> 583476 T2682 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1
[junit4] 2> 583478 T2682 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4] 2> 583477 T2623 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4] 2> 583477 T2640 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2
[junit4] 2> 583478 T2640 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4] 2> 583476 T2654 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1
[junit4] 2> 583479 T2654 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4] 2> 583478 T2682 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4] 2> 583478 T2623 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 583480 T2654 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4] 2> 583480 T2682 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 583479 T2640 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4] 2> 583480 T2623 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 583481 T2682 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 583480 T2654 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 583481 T2682 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4] 2> 583481 T2623 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4] 2> 583481 T2640 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 583482 T2654 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 583483 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4] 2> 583483 T2640 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4] 2> 583483 T2623 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4] 2> 583483 T2682 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4] 2> 583484 T2654 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4] 2> 583485 T2682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/'
[junit4] 2> 583485 T2640 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4] 2> 583485 T2654 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/'
[junit4] 2> 583485 T2623 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/'
[junit4] 2> 583487 T2640 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/'
[junit4] 2> 583537 T2682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 583545 T2640 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 583548 T2623 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 583550 T2654 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 583593 T2682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 583595 T2682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 583612 T2640 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 583614 T2682 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4] 2> 583615 T2623 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 583616 T2654 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 583617 T2640 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 583617 T2623 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 583618 T2654 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 583625 T2640 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4] 2> 583626 T2623 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4] 2> 583626 T2654 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4] 2> 584131 T2654 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 584137 T2654 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 584140 T2654 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 584149 T2654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584152 T2654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584155 T2654 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584156 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584158 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584158 T2654 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584159 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584159 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584159 T2654 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 584160 T2654 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/
[junit4] 2> 584160 T2654 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
[junit4] 2> 584161 T2654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data
[junit4] 2> 584161 T2654 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index/
[junit4] 2> 584161 T2654 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 584161 T2654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index
[junit4] 2> 584162 T2654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
[junit4] 2> 584168 T2654 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18c55aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1792ee4),segFN=segments_1,generation=1}
[junit4] 2> 584169 T2654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584171 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 584171 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584174 T2654 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 584174 T2654 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 584174 T2654 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 584176 T2654 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 584178 T2654 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 584180 T2654 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 584181 T2654 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 584181 T2654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
[junit4] 2> 584182 T2654 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18c55aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1792ee4),segFN=segments_1,generation=1}
[junit4] 2> 584182 T2654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584182 T2654 oass.SolrIndexSearcher.<init> Opening Searcher@cc7f8a main
[junit4] 2> 584188 T2695 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@cc7f8a main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 584189 T2654 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4] 2> 584190 T2654 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:59452 collection:nodes_used_collection shard:shard1
[junit4] 2> 584190 T2654 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 584192 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4] 2> 584200 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 584202 T2654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=0
[junit4] 2> 584203 T2654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
[junit4] 2> 584203 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 584203 T2654 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59452/nodes_used_collection_shard1_replica1/
[junit4] 2> 584204 T2654 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:59452 START replicas=[http://127.0.0.1:40316/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4] 2> 584204 T2654 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:59452 DONE. We have no versions. sync failed.
[junit4] 2> 584205 T2654 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 584213 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 584214 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59452/nodes_used_collection_shard1_replica1/ shard1
[junit4] 2> 584214 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4] 2> 584219 T2623 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 584225 T2623 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 584228 T2682 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 584229 T2623 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 584235 T2640 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 584236 T2682 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 584240 T2623 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584240 T2682 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 584241 T2640 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 584243 T2623 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584244 T2640 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 584248 T2623 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584249 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584249 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584250 T2623 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584251 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584251 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584251 T2623 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 584252 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584252 T2623 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/
[junit4] 2> 584252 T2623 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
[junit4] 2> 584253 T2623 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data
[junit4] 2> 584254 T2623 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index/
[junit4] 2> 584254 T2623 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 584254 T2640 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584255 T2623 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index
[junit4] 2> 584255 T2623 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
[junit4] 2> 584256 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584256 T2623 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fb914c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@456868),segFN=segments_1,generation=1}
[junit4] 2> 584256 T2623 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584258 T2640 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584259 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584260 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 584260 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584261 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584260 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 584261 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584261 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 584261 T2640 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584262 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 584262 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584263 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584263 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 584264 T2682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584264 T2682 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/
[junit4] 2> 584264 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 584265 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584266 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584265 T2682 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
[junit4] 2> 584266 T2640 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 584266 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584267 T2640 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/
[junit4] 2> 584267 T2682 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data
[junit4] 2> 584267 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584267 T2682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index/
[junit4] 2> 584267 T2640 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
[junit4] 2> 584268 T2682 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 584268 T2623 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 584269 T2682 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index
[junit4] 2> 584269 T2640 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data
[junit4] 2> 584270 T2682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
[junit4] 2> 584269 T2623 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 584270 T2640 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index/
[junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 584271 T2640 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 584271 T2682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@110e146 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de0349),segFN=segments_1,generation=1}
[junit4] 2> 584272 T2682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584272 T2640 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index
[junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 584273 T2640 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
[junit4] 2> 584273 T2623 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 584274 T2640 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@141eb4d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1916887),segFN=segments_1,generation=1}
[junit4] 2> 584274 T2623 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 584274 T2640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584275 T2623 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 584276 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 584276 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 584277 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 584277 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 584277 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 584277 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 584277 T2623 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 584278 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 584278 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 584279 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 584278 T2623 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 584279 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 584280 T2623 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
[junit4] 2> 584280 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584279 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 584280 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584281 T2640 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 584280 T2623 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fb914c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@456868),segFN=segments_1,generation=1}
[junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 584282 T2623 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 584281 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 584282 T2623 oass.SolrIndexSearcher.<init> Opening Searcher@1bdbcb1 main
[junit4] 2> 584283 T2640 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 584283 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584284 T2640 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 584284 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584285 T2682 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 584285 T2640 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 584285 T2682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 584285 T2697 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@1bdbcb1 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 584286 T2682 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 584286 T2682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 584287 T2623 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4] 2> 584287 T2682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 584287 T2623 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:40316 collection:nodes_used_collection shard:shard1
[junit4] 2> 584288 T2623 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 584288 T2682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 584288 T2640 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 584289 T2682 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 584289 T2640 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 584290 T2640 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
[junit4] 2> 584290 T2682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 584290 T2640 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@141eb4d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1916887),segFN=segments_1,generation=1}
[junit4] 2> 584291 T2640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584291 T2640 oass.SolrIndexSearcher.<init> Opening Searcher@5fc039 main
[junit4] 2> 584294 T2698 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@5fc039 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 584294 T2682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 584294 T2682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 584294 T2640 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4] 2> 584295 T2640 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:47161 collection:nodes_used_collection shard:shard2
[junit4] 2> 584295 T2682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
[junit4] 2> 584295 T2640 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 584296 T2682 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@110e146 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de0349),segFN=segments_1,generation=1}
[junit4] 2> 584296 T2682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584297 T2640 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4] 2> 584297 T2682 oass.SolrIndexSearcher.<init> Opening Searcher@1b4c99f main
[junit4] 2> 584309 T2699 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1b4c99f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 584310 T2682 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4] 2> 584310 T2640 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 584310 T2682 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:59314 collection:nodes_used_collection shard:shard2
[junit4] 2> 584311 T2682 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 584312 T2640 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=0
[junit4] 2> 5844
[...truncated too long message...]
ZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index;done=false>>]
[junit4] 2> 984163 T2607 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index
[junit4] 2> 984163 T2607 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data;done=false>>]
[junit4] 2> 984164 T2607 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data
[junit4] 2> 984165 T3082 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90533696278036492-127.0.0.1:59314_-n_0000000004) am no longer a leader.
[junit4] 2> 984189 T2607 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 984242 T2607 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 984243 T2607 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:38246 38246
[junit4] 1> "node_name":"127.0.0.1:59314_",
[junit4] 1> "base_url":"http://127.0.0.1:59314"}
[junit4] 1> /solr/collections/awholynewcollection_2/leaders/shard2 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"awholynewcollection_2_shard2_replica1",
[junit4] 1> "node_name":"127.0.0.1:59314_",
[junit4] 1> "base_url":"http://127.0.0.1:59314"}
[junit4] 1> /solr/collections/awholynewcollection_2/leaders/shard3 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"awholynewcollection_2_shard3_replica3",
[junit4] 1> "node_name":"127.0.0.1:59314_",
[junit4] 1> "base_url":"http://127.0.0.1:59314"}
[junit4] 1> /solr/collections/awholynewcollection_1 (2)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/awholynewcollection_1/leader_elect (1)
[junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election (2)
[junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/90533696278036490-core_node2-n_0000000000 (0)
[junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/90533696278036488-core_node1-n_0000000001 (0)
[junit4] 1> /solr/collections/awholynewcollection_1/leaders (1)
[junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"awholynewcollection_1_shard1_replica2",
[junit4] 1> "node_name":"127.0.0.1:55534_",
[junit4] 1> "base_url":"http://127.0.0.1:55534"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90533696278036488-127.0.0.1:59452_-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90533696278036497-127.0.0.1:47161_-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90533696278036483-127.0.0.1:40316_-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90533696278036490-127.0.0.1:55534_-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90533696278036492-127.0.0.1:59314_-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90533696278036483-127.0.0.1:40316_-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=9E6D286B31AA6909 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_IE -Dtests.timezone=Pacific/Tongatapu -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 410s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
[junit4] > at __randomizedtesting.SeedInfo.seed([9E6D286B31AA6909:1F8BA67346F50935]:0)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:172)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:610)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:194)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 984623 T2607 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 409651 T2606 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 985467 T2689 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=en_IE, timezone=Pacific/Tongatapu
[junit4] 2> NOTE: Linux 3.8.0-31-generic i386/Oracle Corporation 1.7.0_40 (32-bit)/cpus=8,threads=3,free=50699632,total=204935168
[junit4] 2> NOTE: All tests run in this JVM: [SimplePostToolTest, TestQuerySenderNoQuery, TestCSVLoader, TestFieldTypeResource, SolrCoreCheckLockOnStartupTest, PluginInfoTest, XmlUpdateRequestHandlerTest, FileUtilsTest, TestBinaryResponseWriter, TermVectorComponentDistributedTest, TestRTGBase, SpellCheckComponentTest, DirectUpdateHandlerTest, TestCSVResponseWriter, TestClassNameShortening, AlternateDirectoryTest, HdfsUnloadDistributedZkTest, TestSweetSpotSimilarityFactory, TestDistributedSearch, TestCopyFieldCollectionResource, SolrIndexConfigTest, DirectSolrConnectionTest, TestOmitPositions, TestManagedSchema, OutputWriterTest, ChaosMonkeyNothingIsSafeTest, TestWordDelimiterFilterFactory, TestSolr4Spatial, BlockCacheTest, TestFastWriter, StatsComponentTest, CurrencyFieldOpenExchangeTest, SortByFunctionTest, ZkNodePropsTest, BasicDistributedZk2Test, AddBlockUpdateTest, CustomCollectionTest, CoreContainerCoreInitFailuresTest, TestCoreDiscovery, HdfsRecoveryZkTest, TestFastLRUCache, TestImplicitCoreProperties, TestReloadAndDeleteDocs, RequestHandlersTest, RequiredFieldsTest, TestDefaultSimilarityFactory, TestSolrJ, DisMaxRequestHandlerTest, DateFieldTest, ShardRoutingCustomTest, TestXIncludeConfig, TestAnalyzedSuggestions, TestInfoStreamLogging, TestStressReorder, PrimUtilsTest, SolrRequestParserTest, TestFieldTypeCollectionResource, NotRequiredUniqueKeyTest, TestReload, DefaultValueUpdateProcessorTest, DocValuesMultiTest, TestDistributedGrouping, TestQuerySenderListener, TimeZoneUtilsTest, TestStressLucene, SolrCmdDistributorTest, OpenExchangeRatesOrgProviderTest, BadIndexSchemaTest, SpellingQueryConverterTest, SignatureUpdateProcessorFactoryTest, IndexSchemaRuntimeFieldTest, HighlighterTest, TestJmxIntegration, TestLazyCores, TestMaxScoreQueryParser, FullSolrCloudDistribCmdsTest, CollectionsAPIDistributedZkTest]
[junit4] Completed on J1 in 410.68s, 1 test, 1 failure <<< FAILURES!
[...truncated 470 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:422: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:402: 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/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 326 suites, 1448 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 45 minutes 22 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_40 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_40) - Build # 7828 - Failure!
Posted by Mark Miller <ma...@gmail.com>.
I'm addressing this in SOLR-5317.
- Mark
On Oct 10, 2013, at 4:05 PM, Policeman Jenkins Server <je...@thetaphi.de> wrote:
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7828/
> Java: 32bit/jdk1.7.0_40 -server -XX:+UseSerialGC
>
> 1 tests failed.
> REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
>
> Error Message:
> There are still nodes recoverying - waited for 330 seconds
>
> Stack Trace:
> java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
> at __randomizedtesting.SeedInfo.seed([9E6D286B31AA6909:1F8BA67346F50935]:0)
> at org.junit.Assert.fail(Assert.java:93)
> at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:172)
> at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
> at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
> at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:610)
> at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:194)
> at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
> 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:724)
>
>
>
>
> Build Log:
> [...truncated 10257 lines...]
> [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
> [junit4] 2> 574976 T2607 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
> [junit4] 2> 574979 T2607 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
> [junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1381434574553
> [junit4] 2> 574980 T2607 oasc.ZkTestServer.run STARTING ZK TEST SERVER
> [junit4] 2> 574980 T2608 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
> [junit4] 2> 575080 T2607 oasc.ZkTestServer.run start zk server on port:38246
> [junit4] 2> 575081 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575264 T2614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c8954 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575264 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575264 T2607 oascc.SolrZkClient.makePath makePath: /solr
> [junit4] 2> 575269 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575270 T2616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f36d6e name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575270 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575270 T2607 oascc.SolrZkClient.makePath makePath: /collections/collection1
> [junit4] 2> 575272 T2607 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
> [junit4] 2> 575274 T2607 oascc.SolrZkClient.makePath makePath: /collections/control_collection
> [junit4] 2> 575275 T2607 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
> [junit4] 2> 575277 T2607 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> 575277 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
> [junit4] 2> 575280 T2607 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> 575280 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
> [junit4] 2> 575283 T2607 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> 575283 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
> [junit4] 2> 575285 T2607 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> 575285 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
> [junit4] 2> 575287 T2607 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> 575287 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
> [junit4] 2> 575289 T2607 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> 575289 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
> [junit4] 2> 575291 T2607 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> 575291 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
> [junit4] 2> 575294 T2607 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> 575294 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
> [junit4] 2> 575296 T2607 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> 575297 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
> [junit4] 2> 575298 T2607 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> 575299 T2607 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
> [junit4] 2> Using old style solr.xml
> [junit4] 2> 575364 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 575367 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40316
> [junit4] 2> 575375 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 575376 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 575376 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874
> [junit4] 2> 575377 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/'
> [junit4] 2> 575386 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/solr.xml
> [junit4] 2> 575416 T2607 oasc.CoreContainer.<init> New CoreContainer 17983889
> [junit4] 2> 575416 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/]
> [junit4] 2> 575417 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
> [junit4] 2> 575417 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 575418 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 575419 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 575419 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
> [junit4] 2> 575421 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 575421 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 575421 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
> [junit4] 2> 575422 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 575422 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575424 T2627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@991529 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575424 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575426 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
> [junit4] 2> 575427 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575428 T2629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15d9902 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575428 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575430 T2607 oascc.SolrZkClient.makePath makePath: /overseer/queue
> [junit4] 2> 575432 T2607 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
> [junit4] 2> 575434 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes
> [junit4] 2> 575435 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40316_
> [junit4] 2> 575436 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40316_
> [junit4] 2> 575438 T2607 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
> [junit4] 2> 575441 T2607 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
> [junit4] 2> 575443 T2607 oasc.Overseer.start Overseer (id=90533696278036483-127.0.0.1:40316_-n_0000000000) starting
> [junit4] 2> 575446 T2607 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
> [junit4] 2> 575449 T2631 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
> [junit4] 2> 575449 T2607 oascc.SolrZkClient.makePath makePath: /clusterstate.json
> [junit4] 2> 575451 T2607 oascc.SolrZkClient.makePath makePath: /aliases.json
> [junit4] 2> 575452 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 575454 T2630 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
> [junit4] 2> 575456 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
> [junit4] 2> 575456 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 575456 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 575457 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:
> [junit4] 2> 575458 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575459 T2634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e2660a name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575459 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575460 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 575462 T2607 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
> [junit4] 2> 575525 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 575527 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47161
> [junit4] 2> 575528 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 575528 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 575528 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035
> [junit4] 2> 575529 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/'
> [junit4] 2> 575538 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/solr.xml
> [junit4] 2> 575575 T2607 oasc.CoreContainer.<init> New CoreContainer 17617877
> [junit4] 2> 575576 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/]
> [junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
> [junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 575577 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 575578 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 575579 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 575579 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
> [junit4] 2> 575580 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 575580 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 575581 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
> [junit4] 2> 575581 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 575582 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575583 T2645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3aae2 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575584 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575585 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
> [junit4] 2> 575587 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 575588 T2647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@165826a name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 575588 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 575591 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 576593 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47161_
> [junit4] 2> 576595 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47161_
> [junit4] 2> 576597 T2634 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 576597 T2629 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 576598 T2647 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 576601 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
> [junit4] 2> 576601 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 576602 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 576665 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 576667 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59452
> [junit4] 2> 576667 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 576667 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 576668 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175
> [junit4] 2> 576668 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/'
> [junit4] 2> 576678 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/solr.xml
> [junit4] 2> 576706 T2607 oasc.CoreContainer.<init> New CoreContainer 2682644
> [junit4] 2> 576706 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/]
> [junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
> [junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 576707 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 576708 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 576709 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 576709 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
> [junit4] 2> 576710 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 576711 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 576711 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
> [junit4] 2> 576711 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 576712 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 576714 T2659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e97b5 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 576714 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 576716 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
> [junit4] 2> 576717 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 576718 T2661 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e851a2 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 576718 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 576722 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 577724 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59452_
> [junit4] 2> 577725 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59452_
> [junit4] 2> 577727 T2629 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 577727 T2634 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 577727 T2647 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 577728 T2661 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 577732 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
> [junit4] 2> 577732 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 577732 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 577797 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 577799 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55534
> [junit4] 2> 577799 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 577800 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 577800 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306
> [junit4] 2> 577800 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/'
> [junit4] 2> 577810 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/solr.xml
> [junit4] 2> 577849 T2607 oasc.CoreContainer.<init> New CoreContainer 15165292
> [junit4] 2> 577849 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381434577306/]
> [junit4] 2> 577850 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
> [junit4] 2> 577850 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 577851 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 577852 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 577853 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
> [junit4] 2> 577854 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 577854 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 577854 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
> [junit4] 2> 577855 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 577856 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 577893 T2673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10eb045 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 577894 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 577896 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
> [junit4] 2> 577898 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 577899 T2675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15387e1 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 577900 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 577904 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 578906 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55534_
> [junit4] 2> 578907 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55534_
> [junit4] 2> 578911 T2634 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 578911 T2629 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 578911 T2661 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 578911 T2647 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 578911 T2675 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 578915 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
> [junit4] 2> 578915 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 578915 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 578980 T2607 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 578982 T2607 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59314
> [junit4] 2> 578982 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 578982 T2607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 578983 T2607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489
> [junit4] 2> 578983 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/'
> [junit4] 2> 578993 T2607 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/solr.xml
> [junit4] 2> 579021 T2607 oasc.CoreContainer.<init> New CoreContainer 6201038
> [junit4] 2> 579021 T2607 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/]
> [junit4] 2> 579022 T2607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
> [junit4] 2> 579022 T2607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 579023 T2607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 579024 T2607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 579025 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
> [junit4] 2> 579026 T2607 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 579026 T2607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 579026 T2607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38246/solr
> [junit4] 2> 579027 T2607 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 579027 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 579029 T2687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dd9220 name:ZooKeeperConnection Watcher:127.0.0.1:38246 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 579029 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 579031 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
> [junit4] 2> 579032 T2607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 579033 T2689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd8586 name:ZooKeeperConnection Watcher:127.0.0.1:38246/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 579033 T2607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 579037 T2607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 580039 T2607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59314_
> [junit4] 2> 580041 T2607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59314_
> [junit4] 2> 580044 T2647 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580044 T2634 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580045 T2689 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580044 T2629 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580045 T2661 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580045 T2675 oascc.ZkStateReader$3.process Updating live nodes... (5)
> [junit4] 2> 580049 T2607 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
> [junit4] 2> 580049 T2607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 580050 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 580050 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
> [junit4] 2> 580052 T2642 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
> [junit4] 2> 580053 T2629 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 580064 T2631 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
> [junit4] 2> "operation":"createcollection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "name":"nodes_used_collection",
> [junit4] 2> "replicationFactor":"2"}
> [junit4] 2> 580064 T2631 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
> [junit4] 2> "operation":"createcollection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "name":"nodes_used_collection",
> [junit4] 2> "replicationFactor":"2"}
> [junit4] 2> 581461 T2630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 581462 T2630 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: nodes_used_collection
> [junit4] 2> 581462 T2630 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with shards [shard1, shard2]
> [junit4] 2> 581464 T2629 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> 581465 T2661 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> 581465 T2634 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> 581465 T2675 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> 581465 T2689 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> 581465 T2647 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> 581468 T2631 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
> [junit4] 2> 581468 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:59452_
> [junit4] 2> 581469 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:40316_
> [junit4] 2> 581469 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:59314_
> [junit4] 2> 581470 T2631 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:47161_
> [junit4] 2> 581471 T2654 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
> [junit4] 2> 581471 T2682 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
> [junit4] 2> 581471 T2623 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
> [junit4] 2> 581472 T2640 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
> [junit4] 2> 581473 T2623 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 581474 T2682 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 581474 T2640 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 581474 T2654 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 582969 T2630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 582970 T2630 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:40316",
> [junit4] 2> "core":"nodes_used_collection_shard1_replica2",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:40316_",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"nodes_used_collection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node1"}
> [junit4] 2> 582974 T2630 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:59452",
> [junit4] 2> "core":"nodes_used_collection_shard1_replica1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:59452_",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"nodes_used_collection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node2"}
> [junit4] 2> 582976 T2630 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:59314",
> [junit4] 2> "core":"nodes_used_collection_shard2_replica1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:59314_",
> [junit4] 2> "shard":"shard2",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"nodes_used_collection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node3"}
> [junit4] 2> 582979 T2630 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:47161",
> [junit4] 2> "core":"nodes_used_collection_shard2_replica2",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:47161_",
> [junit4] 2> "shard":"shard2",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"nodes_used_collection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node4"}
> [junit4] 2> 582981 T2647 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> 582981 T2675 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> 582981 T2634 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> 582981 T2661 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> 582981 T2629 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> 582981 T2689 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> 583473 T2623 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica2
> [junit4] 2> 583474 T2682 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica1
> [junit4] 2> 583474 T2640 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica2
> [junit4] 2> 583475 T2682 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/solr.xml
> [junit4] 2> 583475 T2654 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica1
> [junit4] 2> 583475 T2623 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/solr.xml
> [junit4] 2> 583476 T2654 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/solr.xml
> [junit4] 2> 583476 T2623 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2
> [junit4] 2> 583477 T2623 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
> [junit4] 2> 583476 T2640 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/solr.xml
> [junit4] 2> 583476 T2682 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1
> [junit4] 2> 583478 T2682 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
> [junit4] 2> 583477 T2623 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
> [junit4] 2> 583477 T2640 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2
> [junit4] 2> 583478 T2640 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
> [junit4] 2> 583476 T2654 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1
> [junit4] 2> 583479 T2654 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
> [junit4] 2> 583478 T2682 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
> [junit4] 2> 583478 T2623 oasc.ZkController.getConfName Looking for collection configName
> [junit4] 2> 583480 T2654 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
> [junit4] 2> 583480 T2682 oasc.ZkController.getConfName Looking for collection configName
> [junit4] 2> 583479 T2640 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
> [junit4] 2> 583480 T2623 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
> [junit4] 2> 583481 T2682 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
> [junit4] 2> 583480 T2654 oasc.ZkController.getConfName Looking for collection configName
> [junit4] 2> 583481 T2682 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
> [junit4] 2> 583481 T2623 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
> [junit4] 2> 583481 T2640 oasc.ZkController.getConfName Looking for collection configName
> [junit4] 2> 583482 T2654 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
> [junit4] 2> 583483 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
> [junit4] 2> 583483 T2640 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
> [junit4] 2> 583483 T2623 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
> [junit4] 2> 583483 T2682 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
> [junit4] 2> 583484 T2654 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
> [junit4] 2> 583485 T2682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/'
> [junit4] 2> 583485 T2640 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
> [junit4] 2> 583485 T2654 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/'
> [junit4] 2> 583485 T2623 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/'
> [junit4] 2> 583487 T2640 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/'
> [junit4] 2> 583537 T2682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 583545 T2640 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 583548 T2623 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 583550 T2654 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 583593 T2682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 583595 T2682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 583612 T2640 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 583614 T2682 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
> [junit4] 2> 583615 T2623 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 583616 T2654 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 583617 T2640 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 583617 T2623 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 583618 T2654 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 583625 T2640 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
> [junit4] 2> 583626 T2623 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
> [junit4] 2> 583626 T2654 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
> [junit4] 2> 584131 T2654 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
> [junit4] 2> 584137 T2654 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 584140 T2654 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 584149 T2654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584152 T2654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584155 T2654 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584156 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584158 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584158 T2654 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584159 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584159 T2654 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584159 T2654 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 584160 T2654 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/
> [junit4] 2> 584160 T2654 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
> [junit4] 2> 584161 T2654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data
> [junit4] 2> 584161 T2654 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index/
> [junit4] 2> 584161 T2654 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
> [junit4] 2> 584161 T2654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381434576175/nodes_used_collection_shard1_replica1/data/index
> [junit4] 2> 584162 T2654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
> [junit4] 2> 584168 T2654 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18c55aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1792ee4),segFN=segments_1,generation=1}
> [junit4] 2> 584169 T2654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584171 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 584171 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584172 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584173 T2654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584174 T2654 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 584174 T2654 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 584174 T2654 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 584175 T2654 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 584176 T2654 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 584178 T2654 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 584180 T2654 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 584181 T2654 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 584181 T2654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
> [junit4] 2> 584182 T2654 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18c55aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1792ee4),segFN=segments_1,generation=1}
> [junit4] 2> 584182 T2654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584182 T2654 oass.SolrIndexSearcher.<init> Opening Searcher@cc7f8a main
> [junit4] 2> 584188 T2695 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@cc7f8a main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 584189 T2654 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
> [junit4] 2> 584190 T2654 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:59452 collection:nodes_used_collection shard:shard1
> [junit4] 2> 584190 T2654 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
> [junit4] 2> 584192 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
> [junit4] 2> 584200 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
> [junit4] 2> 584202 T2654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=0
> [junit4] 2> 584203 T2654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
> [junit4] 2> 584203 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
> [junit4] 2> 584203 T2654 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59452/nodes_used_collection_shard1_replica1/
> [junit4] 2> 584204 T2654 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:59452 START replicas=[http://127.0.0.1:40316/nodes_used_collection_shard1_replica2/] nUpdates=100
> [junit4] 2> 584204 T2654 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:59452 DONE. We have no versions. sync failed.
> [junit4] 2> 584205 T2654 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
> [junit4] 2> 584213 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
> [junit4] 2> 584214 T2654 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59452/nodes_used_collection_shard1_replica1/ shard1
> [junit4] 2> 584214 T2654 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
> [junit4] 2> 584219 T2623 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
> [junit4] 2> 584225 T2623 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 584228 T2682 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
> [junit4] 2> 584229 T2623 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 584235 T2640 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
> [junit4] 2> 584236 T2682 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 584240 T2623 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584240 T2682 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 584241 T2640 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 584243 T2623 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584244 T2640 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 584248 T2623 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584249 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584249 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584250 T2623 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584251 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584251 T2623 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584251 T2623 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 584252 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584252 T2623 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/
> [junit4] 2> 584252 T2623 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
> [junit4] 2> 584253 T2623 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data
> [junit4] 2> 584254 T2623 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index/
> [junit4] 2> 584254 T2623 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
> [junit4] 2> 584254 T2640 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584255 T2623 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381434574874/nodes_used_collection_shard1_replica2/data/index
> [junit4] 2> 584255 T2623 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
> [junit4] 2> 584256 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584256 T2623 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fb914c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@456868),segFN=segments_1,generation=1}
> [junit4] 2> 584256 T2623 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584258 T2640 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 584259 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584260 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 584260 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584261 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584260 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 584261 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584261 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 584261 T2640 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584262 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584262 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584263 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584263 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584264 T2682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 584263 T2640 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
> [junit4] 2> 584264 T2682 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/
> [junit4] 2> 584264 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 584265 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
> [junit4] 2> 584266 T2640 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
> [junit4] 2> 584265 T2682 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
> [junit4] 2> 584266 T2640 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 584266 T2623 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584267 T2640 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/
> [junit4] 2> 584267 T2682 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data
> [junit4] 2> 584267 T2623 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584267 T2682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index/
> [junit4] 2> 584267 T2640 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@193710b
> [junit4] 2> 584268 T2682 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
> [junit4] 2> 584268 T2623 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 584269 T2682 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/nodes_used_collection_shard2_replica1/data/index
> [junit4] 2> 584269 T2640 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data
> [junit4] 2> 584270 T2682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
> [junit4] 2> 584269 T2623 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 584270 T2640 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index/
> [junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 584271 T2640 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
> [junit4] 2> 584271 T2682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@110e146 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de0349),segFN=segments_1,generation=1}
> [junit4] 2> 584272 T2682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584272 T2640 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381434575035/nodes_used_collection_shard2_replica2/data/index
> [junit4] 2> 584271 T2623 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 584273 T2640 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=23.125, floorSegmentMB=0.5048828125, forceMergeDeletesPctAllowed=18.999894598593052, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5613401823979633
> [junit4] 2> 584273 T2623 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 584274 T2640 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@141eb4d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1916887),segFN=segments_1,generation=1}
> [junit4] 2> 584274 T2623 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 584274 T2640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584275 T2623 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 584276 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 584276 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 584277 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 584277 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 584277 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 584277 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 584277 T2623 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 584278 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584278 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584279 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584278 T2623 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 584279 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 584280 T2623 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
> [junit4] 2> 584280 T2640 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584279 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 584280 T2640 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584281 T2640 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 584280 T2623 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fb914c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@456868),segFN=segments_1,generation=1}
> [junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 584282 T2623 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 584281 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 584282 T2640 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 584282 T2623 oass.SolrIndexSearcher.<init> Opening Searcher@1bdbcb1 main
> [junit4] 2> 584283 T2640 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 584283 T2682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584284 T2640 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 584284 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 584285 T2682 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 584285 T2640 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 584285 T2682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 584285 T2697 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@1bdbcb1 main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 584286 T2682 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 584286 T2682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 584287 T2623 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
> [junit4] 2> 584287 T2682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 584287 T2623 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:40316 collection:nodes_used_collection shard:shard1
> [junit4] 2> 584288 T2623 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
> [junit4] 2> 584288 T2682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 584288 T2640 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 584289 T2682 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 584289 T2640 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 584290 T2640 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
> [junit4] 2> 584290 T2682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 584290 T2640 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@141eb4d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1916887),segFN=segments_1,generation=1}
> [junit4] 2> 584291 T2640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584291 T2640 oass.SolrIndexSearcher.<init> Opening Searcher@5fc039 main
> [junit4] 2> 584294 T2698 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@5fc039 main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 584294 T2682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 584294 T2682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 584294 T2640 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
> [junit4] 2> 584295 T2640 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:47161 collection:nodes_used_collection shard:shard2
> [junit4] 2> 584295 T2682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=67.3330078125, floorSegmentMB=0.857421875, forceMergeDeletesPctAllowed=0.043760520586229035, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7335370732523536
> [junit4] 2> 584295 T2640 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
> [junit4] 2> 584296 T2682 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@110e146 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de0349),segFN=segments_1,generation=1}
> [junit4] 2> 584296 T2682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 584297 T2640 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
> [junit4] 2> 584297 T2682 oass.SolrIndexSearcher.<init> Opening Searcher@1b4c99f main
> [junit4] 2> 584309 T2699 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1b4c99f main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 584310 T2682 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
> [junit4] 2> 584310 T2640 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
> [junit4] 2> 584310 T2682 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:59314 collection:nodes_used_collection shard:shard2
> [junit4] 2> 584311 T2682 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
> [junit4] 2> 584312 T2640 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=0
> [junit4] 2> 5844
>
> [...truncated too long message...]
>
> ZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index;done=false>>]
> [junit4] 2> 984163 T2607 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data/index
> [junit4] 2> 984163 T2607 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data;done=false>>]
> [junit4] 2> 984164 T2607 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381434578489/awholynewcollection_5_shard4_replica2/data
> [junit4] 2> 984165 T3082 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90533696278036492-127.0.0.1:59314_-n_0000000004) am no longer a leader.
> [junit4] 2> 984189 T2607 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
> [junit4] 2> 984242 T2607 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
> [junit4] 2> 984243 T2607 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:38246 38246
> [junit4] 1> "node_name":"127.0.0.1:59314_",
> [junit4] 1> "base_url":"http://127.0.0.1:59314"}
> [junit4] 1> /solr/collections/awholynewcollection_2/leaders/shard2 (0)
> [junit4] 1> DATA:
> [junit4] 1> {
> [junit4] 1> "core":"awholynewcollection_2_shard2_replica1",
> [junit4] 1> "node_name":"127.0.0.1:59314_",
> [junit4] 1> "base_url":"http://127.0.0.1:59314"}
> [junit4] 1> /solr/collections/awholynewcollection_2/leaders/shard3 (0)
> [junit4] 1> DATA:
> [junit4] 1> {
> [junit4] 1> "core":"awholynewcollection_2_shard3_replica3",
> [junit4] 1> "node_name":"127.0.0.1:59314_",
> [junit4] 1> "base_url":"http://127.0.0.1:59314"}
> [junit4] 1> /solr/collections/awholynewcollection_1 (2)
> [junit4] 1> DATA:
> [junit4] 1> {"configName":"conf1"}
> [junit4] 1> /solr/collections/awholynewcollection_1/leader_elect (1)
> [junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1 (1)
> [junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election (2)
> [junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/90533696278036490-core_node2-n_0000000000 (0)
> [junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/90533696278036488-core_node1-n_0000000001 (0)
> [junit4] 1> /solr/collections/awholynewcollection_1/leaders (1)
> [junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard1 (0)
> [junit4] 1> DATA:
> [junit4] 1> {
> [junit4] 1> "core":"awholynewcollection_1_shard1_replica2",
> [junit4] 1> "node_name":"127.0.0.1:55534_",
> [junit4] 1> "base_url":"http://127.0.0.1:55534"}
> [junit4] 1> /solr/overseer_elect (2)
> [junit4] 1> /solr/overseer_elect/election (5)
> [junit4] 1> /solr/overseer_elect/election/90533696278036488-127.0.0.1:59452_-n_0000000002 (0)
> [junit4] 1> /solr/overseer_elect/election/90533696278036497-127.0.0.1:47161_-n_0000000005 (0)
> [junit4] 1> /solr/overseer_elect/election/90533696278036483-127.0.0.1:40316_-n_0000000000 (0)
> [junit4] 1> /solr/overseer_elect/election/90533696278036490-127.0.0.1:55534_-n_0000000003 (0)
> [junit4] 1> /solr/overseer_elect/election/90533696278036492-127.0.0.1:59314_-n_0000000004 (0)
> [junit4] 1> /solr/overseer_elect/leader (0)
> [junit4] 1> DATA:
> [junit4] 1> {"id":"90533696278036483-127.0.0.1:40316_-n_0000000000"}
> [junit4] 1> /zookeeper (1)
> [junit4] 1> DATA:
> [junit4] 1>
> [junit4] 1>
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=9E6D286B31AA6909 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_IE -Dtests.timezone=Pacific/Tongatapu -Dtests.file.encoding=US-ASCII
> [junit4] FAILURE 410s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
> [junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
> [junit4] > at __randomizedtesting.SeedInfo.seed([9E6D286B31AA6909:1F8BA67346F50935]:0)
> [junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:172)
> [junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
> [junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
> [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:610)
> [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:194)
> [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
> [junit4] > at java.lang.Thread.run(Thread.java:724)
> [junit4] 2> 984623 T2607 oas.SolrTestCaseJ4.deleteCore ###deleteCore
> [junit4] 2> 409651 T2606 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
> [junit4] 2> 985467 T2689 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
> [junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=en_IE, timezone=Pacific/Tongatapu
> [junit4] 2> NOTE: Linux 3.8.0-31-generic i386/Oracle Corporation 1.7.0_40 (32-bit)/cpus=8,threads=3,free=50699632,total=204935168
> [junit4] 2> NOTE: All tests run in this JVM: [SimplePostToolTest, TestQuerySenderNoQuery, TestCSVLoader, TestFieldTypeResource, SolrCoreCheckLockOnStartupTest, PluginInfoTest, XmlUpdateRequestHandlerTest, FileUtilsTest, TestBinaryResponseWriter, TermVectorComponentDistributedTest, TestRTGBase, SpellCheckComponentTest, DirectUpdateHandlerTest, TestCSVResponseWriter, TestClassNameShortening, AlternateDirectoryTest, HdfsUnloadDistributedZkTest, TestSweetSpotSimilarityFactory, TestDistributedSearch, TestCopyFieldCollectionResource, SolrIndexConfigTest, DirectSolrConnectionTest, TestOmitPositions, TestManagedSchema, OutputWriterTest, ChaosMonkeyNothingIsSafeTest, TestWordDelimiterFilterFactory, TestSolr4Spatial, BlockCacheTest, TestFastWriter, StatsComponentTest, CurrencyFieldOpenExchangeTest, SortByFunctionTest, ZkNodePropsTest, BasicDistributedZk2Test, AddBlockUpdateTest, CustomCollectionTest, CoreContainerCoreInitFailuresTest, TestCoreDiscovery, HdfsRecoveryZkTest, TestFastLRUCache, TestImplicitCoreProperties, TestReloadAndDeleteDocs, RequestHandlersTest, RequiredFieldsTest, TestDefaultSimilarityFactory, TestSolrJ, DisMaxRequestHandlerTest, DateFieldTest, ShardRoutingCustomTest, TestXIncludeConfig, TestAnalyzedSuggestions, TestInfoStreamLogging, TestStressReorder, PrimUtilsTest, SolrRequestParserTest, TestFieldTypeCollectionResource, NotRequiredUniqueKeyTest, TestReload, DefaultValueUpdateProcessorTest, DocValuesMultiTest, TestDistributedGrouping, TestQuerySenderListener, TimeZoneUtilsTest, TestStressLucene, SolrCmdDistributorTest, OpenExchangeRatesOrgProviderTest, BadIndexSchemaTest, SpellingQueryConverterTest, SignatureUpdateProcessorFactoryTest, IndexSchemaRuntimeFieldTest, HighlighterTest, TestJmxIntegration, TestLazyCores, TestMaxScoreQueryParser, FullSolrCloudDistribCmdsTest, CollectionsAPIDistributedZkTest]
> [junit4] Completed on J1 in 410.68s, 1 test, 1 failure <<< FAILURES!
>
> [...truncated 470 lines...]
> BUILD FAILED
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:422: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:402: 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/solr/build.xml:189: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 326 suites, 1448 tests, 1 failure, 34 ignored (6 assumptions)
>
> Total time: 45 minutes 22 seconds
> Build step 'Invoke Ant' marked build as failure
> Description set: Java: 32bit/jdk1.7.0_40 -server -XX:+UseSerialGC
> Archiving artifacts
> Recording test results
> Email was triggered for: Failure
> Sending email for trigger: Failure
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org