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/07 04:25:24 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_21) - Build #
6017 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/6017/
Java: 32bit/jdk1.7.0_21 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 230 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
at __randomizedtesting.SeedInfo.seed([B4E530382347FFEC:3503BE2054189FD0]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
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 9409 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 84702 T475 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 84705 T475 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1370570641747
[junit4:junit4] 2> 84708 T475 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 84710 T476 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 84810 T475 oasc.ZkTestServer.run start zk server on port:50489
[junit4:junit4] 2> 84854 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 84911 T482 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b8c830 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 84911 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 84913 T475 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 84936 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 84937 T484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9f7f8b name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 84937 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 84939 T475 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 84942 T475 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 84944 T475 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 84946 T475 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 84949 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 84949 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 84954 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 84954 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 84957 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 84958 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 84961 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 84962 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 84964 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 84965 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 84968 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 84968 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 84971 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 84971 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 84974 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 84975 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 84977 T475 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 84978 T475 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 85074 T475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 85078 T475 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43653
[junit4:junit4] 2> 85078 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 85079 T475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 85079 T475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023
[junit4:junit4] 2> 85079 T475 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/solr.xml
[junit4:junit4] 2> 85080 T475 oasc.CoreContainer.<init> New CoreContainer 1901519
[junit4:junit4] 2> 85080 T475 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/'
[junit4:junit4] 2> 85081 T475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/'
[junit4:junit4] 2> 85127 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023
[junit4:junit4] 2> 85128 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/collection1
[junit4:junit4] 2> 85128 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/collection1/conf
[junit4:junit4] 2> 85133 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/collection1/conf/xslt
[junit4:junit4] 2> 85150 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/collection1/lib
[junit4:junit4] 2> 85151 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/collection1/lib/classes
[junit4:junit4] 2> 85152 T475 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/conf/core.properties, adding to cores
[junit4:junit4] 2> 85154 T475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 85155 T475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 85155 T475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 85155 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 85156 T475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 85156 T475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 85156 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 85157 T475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 85157 T475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 85158 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 85161 T475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 85161 T475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50489/solr
[junit4:junit4] 2> 85169 T475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 85170 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 85171 T495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17cb9d2 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 85172 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 85175 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 85179 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 85180 T497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1afb7c9 name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 85181 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 85185 T475 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 85190 T475 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 85196 T475 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 85198 T475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43653_
[junit4:junit4] 2> 85200 T475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43653_
[junit4:junit4] 2> 85203 T475 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 85212 T475 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 85214 T475 oasc.Overseer.start Overseer (id=89821717582905347-127.0.0.1:43653_-n_0000000000) starting
[junit4:junit4] 2> 85222 T475 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 85230 T499 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 85230 T475 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 85232 T475 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 85235 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 85244 T498 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 85249 T475 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 85250 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 85250 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 85255 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 85258 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 85259 T502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1498c1c name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 85259 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 85261 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 85264 T475 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 85349 T475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 85351 T475 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58276
[junit4:junit4] 2> 85352 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 85352 T475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 85352 T475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307
[junit4:junit4] 2> 85353 T475 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/solr.xml
[junit4:junit4] 2> 85353 T475 oasc.CoreContainer.<init> New CoreContainer 4124135
[junit4:junit4] 2> 85353 T475 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/'
[junit4:junit4] 2> 85354 T475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/'
[junit4:junit4] 2> 85400 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307
[junit4:junit4] 2> 85401 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/collection1
[junit4:junit4] 2> 85402 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/collection1/conf
[junit4:junit4] 2> 85411 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/collection1/conf/xslt
[junit4:junit4] 2> 85428 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/collection1/lib
[junit4:junit4] 2> 85429 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/collection1/lib/classes
[junit4:junit4] 2> 85430 T475 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/conf/core.properties, adding to cores
[junit4:junit4] 2> 85450 T475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 85451 T475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 85452 T475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 85452 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 85453 T475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 85453 T475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 85454 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 85454 T475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 85454 T475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 85455 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 85460 T475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 85460 T475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50489/solr
[junit4:junit4] 2> 85461 T475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 85462 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 85463 T513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1149a00 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 85463 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 85465 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 85469 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 85470 T515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@116b10d name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 85471 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 85474 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 86478 T475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58276_
[junit4:junit4] 2> 86479 T475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58276_
[junit4:junit4] 2> 86485 T497 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 86485 T502 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 86486 T515 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 86492 T475 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 86493 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 86494 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 86574 T475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 86577 T475 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58592
[junit4:junit4] 2> 86578 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 86578 T475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 86579 T475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539
[junit4:junit4] 2> 86579 T475 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/solr.xml
[junit4:junit4] 2> 86580 T475 oasc.CoreContainer.<init> New CoreContainer 19252867
[junit4:junit4] 2> 86581 T475 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/'
[junit4:junit4] 2> 86581 T475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/'
[junit4:junit4] 2> 86650 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539
[junit4:junit4] 2> 86652 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/collection1
[junit4:junit4] 2> 86652 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/collection1/conf
[junit4:junit4] 2> 86660 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/collection1/conf/xslt
[junit4:junit4] 2> 86677 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/collection1/lib
[junit4:junit4] 2> 86678 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/collection1/lib/classes
[junit4:junit4] 2> 86679 T475 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/conf/core.properties, adding to cores
[junit4:junit4] 2> 86681 T475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 86681 T475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 86682 T475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 86682 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 86682 T475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 86683 T475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 86683 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 86684 T475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 86684 T475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 86684 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 86687 T475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 86688 T475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50489/solr
[junit4:junit4] 2> 86688 T475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 86689 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 86690 T527 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e22e1 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 86691 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 86693 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 86696 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 86697 T529 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35dbb name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 86697 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 86703 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 87706 T475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58592_
[junit4:junit4] 2> 87707 T475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58592_
[junit4:junit4] 2> 87710 T497 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 87710 T502 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 87710 T515 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 87710 T529 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 87719 T475 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 87719 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 87720 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 87788 T475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 87789 T475 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36349
[junit4:junit4] 2> 87790 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 87790 T475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 87790 T475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764
[junit4:junit4] 2> 87791 T475 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/solr.xml
[junit4:junit4] 2> 87791 T475 oasc.CoreContainer.<init> New CoreContainer 11179660
[junit4:junit4] 2> 87792 T475 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/'
[junit4:junit4] 2> 87792 T475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/'
[junit4:junit4] 2> 87835 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764
[junit4:junit4] 2> 87836 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/collection1
[junit4:junit4] 2> 87837 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/collection1/conf
[junit4:junit4] 2> 87841 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/collection1/conf/xslt
[junit4:junit4] 2> 87857 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/collection1/lib
[junit4:junit4] 2> 87858 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/collection1/lib/classes
[junit4:junit4] 2> 87859 T475 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/conf/core.properties, adding to cores
[junit4:junit4] 2> 87861 T475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 87861 T475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 87861 T475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 87862 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 87862 T475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 87862 T475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 87863 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 87863 T475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 87863 T475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 87864 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 87867 T475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 87867 T475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50489/solr
[junit4:junit4] 2> 87867 T475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 87868 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 87869 T541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15743b5 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 87870 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 87872 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 87874 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 87875 T543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ccab97 name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 87876 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 87879 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 88883 T475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36349_
[junit4:junit4] 2> 88885 T475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36349_
[junit4:junit4] 2> 88888 T529 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 88888 T502 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 88889 T543 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 88890 T497 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 88890 T515 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 88893 T475 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 88894 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 88894 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 88960 T475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 88962 T475 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58435
[junit4:junit4] 2> 88963 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 88963 T475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 88963 T475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938
[junit4:junit4] 2> 88964 T475 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/solr.xml
[junit4:junit4] 2> 88964 T475 oasc.CoreContainer.<init> New CoreContainer 2575306
[junit4:junit4] 2> 88964 T475 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/'
[junit4:junit4] 2> 88965 T475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/'
[junit4:junit4] 2> 89007 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938
[junit4:junit4] 2> 89008 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/collection1
[junit4:junit4] 2> 89009 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/collection1/conf
[junit4:junit4] 2> 89013 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/collection1/conf/xslt
[junit4:junit4] 2> 89029 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/collection1/lib
[junit4:junit4] 2> 89030 T475 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/collection1/lib/classes
[junit4:junit4] 2> 89031 T475 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/conf/core.properties, adding to cores
[junit4:junit4] 2> 89033 T475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 89034 T475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 89034 T475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 89034 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 89035 T475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 89035 T475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 89035 T475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 89036 T475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 89036 T475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 89036 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 89039 T475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 89040 T475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50489/solr
[junit4:junit4] 2> 89040 T475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 89041 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 89042 T555 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d1759 name:ZooKeeperConnection Watcher:127.0.0.1:50489 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 89042 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 89045 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 89048 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 89050 T557 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f92fc6 name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 89050 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 89054 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 90057 T475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58435_
[junit4:junit4] 2> 90058 T475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58435_
[junit4:junit4] 2> 90062 T515 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90062 T497 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90062 T529 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90062 T502 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90062 T543 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90063 T557 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 90068 T475 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 90068 T475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 90069 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 90074 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 90080 T508 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 90083 T497 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 90085 T499 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> 90085 T499 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:36349_
[junit4:junit4] 2> 90087 T499 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:58435_
[junit4:junit4] 2> 90087 T499 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:58592_
[junit4:junit4] 2> 90088 T499 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:58276_
[junit4:junit4] 2> 90090 T522 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 90090 T510 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 90091 T510 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 90090 T553 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 90092 T553 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 90090 T538 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 90093 T553 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 90092 T510 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 90091 T522 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 90093 T510 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 90093 T553 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 90093 T538 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 90095 T510 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 90094 T522 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 90095 T538 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 90095 T553 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 90095 T510 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 90096 T553 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 90096 T538 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 90095 T522 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 90099 T553 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 90099 T538 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 90099 T522 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 90099 T510 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 90100 T553 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 90101 T538 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 90102 T510 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 90102 T522 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 90103 T538 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 90104 T522 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 90141 T553 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 90158 T538 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 90158 T510 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 90167 T522 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 90182 T553 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 90183 T553 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 90188 T553 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 90221 T538 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 90223 T538 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 90224 T510 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 90227 T510 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 90231 T538 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 90231 T522 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 90233 T522 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 90233 T510 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 90239 T522 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 90741 T538 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 90748 T538 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 90751 T538 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 90761 T522 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 90766 T538 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90767 T522 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 90768 T553 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 90770 T522 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 90771 T538 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90776 T538 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90778 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90778 T553 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 90778 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90780 T538 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90782 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90783 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90783 T553 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 90783 T538 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90783 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90784 T538 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 90785 T538 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 90785 T538 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90786 T538 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 90787 T538 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 90787 T538 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 90788 T538 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 90789 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90790 T538 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15350ac lockFactory=org.apache.lucene.store.NativeFSLockFactory@156d43e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 90791 T538 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 90793 T538 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 90794 T538 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 90795 T538 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 90796 T538 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 90796 T553 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90796 T538 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 90797 T538 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 90798 T538 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 90798 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90798 T538 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 90799 T538 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 90800 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90804 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90804 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90804 T553 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90805 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90806 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90806 T538 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 90807 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90807 T522 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 90808 T522 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 90809 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90815 T522 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 90815 T553 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90815 T538 oass.SolrIndexSearcher.<init> Opening Searcher@1ad953 main
[junit4:junit4] 2> 90815 T522 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 90816 T538 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 90817 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90817 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90818 T553 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90816 T522 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 90817 T538 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 90819 T522 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 90819 T538 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 90819 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90820 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90821 T553 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90821 T522 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b1f1d8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@14194d2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 90821 T553 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 90821 T522 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 90822 T553 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 90823 T553 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90824 T553 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 90824 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 90824 T553 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 90824 T563 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@1ad953 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 90825 T553 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 90825 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 90824 T538 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 90826 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 90826 T553 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 90828 T522 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 90828 T522 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 90829 T522 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 90829 T522 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 90829 T553 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35d7cb lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ece11e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 90830 T553 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 90829 T522 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 90830 T522 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 90831 T553 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 90832 T553 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 90832 T553 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 90833 T553 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 90833 T522 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 90833 T553 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 90833 T553 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 90834 T553 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 90834 T553 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 90835 T553 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 90835 T522 oass.SolrIndexSearcher.<init> Opening Searcher@8cc9f7 main
[junit4:junit4] 2> 90835 T522 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 90836 T553 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 90836 T522 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 90836 T522 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 90838 T553 oass.SolrIndexSearcher.<init> Opening Searcher@c27b65 main
[junit4:junit4] 2> 90839 T553 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 90839 T553 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 90840 T553 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 90841 T564 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@8cc9f7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 90842 T522 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 90844 T565 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@c27b65 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 90845 T553 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 90857 T510 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 90866 T510 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 90869 T510 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 90880 T510 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90886 T510 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 90889 T510 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90890 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90890 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90891 T510 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 90892 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 90892 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 90892 T510 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90893 T510 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 90893 T510 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 90893 T510 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 90894 T510 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 90894 T510 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 90895 T510 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 90895 T510 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 90897 T510 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@24b0a8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b046ff),segFN=segments_1,generation=1}
[junit4:junit4] 2> 90897 T510 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 90898 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 90899 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 90899 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 90900 T510 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 90900 T510 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 90901 T510 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 90901 T510 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 90902 T510 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 90902 T510 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 90905 T510 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 90907 T510 oass.SolrIndexSearcher.<init> Opening Searcher@1e629fc main
[junit4:junit4] 2> 90908 T510 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 90908 T510 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 90908 T510 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 90913 T566 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@1e629fc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 90915 T510 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 91253 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 91254 T498 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:36349_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36349"}
[junit4:junit4] 2> 91254 T498 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 91266 T498 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:58592_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58592"}
[junit4:junit4] 2> 91269 T498 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:58435_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58435"}
[junit4:junit4] 2> 91272 T498 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:58276_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58276"}
[junit4:junit4] 2> 91280 T515 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> 91280 T543 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> 91281 T497 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> 91280 T529 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> 91280 T557 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> 91280 T502 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> 91829 T538 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 91829 T538 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:36349 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 91833 T538 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 91837 T538 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 91843 T522 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 91844 T522 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:58592 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 91844 T538 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 91845 T522 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 91846 T553 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 91846 T553 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:58435 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 91847 T538 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 91850 T522 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 91852 T522 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4] 2> 91917 T510 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 91917 T510 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:58276 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 92348 T538 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 92348 T538 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 92349 T538 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 92352 T538 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 92353 T522 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 92353 T522 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 92354 T522 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 92356 T538 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:36349 START replicas=[http://127.0.0.1:58435/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 92356 T522 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:58592 START replicas=[http://127.0.0.1:58276/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 92357 T538 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:36349 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 92359 T522 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:58592 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 92360 T522 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 92359 T538 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 92360 T522 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> 92360 T538 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> 92361 T538 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 92361 T522 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 92362 T538 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> 92362 T522 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C190 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@216f94 url=http://127.0.0.1:58435/nodes_used_collection_shard1_replica2 node=127.0.0.1:58435_ C190_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:58435_, base_url=http://127.0.0.1:58435}
[junit4:junit4] 2> 92366 T551 C190 P58435 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=0
[junit4:junit4] 2> ASYNC NEW_CORE C191 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@4cbf91 url=http://127.0.0.1:58276/nodes_used_collection_shard2_replica2 node=127.0.0.1:58276_ C191_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:58276_, base_url=http://127.0.0.1:58276}
[junit4:junit4] 2> 92370 T511 C191 P58276 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> 92792 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 92807 T497 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> 92807 T515 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> 92807 T502 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> 92808 T543 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> 92808 T529 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> 92808 T557 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> 92824 T522 oasc.ZkController.register We are http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 92824 T538 oasc.ZkController.register We are http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 92824 T522 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:58592
[junit4:junit4] 2> 92825 T522 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 92824 T538 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:36349
[junit4:junit4] 2> 92825 T538 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 92825 T522 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 92826 T538 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 92827 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 92827 T522 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 92828 T538 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=2739
[junit4:junit4] 2> 92829 T522 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=2740
[junit4:junit4] 2> 92850 T553 oasc.ZkController.register We are http://127.0.0.1:58435/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 92850 T553 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:58435
[junit4:junit4] 2> 92850 T553 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 92851 T553 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 92853 T569 C190 P58435 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 92854 T553 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 92854 T569 C190 P58435 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 92855 T569 C190 P58435 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4] 2> 92855 T553 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=2766
[junit4:junit4] 2> 92856 T569 C190 P58435 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 92860 T539 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:58435__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 92921 T510 oasc.ZkController.register We are http://127.0.0.1:58276/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 92921 T510 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:58276
[junit4:junit4] 2> 92922 T510 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 92922 T510 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 92922 T570 C191 P58276 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 92923 T570 C191 P58276 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 92923 T510 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 92923 T570 C191 P58276 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 2> 92924 T510 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=2834
[junit4:junit4] 2> 92925 T499 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 92926 T570 C191 P58276 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 92929 T525 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:58276__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 92932 T515 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 92932 T497 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 92933 T499 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=2739},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=2740},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=2766},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=2834},core=nodes_used_collection_shard2_replica2}}}
[junit4:junit4] 2> 92935 T508 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=2857
[junit4:junit4] 2> 92935 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 92936 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 92939 T572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19dda8b name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 92939 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 92941 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 92943 T475 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 92944 T475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 92945 T574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4876b0 name:ZooKeeperConnection Watcher:127.0.0.1:50489/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 92945 T475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 92947 T475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 92951 T551 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=4&maxShardsPerNode=5&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 92953 T497 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 92954 T499 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":"4",
[junit4:junit4] 2> "maxShardsPerNode":"5",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 92954 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:58592_
[junit4:junit4] 2> 92954 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:58276_
[junit4:junit4] 2> 92954 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:58435_
[junit4:junit4] 2> 92954 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:36349_
[junit4:junit4] 2> 92955 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:43653_
[junit4:junit4] 2> 92955 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:58592_
[junit4:junit4] 2> 92955 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:58276_
[junit4:junit4] 2> 92956 T491 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard1_replica5
[junit4:junit4] 2> 92956 T552 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 92956 T522 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 92957 T522 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92956 T536 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 92957 T522 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92956 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:58435_
[junit4:junit4] 2> 92956 T491 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92956 T523 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 92956 T509 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 92959 T553 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 92958 T523 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92958 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:36349_
[junit4:junit4] 2> 92958 T522 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92957 T536 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92957 T511 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 92956 T552 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92961 T522 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 92961 T536 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92961 T511 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92961 T537 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 92960 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:43653_
[junit4:junit4] 2> 92960 T523 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92959 T553 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92959 T491 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92959 T509 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92964 T553 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92964 T491 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92964 T490 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5
[junit4:junit4] 2> 92963 T523 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92963 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:58592_
[junit4:junit4] 2> 92962 T511 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92962 T537 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92962 T536 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92961 T522 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92961 T552 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92968 T552 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92967 T537 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92967 T523 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 92966 T524 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 92966 T511 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92966 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:58276_
[junit4:junit4] 2> 92965 T491 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 92965 T490 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92965 T509 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 92965 T553 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92971 T509 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92971 T490 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 92972 T490 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92971 T510 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 92973 T510 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92971 T511 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92970 T491 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92970 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:58435_
[junit4:junit4] 2> 92969 T524 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92969 T522 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92976 T511 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92977 T550 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard3_replica3
[junit4:junit4] 2> 92977 T550 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 92978 T491 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92978 T522 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 92979 T511 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 92969 T552 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 92969 T523 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92968 T537 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 92968 T536 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 92980 T552 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92978 T550 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 92987 T550 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92976 T524 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 92988 T552 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92975 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:36349_
[junit4:junit4] 2> 92974 T509 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92974 T510 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 92990 T510 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92973 T490 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/'
[junit4:junit4] 2> 92973 T553 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92991 T552 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 92991 T510 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/'
[junit4:junit4] 2> 92991 T538 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard3_replica4
[junit4:junit4] 2> 92993 T553 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92991 T550 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard3_replica3/'
[junit4:junit4] 2> 92989 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica5 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:43653_
[junit4:junit4] 2> 92988 T491 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard1_replica5/'
[junit4:junit4] 2> 92988 T523 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92988 T537 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92988 T524 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 92982 T536 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 92998 T509 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93001 T553 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 92993 T538 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93004 T538 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93004 T538 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93005 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:58592_
[junit4:junit4] 2> 93006 T537 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93007 T509 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 93008 T536 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93008 T524 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard3_replica1/'
[junit4:junit4] 2> 93008 T523 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 93010 T537 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 93012 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:58276_
[junit4:junit4] 2> 93008 T538 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard3_replica4/'
[junit4:junit4] 2> 93014 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:58435_
[junit4:junit4] 2> 93016 T493 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard3_replica5
[junit4:junit4] 2> 93016 T493 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93016 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:36349_
[junit4:junit4] 2> 93016 T508 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 93017 T508 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93018 T589 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard4_replica3
[junit4:junit4] 2> 93019 T589 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93027 T592 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard4_replica4
[junit4:junit4] 2> 93023 T499 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica5 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:43653_
[junit4:junit4] 2> 93023 T493 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93029 T493 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93023 T536 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 93021 T508 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93030 T508 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93019 T590 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 93031 T590 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93033 T590 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93033 T590 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93034 T592 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93035 T493 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard3_replica5/'
[junit4:junit4] 2> 93029 T589 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93037 T589 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93038 T592 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93039 T592 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93035 T590 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard4_replica1/'
[junit4:junit4] 2> 93035 T508 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard4_replica2/'
[junit4:junit4] 2> 93042 T589 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370570645938/awholynewcollection_0_shard4_replica3/'
[junit4:junit4] 2> 93053 T492 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5
[junit4:junit4] 2> 93054 T492 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 93055 T492 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 93055 T492 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 93057 T492 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/'
[junit4:junit4] 2> 93057 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard4_replica4/'
[junit4:junit4] 2> 93095 T522 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93102 T511 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93113 T490 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93145 T491 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93155 T536 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93167 T550 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93182 T538 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93226 T510 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93244 T553 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93262 T509 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93272 T522 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93284 T522 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93288 T492 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93298 T523 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93298 T552 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93305 T590 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93309 T522 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 93319 T592 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93343 T493 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93366 T508 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93368 T537 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93378 T524 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93381 T589 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 93383 T511 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93387 T511 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93417 T511 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 93471 T550 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93472 T490 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93485 T491 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93488 T490 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93492 T491 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93494 T536 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93496 T550 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93496 T536 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93500 T491 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica5] Schema name=test
[junit4:junit4] 2> 93504 T536 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 93506 T550 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica3] Schema name=test
[junit4:junit4] 2> 93518 T553 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93520 T553 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93529 T553 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 93539 T490 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica5] Schema name=test
[junit4:junit4] 2> 93548 T492 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93550 T492 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93552 T510 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93571 T510 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93578 T510 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
[junit4:junit4] 2> 93581 T492 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica5] Schema name=test
[junit4:junit4] 2> 93602 T538 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93604 T592 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93608 T538 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93609 T592 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93613 T538 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica4] Schema name=test
[junit4:junit4] 2> 93618 T509 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93620 T509 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93622 T592 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica4] Schema name=test
[junit4:junit4] 2> 93627 T523 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93629 T523 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93630 T509 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 93654 T493 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93658 T493 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93673 T523 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 93699 T493 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica5] Schema name=test
[junit4:junit4] 2> 93707 T537 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93715 T508 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93715 T552 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93721 T537 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93722 T552 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93725 T508 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93728 T537 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 93739 T589 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93741 T508 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
[junit4:junit4] 2> 93741 T524 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93743 T524 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93745 T589 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93746 T552 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 93745 T590 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 93765 T590 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 93767 T589 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica3] Schema name=test
[junit4:junit4] 2> 93780 T524 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
[junit4:junit4] 2> 93785 T590 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
[junit4:junit4] 2> 94328 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 94329 T498 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:58592__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:58592_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58592"}
[junit4:junit4] 2> 94332 T498 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:36349__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:36349_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36349"}
[junit4:junit4] 2> 94336 T498 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:58435__nodes_used_collection_shard1_replica2",
[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_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:58435_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58435"}
[junit4:junit4] 2> 94342 T498 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:58276__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:58276_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58276"}
[junit4:junit4] 2> 94362 T529 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> 94362 T557 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> 94362 T502 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> 94363 T497 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> 94362 T543 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> 94362 T572 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> 94362 T574 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> 94363 T515 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> 94861 T539 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:58435__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 94861 T539 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:58435__nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:58435_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2001
[junit4:junit4] 2> 94931 T525 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:58276__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 94931 T525 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:58276__nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:58276_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4:junit4] 2> 96116 T522 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96192 T522 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96197 T522 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96253 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96305 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96327 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96332 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96332 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96333 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96334 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96335 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96335 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96336 T522 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data/
[junit4:junit4] 2> 96342 T522 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96343 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96345 T522 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data
[junit4:junit4] 2> 96346 T522 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data/index/
[junit4:junit4] 2> 96346 T522 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96347 T522 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data/index
[junit4:junit4] 2> 96377 T522 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@141ebd5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@354ee1),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96378 T522 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96381 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96381 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96382 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96384 T522 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96385 T522 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96385 T522 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96385 T522 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96386 T522 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96387 T522 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96391 T522 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96423 T522 oass.SolrIndexSearcher.<init> Opening Searcher@17cf06f main
[junit4:junit4] 2> 96423 T522 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370570643539/awholynewcollection_0_shard2_replica1/data/tlog
[junit4:junit4] 2> 96439 T522 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 96440 T522 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 96447 T604 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@17cf06f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 96449 T522 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 96450 T536 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96460 T536 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96465 T536 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96505 T536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96507 T511 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96522 T536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96552 T536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96554 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96555 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96555 T536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96570 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96571 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96571 T536 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96572 T536 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica4] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data/
[junit4:junit4] 2> 96572 T536 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96573 T536 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96575 T536 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data
[junit4:junit4] 2> 96579 T536 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data/index/
[junit4:junit4] 2> 96580 T536 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica4] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96580 T536 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data/index
[junit4:junit4] 2> 96583 T536 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d728cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1772bf3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96583 T536 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96585 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96586 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96587 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96609 T536 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96610 T536 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96610 T536 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96611 T536 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96612 T536 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96612 T536 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96602 T511 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96616 T536 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96618 T511 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96624 T536 oass.SolrIndexSearcher.<init> Opening Searcher@e20c67 main
[junit4:junit4] 2> 96624 T536 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370570644764/awholynewcollection_0_shard1_replica4/data/tlog
[junit4:junit4] 2> 96632 T536 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 96632 T536 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 96640 T536 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4] 2> 96643 T605 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica4] Registered new searcher Searcher@e20c67 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 96656 T492 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96676 T510 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96692 T511 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96701 T511 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96703 T510 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96703 T492 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96711 T492 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96725 T511 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96728 T510 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96741 T490 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96741 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96742 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96743 T511 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96745 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96746 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96751 T511 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96746 T492 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96751 T511 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data/
[junit4:junit4] 2> 96753 T511 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96754 T510 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96754 T511 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96755 T511 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data
[junit4:junit4] 2> 96760 T510 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96761 T511 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data/index/
[junit4:junit4] 2> 96762 T511 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96763 T511 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4] 2> 96765 T511 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bec9bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f85604),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96765 T511 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96767 T553 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96768 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96768 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96769 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96770 T511 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96771 T511 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96771 T511 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96772 T511 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96773 T511 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96773 T511 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96778 T511 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96779 T491 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96785 T553 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96789 T492 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96795 T510 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96805 T490 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96807 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96808 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96808 T510 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96811 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96812 T510 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96807 T492 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96812 T510 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96813 T510 oasc.SolrCore.<init> [awholynewcollection_0_shard3_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data/
[junit4:junit4] 2> 96814 T510 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96814 T510 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96815 T510 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data
[junit4:junit4] 2> 96821 T510 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data/index/
[junit4:junit4] 2> 96821 T510 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard3_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96814 T490 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96821 T510 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data/index
[junit4:junit4] 2> 96821 T492 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96820 T511 oass.SolrIndexSearcher.<init> Opening Searcher@671cea main
[junit4:junit4] 2> 96823 T511 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard2_replica2/data/tlog
[junit4:junit4] 2> 96824 T511 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 96825 T511 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 96823 T492 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96827 T492 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96822 T553 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96827 T510 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19b6186 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c08e47),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96829 T510 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96831 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96832 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96831 T511 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 96833 T510 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96832 T606 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica2] Registered new searcher Searcher@671cea main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 96832 T491 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96835 T492 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96835 T492 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96836 T492 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96836 T492 oasc.SolrCore.<init> [awholynewcollection_0_shard4_replica5] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data/
[junit4:junit4] 2> 96837 T492 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96834 T510 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96842 T510 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96842 T510 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96843 T510 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96844 T510 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96844 T510 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96837 T538 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96842 T492 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96850 T490 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96852 T492 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data
[junit4:junit4] 2> 96856 T510 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96857 T492 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data/index/
[junit4:junit4] 2> 96857 T490 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96861 T538 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96857 T550 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> ASYNC NEW_CORE C192 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@216f94 url=http://127.0.0.1:58435/nodes_used_collection_shard1_replica2 node=127.0.0.1:58435_ C192_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:58435_, base_url=http://127.0.0.1:58435}
[junit4:junit4] 2> 96862 T569 C192 P58435 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/ core=nodes_used_collection_shard1_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 96863 T569 C192 P58435 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:58435 START replicas=[http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 96864 T491 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96857 T492 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard4_replica5] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96866 T492 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data/index
[junit4:junit4] 2> 96870 T492 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c9fe7c lockFactory=org.apache.lucene.store.NativeFSLockFactory@1333cb6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96871 T492 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96872 T538 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96873 T492 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96873 T492 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96866 T510 oass.SolrIndexSearcher.<init> Opening Searcher@f6e3c7 main
[junit4:junit4] 2> 96870 T553 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96876 T510 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370570642307/awholynewcollection_0_shard3_replica2/data/tlog
[junit4:junit4] 2> 96877 T490 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96877 T510 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 96882 T510 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 96880 T490 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96880 T569 C192 P58435 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 96883 T569 C192 P58435 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 96884 T569 C192 P58435 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 96884 T569 C192 P58435 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 96884 T569 C192 P58435 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 96885 T569 C192 P58435 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:36349/nodes_used_collection_shard1_replica1/. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 96885 T569 C192 P58435 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 96888 T607 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard3_replica2] Registered new searcher Searcher@f6e3c7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 96884 T490 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96889 T492 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96888 T550 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96890 T510 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica2 state=down
[junit4:junit4] 2> 96889 T490 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96891 T492 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96892 T492 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96893 T490 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96893 T491 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96893 T492 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96894 T492 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96895 T550 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 96893 T490 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96896 T490 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96897 T490 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica5] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/data/
[junit4:junit4] 2> 96898 T490 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96898 T490 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96895 T492 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96905 T492 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96908 T538 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96904 T553 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96913 T492 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96917 T492 oass.SolrIndexSearcher.<init> Opening Searcher@126e0d4 main
[junit4:junit4] 2> 96918 T492 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard4_replica5/data/tlog
[junit4:junit4] 2> 96919 T492 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 96920 T492 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 96899 T490 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/data
[junit4:junit4] 2> 96923 T490 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/data/index/
[junit4:junit4] 2> 96924 T490 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica5] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 96925 T490 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard2_replica5/data/index
[junit4:junit4] 2> 96920 T553 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> ASYNC NEW_CORE C193 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@1667add url=http://127.0.0.1:36349/nodes_used_collection_shard1_replica1 node=127.0.0.1:36349_ C193_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:36349_, base_url=http://127.0.0.1:36349, leader=true}
[junit4:junit4] 2> 96918 T599 C193 P36349 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 96910 T491 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96909 T539 C193 P36349 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=0
[junit4:junit4] 2> 96928 T490 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f61040 lockFactory=org.apache.lucene.store.NativeFSLockFactory@edcb7e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96942 T490 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96936 T609 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard4_replica5] Registered new searcher Searcher@126e0d4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 96935 T538 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96944 T550 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96946 T490 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 96950 T490 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 96951 T550 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 96935 T492 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica5 state=down
[junit4:junit4] 2> ASYNC NEW_CORE C194 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@4cbf91 url=http://127.0.0.1:58276/nodes_used_collection_shard2_replica2 node=127.0.0.1:58276_ C194_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:58276_, base_url=http://127.0.0.1:58276}
[junit4:junit4] 2> 96932 T570 C194 P58276 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/ core=nodes_used_collection_shard2_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 96932 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96953 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96953 T553 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96929 T599 C193 P36349 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15350ac lockFactory=org.apache.lucene.store.NativeFSLockFactory@156d43e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 96952 T570 C194 P58276 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:58276 START replicas=[http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 96951 T490 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 96950 T509 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96949 T538 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96949 T491 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96960 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96961 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96961 T491 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96962 T550 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 96962 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96963 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96963 T491 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 96964 T491 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica5] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard1_replica5/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370570642023/awholynewcollection_0_shard1_replica5/data/
[junit4:junit4] 2> 96965 T491 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@19b4e74
[junit4:junit4] 2> 96946 T524 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96967 T491 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> ASYNC NEW_CORE C195 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@580471 url=http://127.0.0.1:58592/nodes_used_collection_shard2_replica1 node=127.0.0.1:58592_ C195_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:58592_, base_url=http://127.0.0.1:58592, leader=true}
[junit4:junit4] 2> 96967 T525 C195 P58592 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=2
[junit4:junit4] 2> 96962 T493 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96960 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96970 T538 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96958 T490 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 96971 T490 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 96972 T490 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 96972 T490 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 96973 T490 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 96974 T490 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 96958 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 96975 T553 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 96957 T570 C194 P58276 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 96976 T570 C194 P58276 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 96976 T570 C194 P58276 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 96976 T570 C194 P58276 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 96957 T537 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96956 T599 C193 P36349 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 96976 T570 C194 P58276 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 96978 T570 C194 P58276 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58592/nodes_used_collection_shard2_replica1/. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 96978 T570 C194 P58276 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 96979 T493 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 96980 T490 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 96976 T552 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 96976 T553 oasc.SolrCore
[...truncated too long message...]
ynewcollection_1_shard1_replica1",
[junit4:junit4] 1> "node_name":"127.0.0.1:36349_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:36349"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard4 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard4_replica2",
[junit4:junit4] 1> "node_name":"127.0.0.1:58435_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:58435"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard2_replica4",
[junit4:junit4] 1> "node_name":"127.0.0.1:58276_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:58276"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard3 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard3_replica1",
[junit4:junit4] 1> "node_name":"127.0.0.1:36349_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:36349"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89821717582905352-127.0.0.1:58592_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89821717582905347-127.0.0.1:43653_-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89821717582905356-127.0.0.1:58435_-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89821717582905350-127.0.0.1:58276_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89821717582905354-127.0.0.1:36349_-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89821717582905347-127.0.0.1:43653_-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=B4E530382347FFEC -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja -Dtests.timezone=America/North_Dakota/Center -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 279s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([B4E530382347FFEC:3503BE2054189FD0]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
[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> 363993 T475 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 279294 T474 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 365186 T557 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 365186 T557 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 365186 T557 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_2/leader_elect/shard1/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 365187 T557 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_2/leader_elect/shard2/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {timestamp=MockVariableIntBlock(baseBlockSize=67), range_facet_l=MockVariableIntBlock(baseBlockSize=67), id=PostingsFormat(name=NestedPulsing), range_facet_sl=PostingsFormat(name=MockRandom), a_t=MockVariableIntBlock(baseBlockSize=67), text=PostingsFormat(name=MockRandom), range_facet_si=PostingsFormat(name=Lucene41WithOrds), _version_=MockVariableIntBlock(baseBlockSize=67), other_tl1=MockVariableIntBlock(baseBlockSize=67), multiDefault=PostingsFormat(name=Lucene41WithOrds), a_si=PostingsFormat(name=Lucene41WithOrds), intDefault=MockVariableIntBlock(baseBlockSize=67)}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ja, timezone=America/North_Dakota/Center
[junit4:junit4] 2> NOTE: Linux 3.2.0-45-generic i386/Oracle Corporation 1.7.0_21 (32-bit)/cpus=8,threads=2,free=17446544,total=263323648
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestDistributedGrouping, NotRequiredUniqueKeyTest, EchoParamsTest, UpdateParamsTest, DistanceFunctionTest, CoreContainerCoreInitFailuresTest, SolrCmdDistributorTest, TestJmxMonitoredMap, DOMUtilTest, PreAnalyzedUpdateProcessorTest, OutputWriterTest, TestCoreDiscovery, TestDefaultSearchFieldResource, URLClassifyProcessorTest, TestBinaryResponseWriter, TestComponentsName, DisMaxRequestHandlerTest, TestSystemIdResolver, TestFiltering, TestRecovery, XmlUpdateRequestHandlerTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestBM25SimilarityFactory, SpellPossibilityIteratorTest, TestFieldResource, TestCopyFieldCollectionResource, TestJmxIntegration, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed on J1 in 280.57s, 1 test, 1 failure <<< FAILURES!
[...truncated 683 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:385: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:365: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1240: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:884: There were test failures: 296 suites, 1243 tests, 1 failure, 13 ignored (7 assumptions)
Total time: 40 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_21 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure