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/05/24 05:05:25 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_21) - Build #
2820 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2820/
Java: 32bit/jdk1.7.0_21 -server -XX:+UseG1GC
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([9A5BBC4B47E4FC53:1BBD325330BB9C6F]: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 9261 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 15804 T18 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 15813 T18 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-CollectionsAPIDistributedZkTest-1369362081408
[junit4:junit4] 2> 15822 T18 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 15829 T19 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 16109 T18 oasc.ZkTestServer.run start zk server on port:55713
[junit4:junit4] 2> 16278 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16378 T25 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e57a1e name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16379 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16383 T18 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 16476 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16480 T27 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@191ff3 name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16481 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16499 T18 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 16509 T18 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 16517 T18 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 16524 T18 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 16532 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 16559 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 16574 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 16575 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 16584 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 16586 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 16595 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 16596 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 16602 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 16603 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 16612 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 16612 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 16624 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 16625 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 16634 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 16634 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 16643 T18 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 16643 T18 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 17540 T18 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 17806 T18 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55720
[junit4:junit4] 2> 17862 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 17863 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 17864 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247
[junit4:junit4] 2> 17865 T18 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\solr.xml
[junit4:junit4] 2> 17866 T18 oasc.CoreContainer.<init> New CoreContainer 28114992
[junit4:junit4] 2> 17867 T18 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\'
[junit4:junit4] 2> 17868 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\'
[junit4:junit4] 2> 18022 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247
[junit4:junit4] 2> 18023 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\collection1
[junit4:junit4] 2> 18026 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\collection1\conf
[junit4:junit4] 2> 18239 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\collection1\conf\xslt
[junit4:junit4] 2> 18247 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\collection1\lib
[junit4:junit4] 2> 18250 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\collection1\lib\classes
[junit4:junit4] 2> 18256 T18 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\conf\core.properties, adding to cores
[junit4:junit4] 2> 18271 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 18271 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 18272 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 18272 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 18272 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 18273 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 18274 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 18274 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 18275 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 18318 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 18906 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 18907 T18 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55713/solr
[junit4:junit4] 2> 18928 T18 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 18931 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 18964 T40 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18180c name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 18965 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 18979 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 18994 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 18998 T42 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fb09d name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 18998 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 19011 T18 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 19030 T18 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 19049 T18 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 19056 T18 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55720_
[junit4:junit4] 2> 19066 T18 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55720_
[junit4:junit4] 2> 19078 T18 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 19111 T18 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 19118 T18 oasc.Overseer.start Overseer (id=89742513383669763-127.0.0.1:55720_-n_0000000000) starting
[junit4:junit4] 2> 19148 T18 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 19172 T18 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 19176 T44 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 19182 T18 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 19188 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 19212 T43 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 19257 T18 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 19257 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 19320 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19343 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 19351 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 19359 T47 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1995bec name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 19360 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 19364 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 19372 T18 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 19841 T18 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 19855 T18 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55732
[junit4:junit4] 2> 19856 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 19857 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 19857 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966
[junit4:junit4] 2> 19858 T18 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\solr.xml
[junit4:junit4] 2> 19858 T18 oasc.CoreContainer.<init> New CoreContainer 9116636
[junit4:junit4] 2> 19859 T18 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\'
[junit4:junit4] 2> 19860 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\'
[junit4:junit4] 2> 19990 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966
[junit4:junit4] 2> 19993 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\collection1
[junit4:junit4] 2> 19994 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\collection1\conf
[junit4:junit4] 2> 20213 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\collection1\conf\xslt
[junit4:junit4] 2> 20221 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\collection1\lib
[junit4:junit4] 2> 20222 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\collection1\lib\classes
[junit4:junit4] 2> 20228 T18 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\conf\core.properties, adding to cores
[junit4:junit4] 2> 20244 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 20245 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 20245 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 20247 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 20247 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 20248 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 20249 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 20250 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 20250 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 20251 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 20261 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 20262 T18 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55713/solr
[junit4:junit4] 2> 20262 T18 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 20265 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 20288 T58 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16a0cb3 name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 20289 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 20296 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 20308 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 20315 T60 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b48e49 name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 20315 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 20333 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 21341 T18 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55732_
[junit4:junit4] 2> 21347 T18 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55732_
[junit4:junit4] 2> 21376 T42 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 21378 T47 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 21379 T60 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 21397 T18 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 21399 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 21399 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 21853 T18 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 21859 T18 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55741
[junit4:junit4] 2> 21860 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 21860 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 21871 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000
[junit4:junit4] 2> 21871 T18 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\solr.xml
[junit4:junit4] 2> 21872 T18 oasc.CoreContainer.<init> New CoreContainer 5517223
[junit4:junit4] 2> 21873 T18 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\'
[junit4:junit4] 2> 21873 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\'
[junit4:junit4] 2> 21982 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000
[junit4:junit4] 2> 21984 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\collection1
[junit4:junit4] 2> 21986 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\collection1\conf
[junit4:junit4] 2> 22182 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\collection1\conf\xslt
[junit4:junit4] 2> 22190 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\collection1\lib
[junit4:junit4] 2> 22194 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\collection1\lib\classes
[junit4:junit4] 2> 22199 T18 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\conf\core.properties, adding to cores
[junit4:junit4] 2> 22219 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 22219 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 22220 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 22220 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 22221 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 22221 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 22222 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 22222 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 22222 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 22223 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 22235 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 22235 T18 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55713/solr
[junit4:junit4] 2> 22235 T18 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 22238 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22256 T72 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@136d4df name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22257 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22262 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 22263 T20 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ed457277c0007, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 22270 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22275 T74 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bf3d7c name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22275 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22306 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 23313 T18 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55741_
[junit4:junit4] 2> 23317 T18 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55741_
[junit4:junit4] 2> 23325 T42 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 23327 T74 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 23328 T60 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 23329 T47 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 23342 T18 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 23342 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 23343 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 23773 T18 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 23779 T18 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55750
[junit4:junit4] 2> 23781 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 23781 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 23782 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942
[junit4:junit4] 2> 23782 T18 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\solr.xml
[junit4:junit4] 2> 23782 T18 oasc.CoreContainer.<init> New CoreContainer 1426480
[junit4:junit4] 2> 23783 T18 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\'
[junit4:junit4] 2> 23783 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\'
[junit4:junit4] 2> 23890 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942
[junit4:junit4] 2> 23891 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\collection1
[junit4:junit4] 2> 23894 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\collection1\conf
[junit4:junit4] 2> 24096 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\collection1\conf\xslt
[junit4:junit4] 2> 24103 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\collection1\lib
[junit4:junit4] 2> 24105 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\collection1\lib\classes
[junit4:junit4] 2> 24112 T18 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\conf\core.properties, adding to cores
[junit4:junit4] 2> 24128 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 24128 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 24129 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 24129 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 24129 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 24130 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 24130 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 24131 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 24132 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 24132 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 24142 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 24143 T18 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55713/solr
[junit4:junit4] 2> 24143 T18 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 24145 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 24168 T86 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4020c7 name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 24169 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 24174 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 24184 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 24188 T88 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@242376 name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 24190 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 24205 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 25214 T18 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55750_
[junit4:junit4] 2> 25218 T18 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55750_
[junit4:junit4] 2> 25227 T42 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 25228 T74 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 25228 T60 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 25230 T88 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 25231 T47 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 25244 T18 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 25245 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 25245 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 25672 T18 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 25679 T18 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55759
[junit4:junit4] 2> 25680 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 25680 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 25681 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845
[junit4:junit4] 2> 25681 T18 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\solr.xml
[junit4:junit4] 2> 25681 T18 oasc.CoreContainer.<init> New CoreContainer 11248837
[junit4:junit4] 2> 25682 T18 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\'
[junit4:junit4] 2> 25682 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\'
[junit4:junit4] 2> 25815 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845
[junit4:junit4] 2> 25817 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\collection1
[junit4:junit4] 2> 25819 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\collection1\conf
[junit4:junit4] 2> 26018 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\collection1\conf\xslt
[junit4:junit4] 2> 26025 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\collection1\lib
[junit4:junit4] 2> 26027 T18 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\collection1\lib\classes
[junit4:junit4] 2> 26034 T18 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\conf\core.properties, adding to cores
[junit4:junit4] 2> 26055 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 26055 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 26055 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 26056 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 26056 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 26056 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 26057 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 26057 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 26057 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 26058 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 26070 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 26071 T18 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55713/solr
[junit4:junit4] 2> 26071 T18 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 26072 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 26097 T100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b93f90 name:ZooKeeperConnection Watcher:127.0.0.1:55713 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 26098 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 26103 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 26116 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 26120 T102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6be45d name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 26121 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 26133 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 27139 T18 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55759_
[junit4:junit4] 2> 27152 T18 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55759_
[junit4:junit4] 2> 27164 T74 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27165 T88 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27165 T60 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27166 T42 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27166 T47 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27167 T102 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 27179 T18 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 27180 T18 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 27180 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 27193 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 28098 T50 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 28120 T42 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 28128 T44 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> 28132 T44 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:55741_
[junit4:junit4] 2> 28148 T44 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:55759_
[junit4:junit4] 2> 28148 T42 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 28149 T44 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:55720_
[junit4:junit4] 2> 28150 T44 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:55750_
[junit4:junit4] 2> 28197 T38 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 28198 T79 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 28200 T79 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 28198 T70 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 28202 T70 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 28198 T98 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 28205 T98 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 28203 T79 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 28207 T79 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 28199 T38 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 28213 T70 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 28213 T70 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 28215 T98 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 28215 T98 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 28219 T79 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 28239 T79 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 28241 T38 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 28241 T38 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 28270 T70 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 28283 T70 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 28285 T98 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 28285 T98 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 28291 T38 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 28291 T38 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 28299 T79 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 28301 T70 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 28302 T98 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 28303 T38 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 28308 T70 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\'
[junit4:junit4] 2> 28309 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\'
[junit4:junit4] 2> 28309 T79 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\'
[junit4:junit4] 2> 28309 T98 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\'
[junit4:junit4] 2> 28619 T79 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 28725 T79 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 28739 T70 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 28757 T38 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 28776 T79 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 28835 T79 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 28907 T98 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 28984 T38 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 29045 T98 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 29063 T70 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 29067 T38 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 29202 T38 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 29243 T98 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 29271 T70 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 29301 T98 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 29388 T70 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 30712 T70 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 30776 T70 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 30782 T70 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 31088 T79 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 31139 T79 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 31143 T79 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 31537 T38 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 31549 T38 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 31553 T38 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 31572 T98 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 31610 T98 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 31615 T98 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 31656 T70 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31679 T70 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31683 T79 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31692 T70 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31697 T79 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31698 T70 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31699 T70 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31700 T70 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31710 T79 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31710 T70 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31711 T70 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31712 T70 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31713 T70 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 2> 31717 T70 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 31717 T79 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31721 T79 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31721 T79 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31722 T70 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31722 T70 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 2> 31722 T70 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\index/
[junit4:junit4] 2> 31722 T70 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 31724 T70 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\index
[junit4:junit4] 2> 31730 T70 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf3952 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca516e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 31731 T70 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 31735 T79 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31735 T79 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31735 T79 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31736 T79 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 2> 31736 T79 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 31741 T79 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31742 T79 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 2> 31743 T79 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\index/
[junit4:junit4] 2> 31743 T79 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 31745 T79 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\index
[junit4:junit4] 2> 31758 T38 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31767 T98 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31785 T38 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31790 T98 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31793 T79 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2dbac8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@29be28),segFN=segments_1,generation=1}
[junit4:junit4] 2> 31794 T79 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 31806 T70 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 31807 T70 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 31809 T70 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 31810 T70 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 31812 T70 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 31812 T70 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 31812 T70 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 31817 T70 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 31818 T98 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31818 T70 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 31822 T98 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31823 T98 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31824 T98 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31825 T38 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31830 T79 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 31831 T79 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 31833 T79 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 31834 T79 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 31835 T79 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 31836 T79 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 31836 T79 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 31837 T79 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 31839 T79 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 31839 T98 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31840 T98 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31840 T98 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31841 T98 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 2> 31841 T98 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 31842 T98 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31842 T79 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 31841 T38 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31843 T38 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31843 T38 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 31843 T98 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 2> 31845 T98 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\index/
[junit4:junit4] 2> 31845 T98 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 31838 T70 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 31848 T79 oass.SolrIndexSearcher.<init> Opening Searcher@777ecf main
[junit4:junit4] 2> 31849 T98 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\index
[junit4:junit4] 2> 31848 T79 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\nodes_used_collection_shard2_replica2\data\tlog
[junit4:junit4] 2> 31855 T70 oass.SolrIndexSearcher.<init> Opening Searcher@12d54c5 main
[junit4:junit4] 2> 31855 T70 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\nodes_used_collection_shard1_replica1\data\tlog
[junit4:junit4] 2> 31857 T98 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@128b37b lockFactory=org.apache.lucene.store.NativeFSLockFactory@10e9b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 31858 T98 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 31860 T38 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 31860 T38 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 31861 T38 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31861 T38 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 2> 31861 T38 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 31862 T38 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31863 T38 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 2> 31864 T38 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\index/
[junit4:junit4] 2> 31864 T38 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 31866 T70 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 31866 T70 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 31866 T79 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 31867 T79 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 31870 T98 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 31870 T98 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 31872 T38 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\index
[junit4:junit4] 2> 31873 T98 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 31875 T98 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 31877 T98 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 31877 T98 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 31878 T38 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15cb448 lockFactory=org.apache.lucene.store.NativeFSLockFactory@81b008),segFN=segments_1,generation=1}
[junit4:junit4] 2> 31878 T38 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 31883 T38 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 31884 T38 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 31884 T38 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 31885 T38 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 31886 T38 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 31887 T38 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 31887 T38 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 31888 T38 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 31889 T38 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 31878 T98 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 31898 T98 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 31921 T38 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 31923 T98 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 31933 T98 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 31939 T98 oass.SolrIndexSearcher.<init> Opening Searcher@5b27dc main
[junit4:junit4] 2> 31939 T98 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\tlog
[junit4:junit4] 2> 31940 T98 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 31941 T98 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 31931 T38 oass.SolrIndexSearcher.<init> Opening Searcher@1366441 main
[junit4:junit4] 2> 31949 T38 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\tlog
[junit4:junit4] 2> 31951 T38 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 31951 T38 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 31965 T109 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@12d54c5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 31967 T108 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@777ecf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 31967 T110 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1366441 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 31970 T70 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 31971 T79 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 31969 T111 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@5b27dc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 31975 T38 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 31977 T98 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 32431 T43 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 32432 T43 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:55741_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55741"}
[junit4:junit4] 2> 32432 T43 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 32461 T43 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:55750_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55750"}
[junit4:junit4] 2> 32471 T43 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:55720_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55720"}
[junit4:junit4] 2> 32480 T43 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:55759_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55759"}
[junit4:junit4] 2> 32502 T74 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> 32503 T42 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> 32503 T102 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> 32504 T60 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> 32504 T88 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> 32505 T47 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> 32993 T79 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 32994 T79 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:55750 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 32993 T70 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 33017 T70 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:55741 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 32995 T98 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 33018 T98 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:55759 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 32995 T38 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 33021 T38 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:55720 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 33014 T79 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 33069 T98 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 33070 T38 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 33070 T70 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 33072 T79 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 33112 T70 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 33113 T79 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 33123 T79 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 33123 T79 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 33123 T70 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 33124 T70 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 33128 T79 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 33128 T70 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 33137 T79 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 33150 T79 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:55750 START replicas=[http://127.0.0.1:55720/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 33150 T70 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:55741 START replicas=[http://127.0.0.1:55759/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 33152 T70 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:55741 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 33153 T70 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 33154 T70 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> 33154 T70 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 33154 T70 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> 33152 T79 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:55750 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 33156 T79 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 33156 T79 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> 33157 T79 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 33157 T79 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C0 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@12ef3bb url=http://127.0.0.1:55759/nodes_used_collection_shard1_replica2 node=127.0.0.1:55759_ C0_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:55759_, base_url=http://127.0.0.1:55759}
[junit4:junit4] 2> 33204 T97 C0 P55759 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=32
[junit4:junit4] 2> ASYNC NEW_CORE C1 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@11cc0ef url=http://127.0.0.1:55720/nodes_used_collection_shard2_replica1 node=127.0.0.1:55720_ C1_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:55720_, base_url=http://127.0.0.1:55720}
[junit4:junit4] 2> 33204 T37 C1 P55720 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=29
[junit4:junit4] 2> 34036 T43 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34078 T42 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> 34079 T74 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> 34079 T102 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> 34079 T60 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> 34080 T88 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> 34081 T47 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> 34118 T38 oasc.ZkController.register We are http://127.0.0.1:55720/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 34119 T98 oasc.ZkController.register We are http://127.0.0.1:55759/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 34123 T98 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:55759
[junit4:junit4] 2> 34123 T98 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 34123 T98 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 34123 T38 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:55720
[junit4:junit4] 2> 34124 T38 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 34125 T38 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 34129 T79 oasc.ZkController.register We are http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 34129 T79 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:55750
[junit4:junit4] 2> 34130 T79 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 34130 T79 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> ASYNC NEW_CORE C2 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@12ef3bb url=http://127.0.0.1:55759/nodes_used_collection_shard1_replica2 node=127.0.0.1:55759_ C2_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:55759_, base_url=http://127.0.0.1:55759}
[junit4:junit4] 2> 34130 T114 C2 P55759 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 34132 T114 C2 P55759 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 34133 T114 C2 P55759 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4] 2> ASYNC NEW_CORE C3 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@11cc0ef url=http://127.0.0.1:55720/nodes_used_collection_shard2_replica1 node=127.0.0.1:55720_ C3_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:55720_, base_url=http://127.0.0.1:55720}
[junit4:junit4] 2> 34133 T115 C3 P55720 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 34135 T98 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34135 T38 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34135 T115 C3 P55720 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 34136 T115 C3 P55720 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4] 2> 34138 T70 oasc.ZkController.register We are http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 34138 T70 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:55741
[junit4:junit4] 2> 34139 T70 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 34139 T114 C2 P55759 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 34140 T79 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34141 T98 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=5948
[junit4:junit4] 2> 34146 T38 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=5954
[junit4:junit4] 2> 34149 T115 C3 P55720 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 34147 T70 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 34157 T79 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=5965
[junit4:junit4] 2> 34160 T67 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:55759__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 34164 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34163 T82 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:55720__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 34166 T70 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=5973
[junit4:junit4] 2> 34167 T44 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 34186 T60 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 34190 T44 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=5948},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=5954},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=5965},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=5973},core=nodes_used_collection_shard1_replica1}}}
[junit4:junit4] 2> 34199 T50 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=6108
[junit4:junit4] 2> 34200 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 34203 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 34207 T117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29e2c6 name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 34207 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 34211 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 34252 T18 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 34255 T18 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 34260 T119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e05be2 name:ZooKeeperConnection Watcher:127.0.0.1:55713/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 34260 T18 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 34263 T18 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 34284 T96 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=3&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 34287 T42 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 34291 T42 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 34292 T44 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":"2",
[junit4:junit4] 2> "maxShardsPerNode":"3",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 34292 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55741_
[junit4:junit4] 2> 34293 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55759_
[junit4:junit4] 2> 34293 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55732_
[junit4:junit4] 2> 34293 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55750_
[junit4:junit4] 2> 34293 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55720_
[junit4:junit4] 2> 34296 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:55741_
[junit4:junit4] 2> 34298 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:55759_
[junit4:junit4] 2> 34298 T93 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 34299 T93 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34299 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:55732_
[junit4:junit4] 2> 34300 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:55750_
[junit4:junit4] 2> 34300 T66 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 34301 T66 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34301 T84 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 34302 T84 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34303 T93 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34303 T93 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34305 T44 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:55720_
[junit4:junit4] 2> 34304 T66 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34306 T66 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34307 T54 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 34307 T54 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34307 T68 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 34316 T68 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34316 T36 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5
[junit4:junit4] 2> 34318 T36 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34315 T56 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 34319 T56 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34314 T54 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34320 T54 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34320 T95 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 34321 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34321 T68 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34322 T68 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34311 T84 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34323 T84 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34323 T36 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34324 T36 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34313 T35 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5
[junit4:junit4] 2> 34325 T35 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34326 T56 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34326 T56 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34318 T83 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 34329 T83 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 34317 T66 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34329 T66 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34330 T54 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34330 T54 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34331 T68 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34331 T68 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34333 T84 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34333 T84 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34334 T36 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34334 T36 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34335 T35 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34337 T35 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34328 T95 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34338 T95 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34339 T83 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 34339 T83 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 34326 T93 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34353 T93 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34336 T56 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34354 T56 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34358 T68 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34358 T54 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34359 T83 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34360 T83 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34363 T36 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34363 T84 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34364 T66 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34365 T35 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34366 T35 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34369 T54 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard1_replica3\'
[junit4:junit4] 2> 34370 T95 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 34371 T95 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 34368 T68 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\'
[junit4:junit4] 2> 34378 T56 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34386 T84 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard1_replica4\'
[junit4:junit4] 2> 34387 T93 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34388 T66 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard1_replica1\'
[junit4:junit4] 2> 34397 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\'
[junit4:junit4] 2> 34399 T83 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34438 T95 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34441 T93 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\'
[junit4:junit4] 2> 34443 T56 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\'
[junit4:junit4] 2> 34443 T83 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\'
[junit4:junit4] 2> 34443 T35 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 34493 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 34567 T54 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 34633 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\'
[junit4:junit4] 2> 34643 T35 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\'
[junit4:junit4] 2> 34865 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 34873 T36 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 34900 T36 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica5] Schema name=test
[junit4:junit4] 2> 34924 T54 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 34929 T84 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 34929 T66 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 34939 T83 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35008 T66 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35011 T83 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35011 T54 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35036 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35075 T93 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35148 T84 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35156 T56 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35162 T93 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35207 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35218 T35 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35253 T54 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 35322 T56 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35348 T66 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35351 T83 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35363 T83 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 35371 T93 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35373 T84 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35374 T95 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35376 T56 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35500 T93 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 35593 T84 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 35632 T68 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 35681 T56 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 35682 T66 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 35683 T95 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 35752 T68 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35828 T43 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 35840 T68 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35841 T43 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55750__nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55750_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55750"}
[junit4:junit4] 2> 35863 T68 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 37102 T43 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55759__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:55759_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55759"}
[junit4:junit4] 2> 37320 T35 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 37392 T43 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55720__nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55720_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55720"}
[junit4:junit4] 2> 37436 T35 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 37444 T35 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica5] Schema name=test
[junit4:junit4] 2> 37811 T43 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:55741__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:55741_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55741"}
[junit4:junit4] 2> 37947 T42 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> 37948 T60 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> 37950 T102 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> 37951 T74 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> 37951 T88 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> 37952 T117 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> 37953 T47 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> 37953 T119 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> 38372 T68 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 38388 T68 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 38391 T68 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 38406 T83 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 38416 T83 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 38436 T67 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:55759__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 4 seconds.
[junit4:junit4] 2> 38440 T67 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:55759__nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:55759_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=4280
[junit4:junit4] 2> 38442 T83 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 38558 T82 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:55720__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 4 seconds.
[junit4:junit4] 2> 38559 T82 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:55720__nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:55720_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=4396
[junit4:junit4] 2> 38568 T93 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 38578 T93 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 38584 T93 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 39697 T36 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 39707 T36 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 39712 T36 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 39716 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 39731 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 39735 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 39842 T56 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 39850 T56 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 39870 T56 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 39921 T35 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 39929 T35 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 39933 T35 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 40052 T83 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40084 T93 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40162 T93 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40171 T83 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40290 T93 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 40297 T83 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 40362 T66 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 40372 T66 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 40376 T66 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 40443 T54 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 40458 T54 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 40463 T54 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 40639 T84 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 40649 T84 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 40654 T84 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> ASYNC NEW_CORE C4 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@11cc0ef url=http://127.0.0.1:55720/nodes_used_collection_shard2_replica1 node=127.0.0.1:55720_ C4_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:55720_, base_url=http://127.0.0.1:55720}
[junit4:junit4] 2> 40656 T115 C4 P55720 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 40657 T115 C4 P55720 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:55720 START replicas=[http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 40658 T115 C4 P55720 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 40658 T115 C4 P55720 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 40659 T115 C4 P55720 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 40659 T115 C4 P55720 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 40659 T115 C4 P55720 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 40660 T115 C4 P55720 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:55750/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 40660 T115 C4 P55720 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C5 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@12ef3bb url=http://127.0.0.1:55759/nodes_used_collection_shard1_replica2 node=127.0.0.1:55759_ C5_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:55759_, base_url=http://127.0.0.1:55759}
[junit4:junit4] 2> 40665 T114 C5 P55759 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/ core=nodes_used_collection_shard1_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 40665 T114 C5 P55759 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:55759 START replicas=[http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 40666 T114 C5 P55759 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 40666 T114 C5 P55759 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 40667 T114 C5 P55759 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 40667 T114 C5 P55759 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 40667 T114 C5 P55759 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 40674 T114 C5 P55759 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:55741/nodes_used_collection_shard1_replica1/. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 40674 T114 C5 P55759 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 40681 T93 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40681 T93 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40681 T93 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 40699 T68 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> ASYNC NEW_CORE C6 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@cf182 url=http://127.0.0.1:55750/nodes_used_collection_shard2_replica2 node=127.0.0.1:55750_ C6_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:55750_, base_url=http://127.0.0.1:55750, leader=true}
[junit4:junit4] 2> 40720 T79 C6 P55750 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> 40726 T83 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40726 T83 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40726 T83 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 40731 T93 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40732 T93 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40732 T93 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40733 T93 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 2> 40733 T93 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 40733 T93 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40735 T93 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 2> 40735 T93 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\index/
[junit4:junit4] 2> 40736 T93 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 40735 T68 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40739 T93 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\index
[junit4:junit4] 2> 40745 T83 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40746 T83 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40746 T83 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40747 T83 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica4] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\
[junit4:junit4] 2> 40747 T83 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 40748 T83 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40749 T83 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\
[junit4:junit4] 2> 40749 T83 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\index/
[junit4:junit4] 2> 40752 T83 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica4] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 40749 T93 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1cb9267 lockFactory=org.apache.lucene.store.NativeFSLockFactory@b0e6f7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40757 T93 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40761 T83 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\index
[junit4:junit4] 2> 40770 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 40770 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 40771 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 40772 T93 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 40773 T93 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 40773 T93 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 40773 T93 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 40775 T93 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 40776 T93 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 40794 T68 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> ASYNC NEW_CORE C7 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@aad9fc url=http://127.0.0.1:55741/nodes_used_collection_shard1_replica1 node=127.0.0.1:55741_ C7_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:55741_, base_url=http://127.0.0.1:55741, leader=true}
[junit4:junit4] 2> 40805 T69 C7 P55741 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=12
[junit4:junit4] 2> 40812 T93 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 40818 T68 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40818 T68 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40819 T68 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 40843 T81 C6 P55750 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 40844 T93 oass.SolrIndexSearcher.<init> Opening Searcher@15d41b5 main
[junit4:junit4] 2> 40846 T93 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard1_replica2\data\tlog
[junit4:junit4] 2> 40847 T65 C7 P55741 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 40847 T93 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 40848 T93 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 40849 T83 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d45706 lockFactory=org.apache.lucene.store.NativeFSLockFactory@b2f206),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40859 T83 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40871 T93 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> 40876 T65 C7 P55741 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf3952 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca516e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40878 T65 C7 P55741 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40880 T81 C6 P55750 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2dbac8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@29be28),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40881 T81 C6 P55750 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40882 T65 C7 P55741 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf3952 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca516e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf3952 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca516e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 40883 T65 C7 P55741 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 40884 T81 C6 P55750 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2dbac8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@29be28),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2dbac8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@29be28),segFN=segments_2,generation=2}
[junit4:junit4] 2> 40884 T81 C6 P55750 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 40885 T65 C7 P55741 oass.SolrIndexSearcher.<init> Opening Searcher@b4d5fc realtime
[junit4:junit4] 2> 40886 T65 C7 P55741 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 40886 T65 C7 P55741 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 83
[junit4:junit4] 2> 40887 T81 C6 P55750 oass.SolrIndexSearcher.<init> Opening Searcher@1ade260 realtime
[junit4:junit4] 2> 40888 T81 C6 P55750 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 40889 T81 C6 P55750 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 136
[junit4:junit4] 2> 40889 T68 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 40889 T68 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 40889 T68 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40890 T68 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\
[junit4:junit4] 2> 40890 T68 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 40891 T68 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40892 T68 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\
[junit4:junit4] 2> 40892 T68 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\index/
[junit4:junit4] 2> 40898 T68 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 40900 T128 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@15d41b5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 40904 T83 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 40904 T83 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 40905 T68 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\index
[junit4:junit4] 2> 40917 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40918 T83 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 40921 T83 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 40923 T83 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 40923 T83 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 40924 T83 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 40925 T83 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 40926 T83 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 40920 T68 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@9ef54 lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e1be6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40929 T68 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40937 T68 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 40937 T68 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 40938 T68 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 40940 T68 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 40941 T68 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 40941 T68 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 40941 T68 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 40942 T68 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 40943 T68 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 40953 T56 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40961 T35 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41026 T56 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41031 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41033 T68 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 41034 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41026 T35 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41041 T68 oass.SolrIndexSearcher.<init> Opening Searcher@17e916c main
[junit4:junit4] 2> 41041 T68 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369362087000\awholynewcollection_0_shard2_replica1\data\tlog
[junit4:junit4] 2> 41047 T56 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41038 T83 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 41051 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> ASYNC NEW_CORE C8 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@12ef3bb url=http://127.0.0.1:55759/nodes_used_collection_shard1_replica2 node=127.0.0.1:55759_ C8_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:55759_, base_url=http://127.0.0.1:55759}
[junit4:junit4] 2> 41037 T114 C8 P55759 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> ASYNC NEW_CORE C9 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@11cc0ef url=http://127.0.0.1:55720/nodes_used_collection_shard2_replica1 node=127.0.0.1:55720_ C9_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:55720_, base_url=http://127.0.0.1:55720}
[junit4:junit4] 2> 41033 T115 C9 P55720 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 41052 T114 C8 P55759 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 41054 T43 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 41061 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41066 T83 oass.SolrIndexSearcher.<init> Opening Searcher@17a401 main
[junit4:junit4] 2> 41067 T83 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369362088942\awholynewcollection_0_shard2_replica4\data\tlog
[junit4:junit4] 2> 41067 T68 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 41068 T68 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 41069 T83 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 41075 T83 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 41078 T43 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":"awholynewcollection_0_shard1_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55759_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55759"}
[junit4:junit4] 2> 41096 T43 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 2
[junit4:junit4] 2> 41094 T68 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 41101 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41102 T114 C8 P55759 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 41092 T95 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41113 T95 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41113 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41090 T56 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41114 T56 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41115 T56 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41119 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41119 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41120 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41090 T129 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@17e916c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 41126 T66 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41128 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41130 T54 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41131 T56 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41131 T56 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41131 T56 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41133 T56 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica3] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\
[junit4:junit4] 2> 41133 T56 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 41133 T56 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41135 T56 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\
[junit4:junit4] 2> 41135 T56 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\index/
[junit4:junit4] 2> 41135 T56 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica3] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 41136 T56 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\index
[junit4:junit4] 2> 41089 T83 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica4 state=down
[junit4:junit4] 2> 41089 T35 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41086 T130 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica4] Registered new searcher Searcher@17a401 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 41141 T56 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1e611b1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@bce6eb),segFN=segments_1,generation=1}
[junit4:junit4] 2> 41102 T115 C9 P55720 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 41142 T56 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 41146 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41147 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41147 T36 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41149 T36 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica5] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\
[junit4:junit4] 2> 41149 T36 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 41149 T95 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41151 T95 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41151 T95 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41152 T95 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\data\
[junit4:junit4] 2> 41152 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 41153 T95 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41154 T95 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\data\
[junit4:junit4] 2> 41155 T95 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\data\index/
[junit4:junit4] 2> 41155 T95 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 41151 T36 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41158 T36 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\
[junit4:junit4] 2> 41158 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\index/
[junit4:junit4] 2> 41159 T36 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica5] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 41160 T36 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\index
[junit4:junit4] 2> 41161 T56 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 41162 T56 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 41163 T56 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 41164 T56 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 41164 T56 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 41165 T36 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e83e lockFactory=org.apache.lucene.store.NativeFSLockFactory@c274e3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 41166 T36 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 41165 T56 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 41167 T56 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 41168 T56 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 41169 T56 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 41165 T95 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\awholynewcollection_0_shard2_replica2\data\index
[junit4:junit4] 2> 41179 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41179 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41179 T35 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> ASYNC NEW_CORE C10 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@aad9fc url=http://127.0.0.1:55741/nodes_used_collection_shard1_replica1 node=127.0.0.1:55741_ C10_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:55741_, base_url=http://127.0.0.1:55741, leader=true}
[junit4:junit4] 2> 41183 T69 C10 P55741 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 41184 T69 C10 P55741 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=75
[junit4:junit4] 2> ASYNC NEW_CORE C11 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@cf182 url=http://127.0.0.1:55750/nodes_used_collection_shard2_replica2 node=127.0.0.1:55750_ C11_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:55750_, base_url=http://127.0.0.1:55750, leader=true}
[junit4:junit4] 2> 41185 T82 C11 P55750 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 41186 T82 C11 P55750 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 41187 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 41187 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 41188 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 41191 T56 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 41192 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 41192 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 41193 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 41194 T36 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 41195 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 41195 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 41195 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 41197 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 41198 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 41198 T56 oass.SolrIndexSearcher.<init> Opening Searcher@1fde9a main
[junit4:junit4] 2> 41199 T56 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369362084966\awholynewcollection_0_shard2_replica3\data\tlog
[junit4:junit4] 2> 41202 T79 C11 P55750 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=12
[junit4:junit4] 2> 41203 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 41203 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 41203 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 41203 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 41205 T56 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 41207 T56 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 41207 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 41206 T115 C9 P55720 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\nodes_used_collection_shard2_replica1\data\index.20130523222146797
[junit4:junit4] 2> 41224 T43 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":"awholynewcollection_0_shard2_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55741_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55741"}
[junit4:junit4] 2> 41227 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@edb54d lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b214) fullCopy=false
[junit4:junit4] 2> 41228 T131 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica3] Registered new searcher Searcher@1fde9a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 41221 T66 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41220 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41217 T54 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 41233 T36 oass.SolrIndexSearcher.<init> Opening Searcher@129bd25 main
[junit4:junit4] 2> 41214 T65 C10 P55741 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 41234 T36 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard2_replica5\data\tlog
[junit4:junit4] 2> 41231 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41235 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 41236 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41243 T35 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41244 T35 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica5] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\data\
[junit4:junit4] 2> 41244 T35 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@29db51
[junit4:junit4] 2> 41244 T35 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41245 T35 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\data\
[junit4:junit4] 2> 41245 T35 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\data\index/
[junit4:junit4] 2> 41245 T35 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica5] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 41248 T36 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 41248 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 41241 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19dc879 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f65769),segFN=segments_1,generation=1}
[junit4:junit4] 2> 41262 T95 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 41241 T56 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica3 state=down
[junit4:junit4] 2> 41237 T114 C8 P55759 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369362090845\nodes_used_collection_shard1_replica2\data\index.20130523222146829
[junit4:junit4] 2> 41264 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1873a1f lockFactory=org.apache.lucene.store.NativeFSLockFactory@1763eb2) fullCopy=false
[junit4:junit4] 2> 41264 T36 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica5 state=down
[junit4:junit4] 2> 41262 T81 C11 P55750 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=4
[junit4:junit4] 2> 41260 T132 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica5] Registered new searcher Searcher@129bd25 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 41297 T67 C10 P55741 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 41250 T35 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369362082247\awholynewcollection_0_shard1_replica5\data\index
[junit4:junit4] 2> 41294 T66 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41289 T84 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41287 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 41281 T54 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41310 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 41311 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 41312 T114 C8 P55759 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 41312 T115 C9 P55720 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 41313 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 41314 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 41314 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 41315 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 41316 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 41316 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 41317 T35 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f23bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@302871),segFN=segments_1,generation=1}
[junit4:junit4] 2> 41317 T35 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 41319 T66 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41319 T66 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41320 T66 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41321 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41321 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41321 T84 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41325 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41326 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41326 T54 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 41327 T66 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 41327 T66 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 41327 T66 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 41328 T66 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windo
[...truncated too long message...]
[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> 315851 T102 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_1/leader_elect/shard3/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> 315856 T102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 315856 T102 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 315857 T102 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669772-127.0.0.1:55759__awholynewcollection_1_shard3_replica1-n_0000000007 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669766-127.0.0.1:55732__awholynewcollection_1_shard3_replica4-n_0000000006 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669763-127.0.0.1:55720__awholynewcollection_1_shard3_replica3-n_0000000005 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669763-127.0.0.1:55720__awholynewcollection_1_shard3_replica3-n_0000000002 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669766-127.0.0.1:55732__awholynewcollection_1_shard3_replica4-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard3/election/89742513383669772-127.0.0.1:55759__awholynewcollection_1_shard3_replica1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders (4)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard1_replica1",
[junit4:junit4] 1> "node_name":"127.0.0.1:55720_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55720"}
[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:55759_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55759"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard2_replica3",
[junit4:junit4] 1> "node_name":"127.0.0.1:55732_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55732"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard3 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard3_replica4",
[junit4:junit4] 1> "node_name":"127.0.0.1:55732_",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55732"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89742513383669768-127.0.0.1:55741_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89742513383669772-127.0.0.1:55759_-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89742513383669763-127.0.0.1:55720_-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89742513383669770-127.0.0.1:55750_-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89742513383669766-127.0.0.1:55732_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89742513383669763-127.0.0.1:55720_-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=9A5BBC4B47E4FC53 -Dtests.slow=true -Dtests.locale=ar_SD -Dtests.timezone=America/Guadeloupe -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 300s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([9A5BBC4B47E4FC53:1BBD325330BB9C6F]: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> 315947 T18 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 300149 T17 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=ar_SD, timezone=America/Guadeloupe
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (32-bit)/cpus=2,threads=1,free=94944776,total=279969792
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestBadConfig, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 301.64s, 1 test, 1 failure <<< FAILURES!
[...truncated 925 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:386: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:366: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1243: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:887: There were test failures: 296 suites, 1234 tests, 1 failure, 19 ignored (13 assumptions)
Total time: 68 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_21 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure