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/06/01 11:06:56 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 527 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/527/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
collection already exists: awholynewcollection_0
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_0
at __randomizedtesting.SeedInfo.seed([7D6B3C104BE946F9:FC8DB2083CB626C5]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:424)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:306)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1400)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:438)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
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:601)
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:722)
Build Log:
[...truncated 9566 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 2279447 T4597 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2279452 T4597 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1370076082798
[junit4:junit4] 2> 2279455 T4597 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2279456 T4598 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2279556 T4597 oasc.ZkTestServer.run start zk server on port:50524
[junit4:junit4] 2> 2279559 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2279572 T4604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d777df9 name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2279573 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2279574 T4597 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2279591 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2279599 T4606 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f5450db name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2279600 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2279601 T4597 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2279609 T4597 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2279621 T4597 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2279629 T4597 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2279644 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2279645 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2279660 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 2279661 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2279675 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2279676 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2279684 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 2279686 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2279695 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 2279696 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2279704 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2279705 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2279713 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2279714 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2279722 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2279723 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2279731 T4597 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2279732 T4597 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2280499 T4597 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2280511 T4597 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50527
[junit4:junit4] 2> 2280512 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2280514 T4597 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2280514 T4597 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088
[junit4:junit4] 2> 2280515 T4597 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/solr.xml
[junit4:junit4] 2> 2280515 T4597 oasc.CoreContainer.<init> New CoreContainer 1224471084
[junit4:junit4] 2> 2280516 T4597 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/'
[junit4:junit4] 2> 2280517 T4597 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/'
[junit4:junit4] 2> 2280780 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088
[junit4:junit4] 2> 2280783 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/collection1
[junit4:junit4] 2> 2280790 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/collection1/conf
[junit4:junit4] 2> 2281022 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/collection1/conf/xslt
[junit4:junit4] 2> 2281039 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/collection1/lib
[junit4:junit4] 2> 2281042 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/collection1/lib/classes
[junit4:junit4] 2> 2281046 T4597 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/conf/core.properties, adding to cores
[junit4:junit4] 2> 2281071 T4597 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2281072 T4597 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2281075 T4597 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2281083 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2281087 T4597 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2281088 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2281088 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2281089 T4597 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2281090 T4597 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2281090 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2281120 T4597 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2281121 T4597 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50524/solr
[junit4:junit4] 2> 2281122 T4597 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2281123 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2281129 T4617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@553d93a9 name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2281136 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2281142 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2281168 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2281174 T4619 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5672a312 name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2281175 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2281180 T4597 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2281199 T4597 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2281218 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2281223 T4597 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50527_
[junit4:junit4] 2> 2281226 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50527_
[junit4:junit4] 2> 2281238 T4597 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2281280 T4597 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2281289 T4597 oasc.Overseer.start Overseer (id=89789306163298307-127.0.0.1:50527_-n_0000000000) starting
[junit4:junit4] 2> 2281299 T4597 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2281316 T4620 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2281322 T4621 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2281332 T4597 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2281341 T4597 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2281347 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2281359 T4597 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2281359 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2281360 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2281382 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2281396 T4624 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53c2c43a name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2281396 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2281397 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2281400 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2281408 T4597 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2282019 T4597 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2282038 T4597 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50531
[junit4:junit4] 2> 2282039 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2282040 T4597 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2282041 T4597 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753
[junit4:junit4] 2> 2282041 T4597 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/solr.xml
[junit4:junit4] 2> 2282042 T4597 oasc.CoreContainer.<init> New CoreContainer 571273384
[junit4:junit4] 2> 2282043 T4597 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/'
[junit4:junit4] 2> 2282043 T4597 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/'
[junit4:junit4] 2> 2282241 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753
[junit4:junit4] 2> 2282243 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/collection1
[junit4:junit4] 2> 2282245 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/collection1/conf
[junit4:junit4] 2> 2282450 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/collection1/conf/xslt
[junit4:junit4] 2> 2282456 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/collection1/lib
[junit4:junit4] 2> 2282457 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/collection1/lib/classes
[junit4:junit4] 2> 2282460 T4597 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/conf/core.properties, adding to cores
[junit4:junit4] 2> 2282478 T4597 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2282480 T4597 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2282481 T4597 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2282482 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2282483 T4597 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2282484 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2282492 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2282495 T4597 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2282496 T4597 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2282497 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2282530 T4597 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2282531 T4597 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50524/solr
[junit4:junit4] 2> 2282531 T4597 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2282537 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2282542 T4635 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@785a7a6c name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2282543 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2282548 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2282576 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2282602 T4637 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd8b205 name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2282602 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2282613 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2283623 T4597 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50531_
[junit4:junit4] 2> 2283626 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50531_
[junit4:junit4] 2> 2283643 T4637 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2283643 T4624 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2283643 T4619 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2283656 T4597 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2283657 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2283658 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2284373 T4597 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2284407 T4597 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50534
[junit4:junit4] 2> 2284410 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2284411 T4597 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2284412 T4597 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024
[junit4:junit4] 2> 2284413 T4597 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/solr.xml
[junit4:junit4] 2> 2284413 T4597 oasc.CoreContainer.<init> New CoreContainer 277836018
[junit4:junit4] 2> 2284414 T4597 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/'
[junit4:junit4] 2> 2284415 T4597 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/'
[junit4:junit4] 2> 2284601 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024
[junit4:junit4] 2> 2284603 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/collection1
[junit4:junit4] 2> 2284604 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/collection1/conf
[junit4:junit4] 2> 2284799 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/collection1/conf/xslt
[junit4:junit4] 2> 2284805 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/collection1/lib
[junit4:junit4] 2> 2284807 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/collection1/lib/classes
[junit4:junit4] 2> 2284810 T4597 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/conf/core.properties, adding to cores
[junit4:junit4] 2> 2284828 T4597 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2284832 T4597 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2284838 T4597 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2284839 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2284839 T4597 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2284840 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2284840 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2284841 T4597 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2284842 T4597 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2284842 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2284870 T4597 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2284871 T4597 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50524/solr
[junit4:junit4] 2> 2284872 T4597 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2284875 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2284880 T4649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5939229c name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2284881 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2284885 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2284915 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2284919 T4651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e18cc0f name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2284920 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2284932 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2285942 T4597 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50534_
[junit4:junit4] 2> 2285945 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50534_
[junit4:junit4] 2> 2285966 T4637 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2285970 T4597 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2285971 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2285972 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2285973 T4624 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2285974 T4651 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2285974 T4619 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2286623 T4597 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2286630 T4597 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50537
[junit4:junit4] 2> 2286632 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2286633 T4597 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2286634 T4597 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337
[junit4:junit4] 2> 2286635 T4597 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/solr.xml
[junit4:junit4] 2> 2286635 T4597 oasc.CoreContainer.<init> New CoreContainer 2111655305
[junit4:junit4] 2> 2286636 T4597 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/'
[junit4:junit4] 2> 2286637 T4597 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/'
[junit4:junit4] 2> 2286857 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337
[junit4:junit4] 2> 2286859 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/collection1
[junit4:junit4] 2> 2286861 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/collection1/conf
[junit4:junit4] 2> 2287052 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/collection1/conf/xslt
[junit4:junit4] 2> 2287058 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/collection1/lib
[junit4:junit4] 2> 2287060 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/collection1/lib/classes
[junit4:junit4] 2> 2287064 T4597 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/conf/core.properties, adding to cores
[junit4:junit4] 2> 2287082 T4597 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2287082 T4597 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2287083 T4597 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2287084 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2287084 T4597 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2287085 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2287085 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2287086 T4597 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2287086 T4597 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2287087 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2287124 T4597 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2287125 T4597 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50524/solr
[junit4:junit4] 2> 2287126 T4597 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2287128 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2287136 T4663 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20ff029b name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2287138 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2287142 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2287167 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2287172 T4665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71ef0631 name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2287172 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2287184 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2288194 T4597 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50537_
[junit4:junit4] 2> 2288197 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50537_
[junit4:junit4] 2> 2288212 T4651 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2288213 T4619 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2288213 T4624 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2288214 T4637 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2288214 T4665 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2288229 T4597 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2288230 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2288230 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2289306 T4597 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2289338 T4597 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50540
[junit4:junit4] 2> 2289342 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2289343 T4597 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2289344 T4597 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600
[junit4:junit4] 2> 2289344 T4597 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/solr.xml
[junit4:junit4] 2> 2289345 T4597 oasc.CoreContainer.<init> New CoreContainer 2102429602
[junit4:junit4] 2> 2289346 T4597 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/'
[junit4:junit4] 2> 2289346 T4597 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/'
[junit4:junit4] 2> 2289629 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600
[junit4:junit4] 2> 2289633 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/collection1
[junit4:junit4] 2> 2289635 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/collection1/conf
[junit4:junit4] 2> 2289857 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/collection1/conf/xslt
[junit4:junit4] 2> 2289862 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/collection1/lib
[junit4:junit4] 2> 2289864 T4597 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/collection1/lib/classes
[junit4:junit4] 2> 2289869 T4597 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/conf/core.properties, adding to cores
[junit4:junit4] 2> 2289884 T4597 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2289885 T4597 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2289886 T4597 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2289886 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2289887 T4597 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2289888 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2289888 T4597 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2289889 T4597 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2289890 T4597 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2289891 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2289927 T4597 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2289928 T4597 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50524/solr
[junit4:junit4] 2> 2289928 T4597 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2289931 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2289937 T4677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26008177 name:ZooKeeperConnection Watcher:127.0.0.1:50524 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2289939 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2289943 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2289975 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2289981 T4679 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52f86d9b name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2289981 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2289996 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2291018 T4597 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50540_
[junit4:junit4] 2> 2291022 T4597 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50540_
[junit4:junit4] 2> 2291038 T4679 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291039 T4665 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291039 T4624 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291039 T4651 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291041 T4637 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291041 T4619 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2291063 T4597 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2291064 T4597 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2291065 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2291093 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2291127 T4631 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2291134 T4619 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2291139 T4621 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "maxShardsPerNode":null,
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"nodes_used_collection",
[junit4:junit4] 2> "replicationFactor":"2"}
[junit4:junit4] 2> 2291139 T4621 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:50540_
[junit4:junit4] 2> 2291140 T4621 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:50537_
[junit4:junit4] 2> 2291142 T4621 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:50527_
[junit4:junit4] 2> 2291143 T4621 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:50531_
[junit4:junit4] 2> 2291156 T4675 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2291161 T4675 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2291163 T4661 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2291166 T4661 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2291163 T4615 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2291172 T4615 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2291166 T4632 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2291178 T4632 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2291178 T4675 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2291180 T4675 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2291181 T4661 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2291181 T4661 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2291183 T4615 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2291183 T4615 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2291183 T4632 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2291186 T4632 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2291188 T4615 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2291189 T4615 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2291190 T4661 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2291190 T4661 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2291193 T4632 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2291194 T4632 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2291195 T4675 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2291196 T4675 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2291202 T4661 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2291206 T4615 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2291207 T4632 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2291209 T4661 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 2291221 T4615 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 2291223 T4675 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2291224 T4632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 2291233 T4675 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 2291502 T4632 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2291513 T4661 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2291539 T4675 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2291542 T4615 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2291859 T4675 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2291864 T4632 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2291874 T4675 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2291883 T4661 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2291899 T4632 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2291915 T4675 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2291922 T4661 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2291931 T4661 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2291939 T4632 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2291954 T4615 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2291971 T4615 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2291980 T4615 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2295457 T4632 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2295463 T4615 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2295481 T4632 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2295485 T4615 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2295487 T4632 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2295494 T4615 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2295509 T4661 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2295572 T4675 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2295580 T4661 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2295603 T4661 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2295610 T4632 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295618 T4615 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295626 T4675 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2295629 T4632 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295646 T4632 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295649 T4615 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295652 T4675 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2295653 T4632 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295660 T4632 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295661 T4632 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295666 T4615 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295677 T4615 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295707 T4615 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295708 T4615 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295678 T4632 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295709 T4632 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295710 T4632 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295711 T4632 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 2295717 T4632 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c702fb9
[junit4:junit4] 2> 2295718 T4632 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295728 T4615 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295729 T4615 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295730 T4615 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295731 T4615 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 2295731 T4615 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c702fb9
[junit4:junit4] 2> 2295732 T4615 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295728 T4632 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 2295733 T4632 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 2295735 T4632 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2295736 T4632 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 2295738 T4615 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 2295742 T4615 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 2295752 T4615 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2295755 T4615 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 2295777 T4632 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33705350 lockFactory=org.apache.lucene.store.NativeFSLockFactory@473e6d59),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2295779 T4632 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2295780 T4615 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@37f82b32 lockFactory=org.apache.lucene.store.NativeFSLockFactory@796aa629),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2295780 T4615 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2295788 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2295789 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2295790 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2295791 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2295795 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2295797 T4632 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2295798 T4632 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2295798 T4632 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2295799 T4632 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2295794 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2295800 T4632 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2295801 T4615 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2295801 T4632 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2295813 T4615 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2295814 T4615 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2295815 T4615 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2295816 T4615 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2295817 T4615 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2295823 T4661 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295838 T4632 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2295843 T4615 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2295880 T4615 oass.SolrIndexSearcher.<init> Opening Searcher@6eb48c94 main
[junit4:junit4] 2> 2295881 T4615 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 2295882 T4675 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295883 T4615 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2295883 T4615 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2295881 T4661 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295890 T4632 oass.SolrIndexSearcher.<init> Opening Searcher@60ca4e42 main
[junit4:junit4] 2> 2295891 T4632 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 2295893 T4632 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2295893 T4632 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2295904 T4686 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@60ca4e42 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2295912 T4675 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2295914 T4685 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@6eb48c94 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2295915 T4661 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295919 T4615 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 2295924 T4632 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 2295935 T4675 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295937 T4661 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295938 T4661 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295938 T4661 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295939 T4675 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295940 T4675 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295941 T4675 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2295949 T4661 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295950 T4661 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295951 T4661 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295952 T4661 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 2295952 T4661 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c702fb9
[junit4:junit4] 2> 2295957 T4661 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295960 T4675 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2295961 T4675 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2295961 T4675 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295962 T4675 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 2295962 T4675 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c702fb9
[junit4:junit4] 2> 2295963 T4675 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2295967 T4661 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 2295968 T4661 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 2295968 T4661 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2295970 T4661 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 2295974 T4675 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 2295975 T4675 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 2295975 T4675 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2295982 T4675 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 2296015 T4661 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5504b3df lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e7cd276),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2296016 T4661 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2296017 T4675 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19185fa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@588ce62e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2296018 T4675 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2296034 T4661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2296035 T4661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2296037 T4661 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2296038 T4661 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2296039 T4661 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2296039 T4661 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2296041 T4661 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2296042 T4661 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2296037 T4675 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2296044 T4675 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2296045 T4675 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2296043 T4661 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2296047 T4675 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2296052 T4675 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2296053 T4675 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2296054 T4675 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2296057 T4675 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2296059 T4675 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2296076 T4675 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2296088 T4661 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2296095 T4675 oass.SolrIndexSearcher.<init> Opening Searcher@5a01e9c9 main
[junit4:junit4] 2> 2296095 T4675 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 2296099 T4675 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2296099 T4675 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2296102 T4661 oass.SolrIndexSearcher.<init> Opening Searcher@46bcc678 main
[junit4:junit4] 2> 2296102 T4661 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 2296106 T4661 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2296106 T4661 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2296114 T4687 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@5a01e9c9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2296117 T4675 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 2296121 T4688 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@46bcc678 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2296123 T4661 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 2296463 T4620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2296470 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50527_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50527"}
[junit4:junit4] 2> 2296471 T4620 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 2296488 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50531_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50531"}
[junit4:junit4] 2> 2296507 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50540_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50540"}
[junit4:junit4] 2> 2296525 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50537_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50537"}
[junit4:junit4] 2> 2296560 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296561 T4651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296561 T4637 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296562 T4624 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296562 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296566 T4619 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2296938 T4615 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2296940 T4615 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:50527 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2296941 T4632 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2296942 T4632 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:50531 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2296945 T4615 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2296946 T4632 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2296998 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2297019 T4632 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2297020 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2297020 T4632 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2297021 T4632 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50531 START replicas=[http://127.0.0.1:50527/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 2297024 T4632 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50531 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2297025 T4632 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2297027 T4632 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:junit4] 2> 2297027 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2297028 T4632 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C2416 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2416_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2297057 T4614 C2416 P50527 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=9
[junit4:junit4] 2> 2297127 T4675 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2297131 T4675 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:50540 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2297135 T4661 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2297136 T4661 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:50537 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2297136 T4675 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2297140 T4661 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2297217 T4661 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2297235 T4661 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2297236 T4661 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2297236 T4661 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2297237 T4661 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50537 START replicas=[http://127.0.0.1:50540/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 2297239 T4661 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50537 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2297240 T4661 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2297240 T4661 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:junit4] 2> 2297241 T4661 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2297241 T4661 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C2417 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@2bc1b5df url=http://127.0.0.1:50540/nodes_used_collection_shard1_replica1 node=127.0.0.1:50540_ C2417_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50540_, base_url=http://127.0.0.1:50540}
[junit4:junit4] 2> 2297260 T4674 C2417 P50540 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=3
[junit4:junit4] 2> 2298129 T4620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2298174 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298175 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298174 T4651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298175 T4619 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298175 T4637 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298175 T4624 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2298206 T4661 oasc.ZkController.register We are http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2298207 T4661 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:50537
[junit4:junit4] 2> 2298208 T4661 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2298209 T4661 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 2298214 T4661 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2298217 T4615 oasc.ZkController.register We are http://127.0.0.1:50527/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2298218 T4615 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:50527
[junit4:junit4] 2> 2298219 T4615 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2298226 T4615 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2298218 T4661 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=7055
[junit4:junit4] 2> ASYNC NEW_CORE C2418 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2418_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2298228 T4691 C2418 P50527 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2298230 T4691 C2418 P50527 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2298232 T4691 C2418 P50527 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4] 2> 2298234 T4632 oasc.ZkController.register We are http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2298235 T4632 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:50531
[junit4:junit4] 2> 2298236 T4632 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2298236 T4632 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 2298233 T4615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2298232 T4675 oasc.ZkController.register We are http://127.0.0.1:50540/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2298239 T4675 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:50540
[junit4:junit4] 2> 2298239 T4675 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2298240 T4675 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2298237 T4691 C2418 P50527 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2298242 T4615 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=7078
[junit4:junit4] 2> 2298246 T4692 C2417 P50540 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2298247 T4692 C2417 P50540 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2298248 T4692 C2417 P50540 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 2298250 T4675 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2298254 T4692 C2417 P50540 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2298258 T4632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2298264 T4675 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=7108
[junit4:junit4] 2> 2298284 T4630 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50527__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2298285 T4632 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=7119
[junit4:junit4] 2> 2298286 T4621 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 2298303 T4657 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50540__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2298307 T4637 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 2298314 T4631 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=7187
[junit4:junit4] 2> 2298320 T4619 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2298320 T4621 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=7055},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=7078},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=7108},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=7119},core=nodes_used_collection_shard2_replica2}}}
[junit4:junit4] 2> 2298320 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2298323 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2298331 T4694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d5f4463 name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2298332 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2298335 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2298343 T4597 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2298346 T4597 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2298352 T4696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77270ecc name:ZooKeeperConnection Watcher:127.0.0.1:50524/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2298353 T4597 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2298356 T4597 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2298391 T4644 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=5&maxShardsPerNode=6&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2298395 T4619 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2298400 T4621 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "maxShardsPerNode":"6",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 2298401 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50537_
[junit4:junit4] 2> 2298401 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50527_
[junit4:junit4] 2> 2298402 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50540_
[junit4:junit4] 2> 2298403 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50531_
[junit4:junit4] 2> 2298404 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50534_
[junit4:junit4] 2> 2298406 T4658 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 2298406 T4658 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298409 T4612 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 2298410 T4612 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298409 T4633 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 2298411 T4633 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298411 T4672 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 2298415 T4672 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298415 T4645 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard1_replica5
[junit4:junit4] 2> 2298417 T4645 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298414 T4658 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298418 T4658 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298412 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50537_
[junit4:junit4] 2> 2298420 T4645 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298421 T4645 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298420 T4612 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298418 T4672 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298417 T4633 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298423 T4633 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298424 T4658 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2298425 T4658 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298423 T4672 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298422 T4612 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298431 T4660 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 2298432 T4660 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298430 T4645 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2298433 T4645 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298426 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50527_
[junit4:junit4] 2> 2298436 T4633 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2298436 T4633 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298438 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50540_
[junit4:junit4] 2> 2298438 T4660 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2298447 T4660 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2298445 T4672 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2298448 T4672 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298445 T4614 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 2298450 T4614 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298445 T4612 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2298452 T4612 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298441 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50531_
[junit4:junit4] 2> 2298448 T4673 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 2298455 T4673 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298456 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50534_
[junit4:junit4] 2> 2298458 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50537_
[junit4:junit4] 2> 2298465 T4645 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298465 T4673 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298469 T4673 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298465 T4660 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2298465 T4658 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298464 T4629 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 2298473 T4629 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298464 T4633 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298475 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50527_
[junit4:junit4] 2> 2298473 T4614 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298480 T4614 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298468 T4646 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard2_replica5
[junit4:junit4] 2> 2298482 T4646 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298479 T4656 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 2298485 T4656 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298492 T4629 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298493 T4629 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298494 T4645 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard1_replica5/'
[junit4:junit4] 2> 2298491 T4673 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 2298485 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50540_
[junit4:junit4] 2> 2298500 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50531_
[junit4:junit4] 2> 2298491 T4672 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298490 T4610 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 2298515 T4610 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298517 T4633 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 2298514 T4674 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3
[junit4:junit4] 2> 2298519 T4674 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298511 T4632 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard3_replica4
[junit4:junit4] 2> 2298520 T4632 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298511 T4646 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298522 T4646 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298510 T4656 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298528 T4656 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298510 T4660 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298530 T4658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 2298534 T4674 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298534 T4674 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298504 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica5 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50534_
[junit4:junit4] 2> 2298534 T4632 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298542 T4632 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298558 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50537_
[junit4:junit4] 2> 2298560 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50527_
[junit4:junit4] 2> 2298569 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50540_
[junit4:junit4] 2> 2298589 T4646 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard2_replica5/'
[junit4:junit4] 2> 2298588 T4642 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard3_replica5
[junit4:junit4] 2> 2298593 T4642 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298586 T4610 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298585 T4661 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 2298596 T4661 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298596 T4610 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298605 T4613 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 2298609 T4613 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298602 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50531_
[junit4:junit4] 2> 2298608 T4671 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard4_replica3
[junit4:junit4] 2> 2298613 T4671 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298617 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica5 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50534_
[junit4:junit4] 2> 2298643 T4614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 2298642 T4674 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/'
[junit4:junit4] 2> 2298641 T4612 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298640 T4671 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298667 T4671 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298640 T4631 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard4_replica4
[junit4:junit4] 2> 2298668 T4631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298639 T4642 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298670 T4642 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298668 T4629 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 2298654 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica1 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50537_
[junit4:junit4] 2> 2298701 T4612 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 2298700 T4632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard3_replica4/'
[junit4:junit4] 2> 2298697 T4610 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/'
[junit4:junit4] 2> 2298696 T4671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard4_replica3/'
[junit4:junit4] 2> 2298694 T4660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 2298685 T4631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298711 T4631 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298685 T4656 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard3_replica1/'
[junit4:junit4] 2> 2298683 T4661 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298742 T4661 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298683 T4613 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298760 T4613 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298742 T4642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard3_replica5/'
[junit4:junit4] 2> 2298735 T4659 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard5_replica1
[junit4:junit4] 2> 2298769 T4659 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298717 T4643 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard4_replica5
[junit4:junit4] 2> 2298772 T4643 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298773 T4631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard4_replica4/'
[junit4:junit4] 2> 2298717 T4672 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 2298716 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica2 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50527_
[junit4:junit4] 2> 2298785 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica3 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50540_
[junit4:junit4] 2> 2298787 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica4 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50531_
[junit4:junit4] 2> 2298797 T4659 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298824 T4659 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298794 T4643 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298829 T4613 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard4_replica2/'
[junit4:junit4] 2> 2298792 T4615 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard5_replica2
[junit4:junit4] 2> 2298853 T4615 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298853 T4659 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard5_replica1/'
[junit4:junit4] 2> 2298838 T4628 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard5_replica4
[junit4:junit4] 2> 2298856 T4628 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298833 T4661 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370076089337/awholynewcollection_0_shard4_replica1/'
[junit4:junit4] 2> 2298871 T4628 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298873 T4628 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298831 T4621 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica5 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50534_
[junit4:junit4] 2> 2298830 T4643 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298823 T4675 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard5_replica3
[junit4:junit4] 2> 2298881 T4675 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298883 T4628 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard5_replica4/'
[junit4:junit4] 2> 2298884 T4675 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298884 T4675 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298895 T4675 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard5_replica3/'
[junit4:junit4] 2> 2298901 T4647 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard5_replica5
[junit4:junit4] 2> 2298918 T4647 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2298945 T4615 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298947 T4615 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298961 T4647 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2298962 T4647 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2298963 T4643 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard4_replica5/'
[junit4:junit4] 2> 2298993 T4615 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard5_replica2/'
[junit4:junit4] 2> 2299001 T4647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370076087024/awholynewcollection_0_shard5_replica5/'
[junit4:junit4] 2> 2299354 T4656 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299392 T4673 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299412 T4612 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299482 T4645 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299541 T4633 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299566 T4643 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299752 T4620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2299755 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50537__nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50537_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50537"}
[junit4:junit4] 2> 2299821 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50527__nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50527_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50527"}
[junit4:junit4] 2> 2299902 T4629 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2299922 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50531__nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50531_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50531"}
[junit4:junit4] 2> 2299981 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50540__nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50540_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50540"}
[junit4:junit4] 2> 2300065 T4696 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300066 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300066 T4624 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300067 T4651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300066 T4619 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300066 T4694 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300067 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300067 T4637 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2300223 T4671 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300234 T4631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300236 T4656 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2300267 T4656 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2300328 T4657 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50540__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2300329 T4657 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50540__nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:50540_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2026
[junit4:junit4] 2> 2300329 T4630 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50527__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2300331 T4630 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50527__nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:50527_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2047
[junit4:junit4] 2> 2300339 T4610 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300392 T4658 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300498 T4613 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300602 T4656 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
[junit4:junit4] 2> 2300632 T4642 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2300697 T4643 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2300742 T4643 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2300874 T4643 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica5] Schema name=test
[junit4:junit4] 2> 2300971 T4674 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301047 T4647 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301053 T4661 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301122 T4646 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301184 T4660 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301225 T4615 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301400 T4632 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301519 T4672 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301540 T4612 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2301554 T4612 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2301566 T4628 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301661 T4614 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301711 T4633 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2301744 T4675 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2301759 T4633 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2301769 T4633 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 2301770 T4645 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2301770 T4612 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2301804 T4645 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2301813 T4645 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica5] Schema name=test
[junit4:junit4] 2> 2301913 T4629 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2301916 T4659 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2302005 T4629 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302013 T4629 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 2302065 T4673 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2302103 T4673 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302116 T4631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2302119 T4673 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 2302141 T4631 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302150 T4631 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica4] Schema name=test
[junit4:junit4] 2> 2302311 T4613 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> ASYNC NEW_CORE C2419 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@2bc1b5df url=http://127.0.0.1:50540/nodes_used_collection_shard1_replica1 node=127.0.0.1:50540_ C2419_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50540_, base_url=http://127.0.0.1:50540}
[junit4:junit4] 2> 2302331 T4692 C2419 P50540 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2302332 T4692 C2419 P50540 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:50540 START replicas=[http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 2302335 T4692 C2419 P50540 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2302336 T4692 C2419 P50540 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2302337 T4692 C2419 P50540 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2302337 T4692 C2419 P50540 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2302337 T4692 C2419 P50540 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2302338 T4692 C2419 P50540 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50537/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> ASYNC NEW_CORE C2420 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2420_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2302336 T4691 C2420 P50527 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2302339 T4691 C2420 P50527 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:50527 START replicas=[http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 2302338 T4692 C2419 P50540 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2302350 T4691 C2420 P50527 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2302351 T4691 C2420 P50527 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2302351 T4691 C2420 P50527 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2302351 T4691 C2420 P50527 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2302352 T4691 C2420 P50527 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2302352 T4691 C2420 P50527 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50531/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2302352 T4691 C2420 P50527 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2302355 T4613 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302364 T4613 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
[junit4:junit4] 2> 2302651 T4610 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2302701 T4610 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302710 T4610 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
[junit4:junit4] 2> 2302821 T4658 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> ASYNC NEW_CORE C2421 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@a0fc6a6 url=http://127.0.0.1:50531/nodes_used_collection_shard2_replica2 node=127.0.0.1:50531_ C2421_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50531_, base_url=http://127.0.0.1:50531, leader=true}
[junit4:junit4] 2> 2302850 T4630 C2421 P50531 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2302853 T4671 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2302853 T4658 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302894 T4671 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2302952 T4671 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica3] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C2422 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@1439158f url=http://127.0.0.1:50537/nodes_used_collection_shard1_replica2 node=127.0.0.1:50537_ C2422_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50537_, base_url=http://127.0.0.1:50537, leader=true}
[junit4:junit4] 2> 2302962 T4721 C2422 P50537 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2302983 T4721 C2422 P50537 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5504b3df lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e7cd276),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2302997 T4721 C2422 P50537 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> ASYNC NEW_CORE C2423 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@a0fc6a6 url=http://127.0.0.1:50531/nodes_used_collection_shard2_replica2 node=127.0.0.1:50531_ C2423_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50531_, base_url=http://127.0.0.1:50531, leader=true}
[junit4:junit4] 2> 2303060 T4722 C2423 P50531 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=58
[junit4:junit4] 2> 2303062 T4657 C2422 P50537 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=57
[junit4:junit4] 2> 2303081 T4721 C2422 P50537 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5504b3df lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e7cd276),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5504b3df lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e7cd276),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2303082 T4721 C2422 P50537 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2303083 T4721 C2422 P50537 oass.SolrIndexSearcher.<init> Opening Searcher@3007183 realtime
[junit4:junit4] 2> 2303084 T4721 C2422 P50537 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2303085 T4721 C2422 P50537 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 123
[junit4:junit4] 2> ASYNC NEW_CORE C2424 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@2bc1b5df url=http://127.0.0.1:50540/nodes_used_collection_shard1_replica1 node=127.0.0.1:50540_ C2424_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50540_, base_url=http://127.0.0.1:50540}
[junit4:junit4] 2> 2303101 T4692 C2424 P50540 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2303101 T4692 C2424 P50540 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2303107 T4632 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> ASYNC NEW_CORE C2425 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@1439158f url=http://127.0.0.1:50537/nodes_used_collection_shard1_replica2 node=127.0.0.1:50537_ C2425_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50537_, base_url=http://127.0.0.1:50537, leader=true}
[junit4:junit4] 2> 2303134 T4657 C2425 P50537 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2303186 T4657 C2425 P50537 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=54
[junit4:junit4] 2> 2303126 T4658 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2303122 T4615 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> ASYNC NEW_CORE C2426 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@2bc1b5df url=http://127.0.0.1:50540/nodes_used_collection_shard1_replica1 node=127.0.0.1:50540_ C2426_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50540_, base_url=http://127.0.0.1:50540}
[junit4:junit4] 2> 2303193 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2303194 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2303195 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2303202 T4721 C2425 P50537 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2303204 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2303208 T4632 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303208 T4615 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303227 T4615 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica2] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C2427 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@a0fc6a6 url=http://127.0.0.1:50531/nodes_used_collection_shard2_replica2 node=127.0.0.1:50531_ C2427_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50531_, base_url=http://127.0.0.1:50531, leader=true}
[junit4:junit4] 2> 2303232 T4630 C2427 P50531 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33705350 lockFactory=org.apache.lucene.store.NativeFSLockFactory@473e6d59),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2303233 T4630 C2427 P50531 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2303238 T4632 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica4] Schema name=test
[junit4:junit4] 2> 2303256 T4660 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2303276 T4660 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303296 T4630 C2427 P50531 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33705350 lockFactory=org.apache.lucene.store.NativeFSLockFactory@473e6d59),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33705350 lockFactory=org.apache.lucene.store.NativeFSLockFactory@473e6d59),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2303302 T4630 C2427 P50531 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2303312 T4660 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2303319 T4630 C2427 P50531 oass.SolrIndexSearcher.<init> Opening Searcher@1f99d0e3 realtime
[junit4:junit4] 2> 2303320 T4630 C2427 P50531 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2303321 T4630 C2427 P50531 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 471
[junit4:junit4] 2> 2303321 T4692 C2426 P50540 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index.20130601104146549
[junit4:junit4] 2> 2303323 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5e7defa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b60f74a) fullCopy=false
[junit4:junit4] 2> ASYNC NEW_CORE C2428 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2428_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2303324 T4691 C2428 P50527 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2303325 T4691 C2428 P50527 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2303352 T4721 C2425 P50537 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2303357 T4722 C2427 P50531 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2303358 T4722 C2427 P50531 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=13
[junit4:junit4] 2> 2303359 T4691 C2428 P50527 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2303359 T4691 C2428 P50527 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2303360 T4691 C2428 P50527 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2303390 T4630 C2427 P50531 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=12
[junit4:junit4] 2> 2303392 T4691 C2428 P50527 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2303401 T4692 C2426 P50540 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2303405 T4642 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2303414 T4692 C2426 P50540 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2303414 T4692 C2426 P50540 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2303416 T4691 C2428 P50527 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index.20130601104146737
[junit4:junit4] 2> 2303416 T4691 C2428 P50527 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@46f2c8f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@60478628) fullCopy=false
[junit4:junit4] 2> 2303424 T4647 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2303429 T4722 C2427 P50531 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2303437 T4642 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303446 T4674 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2303470 T4674 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> ASYNC NEW_CORE C2429 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@2bc1b5df url=http://127.0.0.1:50540/nodes_used_collection_shard1_replica1 node=127.0.0.1:50540_ C2429_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50540_, base_url=http://127.0.0.1:50540}
[junit4:junit4] 2> 2303538 T4692 C2429 P50540 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19185fa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@588ce62e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19185fa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@588ce62e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2303549 T4692 C2429 P50540 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2303537 T4647 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303560 T4642 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica5] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C2430 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2430_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2303564 T4691 C2430 P50527 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2303582 T4692 C2429 P50540 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2303595 T4692 C2429 P50540 oass.SolrIndexSearcher.<init> Opening Searcher@38933f20 main
[junit4:junit4] 2> 2303597 T4687 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@38933f20 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2303607 T4692 C2429 P50540 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index.20130601104146549 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index.20130601104146549;done=true>>]
[junit4:junit4] 2> 2303607 T4692 C2429 P50540 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index.20130601104146549
[junit4:junit4] 2> 2303607 T4692 C2429 P50540 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/nodes_used_collection_shard1_replica1/data/index.20130601104146549
[junit4:junit4] 2> 2303608 T4692 C2429 P50540 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2303608 T4692 C2429 P50540 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2303608 T4692 C2429 P50540 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 2303641 T4691 C2430 P50527 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2303642 T4691 C2430 P50527 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2303662 T4692 C2429 P50540 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2303688 T4674 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica3] Schema name=test
[junit4:junit4] 2> 2303699 T4691 C2430 P50527 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@37f82b32 lockFactory=org.apache.lucene.store.NativeFSLockFactory@796aa629),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@37f82b32 lockFactory=org.apache.lucene.store.NativeFSLockFactory@796aa629),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2303700 T4691 C2430 P50527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> ASYNC NEW_CORE C2431 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@336dd38 url=http://127.0.0.1:50527/nodes_used_collection_shard2_replica1 node=127.0.0.1:50527_ C2431_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50527_, base_url=http://127.0.0.1:50527}
[junit4:junit4] 2> 2303801 T4691 C2431 P50527 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2303812 T4691 C2431 P50527 oass.SolrIndexSearcher.<init> Opening Searcher@28eed037 main
[junit4:junit4] 2> 2303814 T4685 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@28eed037 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2303816 T4691 C2431 P50527 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index.20130601104146737 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index.20130601104146737;done=true>>]
[junit4:junit4] 2> 2303817 T4691 C2431 P50527 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index.20130601104146737
[junit4:junit4] 2> 2303817 T4691 C2431 P50527 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/nodes_used_collection_shard2_replica1/data/index.20130601104146737
[junit4:junit4] 2> 2303818 T4691 C2431 P50527 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2303818 T4691 C2431 P50527 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2303819 T4691 C2431 P50527 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 2303832 T4647 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica5] Schema name=test
[junit4:junit4] 2> 2303852 T4691 C2431 P50527 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2303890 T4628 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2303957 T4628 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2303979 T4628 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica4] Schema name=test
[junit4:junit4] 2> 2304074 T4614 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2304092 T4614 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2304317 T4659 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2304334 T4646 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2304361 T4614 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2304370 T4659 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2304375 T4659 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica1] Schema name=test
[junit4:junit4] 2> 2304391 T4646 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2304521 T4646 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica5] Schema name=test
[junit4:junit4] 2> 2304555 T4661 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2304562 T4661 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2304569 T4661 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
[junit4:junit4] 2> 2304796 T4620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2304805 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50540__nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50540_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50540"}
[junit4:junit4] 2> 2304838 T4620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50527__nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50527_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50527"}
[junit4:junit4] 2> 2304858 T4696 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304859 T4651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304859 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304860 T4619 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304860 T4624 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304861 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304861 T4694 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304861 T4637 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2304901 T4672 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2304924 T4672 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2305066 T4672 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 2305154 T4675 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2305185 T4675 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2305195 T4675 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica3] Schema name=test
[junit4:junit4] 2> 2321400 T4629 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2321717 T4610 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2321743 T4656 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2321922 T4610 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2322210 T4629 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2322217 T4610 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2322243 T4629 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2322448 T4656 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2322846 T4656 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2322899 T4629 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2322929 T4647 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2322937 T4610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2322950 T4647 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2323068 T4633 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2323088 T4647 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2323107 T4610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2323119 T4631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2323127 T4629 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2323173 T4610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2323211 T4631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2323241 T4631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2323273 T4610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2323275 T4610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2323276 T4610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2323356 T4633 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2323371 T4610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2323372 T4610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2323373 T4610 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2323373 T4610 oasc.SolrCore.<init> [awholynewcollection_0_shard3_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/data/
[junit4:junit4] 2> 2323374 T4610 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c702fb9
[junit4:junit4] 2> 2323375 T4610 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2323378 T4656 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2323380 T4642 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2323404 T4610 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/data
[junit4:junit4] 2> 2323405 T4610 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/data/index/
[junit4:junit4] 2> 2323405 T4610 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard3_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2323406 T4610 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370076083088/awholynewcollection_0_shard3_replica2/data/index
[junit4:junit4] 2> 2323404 T4633 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2323421 T4642 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2323438 T4673 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2323453 T4629 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2323471 T4629 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2323472 T4629 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2323473 T4629 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2323484 T4658 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2323500 T4629 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2323512 T4629 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2323513 T4629 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2323513 T4629 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica4] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370076084753/awholynewcollection_0_shard2_replica4/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.s
[...truncated too long message...]
] 2> 2346759 T4597 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data/index;done=false>>]
[junit4:junit4] 2> 2346759 T4597 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data/index
[junit4:junit4] 2> 2346760 T4597 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data;done=false>>]
[junit4:junit4] 2> 2346760 T4597 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370076091600/awholynewcollection_0_shard3_replica3/data
[junit4:junit4] 2> 2346761 T4841 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89789306163298316-127.0.0.1:50540_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 2346767 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2346795 T4597 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 2346868 T4597 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2346873 T4597 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50524 50524
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=7D6B3C104BE946F9 -Dtests.slow=true -Dtests.locale=ar_LB -Dtests.timezone=Africa/Cairo -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 67.6s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_0
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([7D6B3C104BE946F9:FC8DB2083CB626C5]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:424)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:306)
[junit4:junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1400)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:438)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 2347045 T4597 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 67605 T4596 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 2348069 T4679 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2348070 T4679 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=255), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=255)), sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_LB, timezone=Africa/Cairo
[junit4:junit4] 2> NOTE: Mac OS X 10.8.3 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=3,free=80739152,total=292290560
[junit4:junit4] 2> NOTE: All tests run in this JVM: [NumericFieldsTest, PathHierarchyTokenizerFactoryTest, TestSchemaVersionResource, TestReversedWildcardFilterFactory, CSVRequestHandlerTest, TestIndexSearcher, WordBreakSolrSpellCheckerTest, TestAnalyzedSuggestions, TestConfig, TestQueryTypes, BadCopyFieldTest, SolrRequestParserTest, FileBasedSpellCheckerTest, DistributedSpellCheckComponentTest, SliceStateTest, TestSolrDeletionPolicy2, TestValueSourceCache, XsltUpdateRequestHandlerTest, DocValuesMultiTest, TestUtils, DirectUpdateHandlerTest, TestReloadAndDeleteDocs, TestFieldCollectionResource, DocumentBuilderTest, TestFieldTypeResource, ShardRoutingCustomTest, SearchHandlerTest, FastVectorHighlighterTest, ScriptEngineTest, TestSerializedLuceneMatchVersion, TestClassNameShortening, TestManagedSchemaFieldResource, TestCharFilters, DistributedQueryElevationComponentTest, TestIndexingPerformance, SuggesterTSTTest, SchemaVersionSpecificBehaviorTest, PreAnalyzedFieldTest, TestSurroundQueryParser, TestSolr4Spatial, TestCollationField, TestFieldResource, TestCloudManagedSchema, AnalysisAfterCoreReloadTest, QueryElevationComponentTest, TestCoreDiscovery, TestGroupingSearch, PrimUtilsTest, TestLMJelinekMercerSimilarityFactory, TestJmxIntegration, MinimalSchemaTest, AutoCommitTest, TestFastLRUCache, DocumentAnalysisRequestHandlerTest, ExternalFileFieldSortTest, ZkControllerTest, NotRequiredUniqueKeyTest, SpatialFilterTest, LeaderElectionIntegrationTest, SolrCoreCheckLockOnStartupTest, PluginInfoTest, DistributedTermsComponentTest, TestRandomFaceting, SpellCheckComponentTest, TestDFRSimilarityFactory, TestSuggestSpellingConverter, RegexBoostProcessorTest, CachingDirectoryFactoryTest, TestComponentsName, TestSolrXMLSerializer, TestCodecSupport, DateMathParserTest, UpdateParamsTest, TestSolrCoreProperties, TestStressRecovery, CurrencyFieldOpenExchangeTest, SyncSliceTest, FileUtilsTest, TestBinaryField, TestJoin, TestFastOutputStream, SpellPossibilityIteratorTest, BasicZkTest, SolrIndexConfigTest, OverseerCollectionProcessorTest, SpellingQueryConverterTest, TestDefaultSimilarityFactory, TestLFUCache, PolyFieldTest, TestUpdate, ReturnFieldsTest, TestSweetSpotSimilarityFactory, SolrPluginUtilsTest, URLClassifyProcessorTest, TestRangeQuery, SuggesterFSTTest, TermsComponentTest, SoftAutoCommitTest, TestLMDirichletSimilarityFactory, SliceStateUpdateTest, PeerSyncTest, TestDynamicFieldCollectionResource, RecoveryZkTest, TestFieldTypeCollectionResource, TestIBSimilarityFactory, TestPostingsSolrHighlighter, MBeansHandlerTest, TestSolrXml, FieldAnalysisRequestHandlerTest, PreAnalyzedUpdateProcessorTest, TestSolrIndexConfig, HighlighterTest, ShowFileRequestHandlerTest, TestBinaryResponseWriter, TestSolrQueryParserDefaultOperatorResource, StatelessScriptUpdateProcessorFactoryTest, ZkNodePropsTest, TestDistributedGrouping, TestBadConfig, CircularListTest, SolrCoreTest, HardAutoCommitTest, ChaosMonkeyNothingIsSafeTest, TestSchemaResource, AliasIntegrationTest, TestSolrQueryParserResource, FieldMutatingUpdateProcessorTest, TestXIncludeConfig, SolrInfoMBeanTest, HighlighterConfigTest, TestFaceting, ClusterStateUpdateTest, DefaultValueUpdateProcessorTest, TestDefaultSearchFieldResource, OutputWriterTest, IndexSchemaTest, TestLazyCores, SimplePostToolTest, TestSchemaSimilarityResource, TestSolrDeletionPolicy1, TestCloudManagedSchemaAddField, OverseerTest, TestReplicationHandler, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 68.69s, 1 test, 1 error <<< FAILURES!
[...truncated 452 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:380: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:360: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1240: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:884: There were test failures: 296 suites, 1235 tests, 1 error, 18 ignored (6 assumptions)
Total time: 112 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure