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/12 12:31:40 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 555 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/555/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: 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([229379F9B8588E5C:A375F7E1CF07EE60]: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 9553 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 2110256 T3660 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /c_ao/
[junit4:junit4] 2> 2110268 T3660 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-1371031303221
[junit4:junit4] 2> 2110273 T3660 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2110278 T3661 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2110379 T3660 oasc.ZkTestServer.run start zk server on port:50275
[junit4:junit4] 2> 2110392 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2110436 T3667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50317a03 name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2110444 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2110445 T3660 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2110477 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2110484 T3669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a71562e name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2110484 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2110485 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2110497 T3660 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2110517 T3660 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2110538 T3660 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2110561 T3660 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> 2110563 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2110578 T3660 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> 2110580 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2110590 T3660 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> 2110592 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2110602 T3660 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> 2110603 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2110613 T3660 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> 2110617 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2110633 T3660 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> 2110634 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2110644 T3660 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> 2110646 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2110660 T3660 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> 2110661 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2110671 T3660 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> 2110673 T3660 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2111354 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2111385 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50278
[junit4:junit4] 2> 2111387 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2111388 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2111431 T3660 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-1371031303636
[junit4:junit4] 2> 2111433 T3660 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-1371031303636/solr.xml
[junit4:junit4] 2> 2111435 T3660 oasc.CoreContainer.<init> New CoreContainer 26686617
[junit4:junit4] 2> 2111437 T3660 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-1371031303636/'
[junit4:junit4] 2> 2111438 T3660 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-1371031303636/'
[junit4:junit4] 2> 2111685 T3660 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-1371031303636
[junit4:junit4] 2> 2111688 T3660 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-1371031303636/collection1
[junit4:junit4] 2> 2111689 T3660 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-1371031303636/collection1/conf
[junit4:junit4] 2> 2111894 T3660 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-1371031303636/collection1/conf/xslt
[junit4:junit4] 2> 2111899 T3660 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-1371031303636/collection1/lib
[junit4:junit4] 2> 2111901 T3660 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-1371031303636/collection1/lib/classes
[junit4:junit4] 2> 2111904 T3660 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-1371031303636/conf/core.properties, adding to cores
[junit4:junit4] 2> 2111922 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2111929 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2111936 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2111937 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2111937 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2111938 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2111939 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2111939 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2111940 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2111941 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2111970 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2111971 T3660 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50275/solr
[junit4:junit4] 2> 2111972 T3660 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2111975 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2111982 T3680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ccf86eb name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2111983 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2111991 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2112020 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2112025 T3682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@148ff662 name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2112025 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2112032 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2112045 T3660 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2112056 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2112068 T3660 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2112071 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2112083 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2112100 T3660 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2112108 T3660 oasc.Overseer.start Overseer (id=89851907489005571-127.0.0.1:50278_c_ao-n_0000000000) starting
[junit4:junit4] 2> 2112119 T3660 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2112136 T3684 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2112139 T3660 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2112149 T3660 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2112155 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2112166 T3683 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2112175 T3660 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2112176 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2112176 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2112203 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2112208 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2112212 T3687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42297965 name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2112213 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2112217 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2112225 T3660 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2112825 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2112870 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50282
[junit4:junit4] 2> 2112874 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2112875 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2112876 T3660 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-1371031305175
[junit4:junit4] 2> 2112876 T3660 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-1371031305175/solr.xml
[junit4:junit4] 2> 2112877 T3660 oasc.CoreContainer.<init> New CoreContainer 1431325023
[junit4:junit4] 2> 2112878 T3660 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-1371031305175/'
[junit4:junit4] 2> 2112879 T3660 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-1371031305175/'
[junit4:junit4] 2> 2113066 T3660 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-1371031305175
[junit4:junit4] 2> 2113068 T3660 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-1371031305175/collection1
[junit4:junit4] 2> 2113070 T3660 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-1371031305175/collection1/conf
[junit4:junit4] 2> 2113260 T3660 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-1371031305175/collection1/conf/xslt
[junit4:junit4] 2> 2113265 T3660 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-1371031305175/collection1/lib
[junit4:junit4] 2> 2113267 T3660 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-1371031305175/collection1/lib/classes
[junit4:junit4] 2> 2113271 T3660 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-1371031305175/conf/core.properties, adding to cores
[junit4:junit4] 2> 2113305 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2113306 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2113307 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2113308 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2113308 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2113309 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2113310 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2113310 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2113311 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2113312 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2113348 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2113349 T3660 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50275/solr
[junit4:junit4] 2> 2113349 T3660 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2113355 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2113359 T3698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26f4dac name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2113360 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2113370 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2113391 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2113398 T3700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5dbcdb21 name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2113398 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2113412 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2114431 T3660 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2114434 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2114449 T3682 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2114449 T3687 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2114449 T3700 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2114457 T3660 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2114457 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2114458 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2115109 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2115118 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50285
[junit4:junit4] 2> 2115120 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2115121 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2115122 T3660 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-1371031307434
[junit4:junit4] 2> 2115122 T3660 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-1371031307434/solr.xml
[junit4:junit4] 2> 2115123 T3660 oasc.CoreContainer.<init> New CoreContainer 1873381402
[junit4:junit4] 2> 2115124 T3660 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-1371031307434/'
[junit4:junit4] 2> 2115125 T3660 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-1371031307434/'
[junit4:junit4] 2> 2115318 T3660 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-1371031307434
[junit4:junit4] 2> 2115320 T3660 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-1371031307434/collection1
[junit4:junit4] 2> 2115322 T3660 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-1371031307434/collection1/conf
[junit4:junit4] 2> 2115507 T3660 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-1371031307434/collection1/conf/xslt
[junit4:junit4] 2> 2115513 T3660 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-1371031307434/collection1/lib
[junit4:junit4] 2> 2115515 T3660 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-1371031307434/collection1/lib/classes
[junit4:junit4] 2> 2115519 T3660 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-1371031307434/conf/core.properties, adding to cores
[junit4:junit4] 2> 2115542 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2115543 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2115544 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2115544 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2115545 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2115546 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2115547 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2115547 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2115548 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2115549 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2115578 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2115579 T3660 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50275/solr
[junit4:junit4] 2> 2115580 T3660 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2115583 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2115588 T3712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b8acc1a name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2115590 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2115595 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2115627 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2115633 T3714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5daf5690 name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2115633 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2115650 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2116661 T3660 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2116670 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2116683 T3682 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2116684 T3687 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2116684 T3700 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2116685 T3714 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2116702 T3660 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2116703 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2116704 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2117353 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2117360 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50288
[junit4:junit4] 2> 2117363 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2117364 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2117364 T3660 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-1371031309689
[junit4:junit4] 2> 2117365 T3660 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-1371031309689/solr.xml
[junit4:junit4] 2> 2117365 T3660 oasc.CoreContainer.<init> New CoreContainer 1970547251
[junit4:junit4] 2> 2117366 T3660 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-1371031309689/'
[junit4:junit4] 2> 2117367 T3660 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-1371031309689/'
[junit4:junit4] 2> 2117556 T3660 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-1371031309689
[junit4:junit4] 2> 2117559 T3660 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-1371031309689/collection1
[junit4:junit4] 2> 2117560 T3660 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-1371031309689/collection1/conf
[junit4:junit4] 2> 2117783 T3660 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-1371031309689/collection1/conf/xslt
[junit4:junit4] 2> 2117790 T3660 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-1371031309689/collection1/lib
[junit4:junit4] 2> 2117793 T3660 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-1371031309689/collection1/lib/classes
[junit4:junit4] 2> 2117796 T3660 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-1371031309689/conf/core.properties, adding to cores
[junit4:junit4] 2> 2117814 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2117815 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2117816 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2117816 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2117817 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2117818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2117818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2117819 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2117820 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2117820 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2117858 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2117859 T3660 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50275/solr
[junit4:junit4] 2> 2117860 T3660 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2117862 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2117870 T3726 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@753f0893 name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2117872 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2117879 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2117905 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2117920 T3728 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e0a998e name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2117920 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2117935 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2118948 T3660 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2118951 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2118961 T3700 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2118962 T3682 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2118962 T3714 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2118983 T3728 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2118983 T3687 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2118984 T3660 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2118985 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2118985 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2119870 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2119881 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50291
[junit4:junit4] 2> 2119883 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2119884 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2119884 T3660 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-1371031311961
[junit4:junit4] 2> 2119885 T3660 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-1371031311961/solr.xml
[junit4:junit4] 2> 2119885 T3660 oasc.CoreContainer.<init> New CoreContainer 761198889
[junit4:junit4] 2> 2119886 T3660 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-1371031311961/'
[junit4:junit4] 2> 2119887 T3660 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-1371031311961/'
[junit4:junit4] 2> 2120130 T3660 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-1371031311961
[junit4:junit4] 2> 2120132 T3660 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-1371031311961/collection1
[junit4:junit4] 2> 2120135 T3660 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-1371031311961/collection1/conf
[junit4:junit4] 2> 2120392 T3660 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-1371031311961/collection1/conf/xslt
[junit4:junit4] 2> 2120400 T3660 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-1371031311961/collection1/lib
[junit4:junit4] 2> 2120414 T3660 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-1371031311961/collection1/lib/classes
[junit4:junit4] 2> 2120417 T3660 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-1371031311961/conf/core.properties, adding to cores
[junit4:junit4] 2> 2120453 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2120455 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2120460 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2120463 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2120464 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2120466 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2120466 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2120468 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2120469 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2120471 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2120505 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2120507 T3660 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50275/solr
[junit4:junit4] 2> 2120513 T3660 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2120525 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2120533 T3740 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9331f87 name:ZooKeeperConnection Watcher:127.0.0.1:50275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2120537 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2120544 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2120578 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2120585 T3742 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@218865f1 name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2120585 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2120597 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2121614 T3660 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2121618 T3660 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2121643 T3687 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121643 T3682 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121644 T3728 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121643 T3714 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121644 T3700 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121644 T3742 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2121660 T3660 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2121661 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2121662 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2121684 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2121717 T3695 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2121733 T3682 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2121738 T3684 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> 2121738 T3684 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:50288_c_ao
[junit4:junit4] 2> 2121741 T3684 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:50285_c_ao
[junit4:junit4] 2> 2121743 T3684 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:50291_c_ao
[junit4:junit4] 2> 2121771 T3684 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:50282_c_ao
[junit4:junit4] 2> 2121778 T3722 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 2121789 T3737 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 2121789 T3689 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 2121791 T3709 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 2122748 T3683 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2122756 T3683 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:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2122758 T3683 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 2122774 T3683 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:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2122795 T3683 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:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2122814 T3683 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:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2122862 T3687 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> 2122864 T3742 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> 2122864 T3728 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> 2122864 T3714 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> 2122865 T3700 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> 2122873 T3682 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> 2123806 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2123807 T3709 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2123808 T3737 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-jetty4-1371031311961/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2123808 T3737 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2123807 T3722 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-jetty3-1371031309689/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2123810 T3722 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2123807 T3689 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-1371031305175/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2123812 T3689 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2123812 T3709 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2123813 T3709 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2123814 T3737 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2123815 T3737 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2123816 T3689 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2123814 T3722 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2123817 T3722 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2123816 T3689 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2123820 T3709 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2123821 T3709 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2123823 T3737 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2123824 T3737 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2123826 T3689 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2123827 T3689 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2123827 T3722 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2123828 T3722 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2123835 T3709 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2123837 T3737 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2123839 T3689 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2123841 T3722 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2123844 T3709 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-1371031307434/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 2123846 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 2123849 T3737 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-1371031311961/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 2123853 T3722 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-1371031309689/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 2124038 T3737 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2124160 T3722 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2124160 T3689 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2124174 T3709 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2124397 T3737 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2124431 T3737 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2124440 T3737 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2124488 T3689 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2124512 T3689 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2124530 T3689 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2124575 T3709 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2124587 T3709 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2124594 T3709 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2124607 T3722 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2124627 T3722 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2124641 T3722 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2128022 T3689 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2128049 T3689 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2128057 T3737 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2128068 T3689 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2128084 T3737 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2128093 T3737 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2128105 T3709 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2128132 T3722 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2128140 T3709 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2128151 T3709 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2128192 T3722 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2128199 T3689 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128210 T3722 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2128215 T3689 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128231 T3689 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128244 T3689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128246 T3689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128246 T3689 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128260 T3689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128261 T3689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128262 T3689 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128262 T3689 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-1371031305175/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-1371031305175/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 2128263 T3689 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff2be8
[junit4:junit4] 2> 2128264 T3689 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128266 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 2128275 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 2128276 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2128278 T3737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128283 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 2128298 T3737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128312 T3709 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128319 T3737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128332 T3709 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128335 T3737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128366 T3737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128367 T3737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128358 T3709 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128339 T3689 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5bf55f1b lockFactory=org.apache.lucene.store.NativeFSLockFactory@30acbe33),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2128375 T3689 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2128379 T3737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128379 T3737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128380 T3737 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128380 T3737 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-jetty4-1371031311961/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-jetty4-1371031311961/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 2128381 T3737 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff2be8
[junit4:junit4] 2> 2128382 T3737 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128383 T3737 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-1371031311961/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 2128381 T3689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2128386 T3689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2128387 T3689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2128388 T3689 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2128389 T3689 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2128390 T3689 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2128391 T3689 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2128392 T3689 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2128392 T3689 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2128395 T3709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128396 T3709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128397 T3709 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128395 T3737 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-1371031311961/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 2128398 T3737 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-jetty4-1371031311961/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2128396 T3722 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128411 T3737 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-1371031311961/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 2128423 T3709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128424 T3709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128425 T3709 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128427 T3709 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-jetty2-1371031307434/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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 2128428 T3709 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff2be8
[junit4:junit4] 2> 2128428 T3709 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128437 T3689 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2128448 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 2128455 T3722 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2128459 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 2128459 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2128460 T3737 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5675db24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e76455e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2128461 T3737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2128463 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 2128467 T3737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2128468 T3737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2128478 T3737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2128479 T3737 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2128481 T3737 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2128481 T3737 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2128482 T3737 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2128483 T3737 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2128484 T3737 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2128489 T3689 oass.SolrIndexSearcher.<init> Opening Searcher@2e72f186 main
[junit4:junit4] 2> 2128490 T3689 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-1371031305175/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 2128492 T3689 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2128493 T3689 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2128504 T3709 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4908d3ef lockFactory=org.apache.lucene.store.NativeFSLockFactory@4dc46ab),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2128504 T3709 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2128509 T3709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2128510 T3709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2128511 T3709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2128513 T3748 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@2e72f186 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2128514 T3709 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2128516 T3709 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2128516 T3709 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2128517 T3709 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2128518 T3709 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2128519 T3709 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2128530 T3709 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2128531 T3737 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2128541 T3689 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2128542 T3689 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:50282/c_ao collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2128548 T3689 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2128553 T3722 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128555 T3737 oass.SolrIndexSearcher.<init> Opening Searcher@5ca23924 main
[junit4:junit4] 2> 2128555 T3737 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-1371031311961/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 2128557 T3737 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2128559 T3737 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2128566 T3749 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@5ca23924 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2128568 T3709 oass.SolrIndexSearcher.<init> Opening Searcher@135543ea main
[junit4:junit4] 2> 2128570 T3709 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-jetty2-1371031307434/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 2128572 T3709 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2128572 T3709 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2128574 T3722 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128575 T3722 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128576 T3722 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2128592 T3722 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2128594 T3722 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2128594 T3722 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128598 T3750 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@135543ea main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2128601 T3737 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2128601 T3737 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:50291/c_ao collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2128605 T3709 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2128608 T3709 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:50285/c_ao collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2128599 T3722 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-jetty3-1371031309689/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-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 2128611 T3722 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff2be8
[junit4:junit4] 2> 2128618 T3737 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2128619 T3709 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2128624 T3722 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2128626 T3722 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-1371031309689/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 2128629 T3722 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-1371031309689/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 2128630 T3722 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-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2128636 T3689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2128639 T3722 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-1371031309689/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 2128658 T3689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2128659 T3689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2128659 T3689 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2128660 T3689 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50282/c_ao START replicas=[http://127.0.0.1:50291/c_ao/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 2128661 T3689 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50282/c_ao DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2128662 T3689 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2128662 T3689 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> 2128663 T3689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2128663 T3689 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C698 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@419aae0d url=http://127.0.0.1:50291/c_ao/nodes_used_collection_shard2_replica1 node=127.0.0.1:50291_c_ao C698_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:50291_c_ao, base_url=http://127.0.0.1:50291/c_ao}
[junit4:junit4] 2> 2128684 T3738 C698 P50291 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/c_ao path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=5
[junit4:junit4] 2> 2128687 T3722 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@51c23dda lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d1e64a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2128688 T3722 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2128696 T3709 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2128699 T3722 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2128703 T3722 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2128705 T3722 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2128708 T3722 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2128709 T3722 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2128709 T3722 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2128710 T3722 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2128711 T3722 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2128714 T3722 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2128739 T3709 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179993
[junit4:junit4] 2> 2128749 T3722 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2128777 T3722 oass.SolrIndexSearcher.<init> Opening Searcher@369a2960 main
[junit4:junit4] 2> 2128778 T3722 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-1371031309689/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 2128780 T3722 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2128781 T3722 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2128800 T3752 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@369a2960 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2128807 T3722 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2128823 T3722 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:50288/c_ao collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2129037 T3683 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2129153 T3687 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> 2129154 T3700 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> 2129155 T3728 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> 2129155 T3682 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> 2129156 T3714 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> 2129156 T3742 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> 2129199 T3689 oasc.ZkController.register We are http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2129200 T3689 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:50282/c_ao
[junit4:junit4] 2> 2129201 T3689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2129202 T3689 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 2129217 T3689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2129222 T3689 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=7433
[junit4:junit4] 2> 2129249 T3709 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2129250 T3709 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2129251 T3709 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2129251 T3709 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50285/c_ao START replicas=[http://127.0.0.1:50288/c_ao/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 2129253 T3709 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50285/c_ao DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2129253 T3709 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2129254 T3709 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> 2129255 T3709 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2129259 T3709 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C699 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@176e7ddb url=http://127.0.0.1:50288/c_ao/nodes_used_collection_shard1_replica1 node=127.0.0.1:50288_c_ao C699_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:50288_c_ao, base_url=http://127.0.0.1:50288/c_ao}
[junit4:junit4] 2> 2129277 T3719 C699 P50288 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/c_ao path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=5
[junit4:junit4] 2> 2129678 T3737 oasc.ZkController.register We are http://127.0.0.1:50291/c_ao/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 2129680 T3737 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:50291/c_ao
[junit4:junit4] 2> 2129680 T3737 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2129681 T3737 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2129683 T3754 C698 P50291 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2129683 T3754 C698 P50291 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2129684 T3737 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2129685 T3754 C698 P50291 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4] 2> 2129691 T3737 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=7902
[junit4:junit4] 2> 2129693 T3754 C698 P50291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2129743 T3694 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50291_c_ao_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2130742 T3683 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2130744 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50282_c_ao_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:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2130768 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50291_c_ao_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:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2130779 T3687 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> 2130779 T3742 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> 2130779 T3700 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> 2130779 T3728 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> 2130779 T3682 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> 2130779 T3714 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> 2130813 T3709 oasc.ZkController.register We are http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2130814 T3709 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:50285/c_ao
[junit4:junit4] 2> 2130814 T3709 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2130815 T3709 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 2130828 T3709 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2130830 T3722 oasc.ZkController.register We are http://127.0.0.1:50288/c_ao/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2130831 T3722 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:50288/c_ao
[junit4:junit4] 2> 2130831 T3709 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=9040
[junit4:junit4] 2> 2130831 T3722 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2130833 T3722 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2130834 T3755 C699 P50288 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2130835 T3755 C699 P50288 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2130836 T3755 C699 P50288 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 2130836 T3722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2130839 T3755 C699 P50288 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2130839 T3722 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=9061
[junit4:junit4] 2> 2130842 T3684 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 2130868 T3710 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50288_c_ao_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2130871 T3700 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 2130880 T3682 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2130881 T3684 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=7433},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=7902},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=9040},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=9061},core=nodes_used_collection_shard1_replica1}}}
[junit4:junit4] 2> 2130889 T3695 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=9172
[junit4:junit4] 2> 2130890 T3682 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2130891 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2130893 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2130900 T3757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32b983ee name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2130900 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2130904 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2130917 T3660 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2130920 T3660 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2130929 T3759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c90917e name:ZooKeeperConnection Watcher:127.0.0.1:50275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2130929 T3660 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2130933 T3660 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2130966 T3705 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=5&maxShardsPerNode=5&name=awholynewcollection_0&replicationFactor=4&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2130974 T3682 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2130978 T3684 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":"5",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"4"}
[junit4:junit4] 2> 2130979 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2130979 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2130979 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2130980 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2130980 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2130982 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2130987 T3678 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 2> 2130987 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2130989 T3724 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> 2130991 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2130993 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2131001 T3689 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 2131001 T3733 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4] 2> 2131005 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2131006 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2130999 T3706 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4] 2> 2131010 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2131013 T3673 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 2131024 T3707 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica1 state=down
[junit4:junit4] 2> 2131021 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2131020 T3720 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica3 state=down
[junit4:junit4] 2> 2131033 T3721 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica4 state=down
[junit4:junit4] 2> 2131035 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2131032 T3674 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica3 state=down
[junit4:junit4] 2> 2131037 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2131030 T3691 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica2 state=down
[junit4:junit4] 2> 2131030 T3735 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica4 state=down
[junit4:junit4] 2> 2131046 T3737 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica1 state=down
[junit4:junit4] 2> 2131051 T3692 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica3 state=down
[junit4:junit4] 2> 2131041 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:50278_c_ao
[junit4:junit4] 2> 2131052 T3708 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica2 state=down
[junit4:junit4] 2> 2131054 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica1 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50288_c_ao
[junit4:junit4] 2> 2131057 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica2 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50291_c_ao
[junit4:junit4] 2> 2131063 T3723 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica1 state=down
[junit4:junit4] 2> 2131061 T3675 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica4 state=down
[junit4:junit4] 2> 2131066 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica3 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50285_c_ao
[junit4:junit4] 2> 2131069 T3736 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica2 state=down
[junit4:junit4] 2> 2131072 T3684 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica4 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:50282_c_ao
[junit4:junit4] 2> 2131081 T3709 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica3 state=down
[junit4:junit4] 2> 2131081 T3695 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica4 state=down
[junit4:junit4] 2> 2131747 T3694 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50291_c_ao_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2131748 T3694 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50291_c_ao_nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:50291_c_ao&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2005
[junit4:junit4] 2> 2132311 T3683 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2132313 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50285_c_ao_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:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2132324 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50288_c_ao_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:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2132340 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard1_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278/c_ao"}
[junit4:junit4] 2> 2132341 T3683 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 5
[junit4:junit4] 2> 2132353 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard1_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2132364 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard1_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2132375 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard1_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2132385 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2132396 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278/c_ao"}
[junit4:junit4] 2> 2132406 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2132420 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2132431 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2132442 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278/c_ao"}
[junit4:junit4] 2> 2132453 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2132471 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2132481 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2132492 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2132503 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2132513 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2132524 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2132534 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278/c_ao"}
[junit4:junit4] 2> 2132545 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50285_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50285/c_ao"}
[junit4:junit4] 2> 2132556 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50282_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50282/c_ao"}
[junit4:junit4] 2> 2132568 T3714 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> 2132570 T3687 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> 2132571 T3700 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> 2132574 T3742 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> 2132580 T3728 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> 2132581 T3757 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> 2132582 T3759 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> 2132584 T3682 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> 2132871 T3710 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50288_c_ao_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2132872 T3710 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50288_c_ao_nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:50288_c_ao&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004
[junit4:junit4] 2> 2133012 T3678 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-controljetty-1371031303636/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 2133012 T3678 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133015 T3678 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2133015 T3678 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2133018 T3678 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2133019 T3678 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2133025 T3724 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-jetty3-1371031309689/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 2133026 T3724 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133026 T3678 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133028 T3724 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133029 T3724 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133031 T3706 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-jetty2-1371031307434/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 2133031 T3706 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133035 T3678 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-1371031303636/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 2133036 T3733 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-1371031311961/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 2133037 T3733 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133035 T3724 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-1371031309689/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 2133041 T3689 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-jetty1-1371031305175/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 2133042 T3689 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133043 T3706 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133044 T3706 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133045 T3673 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-1371031303636/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 2133046 T3673 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133045 T3707 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-jetty2-1371031307434/awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 2133052 T3721 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-jetty3-1371031309689/awholynewcollection_0_shard3_replica4
[junit4:junit4] 2> 2133053 T3721 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133053 T3720 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-jetty3-1371031309689/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 2133054 T3720 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133055 T3674 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-controljetty-1371031303636/awholynewcollection_0_shard3_replica3
[junit4:junit4] 2> 2133055 T3674 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133056 T3691 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-jetty1-1371031305175/awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 2133056 T3691 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133059 T3735 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-jetty4-1371031311961/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 2133059 T3735 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133060 T3737 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-jetty4-1371031311961/awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 2133061 T3737 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133062 T3733 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133064 T3733 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133064 T3689 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133065 T3689 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133065 T3707 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133065 T3692 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-jetty1-1371031305175/awholynewcollection_0_shard4_replica3
[junit4:junit4] 2> 2133068 T3692 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133064 T3708 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-jetty2-1371031307434/awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 2133070 T3708 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133067 T3673 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133072 T3673 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133072 T3723 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-1371031309689/awholynewcollection_0_shard5_replica1
[junit4:junit4] 2> 2133073 T3723 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133083 T3736 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-jetty4-1371031311961/awholynewcollection_0_shard5_replica2
[junit4:junit4] 2> 2133085 T3736 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133087 T3675 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-controljetty-1371031303636/awholynewcollection_0_shard4_replica4
[junit4:junit4] 2> 2133089 T3675 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133090 T3695 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-1371031305175/awholynewcollection_0_shard5_replica4
[junit4:junit4] 2> 2133090 T3695 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133090 T3709 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-jetty2-1371031307434/awholynewcollection_0_shard5_replica3
[junit4:junit4] 2> 2133092 T3709 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2133097 T3721 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133100 T3721 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133100 T3675 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133101 T3675 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133102 T3691 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133102 T3691 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133103 T3695 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133104 T3695 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133104 T3735 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133105 T3735 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133104 T3674 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133106 T3674 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133105 T3692 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133107 T3692 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133106 T3736 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133109 T3736 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133106 T3737 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133110 T3737 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133111 T3673 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-1371031303636/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 2133105 T3709 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133112 T3709 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133108 T3723 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133114 T3723 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133108 T3720 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133115 T3720 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133108 T3708 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133116 T3708 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133108 T3707 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2133122 T3707 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2133107 T3706 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-1371031307434/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 2133129 T3733 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-1371031311961/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 2133132 T3689 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-1371031305175/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 2133151 T3721 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-1371031309689/awholynewcollection_0_shard3_replica4/'
[junit4:junit4] 2> 2133152 T3675 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-1371031303636/awholynewcollection_0_shard4_replica4/'
[junit4:junit4] 2> 2133161 T3735 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-1371031311961/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 2133168 T3691 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-1371031305175/awholynewcollection_0_shard3_replica2/'
[junit4:junit4] 2> 2133170 T3674 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-1371031303636/awholynewcollection_0_shard3_replica3/'
[junit4:junit4] 2> 2133173 T3692 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-1371031305175/awholynewcollection_0_shard4_replica3/'
[junit4:junit4] 2> 2133175 T3695 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-1371031305175/awholynewcollection_0_shard5_replica4/'
[junit4:junit4] 2> 2133179 T3736 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-1371031311961/awholynewcollection_0_shard5_replica2/'
[junit4:junit4] 2> 2133180 T3709 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-1371031307434/awholynewcollection_0_shard5_replica3/'
[junit4:junit4] 2> 2133183 T3708 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-1371031307434/awholynewcollection_0_shard4_replica2/'
[junit4:junit4] 2> 2133185 T3723 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-1371031309689/awholynewcollection_0_shard5_replica1/'
[junit4:junit4] 2> 2133186 T3720 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-1371031309689/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 2133190 T3737 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-1371031311961/awholynewcollection_0_shard4_replica1/'
[junit4:junit4] 2> 2133209 T3707 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-1371031307434/awholynewcollection_0_shard3_replica1/'
[junit4:junit4] 2> 2133594 T3721 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2133614 T3678 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2133633 T3692 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> ASYNC NEW_CORE C700 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@419aae0d url=http://127.0.0.1:50291/c_ao/nodes_used_collection_shard2_replica1 node=127.0.0.1:50291_c_ao C700_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:50291_c_ao, base_url=http://127.0.0.1:50291/c_ao}
[junit4:junit4] 2> 2133783 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2133784 T3754 C700 P50291 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:50291/c_ao START replicas=[http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 2133786 T3754 C700 P50291 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2133786 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2133786 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2133787 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2133787 T3754 C700 P50291 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2133787 T3754 C700 P50291 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2133788 T3754 C700 P50291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2133802 T3708 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2133856 T3733 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2133899 T3736 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> ASYNC NEW_CORE C701 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@5a4009aa url=http://127.0.0.1:50282/c_ao/nodes_used_collection_shard2_replica2 node=127.0.0.1:50282_c_ao C701_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:50282_c_ao, base_url=http://127.0.0.1:50282/c_ao, leader=true}
[junit4:junit4] 2> 2133914 T3694 C701 P50282 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/c_ao path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=4
[junit4:junit4] 2> 2133915 T3693 C701 P50282 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2134039 T3673 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134052 T3693 C701 P50282 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5bf55f1b lockFactory=org.apache.lucene.store.NativeFSLockFactory@30acbe33),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2134054 T3693 C701 P50282 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2134056 T3693 C701 P50282 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5bf55f1b lockFactory=org.apache.lucene.store.NativeFSLockFactory@30acbe33),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5bf55f1b lockFactory=org.apache.lucene.store.NativeFSLockFactory@30acbe33),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2134056 T3693 C701 P50282 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2134057 T3693 C701 P50282 oass.SolrIndexSearcher.<init> Opening Searcher@440beaaa realtime
[junit4:junit4] 2> 2134058 T3693 C701 P50282 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2134058 T3693 C701 P50282 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica2] webapp=/c_ao path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 143
[junit4:junit4] 2> 2134062 T3720 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134070 T3754 C700 P50291 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2134071 T3754 C700 P50291 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2134089 T3724 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134095 T3693 C701 P50282 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2134095 T3693 C701 P50282 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/c_ao path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 2134097 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2134097 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2134098 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2134105 T3694 C701 P50282 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/c_ao path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 2134106 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2134108 T3754 C700 P50291 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-1371031311961/nodes_used_collection_shard2_replica1/data/index.20130612153207057
[junit4:junit4] 2> 2134108 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a4f310 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71328f5) fullCopy=false
[junit4:junit4] 2> 2134120 T3693 C701 P50282 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/c_ao path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2134123 T3754 C700 P50291 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2134135 T3754 C700 P50291 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2134136 T3754 C700 P50291 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2134228 T3754 C700 P50291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5675db24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e76455e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5675db24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e76455e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2134230 T3737 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134252 T3754 C700 P50291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2134272 T3754 C700 P50291 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2134273 T3754 C700 P50291 oass.SolrIndexSearcher.<init> Opening Searcher@629eca17 main
[junit4:junit4] 2> 2134275 T3749 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@629eca17 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2134278 T3754 C700 P50291 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-1371031311961/nodes_used_collection_shard2_replica1/data/index.20130612153207057 [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-1371031311961/nodes_used_collection_shard2_replica1/data/index.20130612153207057;done=true>>]
[junit4:junit4] 2> 2134279 T3754 C700 P50291 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-1371031311961/nodes_used_collection_shard2_replica1/data/index.20130612153207057
[junit4:junit4] 2> 2134279 T3754 C700 P50291 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-1371031311961/nodes_used_collection_shard2_replica1/data/index.20130612153207057
[junit4:junit4] 2> 2134283 T3754 C700 P50291 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2134283 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2134283 T3754 C700 P50291 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 2134288 T3754 C700 P50291 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2134338 T3723 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134521 T3735 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2134534 T3708 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2134553 T3678 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2134562 T3708 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2134571 T3708 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
[junit4:junit4] 2> 2134582 T3678 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2134597 T3678 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2134797 T3721 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2134814 T3721 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2134833 T3721 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica4] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C702 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@176e7ddb url=http://127.0.0.1:50288/c_ao/nodes_used_collection_shard1_replica1 node=127.0.0.1:50288_c_ao C702_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:50288_c_ao, base_url=http://127.0.0.1:50288/c_ao}
[junit4:junit4] 2> 2134874 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2134875 T3755 C702 P50288 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:50288/c_ao START replicas=[http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 2134876 T3755 C702 P50288 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2134876 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2134877 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2134877 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2134877 T3755 C702 P50288 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2134878 T3755 C702 P50288 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2134878 T3755 C702 P50288 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2134948 T3675 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> ASYNC NEW_CORE C703 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@4789968e url=http://127.0.0.1:50285/c_ao/nodes_used_collection_shard1_replica2 node=127.0.0.1:50285_c_ao C703_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:50285_c_ao, base_url=http://127.0.0.1:50285/c_ao, leader=true}
[junit4:junit4] 2> 2134965 T3710 C703 P50285 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2134965 T3777 C703 P50285 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/c_ao path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=3
[junit4:junit4] 2> 2135030 T3710 C703 P50285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4908d3ef lockFactory=org.apache.lucene.store.NativeFSLockFactory@4dc46ab),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2135031 T3710 C703 P50285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2135032 T3710 C703 P50285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4908d3ef lockFactory=org.apache.lucene.store.NativeFSLockFactory@4dc46ab),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4908d3ef lockFactory=org.apache.lucene.store.NativeFSLockFactory@4dc46ab),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2135033 T3710 C703 P50285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2135034 T3710 C703 P50285 oass.SolrIndexSearcher.<init> Opening Searcher@7102069d realtime
[junit4:junit4] 2> 2135034 T3710 C703 P50285 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2135035 T3710 C703 P50285 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp=/c_ao path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 70
[junit4:junit4] 2> 2135050 T3755 C702 P50288 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2135051 T3755 C702 P50288 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2135055 T3710 C703 P50285 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2135055 T3710 C703 P50285 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/c_ao path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 2135064 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2135064 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2135064 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2135088 T3777 C703 P50285 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/c_ao path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=3
[junit4:junit4] 2> 2135104 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2135110 T3755 C702 P50288 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-1371031309689/nodes_used_collection_shard1_replica1/data/index.20130612153208055
[junit4:junit4] 2> 2135110 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@26eb21c4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3883812f) fullCopy=false
[junit4:junit4] 2> 2135130 T3709 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135142 T3674 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135148 T3710 C703 P50285 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/c_ao path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 2135170 T3695 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135172 T3755 C702 P50288 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2135203 T3755 C702 P50288 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2135203 T3755 C702 P50288 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2135205 T3755 C702 P50288 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@51c23dda lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d1e64a),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@51c23dda lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d1e64a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2135207 T3755 C702 P50288 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2135207 T3755 C702 P50288 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2135208 T3755 C702 P50288 oass.SolrIndexSearcher.<init> Opening Searcher@3a08f26b main
[junit4:junit4] 2> 2135209 T3752 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@3a08f26b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2135219 T3755 C702 P50288 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-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/index.20130612153208055 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/index.20130612153208055;done=true>>]
[junit4:junit4] 2> 2135222 T3755 C702 P50288 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-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/index.20130612153208055
[junit4:junit4] 2> 2135223 T3755 C702 P50288 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-jetty3-1371031309689/nodes_used_collection_shard1_replica1/data/index.20130612153208055
[junit4:junit4] 2> 2135224 T3755 C702 P50288 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2135224 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2135224 T3755 C702 P50288 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 2135227 T3755 C702 P50288 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2135232 T3692 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2135250 T3692 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2135258 T3692 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica3] Schema name=test
[junit4:junit4] 2> 2135318 T3724 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2135319 T3720 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2135337 T3724 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2135340 T3720 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2135345 T3724 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2135350 T3689 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135487 T3733 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2135510 T3733 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2135569 T3720 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 2135610 T3733 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 2135648 T3706 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135680 T3723 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2135693 T3691 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135698 T3723 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2135756 T3683 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2135763 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50291_c_ao_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:50291_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50291/c_ao"}
[junit4:junit4] 2> 2135774 T3707 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2135793 T3683 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50288_c_ao_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:50288_c_ao",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50288/c_ao"}
[junit4:junit4] 2> 2136007 T3723 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica1] Schema name=test
[junit4:junit4] 2> 2136037 T3673 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136083 T3737 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136157 T3673 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136165 T3714 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> 2136166 T3759 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> 2136167 T3687 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> 2136167 T3728 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> 2136167 T3700 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> 2136168 T3757 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> 2136168 T3742 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> 2136170 T3682 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> 2136195 T3736 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136207 T3673 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2136210 T3737 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136227 T3736 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136230 T3737 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
[junit4:junit4] 2> 2136295 T3736 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica2] Schema name=test
[junit4:junit4] 2> 2136576 T3709 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136604 T3709 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136621 T3709 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica3] Schema name=test
[junit4:junit4] 2> 2136630 T3695 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136646 T3695 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136700 T3695 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica4] Schema name=test
[junit4:junit4] 2> 2136760 T3735 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136768 T3735 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136857 T3735 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 2136888 T3689 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2136901 T3689 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2136919 T3689 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2137133 T3691 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2137172 T3691 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2137273 T3691 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
[junit4:junit4] 2> 2137510 T3674 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2137531 T3674 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2137692 T3706 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2137713 T3675 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2137724 T3706 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2137731 T3675 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2137818 T3706 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 2137830 T3675 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica4] Schema name=test
[junit4:junit4] 2> 2137845 T3674 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica3] Schema name=test
[junit4:junit4] 2> 2137933 T3707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2137989 T3707 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2138019 T3707 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
[junit4:junit4] 2> 2154738 T3724 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2154796 T3724 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2154827 T3724 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2154965 T3723 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2155265 T3724 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2155313 T3723 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2155325 T3723 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2155604 T3721 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2155615 T3724 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2155662 T3724 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2155672 T3733 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2155692 T3724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2155693 T3724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2155693 T3724 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2155719 T3724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2155720 T3724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2155720 T3724 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2155721 T3724 oasc.SolrCore.<init> [awholynewcollection_0_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-1371031309689/awholynewcollection_0_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371031309689/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4] 2> 2155721 T3724 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff2be8
[junit4:junit4] 2> 2155722 T3724 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2155735 T3724 oasc.CachingDirectoryFactory.get return new directory for /U
[...truncated too long message...]
t4:junit4] 2> 2293612 T3660 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard4_replica1] Closing main searcher on request.
[junit4:junit4] 2> 2293613 T3660 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 2293614 T3660 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-1371031311961/awholynewcollection_0_shard4_replica1/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-1371031311961/awholynewcollection_0_shard4_replica1/data;done=false>>]
[junit4:junit4] 2> 2293617 T3660 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-1371031311961/awholynewcollection_0_shard4_replica1/data
[junit4:junit4] 2> 2293617 T3660 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-1371031311961/awholynewcollection_0_shard4_replica1/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-1371031311961/awholynewcollection_0_shard4_replica1/data/index;done=false>>]
[junit4:junit4] 2> 2293618 T3660 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-1371031311961/awholynewcollection_0_shard4_replica1/data/index
[junit4:junit4] 2> 2293621 T3871 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89851907489005580-127.0.0.1:50291_c_ao-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 2293652 T3660 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/c_ao,null}
[junit4:junit4] 2> 2293723 T3660 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2293729 T3660 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50275 50275
[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=229379F9B8588E5C -Dtests.slow=true -Dtests.locale=en_GB -Dtests.timezone=Asia/Kolkata -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 184s | 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([229379F9B8588E5C:A375F7E1CF07EE60]: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> 2293869 T3660 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 183618 T3659 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 2294927 T3742 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2294928 T3742 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> 2294928 T3742 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=en_GB, timezone=Asia/Kolkata
[junit4:junit4] 2> NOTE: Mac OS X 10.8.3 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=2,free=260458816,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestDocumentBuilder, TestFiltering, QueryResultKeyTest, TestSolrDeletionPolicy1, TestQueryUtils, TestSchemaResource, PrimitiveFieldTypeTest, TestRealTimeGet, RequestHandlersTest, ResourceLoaderTest, RecoveryZkTest, TestLuceneMatchVersion, TimeZoneUtilsTest, UpdateParamsTest, LegacyHTMLStripCharFilterTest, FieldMutatingUpdateProcessorTest, TestShardHandlerFactory, StatsComponentTest, BasicFunctionalityTest, FileUtilsTest, DocValuesTest, PeerSyncTest, SolrCoreTest, PreAnalyzedUpdateProcessorTest, SolrPluginUtilsTest, TestPhraseSuggestions, TestFastWriter, TestSolrXMLSerializer, TestCoreDiscovery, TestFieldResource, PreAnalyzedFieldTest, TestFieldTypeCollectionResource, WordBreakSolrSpellCheckerTest, TestManagedSchema, FullSolrCloudDistribCmdsTest, TestSolr4Spatial, TestIndexSearcher, TestJmxMonitoredMap, LukeRequestHandlerTest, MinimalSchemaTest, XsltUpdateRequestHandlerTest, TestSchemaNameResource, TestMultiCoreConfBootstrap, TestSolrDeletionPolicy2, LoggingHandlerTest, SliceStateTest, TermVectorComponentDistributedTest, TestPHPSerializedResponseWriter, TermVectorComponentTest, TestCSVResponseWriter, BadIndexSchemaTest, ChaosMonkeySafeLeaderTest, NotRequiredUniqueKeyTest, TestLMDirichletSimilarityFactory, TestManagedSchemaFieldResource, TestFieldTypeResource, ResponseLogComponentTest, PolyFieldTest, StandardRequestHandlerTest, TestSuggestSpellingConverter, TestStressRecovery, TestSystemIdResolver, TestAddFieldRealTimeGet, UUIDFieldTest, TestReload, TestCollationField, QueryElevationComponentTest, CacheHeaderTest, TestPropInject, TestRandomFaceting, TestCloudManagedSchemaAddField, IndexSchemaTest, TestDynamicFieldResource, TestZkChroot, SolrInfoMBeanTest, TestAtomicUpdateErrorCases, RAMDirectoryFactoryTest, TestUtils, ZkSolrClientTest, AnalysisAfterCoreReloadTest, TestMaxScoreQueryParser, TestSchemaVersionResource, DistributedSpellCheckComponentTest, ZkControllerTest, HighlighterConfigTest, DisMaxRequestHandlerTest, TestCoreContainer, TestReversedWildcardFilterFactory, TestUpdate, HardAutoCommitTest, CoreContainerCoreInitFailuresTest, AliasIntegrationTest, PrimUtilsTest, TestBinaryResponseWriter, TestWordDelimiterFilterFactory, LeaderElectionTest, SuggesterTSTTest, TestLazyCores, EchoParamsTest, TestSort, TestSolrXml, TestFieldCollectionResource, ShardRoutingCustomTest, TestStressLucene, StatelessScriptUpdateProcessorFactoryTest, TestAnalyzedSuggestions, TestLMJelinekMercerSimilarityFactory, SuggesterFSTTest, OpenExchangeRatesOrgProviderTest, IndexReaderFactoryTest, CircularListTest, TestSolrQueryParserDefaultOperatorResource, DateFieldTest, UniqFieldsUpdateProcessorFactoryTest, XmlUpdateRequestHandlerTest, TestReloadAndDeleteDocs, DocumentAnalysisRequestHandlerTest, QueryEqualityTest, TestRecovery, TestStressReorder, CachingDirectoryFactoryTest, SpellCheckCollatorTest, SortByFunctionTest, TestDistributedSearch, DirectSolrSpellCheckerTest, ReturnFieldsTest, TestJoin, TestSolrJ, TestComponentsName, TestCloudManagedSchema, NumericFieldsTest, AlternateDirectoryTest, BasicZkTest, TestExtendedDismaxParser, TestGroupingSearch, BadCopyFieldTest, DebugComponentTest, DefaultValueUpdateProcessorTest, TestSolrQueryParser, TestElisionMultitermQuery, QueryParsingTest, BadComponentTest, TestSearchPerf, TestArbitraryIndexDir, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 184.93s, 1 test, 1 error <<< FAILURES!
[...truncated 456 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:385: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:365: 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, 1243 tests, 1 error, 18 ignored (6 assumptions)
Total time: 117 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure