lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.6.0_35) - Build # 1304 - Still Failing!
Date Thu, 25 Oct 2012 21:53:16 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Windows/1304/
Java: 32bit/jdk1.6.0_35 -server -XX:+UseParallelGC

4 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch

Error Message:
There are still nodes recoverying

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying
	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3:93EA09420DB7329F]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:154)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:115)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:110)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:558)
	at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:163)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:695)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	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:45)
	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:662)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest

Error Message:
ERROR: SolrIndexSearcher opens=7 closes=6

Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=7 closes=6
	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:242)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
	at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
	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:45)
	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:662)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:     1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)         at java.lang.Thread.run(Thread.java:662)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:662)
	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)         at java.lang.Thread.run(Thread.java:662)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:662)
	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)




Build Log:
[...truncated 7824 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4:junit4]   2> 4 T927 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZkTest-1351200942456
[junit4:junit4]   2> 6 T927 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 10 T928 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 11 T928 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 12 T928 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 96 T927 oasc.ZkTestServer.run start zk server on port:63840
[junit4:junit4]   2> 96 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@11fc97a
[junit4:junit4]   2> 98 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 99 T933 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 100 T933 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 100 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63843
[junit4:junit4]   2> 100 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63843
[junit4:junit4]   2> 101 T931 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 110 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800000 with negotiated timeout 10000 for client /127.0.0.1:63843
[junit4:junit4]   2> 110 T933 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800000, negotiated timeout = 10000
[junit4:junit4]   2> 110 T934 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11fc97a name:ZooKeeperConnection Watcher:127.0.0.1:63840 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 110 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 111 T927 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 115 T932 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13a99da29800000
[junit4:junit4]   2> 117 T934 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 117 T927 oaz.ZooKeeper.close Session: 0x13a99da29800000 closed
[junit4:junit4]   2> 118 T929 oazs.NIOServerCnxn.doIO WARNING EndOfStreamException: Unable to read additional data from client sessionid 0x13a99da29800000, likely client has closed socket
[junit4:junit4]   2> 118 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3fdbd6
[junit4:junit4]   2> 120 T929 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:63843 which had sessionid 0x13a99da29800000
[junit4:junit4]   2> 120 T935 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 120 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 122 T935 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 122 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63846
[junit4:junit4]   2> 123 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63846
[junit4:junit4]   2> 125 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800001 with negotiated timeout 10000 for client /127.0.0.1:63846
[junit4:junit4]   2> 126 T935 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800001, negotiated timeout = 10000
[junit4:junit4]   2> 126 T936 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fdbd6 name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 127 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 127 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 134 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 139 T927 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 142 T927 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 147 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 147 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 156 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 157 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 163 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 164 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 168 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 169 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 178 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 179 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 183 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 183 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 189 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 189 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 194 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 195 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 201 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 201 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 207 T927 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 207 T927 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 212 T932 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13a99da29800001
[junit4:junit4]   2> 214 T936 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 214 T927 oaz.ZooKeeper.close Session: 0x13a99da29800001 closed
[junit4:junit4]   2> 216 T929 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:63846 which had sessionid 0x13a99da29800001
[junit4:junit4]   2> 525 T927 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 529 T927 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:63847
[junit4:junit4]   2> 529 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 529 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665
[junit4:junit4]   2> 529 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\'
[junit4:junit4]   2> 564 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 565 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 566 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665
[junit4:junit4]   2> 566 T927 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\solr.xml
[junit4:junit4]   2> 567 T927 oasc.CoreContainer.<init> New CoreContainer 26463926
[junit4:junit4]   2> 567 T927 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\'
[junit4:junit4]   2> 567 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\'
[junit4:junit4]   2> 589 T927 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 607 T927 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:63840/solr
[junit4:junit4]   2> 607 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@12a9475
[junit4:junit4]   2> 608 T946 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 608 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 610 T946 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 611 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63852
[junit4:junit4]   2> 611 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63852
[junit4:junit4]   2> 623 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800002 with negotiated timeout 5000 for client /127.0.0.1:63852
[junit4:junit4]   2> 623 T946 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800002, negotiated timeout = 5000
[junit4:junit4]   2> 623 T947 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12a9475 name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 623 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 627 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 629 T927 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 634 T927 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63847_solr
[junit4:junit4]   2> 635 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:63847_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:63847_solr
[junit4:junit4]   2> 636 T927 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63847_solr
[junit4:junit4]   2> 643 T927 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 643 T927 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 643 T927 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 643 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 644 T927 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 644 T927 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 644 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 645 T927 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 645 T927 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 646 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 656 T927 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 663 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:delete cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 665 T927 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 676 T927 oasc.Overseer.start Overseer (id=88552304965320706-127.0.0.1:63847_solr-n_0000000000) starting
[junit4:junit4]   2> 676 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 678 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 680 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 682 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 684 T949 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 684 T927 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 690 T927 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 692 T948 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 697 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\collection1
[junit4:junit4]   2> 697 T927 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 699 T927 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 699 T927 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 703 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\collection1\'
[junit4:junit4]   2> 705 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 706 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665/collection1/lib/README' to classloader
[junit4:junit4]   2> 760 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 837 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 839 T927 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 846 T927 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1539 T927 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1551 T927 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1554 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1579 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1584 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1591 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1594 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1595 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1351200942665\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/control/data\
[junit4:junit4]   2> 1596 T927 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c943d1
[junit4:junit4]   2> 1598 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/control/data\index/
[junit4:junit4]   2> 1599 T927 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1600 T927 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\control\data\index forceNew:false
[junit4:junit4]   2> 1613 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@18bd36f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1614 T927 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1617 T927 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1619 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1619 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1619 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1620 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1620 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1620 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1620 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1621 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1621 T927 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1622 T927 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1622 T927 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1623 T927 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1623 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1624 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1624 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1624 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1624 T927 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1625 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1625 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1626 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1627 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1627 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1627 T927 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1627 T927 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1628 T927 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1636 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1641 T927 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1642 T927 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 1648 T927 oass.SolrIndexSearcher.<init> Opening Searcher@174be3f main
[junit4:junit4]   2> 1649 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1649 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1650 T927 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1663 T927 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1726 T950 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@174be3f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1728 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1730 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x56 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1736 T927 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1737 T927 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:63847/solr shardId:control_shard
[junit4:junit4]   2> 1738 T927 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1751 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1753 T927 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1754 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2038 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2039 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":null,
[junit4:junit4]   2> 	  "shard":"control_shard",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63847_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63847/solr"}
[junit4:junit4]   2> 2040 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2056 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 2202 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2203 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2203 T927 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63847/solr/collection1/
[junit4:junit4]   2> 2203 T927 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2203 T927 oasc.SyncStrategy.syncToMe http://127.0.0.1:63847/solr/collection1/ has no replicas
[junit4:junit4]   2> 2204 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63847/solr/collection1/
[junit4:junit4]   2> 2204 T927 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2212 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800002 type:create cxid:0x8b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2512 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2522 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 2534 T927 oasc.ZkController.register We are http://127.0.0.1:63847/solr/collection1/ and leader is http://127.0.0.1:63847/solr/collection1/
[junit4:junit4]   2> 2534 T927 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63847/solr
[junit4:junit4]   2> 2535 T927 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2535 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2541 T927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2543 T927 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 2543 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2543 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2880 T927 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2884 T927 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:63853
[junit4:junit4]   2> 2885 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2885 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005
[junit4:junit4]   2> 2885 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\'
[junit4:junit4]   2> 2921 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2922 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2923 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005
[junit4:junit4]   2> 2923 T927 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\solr.xml
[junit4:junit4]   2> 2924 T927 oasc.CoreContainer.<init> New CoreContainer 31297812
[junit4:junit4]   2> 2924 T927 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\'
[junit4:junit4]   2> 2924 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\'
[junit4:junit4]   2> 2956 T927 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2972 T927 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:63840/solr
[junit4:junit4]   2> 2973 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@f13898
[junit4:junit4]   2> 2975 T960 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 2975 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2979 T960 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 2979 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63858
[junit4:junit4]   2> 2979 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63858
[junit4:junit4]   2> 2990 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800003 with negotiated timeout 5000 for client /127.0.0.1:63858
[junit4:junit4]   2> 2990 T960 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800003, negotiated timeout = 5000
[junit4:junit4]   2> 2991 T961 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f13898 name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2991 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2991 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2996 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2998 T927 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63853_solr
[junit4:junit4]   2> 2999 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:63853_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:63853_solr
[junit4:junit4]   2> 3001 T927 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63853_solr
[junit4:junit4]   2> 3007 T947 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 3007 T927 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3007 T927 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3008 T927 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3008 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3008 T927 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3008 T927 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3008 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3009 T927 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3009 T927 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3010 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3018 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3019 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":null,
[junit4:junit4]   2> 	  "shard":"control_shard",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63847_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63847/solr"}
[junit4:junit4]   2> 3027 T927 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3030 T961 oaz.ClientCnxn$EventThread.processEvent SEVERE Error while calling watcher  java.lang.NullPointerException
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader$2.process(ZkStateReader.java:189)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 
[junit4:junit4]   2> 3030 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 3035 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\collection1
[junit4:junit4]   2> 3037 T927 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3038 T927 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3038 T927 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3042 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\collection1\'
[junit4:junit4]   2> 3044 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3045 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005/collection1/lib/README' to classloader
[junit4:junit4]   2> 3110 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 3199 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3201 T927 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3208 T927 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3960 T927 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3971 T927 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3976 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3996 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4003 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4011 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4013 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4015 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1351200945005\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty1\
[junit4:junit4]   2> 4015 T927 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c943d1
[junit4:junit4]   2> 4017 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty1\index/
[junit4:junit4]   2> 4019 T927 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4021 T927 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty1\index forceNew:false
[junit4:junit4]   2> 4034 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@23712f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4035 T927 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4038 T927 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4039 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4040 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4040 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4042 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4042 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4043 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4043 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4044 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4044 T927 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4045 T927 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4046 T927 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4046 T927 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4047 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4047 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4047 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4049 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4049 T927 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4050 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4050 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4050 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4050 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4051 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4051 T927 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4052 T927 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4053 T927 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4061 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4067 T927 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4068 T927 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 4074 T927 oass.SolrIndexSearcher.<init> Opening Searcher@aeb4f0 main
[junit4:junit4]   2> 4076 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4076 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4077 T927 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4089 T927 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4156 T962 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@aeb4f0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4160 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4509 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4510 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63853_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63853/solr"}
[junit4:junit4]   2> 4511 T948 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 4522 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 65762 T927 oasc.SolrException.log SEVERE null:org.apache.solr.common.SolrException: Could not get shard_id for core: collection1
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.doGetShardIdProcess(ZkController.java:996)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.preRegister(ZkController.java:1054)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.register(CoreContainer.java:657)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:530)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:351)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer$Initializer.initialize(CoreContainer.java:303)
[junit4:junit4]   2> 		at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:107)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.FilterHolder.doStart(FilterHolder.java:114)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:59)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:754)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.updateMappings(ServletHandler.java:1227)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.setFilterMappings(ServletHandler.java:1263)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:965)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:923)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletContextHandler.addFilter(ServletContextHandler.java:333)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner$1.lifeCycleStarted(JettySolrRunner.java:173)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.setStarted(AbstractLifeCycle.java:169)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:60)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:225)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:205)
[junit4:junit4]   2> 		at org.apache.solr.BaseDistributedSearchTestCase.createJetty(BaseDistributedSearchTestCase.java:262)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createJettys(AbstractFullDistribZkTestBase.java:299)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:273)
[junit4:junit4]   2> 		at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:693)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4:junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4:junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:597)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   2> 		at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2> 	
[junit4:junit4]   2> 65763 T927 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 65763 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 65764 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 66105 T927 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 66107 T927 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:63859
[junit4:junit4]   2> 66109 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 66109 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226
[junit4:junit4]   2> 66109 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\'
[junit4:junit4]   2> 66148 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 66148 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 66148 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226
[junit4:junit4]   2> 66148 T927 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\solr.xml
[junit4:junit4]   2> 66149 T927 oasc.CoreContainer.<init> New CoreContainer 24098287
[junit4:junit4]   2> 66149 T927 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\'
[junit4:junit4]   2> 66149 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\'
[junit4:junit4]   2> 66179 T927 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 66199 T927 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:63840/solr
[junit4:junit4]   2> 66200 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@14135cb
[junit4:junit4]   2> 66201 T972 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 66201 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 66202 T972 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 66202 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63864
[junit4:junit4]   2> 66202 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63864
[junit4:junit4]   2> 66223 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800004 with negotiated timeout 5000 for client /127.0.0.1:63864
[junit4:junit4]   2> 66223 T972 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800004, negotiated timeout = 5000
[junit4:junit4]   2> 66223 T973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14135cb name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 66223 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 66225 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 66227 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 66230 T927 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63859_solr
[junit4:junit4]   2> 66230 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:63859_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:63859_solr
[junit4:junit4]   2> 66231 T927 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63859_solr
[junit4:junit4]   2> 66247 T947 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 66247 T961 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 66248 T927 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 66248 T927 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 66248 T927 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 66248 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 66249 T927 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 66249 T927 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 66250 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 66251 T927 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 66251 T927 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 66252 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 66270 T927 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 66278 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\collection1
[junit4:junit4]   2> 66278 T927 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 66280 T927 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 66280 T927 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 66282 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\collection1\'
[junit4:junit4]   2> 66284 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 66285 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226/collection1/lib/README' to classloader
[junit4:junit4]   2> 66342 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 66421 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 66425 T927 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 66431 T927 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 67162 T927 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 67174 T927 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 67178 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 67199 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 67206 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 67211 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 67213 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 67215 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1351201008226\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty2\
[junit4:junit4]   2> 67216 T927 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c943d1
[junit4:junit4]   2> 67218 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty2\index/
[junit4:junit4]   2> 67220 T927 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 67220 T927 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty2\index forceNew:false
[junit4:junit4]   2> 67232 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f66fa5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 67233 T927 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 67236 T927 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 67239 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 67239 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 67240 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 67240 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 67241 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 67241 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 67241 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 67243 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 67243 T927 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 67244 T927 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 67244 T927 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 67245 T927 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 67245 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 67246 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 67247 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 67248 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 67249 T927 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67249 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67249 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67250 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67250 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67250 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67252 T927 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 67253 T927 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 67254 T927 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 67267 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 67274 T927 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 67277 T927 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 67281 T927 oass.SolrIndexSearcher.<init> Opening Searcher@cc1d2c main
[junit4:junit4]   2> 67284 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 67284 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 67285 T927 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 67300 T927 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 67366 T974 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cc1d2c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 67369 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 67378 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 67379 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63859_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63859/solr"}
[junit4:junit4]   2> 67388 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 67388 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 67869 T927 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 67869 T927 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:63859/solr shardId:shard2
[junit4:junit4]   2> 67870 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 67886 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 67888 T927 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 67888 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 67892 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 67892 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 67892 T927 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63859/solr/collection1/
[junit4:junit4]   2> 67892 T927 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 67893 T927 oasc.SyncStrategy.syncToMe http://127.0.0.1:63859/solr/collection1/ has no replicas
[junit4:junit4]   2> 67893 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63859/solr/collection1/
[junit4:junit4]   2> 67894 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 67896 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 67903 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800004 type:create cxid:0x4d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 67917 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 67917 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 67958 T927 oasc.ZkController.register We are http://127.0.0.1:63859/solr/collection1/ and leader is http://127.0.0.1:63859/solr/collection1/
[junit4:junit4]   2> 67958 T927 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63859/solr
[junit4:junit4]   2> 67958 T927 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 67958 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 67962 T927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 67963 T927 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 67963 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 67963 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 68276 T927 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 68280 T927 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:63865
[junit4:junit4]   2> 68281 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 68281 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424
[junit4:junit4]   2> 68281 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\'
[junit4:junit4]   2> 68316 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 68317 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 68317 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424
[junit4:junit4]   2> 68317 T927 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\solr.xml
[junit4:junit4]   2> 68318 T927 oasc.CoreContainer.<init> New CoreContainer 15482600
[junit4:junit4]   2> 68318 T927 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\'
[junit4:junit4]   2> 68318 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\'
[junit4:junit4]   2> 68342 T927 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 68357 T927 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:63840/solr
[junit4:junit4]   2> 68357 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@13d8d82
[junit4:junit4]   2> 68359 T984 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 68359 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 68361 T984 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 68361 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63870
[junit4:junit4]   2> 68362 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63870
[junit4:junit4]   2> 68374 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800005 with negotiated timeout 5000 for client /127.0.0.1:63870
[junit4:junit4]   2> 68374 T984 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800005, negotiated timeout = 5000
[junit4:junit4]   2> 68374 T985 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13d8d82 name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 68375 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 68376 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 68378 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 68382 T927 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63865_solr
[junit4:junit4]   2> 68383 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:63865_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:63865_solr
[junit4:junit4]   2> 68384 T927 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63865_solr
[junit4:junit4]   2> 68388 T961 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 68388 T973 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 68388 T947 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 68388 T927 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 68389 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 68390 T927 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 68390 T927 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 68391 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 68404 T927 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 68411 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\collection1
[junit4:junit4]   2> 68412 T927 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 68414 T927 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 68414 T927 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 68415 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\collection1\'
[junit4:junit4]   2> 68417 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 68418 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424/collection1/lib/README' to classloader
[junit4:junit4]   2> 68421 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 68422 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63859_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63859/solr"}
[junit4:junit4]   2> 68430 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 68430 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 68431 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 68480 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 68554 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 68556 T927 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 68562 T927 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 69264 T927 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 69275 T927 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 69280 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 69299 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 69305 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 69309 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 69311 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 69312 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1351201010424\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty3\
[junit4:junit4]   2> 69313 T927 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c943d1
[junit4:junit4]   2> 69314 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty3\index/
[junit4:junit4]   2> 69315 T927 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 69316 T927 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty3\index forceNew:false
[junit4:junit4]   2> 69328 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e3862b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 69328 T927 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 69330 T927 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 69332 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 69332 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 69332 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 69333 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 69334 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 69334 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 69334 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 69335 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 69336 T927 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 69336 T927 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 69337 T927 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 69337 T927 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 69337 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 69337 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 69338 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 69339 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 69339 T927 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69340 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69340 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69340 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69341 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69341 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69342 T927 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 69343 T927 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 69344 T927 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 69350 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 69356 T927 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 69357 T927 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 69362 T927 oass.SolrIndexSearcher.<init> Opening Searcher@26b71a main
[junit4:junit4]   2> 69365 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 69365 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 69365 T927 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 69376 T927 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 69435 T986 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@26b71a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 69438 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 69926 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 69927 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63865_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63865/solr"}
[junit4:junit4]   2> 69937 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 69937 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 69938 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 70432 T927 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 70432 T927 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:63865/solr shardId:shard1
[junit4:junit4]   2> 70433 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 70446 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 70448 T927 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 70448 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 70453 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   2> 70938 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 70948 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 70948 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 70948 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 70949 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179503
[junit4:junit4]   2> 71445 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179007
[junit4:junit4]   2> 71940 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178512
[junit4:junit4]   2> 72436 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178016
[junit4:junit4]   2> 72932 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177520
[junit4:junit4]   2> 73427 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177025
[junit4:junit4]   2> 73923 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176529
[junit4:junit4]   2> 74380 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176072
[junit4:junit4]   2> 74826 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175626
[junit4:junit4]   2> 75273 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175179
[junit4:junit4]   2> 75718 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174734
[junit4:junit4]   2> 76165 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174287
[junit4:junit4]   2> 76611 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173841
[junit4:junit4]   2> 77056 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173396
[junit4:junit4]   2> 77502 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172950
[junit4:junit4]   2> 77948 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172504
[junit4:junit4]   2> 78395 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172057
[junit4:junit4]   2> 78841 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171611
[junit4:junit4]   2> 79287 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171165
[junit4:junit4]   2> 79735 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170717
[junit4:junit4]   2> 80181 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170271
[junit4:junit4]   2> 80628 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169824
[junit4:junit4]   2> 81074 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169378
[junit4:junit4]   2> 81520 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168932
[junit4:junit4]   2> 81966 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168486
[junit4:junit4]   2> 82413 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168039
[junit4:junit4]   2> 82859 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167593
[junit4:junit4]   2> 83343 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167109
[junit4:junit4]   2> 83833 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166619
[junit4:junit4]   2> 84325 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166127
[junit4:junit4]   2> 84815 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165637
[junit4:junit4]   2> 85305 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165147
[junit4:junit4]   2> 85796 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164656
[junit4:junit4]   2> 86287 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164165
[junit4:junit4]   2> 86778 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163674
[junit4:junit4]   2> 87270 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163182
[junit4:junit4]   2> 87761 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162691
[junit4:junit4]   2> 88251 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162201
[junit4:junit4]   2> 88742 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161710
[junit4:junit4]   2> 89233 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161219
[junit4:junit4]   2> 89724 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160728
[junit4:junit4]   2> 90216 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160236
[junit4:junit4]   2> 90707 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159745
[junit4:junit4]   2> 91197 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159255
[junit4:junit4]   2> 91688 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158764
[junit4:junit4]   2> 92179 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158273
[junit4:junit4]   2> 92669 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157783
[junit4:junit4]   2> 93205 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157247
[junit4:junit4]   2> 93745 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156707
[junit4:junit4]   2> 94284 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156168
[junit4:junit4]   2> 94824 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155628
[junit4:junit4]   2> 95365 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155087
[junit4:junit4]   2> 95905 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154547
[junit4:junit4]   2> 96444 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154008
[junit4:junit4]   2> 96984 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153468
[junit4:junit4]   2> 97524 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152928
[junit4:junit4]   2> 98063 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152389
[junit4:junit4]   2> 98603 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151849
[junit4:junit4]   2> 99144 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151308
[junit4:junit4]   2> 99683 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150769
[junit4:junit4]   2> 100223 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150229
[junit4:junit4]   2> 100763 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149689
[junit4:junit4]   2> 101303 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149149
[junit4:junit4]   2> 101845 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148607
[junit4:junit4]   2> 102386 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148066
[junit4:junit4]   2> 102926 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147526
[junit4:junit4]   2> 103466 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146986
[junit4:junit4]   2> 103970 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146482
[junit4:junit4]   2> 104471 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145981
[junit4:junit4]   2> 104973 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145479
[junit4:junit4]   2> 105475 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144977
[junit4:junit4]   2> 105975 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144477
[junit4:junit4]   2> 106476 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143976
[junit4:junit4]   2> 106979 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143473
[junit4:junit4]   2> 107479 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142973
[junit4:junit4]   2> 107980 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142472
[junit4:junit4]   2> 108482 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141970
[junit4:junit4]   2> 108984 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141468
[junit4:junit4]   2> 109485 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140967
[junit4:junit4]   2> 109986 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140466
[junit4:junit4]   2> 110487 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139965
[junit4:junit4]   2> 110988 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139464
[junit4:junit4]   2> 111490 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138962
[junit4:junit4]   2> 111991 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138461
[junit4:junit4]   2> 112492 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137960
[junit4:junit4]   2> 112993 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137459
[junit4:junit4]   2> 113494 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136958
[junit4:junit4]   2> 113995 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136457
[junit4:junit4]   2> 114495 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135957
[junit4:junit4]   2> 114995 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135457
[junit4:junit4]   2> 115496 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134956
[junit4:junit4]   2> 115997 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134455
[junit4:junit4]   2> 116499 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133954
[junit4:junit4]   2> 116999 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133453
[junit4:junit4]   2> 117500 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132952
[junit4:junit4]   2> 118000 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132452
[junit4:junit4]   2> 118502 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131950
[junit4:junit4]   2> 119002 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131450
[junit4:junit4]   2> 119502 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130950
[junit4:junit4]   2> 120004 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130448
[junit4:junit4]   2> 120505 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129947
[junit4:junit4]   2> 121007 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129445
[junit4:junit4]   2> 121508 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128944
[junit4:junit4]   2> 122008 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128444
[junit4:junit4]   2> 122510 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127942
[junit4:junit4]   2> 123010 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127442
[junit4:junit4]   2> 123512 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126940
[junit4:junit4]   2> 124012 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126440
[junit4:junit4]   2> 124514 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125938
[junit4:junit4]   2> 125014 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125438
[junit4:junit4]   2> 125515 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124937
[junit4:junit4]   2> 126017 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124435
[junit4:junit4]   2> 126518 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123934
[junit4:junit4]   2> 127018 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123434
[junit4:junit4]   2> 127520 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122932
[junit4:junit4]   2> 128020 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122432
[junit4:junit4]   2> 128521 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121931
[junit4:junit4]   2> 129022 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121430
[junit4:junit4]   2> 129524 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120928
[junit4:junit4]   2> 130025 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120427
[junit4:junit4]   2> 130525 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119927
[junit4:junit4]   2> 131026 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119426
[junit4:junit4]   2> 131526 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118926
[junit4:junit4]   2> 132027 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118425
[junit4:junit4]   2> 132528 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117924
[junit4:junit4]   2> 133028 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117424
[junit4:junit4]   2> 133531 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116921
[junit4:junit4]   2> 134083 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116369
[junit4:junit4]   2> 134635 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115817
[junit4:junit4]   2> 135185 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115267
[junit4:junit4]   2> 135736 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114716
[junit4:junit4]   2> 136287 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114165
[junit4:junit4]   2> 136838 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113614
[junit4:junit4]   2> 137388 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113064
[junit4:junit4]   2> 137940 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112512
[junit4:junit4]   2> 138493 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111959
[junit4:junit4]   2> 139043 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111409
[junit4:junit4]   2> 139595 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110857
[junit4:junit4]   2> 140146 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110306
[junit4:junit4]   2> 140697 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109755
[junit4:junit4]   2> 141248 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109204
[junit4:junit4]   2> 141799 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108653
[junit4:junit4]   2> 142351 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108101
[junit4:junit4]   2> 142902 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107550
[junit4:junit4]   2> 143455 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106997
[junit4:junit4]   2> 144006 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106446
[junit4:junit4]   2> 144552 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105900
[junit4:junit4]   2> 145049 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105403
[junit4:junit4]   2> 145545 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104907
[junit4:junit4]   2> 146040 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104412
[junit4:junit4]   2> 146536 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103916
[junit4:junit4]   2> 147032 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103420
[junit4:junit4]   2> 147528 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102924
[junit4:junit4]   2> 148023 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102429
[junit4:junit4]   2> 148519 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101933
[junit4:junit4]   2> 149015 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101437
[junit4:junit4]   2> 149510 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100942
[junit4:junit4]   2> 150006 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100446
[junit4:junit4]   2> 150502 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99950
[junit4:junit4]   2> 150998 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99454
[junit4:junit4]   2> 151495 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98957
[junit4:junit4]   2> 151991 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98461
[junit4:junit4]   2> 152487 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97965
[junit4:junit4]   2> 152983 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97469
[junit4:junit4]   2> 153479 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96973
[junit4:junit4]   2> 153975 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96477
[junit4:junit4]   2> 154464 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95988
[junit4:junit4]   2> 154911 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95541
[junit4:junit4]   2> 155359 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95093
[junit4:junit4]   2> 155805 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94647
[junit4:junit4]   2> 156251 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94201
[junit4:junit4]   2> 156698 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93754
[junit4:junit4]   2> 157145 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93307
[junit4:junit4]   2> 157592 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92860
[junit4:junit4]   2> 158039 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92413
[junit4:junit4]   2> 158486 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91966
[junit4:junit4]   2> 158931 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91521
[junit4:junit4]   2> 159378 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91074
[junit4:junit4]   2> 159825 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90627
[junit4:junit4]   2> 160272 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90180
[junit4:junit4]   2> 160718 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89734
[junit4:junit4]   2> 161164 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89288
[junit4:junit4]   2> 161610 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88842
[junit4:junit4]   2> 162058 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88394
[junit4:junit4]   2> 162505 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87947
[junit4:junit4]   2> 162951 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87501
[junit4:junit4]   2> 163405 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87047
[junit4:junit4]   2> 163897 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86555
[junit4:junit4]   2> 164389 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86063
[junit4:junit4]   2> 164881 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85571
[junit4:junit4]   2> 165372 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85080
[junit4:junit4]   2> 165864 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84588
[junit4:junit4]   2> 166355 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84097
[junit4:junit4]   2> 166847 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83605
[junit4:junit4]   2> 167339 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83113
[junit4:junit4]   2> 167832 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82620
[junit4:junit4]   2> 168324 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82128
[junit4:junit4]   2> 168816 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81636
[junit4:junit4]   2> 169308 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81144
[junit4:junit4]   2> 169800 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80652
[junit4:junit4]   2> 170292 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80160
[junit4:junit4]   2> 170784 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79668
[junit4:junit4]   2> 171275 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79177
[junit4:junit4]   2> 171766 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78686
[junit4:junit4]   2> 172257 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78195
[junit4:junit4]   2> 172747 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77705
[junit4:junit4]   2> 173250 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77202
[junit4:junit4]   2> 173791 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76661
[junit4:junit4]   2> 174331 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76121
[junit4:junit4]   2> 174873 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75579
[junit4:junit4]   2> 175414 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75038
[junit4:junit4]   2> 175955 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74497
[junit4:junit4]   2> 176495 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73957
[junit4:junit4]   2> 177036 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73416
[junit4:junit4]   2> 177576 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72876
[junit4:junit4]   2> 178117 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72335
[junit4:junit4]   2> 178657 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71795
[junit4:junit4]   2> 179198 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71254
[junit4:junit4]   2> 179739 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70713
[junit4:junit4]   2> 180280 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70172
[junit4:junit4]   2> 180821 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69631
[junit4:junit4]   2> 181360 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69092
[junit4:junit4]   2> 181900 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68552
[junit4:junit4]   2> 182440 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68012
[junit4:junit4]   2> 182980 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67472
[junit4:junit4]   2> 183521 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66931
[junit4:junit4]   2> 184050 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66402
[junit4:junit4]   2> 184552 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65900
[junit4:junit4]   2> 185053 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65399
[junit4:junit4]   2> 185554 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64898
[junit4:junit4]   2> 186054 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64398
[junit4:junit4]   2> 186556 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63896
[junit4:junit4]   2> 187059 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63393
[junit4:junit4]   2> 187560 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62892
[junit4:junit4]   2> 188061 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62391
[junit4:junit4]   2> 188562 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61890
[junit4:junit4]   2> 189063 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61389
[junit4:junit4]   2> 189565 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60887
[junit4:junit4]   2> 190067 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60385
[junit4:junit4]   2> 190569 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59883
[junit4:junit4]   2> 191070 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59382
[junit4:junit4]   2> 191572 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58880
[junit4:junit4]   2> 192074 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58378
[junit4:junit4]   2> 192575 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57877
[junit4:junit4]   2> 193076 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57376
[junit4:junit4]   2> 193578 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56874
[junit4:junit4]   2> 194080 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56372
[junit4:junit4]   2> 194581 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55871
[junit4:junit4]   2> 195082 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55370
[junit4:junit4]   2> 195584 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54868
[junit4:junit4]   2> 196086 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54366
[junit4:junit4]   2> 196589 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53863
[junit4:junit4]   2> 197091 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53361
[junit4:junit4]   2> 197593 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52859
[junit4:junit4]   2> 198094 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52358
[junit4:junit4]   2> 198597 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51855
[junit4:junit4]   2> 199100 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51352
[junit4:junit4]   2> 199601 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50851
[junit4:junit4]   2> 200102 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50350
[junit4:junit4]   2> 200603 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49849
[junit4:junit4]   2> 201104 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49348
[junit4:junit4]   2> 201606 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48846
[junit4:junit4]   2> 202106 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48346
[junit4:junit4]   2> 202607 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47845
[junit4:junit4]   2> 203108 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47344
[junit4:junit4]   2> 203608 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46844
[junit4:junit4]   2> 204130 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46322
[junit4:junit4]   2> 204681 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45771
[junit4:junit4]   2> 205232 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45220
[junit4:junit4]   2> 205785 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44667
[junit4:junit4]   2> 206335 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44117
[junit4:junit4]   2> 206886 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43566
[junit4:junit4]   2> 207438 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43014
[junit4:junit4]   2> 207988 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42464
[junit4:junit4]   2> 208541 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41911
[junit4:junit4]   2> 209093 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41359
[junit4:junit4]   2> 209643 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40809
[junit4:junit4]   2> 210194 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40258
[junit4:junit4]   2> 210746 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39706
[junit4:junit4]   2> 211298 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39154
[junit4:junit4]   2> 211849 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38603
[junit4:junit4]   2> 212401 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38051
[junit4:junit4]   2> 212951 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37501
[junit4:junit4]   2> 213504 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36948
[junit4:junit4]   2> 214056 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36396
[junit4:junit4]   2> 214608 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35844
[junit4:junit4]   2> 215133 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35319
[junit4:junit4]   2> 215628 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34824
[junit4:junit4]   2> 216125 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34327
[junit4:junit4]   2> 216620 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33832
[junit4:junit4]   2> 217117 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33335
[junit4:junit4]   2> 217617 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32835
[junit4:junit4]   2> 218112 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32340
[junit4:junit4]   2> 218608 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31844
[junit4:junit4]   2> 219104 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31348
[junit4:junit4]   2> 219599 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30853
[junit4:junit4]   2> 220097 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30355
[junit4:junit4]   2> 220594 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29858
[junit4:junit4]   2> 221089 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29363
[junit4:junit4]   2> 221584 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28868
[junit4:junit4]   2> 222081 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28371
[junit4:junit4]   2> 222577 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27875
[junit4:junit4]   2> 223072 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27380
[junit4:junit4]   2> 223569 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26883
[junit4:junit4]   2> 224065 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26387
[junit4:junit4]   2> 224561 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25891
[junit4:junit4]   2> 225030 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25422
[junit4:junit4]   2> 225476 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24976
[junit4:junit4]   2> 225922 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24530
[junit4:junit4]   2> 226368 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24084
[junit4:junit4]   2> 226815 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23637
[junit4:junit4]   2> 227261 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23191
[junit4:junit4]   2> 227707 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22745
[junit4:junit4]   2> 228154 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22298
[junit4:junit4]   2> 228599 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21853
[junit4:junit4]   2> 229045 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21407
[junit4:junit4]   2> 229491 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20961
[junit4:junit4]   2> 229937 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20515
[junit4:junit4]   2> 230385 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20067
[junit4:junit4]   2> 230830 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19622
[junit4:junit4]   2> 231277 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19175
[junit4:junit4]   2> 231724 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18728
[junit4:junit4]   2> 232171 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18281
[junit4:junit4]   2> 232617 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17835
[junit4:junit4]   2> 233065 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17387
[junit4:junit4]   2> 233511 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16941
[junit4:junit4]   2> 233983 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16469
[junit4:junit4]   2> 234473 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15979
[junit4:junit4]   2> 234964 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15488
[junit4:junit4]   2> 235455 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14997
[junit4:junit4]   2> 235947 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14505
[junit4:junit4]   2> 236438 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14014
[junit4:junit4]   2> 236928 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13524
[junit4:junit4]   2> 237418 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13034
[junit4:junit4]   2> 237909 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12543
[junit4:junit4]   2> 238401 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12051
[junit4:junit4]   2> 238891 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11561
[junit4:junit4]   2> 239381 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11071
[junit4:junit4]   2> 239873 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10579
[junit4:junit4]   2> 240363 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10089
[junit4:junit4]   2> 240854 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9598
[junit4:junit4]   2> 241345 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9107
[junit4:junit4]   2> 241836 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8616
[junit4:junit4]   2> 242326 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8126
[junit4:junit4]   2> 242816 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7636
[junit4:junit4]   2> 243307 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7145
[junit4:junit4]   2> 243827 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6625
[junit4:junit4]   2> 244366 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6086
[junit4:junit4]   2> 244907 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5545
[junit4:junit4]   2> 245446 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5006
[junit4:junit4]   2> 245986 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4466
[junit4:junit4]   2> 246526 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3926
[junit4:junit4]   2> 247067 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3385
[junit4:junit4]   2> 247606 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2846
[junit4:junit4]   2> 248147 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2305
[junit4:junit4]   2> 248686 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1766
[junit4:junit4]   2> 249226 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1226
[junit4:junit4]   2> 249766 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=686
[junit4:junit4]   2> 250306 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146
[junit4:junit4]   2> 250845 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=-393
[junit4:junit4]   2> 250846 T927 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
[junit4:junit4]   2> 250847 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 250847 T927 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63865/solr/collection1/
[junit4:junit4]   2> 250848 T927 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63865/solr START replicas=[http://127.0.0.1:63853/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 250848 T927 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63865/solr DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 250849 T927 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 250849 T927 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> 250851 T927 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63865/solr/collection1/
[junit4:junit4]   2> 250853 T927 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 250859 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800005 type:create cxid:0x1b5 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 251304 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 251315 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251315 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251315 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251358 T927 oasc.ZkController.register We are http://127.0.0.1:63865/solr/collection1/ and leader is http://127.0.0.1:63865/solr/collection1/
[junit4:junit4]   2> 251358 T927 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63865/solr
[junit4:junit4]   2> 251358 T927 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 251360 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 251364 T927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 251366 T927 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 251366 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 251366 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 251777 T927 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 251780 T927 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:63872
[junit4:junit4]   2> 251783 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 251783 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829
[junit4:junit4]   2> 251784 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\'
[junit4:junit4]   2> 251828 T927 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 251828 T927 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 251829 T927 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829
[junit4:junit4]   2> 251829 T927 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\solr.xml
[junit4:junit4]   2> 251829 T927 oasc.CoreContainer.<init> New CoreContainer 31058874
[junit4:junit4]   2> 251830 T927 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\'
[junit4:junit4]   2> 251830 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\'
[junit4:junit4]   2> 251858 T927 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 251864 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 251865 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63865_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63865/solr"}
[junit4:junit4]   2> 251884 T927 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:63840/solr
[junit4:junit4]   2> 251884 T927 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:63840/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@485eb2
[junit4:junit4]   2> 251886 T927 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 251887 T997 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:63840
[junit4:junit4]   2> 251888 T997 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:63840, initiating session
[junit4:junit4]   2> 251889 T929 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:63877
[junit4:junit4]   2> 251889 T929 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:63877
[junit4:junit4]   2> 251892 T997 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:63840, sessionid = 0x13a99da29800006, negotiated timeout = 5000
[junit4:junit4]   2> 251892 T931 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a99da29800006 with negotiated timeout 5000 for client /127.0.0.1:63877
[junit4:junit4]   2> 251892 T998 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@485eb2 name:ZooKeeperConnection Watcher:127.0.0.1:63840/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 251892 T927 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 251895 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 251895 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251896 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251896 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 251898 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 251903 T927 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63872_solr
[junit4:junit4]   2> 251904 T932 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a99da29800006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:63872_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:63872_solr
[junit4:junit4]   2> 251906 T927 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63872_solr
[junit4:junit4]   2> 251916 T961 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 251916 T947 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 251917 T973 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 251917 T985 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 251921 T927 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 251923 T927 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 251923 T927 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 251923 T927 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 251939 T927 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 251950 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\collection1
[junit4:junit4]   2> 251951 T927 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 251952 T927 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 251953 T927 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 251956 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\collection1\'
[junit4:junit4]   2> 251958 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 251959 T927 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829/collection1/lib/README' to classloader
[junit4:junit4]   2> 252028 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 252123 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 252125 T927 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 252132 T927 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 252972 T927 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 253001 T927 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 253006 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 253028 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 253038 T927 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 253044 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 253048 T927 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 253050 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1351201193829\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty4\
[junit4:junit4]   2> 253050 T927 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c943d1
[junit4:junit4]   2> 253053 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455/jetty4\index/
[junit4:junit4]   2> 253054 T927 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 253055 T927 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty4\index forceNew:false
[junit4:junit4]   2> 253069 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZkTest-1351200942455\jetty4\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8ae6c5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 253070 T927 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 253073 T927 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 253075 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 253075 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 253075 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 253076 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 253076 T927 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 253076 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 253078 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 253079 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 253079 T927 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 253080 T927 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 253081 T927 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 253082 T927 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 253082 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 253082 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 253083 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 253083 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 253084 T927 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253084 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253084 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253085 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253086 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253087 T927 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253088 T927 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 253088 T927 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 253089 T927 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 253100 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 253108 T927 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 253109 T927 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 253115 T927 oass.SolrIndexSearcher.<init> Opening Searcher@17b9d1f main
[junit4:junit4]   2> 253120 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 253120 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 253121 T927 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 253138 T927 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 253217 T999 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17b9d1f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 253220 T927 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 253528 T948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 253532 T948 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:63872_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:63872/solr"}
[junit4:junit4]   2> 253542 T947 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 253543 T998 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 253545 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 253545 T973 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 253763 T927 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 253763 T927 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:63872/solr shardId:shard2
[junit4:junit4]   2> 253768 T927 oasc.ZkController.register We are http://127.0.0.1:63872/solr/collection1/ and leader is http://127.0.0.1:63859/solr/collection1/
[junit4:junit4]   2> 253769 T927 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63872/solr
[junit4:junit4]   2> 253769 T927 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 253769 T927 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C44 name=collection1 org.apache.solr.core.SolrCore@1b6bad7 url=http://127.0.0.1:63872/solr/collection1 node=127.0.0.1:63872_solr
[junit4:junit4]   2> 253770 T1000 C44 P63872 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 253771 T1000 C44 P63872 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 253771 T1000 C44 P63872 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 253771 T927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 253778 T1000 C44 P63872 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63859/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 253778 T1000 C44 P63872 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63872/solr START replicas=[http://127.0.0.1:63859/solr/collection1/

[...truncated too long message...]

ger awaiting termination of 1 leaked thread(s).
[junit4:junit4]   2> 1011399 T926 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
[junit4:junit4]   2> 	   1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2> 1011399 T926 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4:junit4]   2> 	   1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]   2> 1014400 T926 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4:junit4]   2> 	   1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2> NOTE: test params are: codec=SimpleText, sim=DefaultSimilarity, locale=en_CA, timezone=America/Guadeloupe
[junit4:junit4]   2> NOTE: Windows 7 6.1 x86/Sun Microsystems Inc. 1.6.0_35 (32-bit)/cpus=2,threads=2,free=62496912,total=203554816
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestFastWriter, WordBreakSolrSpellCheckerTest, BasicDistributedZk2Test, DateFieldTest, TestQueryTypes, DocumentBuilderTest, TestQueryUtils, TestStressVersions, RecoveryZkTest, TestSolr4Spatial, TestPhraseSuggestions, TestIndexSearcher, TestXIncludeConfig, ZkCLITest, TimeZoneUtilsTest, SimplePostToolTest, PeerSyncTest, TestSolrDeletionPolicy2, TestBinaryField, OpenExchangeRatesOrgProviderTest, TestAnalyzedSuggestions, SortByFunctionTest, SoftAutoCommitTest, DOMUtilTest, TestSolrJ, TestConfig, IndexSchemaTest, QueryElevationComponentTest, AlternateDirectoryTest, SyncSliceTest, TestRandomFaceting, TestNumberUtils, TestWordDelimiterFilterFactory, SpellingQueryConverterTest, BasicDistributedZkTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=120C875A7AE852A3 -Dtests.slow=true -Dtests.locale=en_CA -Dtests.timezone=America/Guadeloupe -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR   0.00s | BasicDistributedZkTest (suite) <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=7 closes=6
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:242)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
[junit4:junit4]    > 	at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:597)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]    > Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
[junit4:junit4]    >    1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]    >         at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4:junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
[junit4:junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
[junit4:junit4]    >         at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)
[junit4:junit4]    > Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4:junit4]    >    1) Thread[id=962, name=searcherExecutor-401-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]    >         at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4:junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
[junit4:junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
[junit4:junit4]    >         at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([120C875A7AE852A3]:0)
[junit4:junit4] Completed in 1014.45s, 1 test, 2 failures, 2 errors <<< FAILURES!

[...truncated 598 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:335: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:178: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\module-build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1171: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:839: There were test failures: 232 suites, 961 tests, 3 suite-level errors, 1 failure, 755 ignored (4 assumptions)

Total time: 42 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.6.0_35 -server -XX:+UseParallelGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message