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/04 09:18:10 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 515 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/515/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
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([B5E219C0F1A468B0:340497D886FB088C]: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 9745 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 2150633 T4297 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2150644 T4297 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1370328528933
[junit4:junit4] 2> 2150647 T4297 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2150648 T4298 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2150749 T4297 oasc.ZkTestServer.run start zk server on port:53167
[junit4:junit4] 2> 2150751 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2150765 T4304 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aabbebb name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2150766 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2150767 T4297 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2150783 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2150798 T4306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72833e7d name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2150801 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2150801 T4297 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2150843 T4297 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2150867 T4297 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2150893 T4297 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2150913 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2150914 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2150957 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 2150958 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2150984 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2150985 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2151013 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 2151020 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2151039 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 2151042 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2151071 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2151072 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2151103 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2151104 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2151132 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2151135 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2151152 T4297 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2151153 T4297 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2152177 T4297 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2152209 T4297 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53170
[junit4:junit4] 2> 2152213 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2152214 T4297 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2152215 T4297 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476
[junit4:junit4] 2> 2152216 T4297 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/solr.xml
[junit4:junit4] 2> 2152216 T4297 oasc.CoreContainer.<init> New CoreContainer 1106571575
[junit4:junit4] 2> 2152217 T4297 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/'
[junit4:junit4] 2> 2152230 T4297 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/'
[junit4:junit4] 2> 2152488 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476
[junit4:junit4] 2> 2152491 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/collection1
[junit4:junit4] 2> 2152493 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/collection1/conf
[junit4:junit4] 2> 2152782 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/collection1/conf/xslt
[junit4:junit4] 2> 2152788 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/collection1/lib
[junit4:junit4] 2> 2152818 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/collection1/lib/classes
[junit4:junit4] 2> 2152821 T4297 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/conf/core.properties, adding to cores
[junit4:junit4] 2> 2152868 T4297 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2152871 T4297 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2152872 T4297 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2152873 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2152875 T4297 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2152880 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2152884 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2152885 T4297 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2152887 T4297 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2152891 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2152935 T4297 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2152936 T4297 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53167/solr
[junit4:junit4] 2> 2152937 T4297 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2152940 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2152949 T4317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3447f0e4 name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2152952 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2152986 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2153059 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2153072 T4319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64946b51 name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2153073 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2153099 T4297 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2153143 T4297 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2153190 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2153219 T4297 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53170_
[junit4:junit4] 2> 2153232 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53170_
[junit4:junit4] 2> 2153280 T4297 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2153337 T4297 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2153381 T4297 oasc.Overseer.start Overseer (id=89805850472939523-127.0.0.1:53170_-n_0000000000) starting
[junit4:junit4] 2> 2153414 T4297 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2153451 T4321 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2153463 T4297 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2153480 T4297 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2153496 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2153521 T4320 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2153540 T4297 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2153541 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2153542 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2153581 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2153584 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2153597 T4324 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b888aeb name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2153598 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2153617 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2153655 T4297 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2154731 T4297 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2154740 T4297 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53174
[junit4:junit4] 2> 2154742 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2154743 T4297 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2154744 T4297 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943
[junit4:junit4] 2> 2154745 T4297 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/solr.xml
[junit4:junit4] 2> 2154745 T4297 oasc.CoreContainer.<init> New CoreContainer 1383183141
[junit4:junit4] 2> 2154746 T4297 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/'
[junit4:junit4] 2> 2154746 T4297 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/'
[junit4:junit4] 2> 2154906 T3 oasu.ConcurrentLRUCache.finalize ERROR ConcurrentLRUCache was not destroyed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!
[junit4:junit4] 2> 2155037 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943
[junit4:junit4] 2> 2155040 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/collection1
[junit4:junit4] 2> 2155046 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/collection1/conf
[junit4:junit4] 2> 2155336 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/collection1/conf/xslt
[junit4:junit4] 2> 2155348 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/collection1/lib
[junit4:junit4] 2> 2155355 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/collection1/lib/classes
[junit4:junit4] 2> 2155360 T4297 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/conf/core.properties, adding to cores
[junit4:junit4] 2> 2155383 T4297 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2155384 T4297 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2155384 T4297 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2155385 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2155385 T4297 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2155386 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2155387 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2155387 T4297 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2155388 T4297 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2155388 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2155430 T4297 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2155431 T4297 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53167/solr
[junit4:junit4] 2> 2155432 T4297 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2155442 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2155444 T4335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@551c63c2 name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2155446 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2155470 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2155517 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2155518 T4337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d304c8b name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2155520 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2155565 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2156584 T4297 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53174_
[junit4:junit4] 2> 2156590 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53174_
[junit4:junit4] 2> 2156606 T4319 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2156607 T4324 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2156608 T4337 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2156636 T4297 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2156637 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2156638 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2157492 T4297 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2157549 T4297 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53177
[junit4:junit4] 2> 2157552 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2157553 T4297 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2157554 T4297 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949
[junit4:junit4] 2> 2157554 T4297 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/solr.xml
[junit4:junit4] 2> 2157555 T4297 oasc.CoreContainer.<init> New CoreContainer 1506311120
[junit4:junit4] 2> 2157555 T4297 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/'
[junit4:junit4] 2> 2157556 T4297 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/'
[junit4:junit4] 2> 2157762 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949
[junit4:junit4] 2> 2157777 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/collection1
[junit4:junit4] 2> 2157780 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/collection1/conf
[junit4:junit4] 2> 2158062 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/collection1/conf/xslt
[junit4:junit4] 2> 2158072 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/collection1/lib
[junit4:junit4] 2> 2158083 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/collection1/lib/classes
[junit4:junit4] 2> 2158086 T4297 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/conf/core.properties, adding to cores
[junit4:junit4] 2> 2158106 T4297 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2158107 T4297 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2158108 T4297 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2158108 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2158109 T4297 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2158109 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2158110 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2158112 T4297 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2158112 T4297 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2158117 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2158164 T4297 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2158164 T4297 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53167/solr
[junit4:junit4] 2> 2158165 T4297 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2158186 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2158191 T4349 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b2df546 name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2158197 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2158205 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2158241 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2158250 T4351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22f92de6 name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2158252 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2158285 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2159313 T4297 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53177_
[junit4:junit4] 2> 2159316 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53177_
[junit4:junit4] 2> 2159337 T4324 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2159337 T4319 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2159338 T4351 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2159339 T4337 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2159355 T4297 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2159356 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2159356 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2160246 T4297 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2160294 T4297 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53180
[junit4:junit4] 2> 2160296 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2160296 T4297 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2160297 T4297 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675
[junit4:junit4] 2> 2160298 T4297 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/solr.xml
[junit4:junit4] 2> 2160306 T4297 oasc.CoreContainer.<init> New CoreContainer 1983359988
[junit4:junit4] 2> 2160307 T4297 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/'
[junit4:junit4] 2> 2160308 T4297 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/'
[junit4:junit4] 2> 2160557 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675
[junit4:junit4] 2> 2160559 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/collection1
[junit4:junit4] 2> 2160561 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/collection1/conf
[junit4:junit4] 2> 2160820 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/collection1/conf/xslt
[junit4:junit4] 2> 2160826 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/collection1/lib
[junit4:junit4] 2> 2160827 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/collection1/lib/classes
[junit4:junit4] 2> 2160831 T4297 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/conf/core.properties, adding to cores
[junit4:junit4] 2> 2160863 T4297 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2160864 T4297 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2160876 T4297 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2160877 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2160877 T4297 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2160879 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2160879 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2160880 T4297 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2160880 T4297 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2160881 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2160942 T4297 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2160943 T4297 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53167/solr
[junit4:junit4] 2> 2160944 T4297 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2160952 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2160968 T4363 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2524477 name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2160972 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2160995 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2161032 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2161040 T4365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b7ac998 name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2161040 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2161079 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2162110 T4297 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53180_
[junit4:junit4] 2> 2162114 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53180_
[junit4:junit4] 2> 2162127 T4365 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2162127 T4337 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2162128 T4351 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2162128 T4324 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2162129 T4319 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2162154 T4297 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2162155 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2162155 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2162990 T4297 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2163013 T4297 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53183
[junit4:junit4] 2> 2163015 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2163015 T4297 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2163016 T4297 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468
[junit4:junit4] 2> 2163016 T4297 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/solr.xml
[junit4:junit4] 2> 2163017 T4297 oasc.CoreContainer.<init> New CoreContainer 1107421625
[junit4:junit4] 2> 2163018 T4297 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/'
[junit4:junit4] 2> 2163018 T4297 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/'
[junit4:junit4] 2> 2163239 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468
[junit4:junit4] 2> 2163246 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/collection1
[junit4:junit4] 2> 2163247 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/collection1/conf
[junit4:junit4] 2> 2163515 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/collection1/conf/xslt
[junit4:junit4] 2> 2163530 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/collection1/lib
[junit4:junit4] 2> 2163533 T4297 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/collection1/lib/classes
[junit4:junit4] 2> 2163543 T4297 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/conf/core.properties, adding to cores
[junit4:junit4] 2> 2163562 T4297 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2163562 T4297 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2163563 T4297 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2163564 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2163565 T4297 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2163566 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2163576 T4297 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2163577 T4297 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2163577 T4297 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2163579 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2163631 T4297 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2163632 T4297 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53167/solr
[junit4:junit4] 2> 2163636 T4297 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2163640 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2163650 T4377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79b372f3 name:ZooKeeperConnection Watcher:127.0.0.1:53167 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2163659 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2163674 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2163709 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2163716 T4379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@427a7796 name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2163717 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2163756 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2164779 T4297 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53183_
[junit4:junit4] 2> 2164785 T4297 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53183_
[junit4:junit4] 2> 2164799 T4365 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164801 T4319 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164801 T4337 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164802 T4379 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164802 T4324 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164802 T4351 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2164829 T4297 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2164830 T4297 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2164831 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2164860 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2164895 T4332 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2164904 T4319 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2164913 T4321 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> 2164914 T4321 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:53177_
[junit4:junit4] 2> 2164919 T4321 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:53170_
[junit4:junit4] 2> 2164930 T4321 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:53183_
[junit4:junit4] 2> 2164931 T4321 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:53174_
[junit4:junit4] 2> 2164972 T4314 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2164974 T4314 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2164973 T4342 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2164976 T4342 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2164973 T4374 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2164977 T4374 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2164975 T4333 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2164979 T4333 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2164981 T4314 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2164982 T4314 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2164982 T4342 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2164983 T4342 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2164986 T4333 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2164986 T4333 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2164989 T4374 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2164990 T4374 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2164992 T4314 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2164993 T4314 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2164994 T4342 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2164995 T4342 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2164996 T4333 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2164996 T4333 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2165004 T4374 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2165005 T4374 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2165008 T4342 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2165010 T4314 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2165013 T4333 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2165019 T4342 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 2165022 T4314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 2165024 T4374 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2165035 T4333 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 2165061 T4374 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 2165279 T4314 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2165358 T4374 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2165386 T4333 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2165436 T4342 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2165622 T4314 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2165660 T4374 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2165663 T4314 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2165675 T4314 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2165682 T4333 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2165684 T4374 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2165694 T4374 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2165706 T4333 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2165721 T4333 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2165814 T4342 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2165844 T4342 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2165884 T4342 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2169280 T4314 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2169297 T4314 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2169328 T4333 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2169340 T4374 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2169351 T4374 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2169359 T4314 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2169369 T4374 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2169401 T4333 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2169410 T4333 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2169466 T4342 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2169517 T4342 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2169563 T4342 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2169570 T4314 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169570 T4374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169599 T4314 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169602 T4374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169630 T4374 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169636 T4314 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169644 T4374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169650 T4374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169651 T4374 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169654 T4333 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169667 T4314 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169706 T4314 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169707 T4314 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169691 T4333 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169675 T4374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169715 T4374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169716 T4374 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169717 T4374 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 2169718 T4374 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2169720 T4374 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169725 T4374 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 2169726 T4374 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 2169727 T4374 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2169731 T4374 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 2169730 T4314 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169734 T4314 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169734 T4314 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169736 T4314 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 2169736 T4314 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2169738 T4314 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169740 T4314 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 2169742 T4374 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ff20f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6faf525d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2169755 T4374 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2169752 T4314 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 2169756 T4314 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2169757 T4314 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 2169769 T4374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2169770 T4374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2169771 T4374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2169774 T4374 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2169775 T4374 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2169779 T4374 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2169783 T4374 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2169787 T4374 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2169788 T4374 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2169781 T4333 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169798 T4333 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169800 T4333 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169800 T4333 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2169824 T4374 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2169840 T4314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3bfd54ee lockFactory=org.apache.lucene.store.NativeFSLockFactory@3242faa2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2169841 T4314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2169843 T4333 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2169843 T4333 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2169844 T4333 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169845 T4333 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 2169845 T4333 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2169847 T4333 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2169848 T4333 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 2169851 T4342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169860 T4374 oass.SolrIndexSearcher.<init> Opening Searcher@14e1541b main
[junit4:junit4] 2> 2169863 T4374 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 2169866 T4374 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2169869 T4374 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2169859 T4333 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 2169875 T4333 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2169857 T4314 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2169882 T4314 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2169883 T4314 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2169885 T4314 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2169886 T4314 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2169887 T4314 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2169887 T4314 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2169889 T4314 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2169890 T4314 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2169878 T4333 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 2169884 T4385 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@14e1541b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2169912 T4314 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2169932 T4314 oass.SolrIndexSearcher.<init> Opening Searcher@532edb57 main
[junit4:junit4] 2> 2169936 T4314 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 2169944 T4374 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 2169954 T4342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2169952 T4314 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2169969 T4314 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2169979 T4386 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@532edb57 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2169980 T4314 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 2169995 T4333 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7fda270d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d0de9d9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2169997 T4333 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2170010 T4333 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2170011 T4333 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2170013 T4333 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2170014 T4333 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2170015 T4333 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2170016 T4333 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2170016 T4333 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2170017 T4333 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2170018 T4333 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2170026 T4342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2170043 T4333 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2170054 T4342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2170055 T4342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2170055 T4342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2170057 T4333 oass.SolrIndexSearcher.<init> Opening Searcher@1464b4a6 main
[junit4:junit4] 2> 2170057 T4333 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 2170063 T4333 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2170068 T4333 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2170073 T4342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2170076 T4342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2170077 T4342 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2170079 T4342 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 2170079 T4342 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2170081 T4342 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2170082 T4387 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@1464b4a6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2170085 T4333 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 2170082 T4342 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 2170097 T4342 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 2170098 T4342 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2170099 T4342 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 2170110 T4342 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@762dfa31 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23651080),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2170111 T4342 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2170132 T4342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2170133 T4342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2170135 T4342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2170137 T4342 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2170139 T4342 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2170140 T4342 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2170141 T4342 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2170148 T4342 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2170150 T4342 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2170192 T4342 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2170231 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2170234 T4342 oass.SolrIndexSearcher.<init> Opening Searcher@3a824f6c main
[junit4:junit4] 2> 2170235 T4320 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:53183_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53183"}
[junit4:junit4] 2> 2170236 T4320 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 2170236 T4342 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 2170240 T4342 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2170241 T4342 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2170248 T4342 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 2170248 T4388 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@3a824f6c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2170274 T4320 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:53170_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53170"}
[junit4:junit4] 2> 2170296 T4320 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:53174_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53174"}
[junit4:junit4] 2> 2170335 T4320 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:53177_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53177"}
[junit4:junit4] 2> 2170385 T4365 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> 2170389 T4337 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> 2170389 T4324 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> 2170390 T4379 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> 2170391 T4319 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> 2170391 T4351 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> 2170977 T4374 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2170978 T4374 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:53183 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2170981 T4374 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2170994 T4314 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2170995 T4314 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:53170 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2171000 T4314 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2171022 T4374 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2171053 T4374 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179988
[junit4:junit4] 2> 2171085 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2171104 T4333 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2171106 T4333 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:53174 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2171121 T4314 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179994
[junit4:junit4] 2> 2171261 T4342 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2171262 T4342 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:53177 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2171567 T4374 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2171568 T4374 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2171573 T4374 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2171574 T4374 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:53183 START replicas=[http://127.0.0.1:53174/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 2171576 T4374 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:53183 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2171577 T4374 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2171577 T4374 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> 2171578 T4374 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2171580 T4374 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C837 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@719eafb3 url=http://127.0.0.1:53174/nodes_used_collection_shard2_replica2 node=127.0.0.1:53174_ C837_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:53174_, base_url=http://127.0.0.1:53174}
[junit4:junit4] 2> 2171603 T4331 C837 P53174 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 2171626 T4314 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2171628 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2171628 T4314 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2171629 T4314 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:53170 START replicas=[http://127.0.0.1:53177/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 2171631 T4314 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:53170 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2171632 T4314 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2171632 T4314 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> 2171633 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2171633 T4314 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C838 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@309b39d6 url=http://127.0.0.1:53177/nodes_used_collection_shard1_replica1 node=127.0.0.1:53177_ C838_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:53177_, base_url=http://127.0.0.1:53177}
[junit4:junit4] 2> 2171656 T4343 C838 P53177 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=7
[junit4:junit4] 2> 2172033 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2172184 T4365 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> 2172184 T4319 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> 2172185 T4351 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> 2172187 T4337 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> 2172188 T4379 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> 2172188 T4324 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> 2172217 T4374 oasc.ZkController.register We are http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2172218 T4374 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:53183
[junit4:junit4] 2> 2172219 T4374 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2172219 T4374 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 2172225 T4374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2172228 T4374 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=7255
[junit4:junit4] 2> 2172243 T4333 oasc.ZkController.register We are http://127.0.0.1:53174/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2172244 T4333 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:53174
[junit4:junit4] 2> 2172245 T4333 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2172245 T4333 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2172246 T4391 C837 P53174 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 2172247 T4391 C837 P53174 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2172248 T4391 C837 P53174 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 2> 2172250 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2172252 T4391 C837 P53174 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2172255 T4333 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=7280
[junit4:junit4] 2> 2172302 T4314 oasc.ZkController.register We are http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2172305 T4314 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:53170
[junit4:junit4] 2> 2172305 T4314 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2172306 T4314 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 2172308 T4371 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53174__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2172309 T4342 oasc.ZkController.register We are http://127.0.0.1:53177/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2172310 T4342 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:53177
[junit4:junit4] 2> 2172310 T4342 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2172311 T4342 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2172312 T4392 C838 P53177 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2172313 T4392 C838 P53177 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2172318 T4392 C838 P53177 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 2172320 T4342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2172322 T4392 C838 P53177 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2172337 T4342 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=7364
[junit4:junit4] 2> 2172338 T4314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2172359 T4311 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53177__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2172362 T4314 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=7390
[junit4:junit4] 2> 2172364 T4321 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 2172405 T4337 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 2172412 T4319 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2172418 T4332 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=7523
[junit4:junit4] 2> 2172420 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2172424 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2172426 T4321 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=7255},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=7280},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=7364},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=7390},core=nodes_used_collection_shard1_replica2}}}
[junit4:junit4] 2> 2172450 T4394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18499efe name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2172451 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2172469 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2172497 T4297 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2172503 T4297 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2172521 T4396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65d72410 name:ZooKeeperConnection Watcher:127.0.0.1:53167/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2172522 T4297 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2172543 T4297 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2172624 T4360 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=5&maxShardsPerNode=6&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2172636 T4319 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2172646 T4321 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "maxShardsPerNode":"6",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 2172647 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:53180_
[junit4:junit4] 2> 2172647 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:53174_
[junit4:junit4] 2> 2172648 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:53177_
[junit4:junit4] 2> 2172653 T4361 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 2172662 T4361 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172664 T4330 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 2172666 T4330 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172655 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:53183_
[junit4:junit4] 2> 2172668 T4345 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 2172669 T4345 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172669 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:53170_
[junit4:junit4] 2> 2172678 T4372 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 2172679 T4372 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172682 T4345 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172684 T4345 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172688 T4372 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172690 T4372 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172690 T4312 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard1_replica5
[junit4:junit4] 2> 2172692 T4312 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172679 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53180_
[junit4:junit4] 2> 2172683 T4361 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172680 T4330 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172697 T4330 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172696 T4361 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172698 T4345 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2172700 T4345 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172698 T4372 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2172705 T4372 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172708 T4356 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 2172709 T4356 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172703 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53174_
[junit4:junit4] 2> 2172714 T4312 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172715 T4312 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172719 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53177_
[junit4:junit4] 2> 2172729 T4331 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 2172731 T4331 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172720 T4361 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2172733 T4361 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172727 T4356 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2172734 T4356 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2172723 T4330 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2172741 T4347 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 2172743 T4347 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172735 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53183_
[junit4:junit4] 2> 2172742 T4330 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172747 T4331 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172749 T4331 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172752 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53170_
[junit4:junit4] 2> 2172756 T4375 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 2172757 T4375 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172759 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:53180_
[junit4:junit4] 2> 2172763 T4315 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard2_replica5
[junit4:junit4] 2> 2172765 T4315 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172762 T4345 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172774 T4375 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172775 T4375 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172776 T4312 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172759 T4372 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172773 T4358 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 2172780 T4358 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172773 T4347 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172786 T4347 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172766 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:53174_
[junit4:junit4] 2> 2172791 T4315 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172794 T4315 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172790 T4331 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 2172796 T4358 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172797 T4358 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172797 T4356 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2172797 T4361 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172801 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:53177_
[junit4:junit4] 2> 2172807 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:53183_
[junit4:junit4] 2> 2172809 T4328 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 2172823 T4328 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172815 T4343 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard3_replica3
[junit4:junit4] 2> 2172829 T4343 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172820 T4330 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172828 T4375 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 2172828 T4372 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 2172828 T4370 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard3_replica4
[junit4:junit4] 2> 2172842 T4370 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172846 T4328 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172849 T4328 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172847 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica5 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:53170_
[junit4:junit4] 2> 2172852 T4343 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172853 T4343 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172854 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:53180_
[junit4:junit4] 2> 2172857 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:53174_
[junit4:junit4] 2> 2172875 T4370 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172892 T4370 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172894 T4356 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172863 T4361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 2172918 T4330 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 2172921 T4356 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 2172862 T4345 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 2172862 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 2172860 T4315 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard2_replica5/'
[junit4:junit4] 2> 2172861 T4358 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard3_replica1/'
[junit4:junit4] 2> 2172861 T4310 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard3_replica5
[junit4:junit4] 2> 2172940 T4310 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172942 T4328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard3_replica2/'
[junit4:junit4] 2> 2172889 T4343 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard3_replica3/'
[junit4:junit4] 2> 2172887 T4332 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 2172946 T4332 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172885 T4359 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 2172948 T4359 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172885 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:53177_
[junit4:junit4] 2> 2172884 T4312 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172956 T4332 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172957 T4332 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172961 T4370 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard3_replica4/'
[junit4:junit4] 2> 2172965 T4310 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172965 T4310 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172969 T4359 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2172970 T4359 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2172977 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:53183_
[junit4:junit4] 2> 2172981 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica5 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:53170_
[junit4:junit4] 2> 2173003 T4374 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard4_replica4
[junit4:junit4] 2> 2173004 T4374 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2172989 T4344 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard4_replica3
[junit4:junit4] 2> 2173013 T4344 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173018 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica1 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:53180_
[junit4:junit4] 2> 2173028 T4344 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173029 T4344 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173027 T4332 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard4_replica2/'
[junit4:junit4] 2> 2173027 T4314 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard4_replica5
[junit4:junit4] 2> 2173031 T4314 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173026 T4374 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173032 T4374 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173037 T4310 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard3_replica5/'
[junit4:junit4] 2> 2173040 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica2 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:53174_
[junit4:junit4] 2> 2173044 T4357 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard5_replica1
[junit4:junit4] 2> 2173045 T4357 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173044 T4359 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard4_replica1/'
[junit4:junit4] 2> 2173046 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica3 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:53177_
[junit4:junit4] 2> 2173046 T4312 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard1_replica5/'
[junit4:junit4] 2> 2173084 T4344 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard4_replica3/'
[junit4:junit4] 2> 2173083 T4374 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard4_replica4/'
[junit4:junit4] 2> 2173080 T4357 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173099 T4357 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173069 T4314 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173069 T4329 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard5_replica2
[junit4:junit4] 2> 2173106 T4329 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173106 T4314 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173123 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica4 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:53183_
[junit4:junit4] 2> 2173125 T4321 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica5 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:53170_
[junit4:junit4] 2> 2173133 T4373 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard5_replica4
[junit4:junit4] 2> 2173134 T4373 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173134 T4329 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173135 T4329 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173128 T4346 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3
[junit4:junit4] 2> 2173137 T4346 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173134 T4357 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard5_replica1/'
[junit4:junit4] 2> 2173144 T4313 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard5_replica5
[junit4:junit4] 2> 2173145 T4313 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2173149 T4346 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173149 T4346 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173149 T4373 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173151 T4373 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173153 T4314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard4_replica5/'
[junit4:junit4] 2> 2173161 T4329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/awholynewcollection_0_shard5_replica2/'
[junit4:junit4] 2> 2173165 T4313 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2173167 T4313 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2173183 T4373 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard5_replica4/'
[junit4:junit4] 2> 2173193 T4346 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/'
[junit4:junit4] 2> 2173250 T4313 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370328529476/awholynewcollection_0_shard5_replica5/'
[junit4:junit4] 2> 2173607 T4347 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2173720 T4332 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2173731 T4374 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2173737 T4314 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2173754 T4375 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2173811 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2173824 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53183__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:53183_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53183"}
[junit4:junit4] 2> 2173906 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53174__nodes_used_collection_shard2_replica2",
[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_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53174_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53174"}
[junit4:junit4] 2> 2173976 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53170__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:53170_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53170"}
[junit4:junit4] 2> 2174031 T4313 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174041 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53177__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:53177_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53177"}
[junit4:junit4] 2> 2174149 T4344 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174173 T4396 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> 2174174 T4394 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> 2174174 T4365 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> 2174182 T4319 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> 2174194 T4337 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> 2174204 T4379 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> 2174204 T4351 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> 2174205 T4324 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> 2174241 T4358 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174268 T4331 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174268 T4346 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174311 T4371 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:53174__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2174313 T4371 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:53174__nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:53174_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2005
[junit4:junit4] 2> 2174408 T4312 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174608 T4372 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174810 T4356 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2174849 T4328 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175045 T4359 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175317 T4315 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175364 T4311 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:53177__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 3 seconds.
[junit4:junit4] 2> 2175364 T4311 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:53177__nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:53177_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=3005
[junit4:junit4] 2> 2175379 T4370 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175391 T4361 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175431 T4345 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175444 T4347 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2175451 T4329 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175453 T4330 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175460 T4310 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175503 T4347 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2175532 T4343 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175656 T4374 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2175663 T4374 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2175678 T4357 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2175731 T4347 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 2175861 T4358 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2175942 T4358 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176007 T4356 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176009 T4332 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176011 T4373 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 2176014 T4375 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176023 T4375 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176028 T4314 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176029 T4356 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176034 T4375 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 2176043 T4332 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176057 T4332 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
[junit4:junit4] 2> 2176034 T4314 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176068 T4314 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica5] Schema name=test
[junit4:junit4] 2> 2176172 T4358 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
[junit4:junit4] 2> 2176234 T4374 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica4] Schema name=test
[junit4:junit4] 2> 2176284 T4346 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176299 T4346 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> ASYNC NEW_CORE C839 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@719eafb3 url=http://127.0.0.1:53174/nodes_used_collection_shard2_replica2 node=127.0.0.1:53174_ C839_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:53174_, base_url=http://127.0.0.1:53174}
[junit4:junit4] 2> 2176316 T4391 C839 P53174 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/ core=nodes_used_collection_shard2_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 2176317 T4391 C839 P53174 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:53174 START replicas=[http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 2176317 T4391 C839 P53174 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2176318 T4391 C839 P53174 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2176318 T4391 C839 P53174 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2176319 T4391 C839 P53174 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2176319 T4391 C839 P53174 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2176320 T4391 C839 P53174 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53183/nodes_used_collection_shard2_replica1/. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2176320 T4391 C839 P53174 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C840 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@35392630 url=http://127.0.0.1:53183/nodes_used_collection_shard2_replica1 node=127.0.0.1:53183_ C840_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:53183_, base_url=http://127.0.0.1:53183, leader=true}
[junit4:junit4] 2> 2176362 T4422 C840 P53183 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 2176375 T4356 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2176394 T4371 C840 P53183 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2176402 T4346 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica3] Schema name=test
[junit4:junit4] 2> 2176609 T4313 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176622 T4313 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> ASYNC NEW_CORE C841 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@35392630 url=http://127.0.0.1:53183/nodes_used_collection_shard2_replica1 node=127.0.0.1:53183_ C841_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:53183_, base_url=http://127.0.0.1:53183, leader=true}
[junit4:junit4] 2> 2176630 T4371 C841 P53183 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ff20f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6faf525d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2176637 T4371 C841 P53183 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2176642 T4371 C841 P53183 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ff20f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6faf525d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ff20f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6faf525d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2176643 T4371 C841 P53183 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2176644 T4371 C841 P53183 oass.SolrIndexSearcher.<init> Opening Searcher@5df50047 realtime
[junit4:junit4] 2> 2176644 T4371 C841 P53183 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2176645 T4371 C841 P53183 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 251
[junit4:junit4] 2> ASYNC NEW_CORE C842 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@719eafb3 url=http://127.0.0.1:53174/nodes_used_collection_shard2_replica2 node=127.0.0.1:53174_ C842_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:53174_, base_url=http://127.0.0.1:53174}
[junit4:junit4] 2> 2176647 T4391 C842 P53174 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2176647 T4391 C842 P53174 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2176662 T4422 C841 P53183 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2176663 T4422 C841 P53183 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=6
[junit4:junit4] 2> 2176680 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2176680 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2176681 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2176692 T4371 C841 P53183 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2176700 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2176709 T4391 C842 P53174 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index.20130604144914988
[junit4:junit4] 2> 2176724 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5cae2e57 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d005cae) fullCopy=false
[junit4:junit4] 2> 2176748 T4422 C841 P53183 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2176749 T4328 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176749 T4312 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176758 T4328 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176771 T4391 C842 P53174 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2176783 T4312 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2176791 T4312 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica5] Schema name=test
[junit4:junit4] 2> 2176800 T4328 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
[junit4:junit4] 2> 2176816 T4391 C842 P53174 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2176817 T4391 C842 P53174 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2176914 T4313 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica5] Schema name=test
[junit4:junit4] 2> 2176954 T4361 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176965 T4344 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2176990 T4344 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> ASYNC NEW_CORE C843 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@719eafb3 url=http://127.0.0.1:53174/nodes_used_collection_shard2_replica2 node=127.0.0.1:53174_ C843_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:53174_, base_url=http://127.0.0.1:53174}
[junit4:junit4] 2> 2177012 T4391 C843 P53174 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7fda270d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d0de9d9),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7fda270d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d0de9d9),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2177016 T4361 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177018 T4391 C843 P53174 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2177030 T4391 C843 P53174 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2177033 T4391 C843 P53174 oass.SolrIndexSearcher.<init> Opening Searcher@6fb5c5df main
[junit4:junit4] 2> 2177045 T4387 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@6fb5c5df main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2177056 T4391 C843 P53174 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index.20130604144914988 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index.20130604144914988;done=true>>]
[junit4:junit4] 2> 2177057 T4391 C843 P53174 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index.20130604144914988
[junit4:junit4] 2> 2177057 T4391 C843 P53174 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370328531943/nodes_used_collection_shard2_replica2/data/index.20130604144914988
[junit4:junit4] 2> 2177057 T4391 C843 P53174 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2177058 T4391 C843 P53174 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2177064 T4391 C843 P53174 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 2177077 T4361 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2177081 T4391 C843 P53174 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2177109 T4344 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica3] Schema name=test
[junit4:junit4] 2> 2177182 T4315 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177248 T4315 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177251 T4329 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177303 T4329 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177332 T4329 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica2] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C844 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@309b39d6 url=http://127.0.0.1:53177/nodes_used_collection_shard1_replica1 node=127.0.0.1:53177_ C844_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:53177_, base_url=http://127.0.0.1:53177}
[junit4:junit4] 2> 2177375 T4392 C844 P53177 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2177376 T4392 C844 P53177 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:53177 START replicas=[http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 2177383 T4392 C844 P53177 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2177383 T4392 C844 P53177 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2177383 T4392 C844 P53177 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2177384 T4392 C844 P53177 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2177384 T4392 C844 P53177 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2177384 T4392 C844 P53177 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53170/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2177385 T4392 C844 P53177 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2177397 T4372 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177415 T4372 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177424 T4372 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 2177427 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2177443 T4345 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177446 T4370 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177451 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53174__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:53174_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53174"}
[junit4:junit4] 2> 2177463 T4370 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177467 T4345 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177504 T4324 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> 2177511 T4337 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> 2177516 T4379 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> 2177516 T4319 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> 2177517 T4394 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> 2177525 T4396 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> 2177526 T4351 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> 2177526 T4365 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> 2177541 T4345 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 2177562 T4315 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica5] Schema name=test
[junit4:junit4] 2> 2177575 T4359 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177589 T4331 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177594 T4359 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177611 T4331 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177648 T4357 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177680 T4330 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177684 T4357 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177690 T4331 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2177702 T4359 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
[junit4:junit4] 2> 2177711 T4330 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2177714 T4310 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2177733 T4330 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2177866 T4310 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> ASYNC NEW_CORE C845 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@15247264 url=http://127.0.0.1:53170/nodes_used_collection_shard1_replica2 node=127.0.0.1:53170_ C845_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:53170_, base_url=http://127.0.0.1:53170, leader=true}
[junit4:junit4] 2> 2177885 T4423 C845 P53170 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=20
[junit4:junit4] 2> 2177946 T4310 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica5] Schema name=test
[junit4:junit4] 2> 2178014 T4311 C845 P53170 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2178095 T4343 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2178162 T4343 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2178163 T4370 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica4] Schema name=test
[junit4:junit4] 2> 2178174 T4343 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica3] Schema name=test
[junit4:junit4] 2> 2178197 T4357 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C846 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@15247264 url=http://127.0.0.1:53170/nodes_used_collection_shard1_replica2 node=127.0.0.1:53170_ C846_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:53170_, base_url=http://127.0.0.1:53170, leader=true}
[junit4:junit4] 2> 2178431 T4311 C846 P53170 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3bfd54ee lockFactory=org.apache.lucene.store.NativeFSLockFactory@3242faa2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2178442 T4311 C846 P53170 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2178466 T4311 C846 P53170 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3bfd54ee lockFactory=org.apache.lucene.store.NativeFSLockFactory@3242faa2),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3bfd54ee lockFactory=org.apache.lucene.store.NativeFSLockFactory@3242faa2),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2178467 T4311 C846 P53170 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2178468 T4311 C846 P53170 oass.SolrIndexSearcher.<init> Opening Searcher@6a7149ec realtime
[junit4:junit4] 2> 2178468 T4311 C846 P53170 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2178469 T4311 C846 P53170 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 455
[junit4:junit4] 2> ASYNC NEW_CORE C847 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@309b39d6 url=http://127.0.0.1:53177/nodes_used_collection_shard1_replica1 node=127.0.0.1:53177_ C847_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:53177_, base_url=http://127.0.0.1:53177}
[junit4:junit4] 2> 2178470 T4392 C847 P53177 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2178471 T4392 C847 P53177 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2178491 T4311 C846 P53170 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2178492 T4311 C846 P53170 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 2178497 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2178498 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2178498 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2178523 T4423 C846 P53170 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=14
[junit4:junit4] 2> 2178525 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2178533 T4392 C847 P53177 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index.20130604144916812
[junit4:junit4] 2> 2178542 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3be8a370 lockFactory=org.apache.lucene.store.NativeFSLockFactory@18563c04) fullCopy=false
[junit4:junit4] 2> 2178554 T4311 C846 P53170 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2178565 T4392 C847 P53177 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2178629 T4392 C847 P53177 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2178630 T4392 C847 P53177 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2178634 T4392 C847 P53177 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@762dfa31 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23651080),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@762dfa31 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23651080),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2178635 T4392 C847 P53177 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2178636 T4392 C847 P53177 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2178637 T4392 C847 P53177 oass.SolrIndexSearcher.<init> Opening Searcher@23ffcbf9 main
[junit4:junit4] 2> 2178639 T4388 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@23ffcbf9 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2178643 T4392 C847 P53177 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index.20130604144916812 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index.20130604144916812;done=true>>]
[junit4:junit4] 2> 2178644 T4392 C847 P53177 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index.20130604144916812
[junit4:junit4] 2> 2178646 T4392 C847 P53177 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/nodes_used_collection_shard1_replica1/data/index.20130604144916812
[junit4:junit4] 2> 2178647 T4392 C847 P53177 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2178647 T4392 C847 P53177 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2178648 T4392 C847 P53177 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 2178654 T4392 C847 P53177 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2179083 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2179095 T4320 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53177__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:53177_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53177"}
[junit4:junit4] 2> 2179121 T4365 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> 2179122 T4337 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> 2179122 T4396 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> 2179123 T4394 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> 2179124 T4319 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> 2179126 T4324 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> 2179123 T4351 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> 2179123 T4379 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> 2179275 T4373 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2179284 T4373 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2179485 T4373 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica4] Schema name=test
[junit4:junit4] 2> 2181348 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=612206477
[junit4:junit4] 2> 2197836 T4361 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2197896 T4346 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2198277 T4359 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2198316 T4346 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2198321 T4361 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2198342 T4346 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2198346 T4361 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2198355 T4359 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2198468 T4356 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2198484 T4359 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2198773 T4361 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2198854 T4356 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2198896 T4356 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2198912 T4346 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2199118 T4345 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2199184 T4332 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2199262 T4328 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2199265 T4346 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2199269 T4312 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2199274 T4359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2199312 T4359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2199377 T4359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2199391 T4345 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2199380 T4361 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2199436 T4345 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2199446 T4312 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2199461 T4312 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2199472 T4346 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2199473 T4328 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2199476 T4359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2199477 T4359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2199478 T4359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2199486 T4346 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2199487 T4346 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2199490 T4346 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2199500 T4359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2199501 T4359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2199502 T4359 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2199503 T4359 oasc.SolrCore.<init> [awholynewcollection_0_shard4_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard4_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard4_replica1/data/
[junit4:junit4] 2> 2199504 T4359 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2199505 T4359 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2199508 T4359 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370328537675/awholynewcollection_0_shard4_replica1/data
[junit4:junit4] 2> 2199516 T4346 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2199517 T4346 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2199518 T4346 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2199519 T4346 oasc.SolrCore.<init> [awholynewcollection_0_shard5_replica3] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/data/
[junit4:junit4] 2> 2199520 T4346 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3cf28f60
[junit4:junit4] 2> 2199523 T4346 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2199524 T4346 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/data
[junit4:junit4] 2> 2199545 T4346 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/data/index/
[junit4:junit4] 2> 2199546 T4346 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard5_replica3] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2199548 T4346 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370328534949/awholynewcollection_0_shard5_replica3/data/index
[junit4:junit4] 2> 2199582 T4356 oass.FileExchangeRateProvider.reload Reload
[...truncated too long message...]
s/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data;done=false>>]
[junit4:junit4] 2> 2250022 T4297 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data
[junit4:junit4] 2> 2250020 T4542 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53183__awholynewcollection_0_shard4_replica4",
[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:53183_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53183"}
[junit4:junit4] 2> 2250028 T4297 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data/index;done=false>>]
[junit4:junit4] 2> 2250031 T4297 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370328540468/awholynewcollection_0_shard2_replica4/data/index
[junit4:junit4] 2> 2250065 T4297 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 2250128 T4297 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2250135 T4297 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53167 53167
[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=B5E219C0F1A468B0 -Dtests.slow=true -Dtests.locale=ar_AE -Dtests.timezone=Asia/Chungking -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 99.7s | 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([B5E219C0F1A468B0:340497D886FB088C]: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> 2250309 T4297 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 99686 T4296 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 2251345 T4379 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2251345 T4379 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> 2251346 T4379 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=ar_AE, timezone=Asia/Chungking
[junit4:junit4] 2> NOTE: Mac OS X 10.8.3 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=5,free=101461080,total=356909056
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestRTGBase, JsonLoaderTest, TestStressLucene, ZkNodePropsTest, TestTrie, TestNumberUtils, ZkSolrClientTest, TestSolrXMLSerializer, TestSystemIdResolver, AlternateDirectoryTest, TestSolrQueryParserResource, TestPluginEnable, TestExtendedDismaxParser, ChaosMonkeyNothingIsSafeTest, OverseerCollectionProcessorTest, TestCollationField, ConvertedLegacyTest, ShardRoutingTest, HighlighterTest, BasicDistributedZk2Test, FastVectorHighlighterTest, TestRealTimeGet, TestBM25SimilarityFactory, TestLRUCache, TestStressVersions, TestSolrQueryParser, UnloadDistributedZkTest, TestMaxScoreQueryParser, TestRandomFaceting, TestSolrQueryParserDefaultOperatorResource, HardAutoCommitTest, ReturnFieldsTest, SimpleFacetsTest, RequestHandlersTest, TermsComponentTest, TestSolr4Spatial, XsltUpdateRequestHandlerTest, BinaryUpdateRequestHandlerTest, TestFastWriter, TestIndexSearcher, TestQueryTypes, TestDistributedSearch, SpellPossibilityIteratorTest, MBeansHandlerTest, SchemaVersionSpecificBehaviorTest, SolrPluginUtilsTest, DOMUtilTest, TestUtils, CopyFieldTest, TestLMDirichletSimilarityFactory, DateFieldTest, TestCoreContainer, ClusterStateUpdateTest, SolrCoreTest, PreAnalyzedUpdateProcessorTest, RegexBoostProcessorTest, SyncSliceTest, TestFieldResource, SuggesterTSTTest, UUIDFieldTest, FileBasedSpellCheckerTest, SliceStateTest, BasicFunctionalityTest, TestLFUCache, SolrIndexSplitterTest, TestBinaryResponseWriter, BadCopyFieldTest, TestReplicationHandler, SimplePostToolTest, TestCoreDiscovery, CachingDirectoryFactoryTest, SuggesterWFSTTest, TestQuerySenderListener, TestSchemaSimilarityResource, TestFoldingMultitermQuery, TestDistributedGrouping, DirectSolrConnectionTest, TestCSVLoader, TestConfig, StandardRequestHandlerTest, TestPerFieldSimilarity, StatelessScriptUpdateProcessorFactoryTest, PeerSyncTest, HighlighterConfigTest, PrimitiveFieldTypeTest, DocValuesTest, TestLazyCores, TestLuceneMatchVersion, PolyFieldTest, ResourceLoaderTest, SliceStateUpdateTest, MoreLikeThisHandlerTest, FieldMutatingUpdateProcessorTest, SpellCheckComponentTest, TestMergePolicyConfig, BasicDistributedZkTest, ExternalFileFieldSortTest, NotRequiredUniqueKeyTest, SolrCmdDistributorTest, DebugComponentTest, ChaosMonkeySafeLeaderTest, DirectUpdateHandlerTest, SystemInfoHandlerTest, TestSolrDeletionPolicy2, TestCollationKeyRangeQueries, TestCodecSupport, LeaderElectionIntegrationTest, TestClassNameShortening, OutputWriterTest, TestFieldCollectionResource, UniqFieldsUpdateProcessorFactoryTest, LukeRequestHandlerTest, TestXIncludeConfig, DistributedSpellCheckComponentTest, MultiTermTest, TestFuzzyAnalyzedSuggestions, TestJoin, TestSolrCoreProperties, IndexReaderFactoryTest, CSVRequestHandlerTest, TestFiltering, TimeZoneUtilsTest, TestCharFilters, ZkCLITest, TestGroupingSearch, TestPropInject, SortByFunctionTest, UpdateRequestProcessorFactoryTest, AutoCommitTest, TestElisionMultitermQuery, TestDefaultSearchFieldResource, FileUtilsTest, EchoParamsTest, FullSolrCloudDistribCmdsTest, IndexSchemaTest, TestSearchPerf, BasicZkTest, BadComponentTest, TestStressReorder, TestManagedSchemaFieldResource, DateMathParserTest, SpellCheckCollatorTest, CurrencyFieldOpenExchangeTest, CacheHeaderTest, TestFastLRUCache, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 100.78s, 1 test, 1 error <<< FAILURES!
[...truncated 464 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:386: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:366: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1243: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:887: There were test failures: 297 suites, 1238 tests, 1 error, 18 ignored (6 assumptions)
Total time: 119 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 516 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/516/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
All tests passed
Build Log:
[...truncated 9243 lines...]
[junit4:junit4] ERROR: JVM J0 ended with an exception, command line: /Library/Java/JavaVirtualMachines/jdk1.7.0_21.jdk/Contents/Home/jre/bin/java -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/heapdumps -Dtests.prefix=tests -Dtests.seed=936B1AF99911A1D4 -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=4.4 -Dtests.cleanthreads=perClass -Djava.util.logging.config.file=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/junit4/logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.slow=true -Dtests.asserts.gracious=false -Dtests.multiplier=1 -DtempDir=. -Djava.io.tmpdir=. -Djunit4.tempDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp -Dclover.db.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/clover/db -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Djava.security.policy=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/junit4/tests.policy -Dlucene.version=4.4-SNAPSHOT -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -classpath /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/classes/test:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-test-framework/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/test-framework/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/codecs/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/common/lucene-analyzers-common-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/codecs/lucene-codecs-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/highlighter/lucene-highlighter-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/memory/lucene-memory-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/misc/lucene-misc-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/spatial/lucene-spatial-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/suggest/lucene-suggest-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/grouping/lucene-grouping-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queries/lucene-queries-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queryparser/lucene-queryparser-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/cglib-nodep-2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-cli-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-codec-1.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-fileupload-1.2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-lang-2.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/easymock-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/guava-14.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/javax.servlet-api-3.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/objenesis-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/spatial4j-0.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/commons-io-2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpclient-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpcore-4.2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpmime-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/jcl-over-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/jul-to-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/log4j-1.2.16.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/noggit-0.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/slf4j-api-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/slf4j-log4j12-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/wstx-asl-3.2.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/zookeeper-3.4.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-continuation-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-deploy-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-http-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-io-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-jmx-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-security-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-server-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-servlet-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-util-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-webapp-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-xml-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/servlet-api-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/core/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/junit-4.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/randomizedtesting-runner-2.0.10.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/Users/jenkins/.ant/lib/ivy-2.3.0.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_21.jdk/Contents/Home/lib/tools.jar:/Users/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.10.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -flush -eventsfile /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130604_140734_472.events @/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130604_140734_472.suites
[junit4:junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1254)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:67)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:822)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:819)
[junit4:junit4] at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] at java.lang.Thread.run(Thread.java:722)
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:386: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:366: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1243: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:887: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
Total time: 63 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure