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 # 1331 - Still Failing!
Date Sat, 27 Oct 2012 20:02:05 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Windows/1331/
Java: 32bit/jdk1.6.0_35 -client -XX:+UseSerialGC

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([3C2D05D42C2AAA16:BDCB8BCC5B75CA2A]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:155)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:116)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:111)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:553)
	at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:169)
	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([3C2D05D42C2AAA16]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:243)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
	at sun.reflect.GeneratedMethodAccessor24.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=628, name=searcherExecutor-390-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=628, name=searcherExecutor-390-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([3C2D05D42C2AAA16]: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=628, name=searcherExecutor-390-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=628, name=searcherExecutor-390-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([3C2D05D42C2AAA16]:0)




Build Log:
[...truncated 7894 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4:junit4]   2> 3 T591 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-1351367051209
[junit4:junit4]   2> 8 T591 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 12 T592 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 13 T592 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 14 T592 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 124 T591 oasc.ZkTestServer.run start zk server on port:60243
[junit4:junit4]   2> 125 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@15de9c
[junit4:junit4]   2> 127 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 127 T597 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 132 T597 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 132 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60246
[junit4:junit4]   2> 133 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60246
[junit4:junit4]   2> 134 T595 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 145 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30000 with negotiated timeout 10000 for client /127.0.0.1:60246
[junit4:junit4]   2> 145 T597 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30000, negotiated timeout = 10000
[junit4:junit4]   2> 146 T598 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15de9c name:ZooKeeperConnection Watcher:127.0.0.1:60243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 146 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 147 T591 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 157 T596 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13aa3c0c7d30000
[junit4:junit4]   2> 160 T591 oaz.ZooKeeper.close Session: 0x13aa3c0c7d30000 closed
[junit4:junit4]   2> 160 T593 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60246 which had sessionid 0x13aa3c0c7d30000
[junit4:junit4]   2> 160 T598 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 160 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b2cfd
[junit4:junit4]   2> 164 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 164 T599 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 168 T599 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 169 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60249
[junit4:junit4]   2> 169 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60249
[junit4:junit4]   2> 171 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30001 with negotiated timeout 10000 for client /127.0.0.1:60249
[junit4:junit4]   2> 171 T599 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30001, negotiated timeout = 10000
[junit4:junit4]   2> 171 T600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b2cfd name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 171 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 171 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 178 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 181 T591 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 185 T591 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 190 T591 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> 191 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 199 T591 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> 199 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 205 T591 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> 205 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 212 T591 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> 212 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 216 T591 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> 217 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 222 T591 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> 222 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 229 T591 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> 229 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 236 T591 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> 237 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 245 T591 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> 246 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 249 T591 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> 250 T591 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 256 T596 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13aa3c0c7d30001
[junit4:junit4]   2> 257 T591 oaz.ZooKeeper.close Session: 0x13aa3c0c7d30001 closed
[junit4:junit4]   2> 257 T593 oazs.NIOServerCnxn.doIO WARNING EndOfStreamException: Unable to read additional data from client sessionid 0x13aa3c0c7d30001, likely client has closed socket
[junit4:junit4]   2> 258 T593 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60249 which had sessionid 0x13aa3c0c7d30001
[junit4:junit4]   2> 258 T600 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 630 T591 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 634 T591 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:60250
[junit4:junit4]   2> 635 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 635 T591 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-1351367051462
[junit4:junit4]   2> 635 T591 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-1351367051462\'
[junit4:junit4]   2> 663 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 663 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 664 T591 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-1351367051462
[junit4:junit4]   2> 664 T591 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-1351367051462\solr.xml
[junit4:junit4]   2> 665 T591 oasc.CoreContainer.<init> New CoreContainer 9601232
[junit4:junit4]   2> 665 T591 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-1351367051462\'
[junit4:junit4]   2> 665 T591 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-1351367051462\'
[junit4:junit4]   2> 690 T591 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 711 T591 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60243/solr
[junit4:junit4]   2> 711 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@aebbd2
[junit4:junit4]   2> 712 T610 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 712 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 715 T610 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 715 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60255
[junit4:junit4]   2> 716 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60255
[junit4:junit4]   2> 725 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30002 with negotiated timeout 5000 for client /127.0.0.1:60255
[junit4:junit4]   2> 725 T610 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30002, negotiated timeout = 5000
[junit4:junit4]   2> 725 T611 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aebbd2 name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 725 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 729 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 730 T591 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 733 T591 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60250_solr
[junit4:junit4]   2> 734 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60250_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60250_solr
[junit4:junit4]   2> 735 T591 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60250_solr
[junit4:junit4]   2> 740 T591 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 740 T591 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 740 T591 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 741 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 741 T591 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 741 T591 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 742 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 742 T591 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 742 T591 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 743 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 753 T591 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 762 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 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> 764 T591 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 767 T591 oasc.Overseer.start Overseer (id=88563191068688386-127.0.0.1:60250_solr-n_0000000000) starting
[junit4:junit4]   2> 768 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 769 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 771 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 774 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 777 T613 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 777 T591 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 782 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 784 T612 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 791 T591 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-1351367051462\collection1
[junit4:junit4]   2> 791 T591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 792 T591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 794 T591 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 799 T591 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-1351367051462\collection1\'
[junit4:junit4]   2> 802 T591 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-1351367051462/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 803 T591 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-1351367051462/collection1/lib/README' to classloader
[junit4:junit4]   2> 871 T591 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 955 T591 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 959 T591 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 964 T591 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1846 T591 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1865 T591 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1874 T591 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1894 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1900 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1910 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1912 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1915 T591 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-1351367051462\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/control/data\
[junit4:junit4]   2> 1915 T591 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad6b4b
[junit4:junit4]   2> 1916 T591 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1943 T591 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for 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-1351367051207\control\data lockFactory=org.apache.lucene.store.NativeFSLockFactory@f01177; maxCacheMB=48.0 maxMergeSizeMB=4.0) assuming 'simple'
[junit4:junit4]   2> 1944 T591 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-1351367051207\control\data forceNew:false
[junit4:junit4]   2> 1945 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\control\data
[junit4:junit4]   2> 1945 T591 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/control/data\index/
[junit4:junit4]   2> 1946 T591 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1947 T591 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-1351367051207\control\data\index forceNew:false
[junit4:junit4]   2> 1960 T591 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-1351367051207\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3f7824; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1960 T591 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1962 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\control\data\index
[junit4:junit4]   2> 1962 T591 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1964 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1964 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1965 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1965 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1966 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1966 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1966 T591 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1968 T591 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1969 T591 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1969 T591 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1970 T591 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1970 T591 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1970 T591 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1971 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1971 T591 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1972 T591 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1972 T591 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1973 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1973 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1974 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1974 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1975 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1975 T591 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1977 T591 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1977 T591 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1986 T591 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1992 T591 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1994 T591 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> 1996 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\control\data
[junit4:junit4]   2> 1998 T591 oass.SolrIndexSearcher.<init> Opening Searcher@f4d225 main
[junit4:junit4]   2> 2000 T591 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2001 T591 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2001 T591 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2016 T591 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2091 T614 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f4d225 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2098 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2100 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 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> 2106 T591 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 2106 T591 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:60250/solr shardId:control_shard
[junit4:junit4]   2> 2109 T591 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 2120 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 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> 2122 T591 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2123 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2527 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2527 T612 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:60250_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60250/solr"}
[junit4:junit4]   2> 2528 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 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> 2545 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 2704 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2704 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2706 T591 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60250/solr/collection1/
[junit4:junit4]   2> 2707 T591 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2707 T591 oasc.SyncStrategy.syncToMe http://127.0.0.1:60250/solr/collection1/ has no replicas
[junit4:junit4]   2> 2707 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60250/solr/collection1/
[junit4:junit4]   2> 2707 T591 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2716 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30002 type:create cxid:0x8c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3168 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3176 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 3230 T591 oasc.ZkController.register We are http://127.0.0.1:60250/solr/collection1/ and leader is http://127.0.0.1:60250/solr/collection1/
[junit4:junit4]   2> 3230 T591 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60250/solr
[junit4:junit4]   2> 3231 T591 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3231 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3235 T591 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3236 T591 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 3236 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3238 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3246 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3253 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@8bbe62
[junit4:junit4]   2> 3254 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3254 T615 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 3258 T615 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 3258 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60258
[junit4:junit4]   2> 3258 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60258
[junit4:junit4]   2> 3261 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30003 with negotiated timeout 10000 for client /127.0.0.1:60258
[junit4:junit4]   2> 3261 T615 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30003, negotiated timeout = 10000
[junit4:junit4]   2> 3261 T616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8bbe62 name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3262 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3263 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3268 T591 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3660 T591 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3665 T591 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:60259
[junit4:junit4]   2> 3668 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3668 T591 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-1351367054472
[junit4:junit4]   2> 3668 T591 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-1351367054472\'
[junit4:junit4]   2> 3711 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3711 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3712 T591 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-1351367054472
[junit4:junit4]   2> 3712 T591 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-1351367054472\solr.xml
[junit4:junit4]   2> 3714 T591 oasc.CoreContainer.<init> New CoreContainer 18027605
[junit4:junit4]   2> 3714 T591 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-1351367054472\'
[junit4:junit4]   2> 3714 T591 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-1351367054472\'
[junit4:junit4]   2> 3741 T591 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3765 T591 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60243/solr
[junit4:junit4]   2> 3765 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b56444
[junit4:junit4]   2> 3767 T626 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 3767 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3770 T626 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 3770 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60264
[junit4:junit4]   2> 3771 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60264
[junit4:junit4]   2> 3784 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30004 with negotiated timeout 5000 for client /127.0.0.1:60264
[junit4:junit4]   2> 3784 T626 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30004, negotiated timeout = 5000
[junit4:junit4]   2> 3786 T627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b56444 name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3786 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3787 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3789 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3792 T591 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60259_solr
[junit4:junit4]   2> 3793 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60259_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60259_solr
[junit4:junit4]   2> 3794 T591 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60259_solr
[junit4:junit4]   2> 3798 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 3802 T616 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 3802 T591 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3803 T611 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 3803 T591 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3803 T591 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3804 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3804 T591 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3806 T591 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3806 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3806 T591 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3807 T591 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3807 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3818 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3819 T612 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:60250_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60250/solr"}
[junit4:junit4]   2> 3828 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3832 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 3832 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 3833 T627 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> 3853 T591 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-1351367054472\collection1
[junit4:junit4]   2> 3854 T591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3855 T591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3855 T591 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3859 T591 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-1351367054472\collection1\'
[junit4:junit4]   2> 3860 T591 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-1351367054472/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3861 T591 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-1351367054472/collection1/lib/README' to classloader
[junit4:junit4]   2> 3933 T591 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4028 T591 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4029 T591 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4035 T591 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4806 T591 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4817 T591 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4821 T591 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4841 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4848 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4853 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4856 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4857 T591 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-1351367054472\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty1\
[junit4:junit4]   2> 4857 T591 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad6b4b
[junit4:junit4]   2> 4859 T591 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 4859 T591 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for 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-1351367051207\jetty1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ccef60; maxCacheMB=48.0 maxMergeSizeMB=4.0) assuming 'simple'
[junit4:junit4]   2> 4861 T591 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-1351367051207\jetty1 forceNew:false
[junit4:junit4]   2> 4861 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty1
[junit4:junit4]   2> 4862 T591 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty1\index/
[junit4:junit4]   2> 4862 T591 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4863 T591 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-1351367051207\jetty1\index forceNew:false
[junit4:junit4]   2> 4878 T591 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-1351367051207\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@54067e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4878 T591 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 4880 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty1\index
[junit4:junit4]   2> 4882 T591 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4883 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4884 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4884 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4884 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4885 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4885 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4887 T591 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4887 T591 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4888 T591 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4889 T591 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4889 T591 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4890 T591 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4890 T591 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4890 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4892 T591 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4892 T591 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4893 T591 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4894 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4894 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4895 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4895 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4897 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4897 T591 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4898 T591 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4899 T591 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4909 T591 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4916 T591 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4918 T591 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> 4923 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty1
[junit4:junit4]   2> 4925 T591 oass.SolrIndexSearcher.<init> Opening Searcher@77830c main
[junit4:junit4]   2> 4928 T591 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4928 T591 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4929 T591 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4942 T591 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5014 T628 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77830c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5021 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 5119 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5120 T612 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:60259_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60259/solr"}
[junit4:junit4]   2> 5121 T612 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 5150 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 5150 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 74201 T591 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:998)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.preRegister(ZkController.java:1056)
[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:292)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:245)
[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> 74203 T591 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 74203 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 74204 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 74484 T591 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 74487 T591 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:60265
[junit4:junit4]   2> 74488 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 74489 T591 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-1351367125415
[junit4:junit4]   2> 74489 T591 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-1351367125415\'
[junit4:junit4]   2> 74521 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 74521 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 74521 T591 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-1351367125415
[junit4:junit4]   2> 74521 T591 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-1351367125415\solr.xml
[junit4:junit4]   2> 74521 T591 oasc.CoreContainer.<init> New CoreContainer 12312026
[junit4:junit4]   2> 74522 T591 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-1351367125415\'
[junit4:junit4]   2> 74522 T591 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-1351367125415\'
[junit4:junit4]   2> 74547 T591 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 74563 T591 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60243/solr
[junit4:junit4]   2> 74563 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1345875
[junit4:junit4]   2> 74564 T638 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 74564 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 74567 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60270
[junit4:junit4]   2> 74567 T638 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 74567 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60270
[junit4:junit4]   2> 74586 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30005 with negotiated timeout 5000 for client /127.0.0.1:60270
[junit4:junit4]   2> 74587 T638 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30005, negotiated timeout = 5000
[junit4:junit4]   2> 74587 T639 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1345875 name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 74588 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 74589 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 74592 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 74594 T591 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60265_solr
[junit4:junit4]   2> 74595 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60265_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60265_solr
[junit4:junit4]   2> 74596 T591 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60265_solr
[junit4:junit4]   2> 74598 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 74598 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 74600 T627 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74600 T616 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74600 T611 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74600 T591 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 74601 T591 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 74601 T591 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 74601 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 74602 T591 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 74603 T591 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 74603 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 74603 T591 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 74603 T591 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 74604 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 74614 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 74622 T591 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-1351367125415\collection1
[junit4:junit4]   2> 74622 T591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 74624 T591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 74624 T591 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 74626 T591 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-1351367125415\collection1\'
[junit4:junit4]   2> 74628 T591 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-1351367125415/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 74629 T591 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-1351367125415/collection1/lib/README' to classloader
[junit4:junit4]   2> 74681 T591 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 74751 T591 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 74753 T591 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 74758 T591 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 75449 T591 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 75456 T591 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 75458 T591 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 75471 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 75474 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 75478 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 75481 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 75482 T591 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-1351367125415\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty2\
[junit4:junit4]   2> 75482 T591 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad6b4b
[junit4:junit4]   2> 75482 T591 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 75483 T591 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for 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-1351367051207\jetty2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@cf1128; maxCacheMB=48.0 maxMergeSizeMB=4.0) assuming 'simple'
[junit4:junit4]   2> 75483 T591 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-1351367051207\jetty2 forceNew:false
[junit4:junit4]   2> 75484 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty2
[junit4:junit4]   2> 75484 T591 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty2\index/
[junit4:junit4]   2> 75485 T591 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 75486 T591 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-1351367051207\jetty2\index forceNew:false
[junit4:junit4]   2> 75497 T591 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-1351367051207\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1bf6255; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 75498 T591 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 75500 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty2\index
[junit4:junit4]   2> 75501 T591 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 75503 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 75503 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 75503 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 75503 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 75504 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 75504 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 75505 T591 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 75505 T591 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 75506 T591 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 75506 T591 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 75507 T591 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 75507 T591 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 75507 T591 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 75508 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 75508 T591 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 75509 T591 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 75509 T591 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75510 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75511 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75511 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75511 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75511 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75512 T591 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 75513 T591 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 75514 T591 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 75521 T591 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 75527 T591 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 75528 T591 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> 75530 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty2
[junit4:junit4]   2> 75532 T591 oass.SolrIndexSearcher.<init> Opening Searcher@1f7b082 main
[junit4:junit4]   2> 75534 T591 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 75534 T591 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 75535 T591 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 75545 T591 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 75599 T640 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f7b082 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 75603 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 75787 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 75790 T612 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:60265_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60265/solr"}
[junit4:junit4]   2> 75802 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 75802 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 75803 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76018 T591 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 76019 T591 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:60265/solr shardId:shard2
[junit4:junit4]   2> 76021 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 76041 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:delete cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 76044 T591 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 76045 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76052 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 76052 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 76053 T591 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60265/solr/collection1/
[junit4:junit4]   2> 76053 T591 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 76054 T591 oasc.SyncStrategy.syncToMe http://127.0.0.1:60265/solr/collection1/ has no replicas
[junit4:junit4]   2> 76054 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60265/solr/collection1/
[junit4:junit4]   2> 76055 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 76060 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30005 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76225 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 76238 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76239 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76239 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76274 T591 oasc.ZkController.register We are http://127.0.0.1:60265/solr/collection1/ and leader is http://127.0.0.1:60265/solr/collection1/
[junit4:junit4]   2> 76274 T591 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60265/solr
[junit4:junit4]   2> 76274 T591 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 76275 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 76279 T591 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 76281 T591 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 76281 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 76281 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 76570 T591 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 76574 T591 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:60271
[junit4:junit4]   2> 76575 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 76575 T591 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-1351367127497
[junit4:junit4]   2> 76575 T591 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-1351367127497\'
[junit4:junit4]   2> 76609 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 76609 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 76610 T591 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-1351367127497
[junit4:junit4]   2> 76610 T591 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-1351367127497\solr.xml
[junit4:junit4]   2> 76610 T591 oasc.CoreContainer.<init> New CoreContainer 18798417
[junit4:junit4]   2> 76611 T591 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-1351367127497\'
[junit4:junit4]   2> 76611 T591 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-1351367127497\'
[junit4:junit4]   2> 76633 T591 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 76651 T591 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60243/solr
[junit4:junit4]   2> 76652 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1ba2bee
[junit4:junit4]   2> 76653 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 76654 T650 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 76655 T650 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 76655 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60276
[junit4:junit4]   2> 76656 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60276
[junit4:junit4]   2> 76666 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30006 with negotiated timeout 5000 for client /127.0.0.1:60276
[junit4:junit4]   2> 76668 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 76668 T612 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:60265_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60265/solr"}
[junit4:junit4]   2> 76672 T650 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30006, negotiated timeout = 5000
[junit4:junit4]   2> 76672 T651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ba2bee name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 76673 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 76674 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76676 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76677 T591 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60271_solr
[junit4:junit4]   2> 76678 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60271_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60271_solr
[junit4:junit4]   2> 76689 T591 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60271_solr
[junit4:junit4]   2> 76692 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76692 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76692 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76697 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76697 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76701 T627 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 76704 T591 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 76705 T591 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 76705 T591 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 76705 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 76705 T591 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 76705 T591 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 76706 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 76706 T591 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 76707 T591 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 76708 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 76711 T616 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 76711 T639 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 76713 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76715 T611 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 76719 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 76724 T591 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-1351367127497\collection1
[junit4:junit4]   2> 76725 T591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 76726 T591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 76726 T591 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 76727 T591 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-1351367127497\collection1\'
[junit4:junit4]   2> 76729 T591 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-1351367127497/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 76730 T591 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-1351367127497/collection1/lib/README' to classloader
[junit4:junit4]   2> 76779 T591 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 76851 T591 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 76852 T591 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 76857 T591 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 77541 T591 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 77552 T591 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 77555 T591 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 77572 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 77577 T591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 77583 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 77585 T591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 77587 T591 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-1351367127497\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty3\
[junit4:junit4]   2> 77587 T591 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad6b4b
[junit4:junit4]   2> 77587 T591 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 77588 T591 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for 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-1351367051207\jetty3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12e5caf; maxCacheMB=48.0 maxMergeSizeMB=4.0) assuming 'simple'
[junit4:junit4]   2> 77589 T591 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-1351367051207\jetty3 forceNew:false
[junit4:junit4]   2> 77589 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty3
[junit4:junit4]   2> 77589 T591 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207/jetty3\index/
[junit4:junit4]   2> 77590 T591 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 77590 T591 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-1351367051207\jetty3\index forceNew:false
[junit4:junit4]   2> 77599 T591 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-1351367051207\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1118a2d; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 77599 T591 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 77601 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty3\index
[junit4:junit4]   2> 77601 T591 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 77603 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 77604 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 77604 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 77604 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 77604 T591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 77605 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 77605 T591 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 77610 T591 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 77610 T591 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 77611 T591 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 77612 T591 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 77612 T591 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 77612 T591 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 77613 T591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 77613 T591 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 77614 T591 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 77614 T591 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77615 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77615 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77616 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77616 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77616 T591 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77617 T591 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77617 T591 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 77618 T591 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 77625 T591 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 77630 T591 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 77631 T591 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> 77634 T591 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZkTest-1351367051207\jetty3
[junit4:junit4]   2> 77637 T591 oass.SolrIndexSearcher.<init> Opening Searcher@18054fe main
[junit4:junit4]   2> 77639 T591 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 77639 T591 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 77639 T591 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 77649 T591 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 77704 T652 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18054fe main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 77707 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 77952 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 77953 T612 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:60271_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60271/solr"}
[junit4:junit4]   2> 77958 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 77958 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 77959 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 77959 T651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78122 T591 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 78123 T591 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:60271/solr shardId:shard1
[junit4:junit4]   2> 78124 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 78143 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 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> 78145 T591 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 78147 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 78153 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   2> 78377 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 78384 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78385 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78385 T651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78385 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78566 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179586
[junit4:junit4]   2> 78980 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179172
[junit4:junit4]   2> 79394 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178758
[junit4:junit4]   2> 79808 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178344
[junit4:junit4]   2> 80221 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177931
[junit4:junit4]   2> 80635 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177517
[junit4:junit4]   2> 81044 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177108
[junit4:junit4]   2> 81416 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176736
[junit4:junit4]   2> 81788 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176364
[junit4:junit4]   2> 82162 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175990
[junit4:junit4]   2> 82534 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175618
[junit4:junit4]   2> 82906 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175246
[junit4:junit4]   2> 83279 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174873
[junit4:junit4]   2> 83652 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174500
[junit4:junit4]   2> 84024 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174128
[junit4:junit4]   2> 84396 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173756
[junit4:junit4]   2> 84768 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173384
[junit4:junit4]   2> 85141 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173011
[junit4:junit4]   2> 85514 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172638
[junit4:junit4]   2> 85888 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172264
[junit4:junit4]   2> 86260 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171892
[junit4:junit4]   2> 86633 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171519
[junit4:junit4]   2> 87005 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171147
[junit4:junit4]   2> 87378 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170774
[junit4:junit4]   2> 87751 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170401
[junit4:junit4]   2> 88124 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170028
[junit4:junit4]   2> 88522 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169630
[junit4:junit4]   2> 89024 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169128
[junit4:junit4]   2> 89525 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168627
[junit4:junit4]   2> 90026 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168126
[junit4:junit4]   2> 90528 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167624
[junit4:junit4]   2> 91032 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167120
[junit4:junit4]   2> 91534 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166618
[junit4:junit4]   2> 92036 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166116
[junit4:junit4]   2> 92538 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165614
[junit4:junit4]   2> 93038 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165114
[junit4:junit4]   2> 93538 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164614
[junit4:junit4]   2> 94040 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164112
[junit4:junit4]   2> 94541 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163611
[junit4:junit4]   2> 95043 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163109
[junit4:junit4]   2> 95545 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162607
[junit4:junit4]   2> 96047 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162105
[junit4:junit4]   2> 96549 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161603
[junit4:junit4]   2> 97050 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161102
[junit4:junit4]   2> 97551 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160601
[junit4:junit4]   2> 98053 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160099
[junit4:junit4]   2> 98568 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159584
[junit4:junit4]   2> 99120 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159032
[junit4:junit4]   2> 99672 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158480
[junit4:junit4]   2> 100223 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157929
[junit4:junit4]   2> 100774 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157378
[junit4:junit4]   2> 101325 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156827
[junit4:junit4]   2> 101879 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156273
[junit4:junit4]   2> 102430 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155722
[junit4:junit4]   2> 102981 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155171
[junit4:junit4]   2> 103532 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154620
[junit4:junit4]   2> 104083 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154069
[junit4:junit4]   2> 104635 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153517
[junit4:junit4]   2> 105187 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152965
[junit4:junit4]   2> 105739 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152413
[junit4:junit4]   2> 106290 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151862
[junit4:junit4]   2> 106843 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151309
[junit4:junit4]   2> 107394 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150758
[junit4:junit4]   2> 107945 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150207
[junit4:junit4]   2> 108497 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149655
[junit4:junit4]   2> 109049 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149103
[junit4:junit4]   2> 109583 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148569
[junit4:junit4]   2> 110080 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148072
[junit4:junit4]   2> 110576 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147576
[junit4:junit4]   2> 111072 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147080
[junit4:junit4]   2> 111569 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146583
[junit4:junit4]   2> 112065 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146087
[junit4:junit4]   2> 112562 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145590
[junit4:junit4]   2> 113059 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145093
[junit4:junit4]   2> 113555 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144597
[junit4:junit4]   2> 114051 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144101
[junit4:junit4]   2> 114547 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143605
[junit4:junit4]   2> 115043 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143109
[junit4:junit4]   2> 115540 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142612
[junit4:junit4]   2> 116036 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142116
[junit4:junit4]   2> 116532 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141620
[junit4:junit4]   2> 117029 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141123
[junit4:junit4]   2> 117526 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140626
[junit4:junit4]   2> 118022 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140130
[junit4:junit4]   2> 118519 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139633
[junit4:junit4]   2> 119016 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139136
[junit4:junit4]   2> 119514 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138638
[junit4:junit4]   2> 120015 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138137
[junit4:junit4]   2> 120517 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137635
[junit4:junit4]   2> 121018 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137134
[junit4:junit4]   2> 121518 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136634
[junit4:junit4]   2> 122020 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136132
[junit4:junit4]   2> 122522 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135630
[junit4:junit4]   2> 123023 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135129
[junit4:junit4]   2> 123525 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134627
[junit4:junit4]   2> 124027 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134125
[junit4:junit4]   2> 124528 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133624
[junit4:junit4]   2> 125030 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133122
[junit4:junit4]   2> 125532 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132620
[junit4:junit4]   2> 126034 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132118
[junit4:junit4]   2> 126536 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131616
[junit4:junit4]   2> 127037 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131115
[junit4:junit4]   2> 127538 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130614
[junit4:junit4]   2> 128040 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130112
[junit4:junit4]   2> 128542 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129610
[junit4:junit4]   2> 129044 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129108
[junit4:junit4]   2> 129567 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128585
[junit4:junit4]   2> 130118 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128034
[junit4:junit4]   2> 130669 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127483
[junit4:junit4]   2> 131219 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126933
[junit4:junit4]   2> 131771 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126381
[junit4:junit4]   2> 132322 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125830
[junit4:junit4]   2> 132874 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125278
[junit4:junit4]   2> 133425 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124727
[junit4:junit4]   2> 133975 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124177
[junit4:junit4]   2> 134527 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123625
[junit4:junit4]   2> 135078 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123074
[junit4:junit4]   2> 135629 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122523
[junit4:junit4]   2> 136180 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121972
[junit4:junit4]   2> 136733 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121419
[junit4:junit4]   2> 137284 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120868
[junit4:junit4]   2> 137836 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120316
[junit4:junit4]   2> 138388 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119764
[junit4:junit4]   2> 138939 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119213
[junit4:junit4]   2> 139490 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118662
[junit4:junit4]   2> 140042 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118110
[junit4:junit4]   2> 140567 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117585
[junit4:junit4]   2> 141063 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117089
[junit4:junit4]   2> 141558 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116594
[junit4:junit4]   2> 142053 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116099
[junit4:junit4]   2> 142550 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115602
[junit4:junit4]   2> 143046 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115106
[junit4:junit4]   2> 143543 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114609
[junit4:junit4]   2> 144040 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114112
[junit4:junit4]   2> 144537 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113615
[junit4:junit4]   2> 145033 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113119
[junit4:junit4]   2> 145530 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112622
[junit4:junit4]   2> 146027 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112125
[junit4:junit4]   2> 146523 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111629
[junit4:junit4]   2> 147020 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111132
[junit4:junit4]   2> 147516 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110636
[junit4:junit4]   2> 148012 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110140
[junit4:junit4]   2> 148509 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109643
[junit4:junit4]   2> 149004 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109148
[junit4:junit4]   2> 149500 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108652
[junit4:junit4]   2> 149996 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108156
[junit4:junit4]   2> 150495 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107657
[junit4:junit4]   2> 150997 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107155
[junit4:junit4]   2> 151499 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106653
[junit4:junit4]   2> 152001 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106151
[junit4:junit4]   2> 152501 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105651
[junit4:junit4]   2> 153002 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105150
[junit4:junit4]   2> 153504 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104648
[junit4:junit4]   2> 154005 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104147
[junit4:junit4]   2> 154505 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103647
[junit4:junit4]   2> 155006 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103146
[junit4:junit4]   2> 155508 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102644
[junit4:junit4]   2> 156010 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102142
[junit4:junit4]   2> 156512 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101640
[junit4:junit4]   2> 157014 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101138
[junit4:junit4]   2> 157516 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100636
[junit4:junit4]   2> 158018 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100134
[junit4:junit4]   2> 158520 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99632
[junit4:junit4]   2> 159021 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99131
[junit4:junit4]   2> 159523 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98629
[junit4:junit4]   2> 160023 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98129
[junit4:junit4]   2> 160555 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97597
[junit4:junit4]   2> 161106 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97046
[junit4:junit4]   2> 161656 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96496
[junit4:junit4]   2> 162208 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95944
[junit4:junit4]   2> 162759 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95393
[junit4:junit4]   2> 163310 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94842
[junit4:junit4]   2> 163862 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94290
[junit4:junit4]   2> 164415 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93737
[junit4:junit4]   2> 164966 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93186
[junit4:junit4]   2> 165518 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92634
[junit4:junit4]   2> 166072 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92080
[junit4:junit4]   2> 166624 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91528
[junit4:junit4]   2> 167175 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90977
[junit4:junit4]   2> 167726 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90426
[junit4:junit4]   2> 168278 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89874
[junit4:junit4]   2> 168828 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89324
[junit4:junit4]   2> 169380 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88772
[junit4:junit4]   2> 169932 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88220
[junit4:junit4]   2> 170483 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87669
[junit4:junit4]   2> 171034 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87118
[junit4:junit4]   2> 171549 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86603
[junit4:junit4]   2> 172046 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86106
[junit4:junit4]   2> 172542 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85610
[junit4:junit4]   2> 173037 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85115
[junit4:junit4]   2> 173532 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84620
[junit4:junit4]   2> 174027 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84125
[junit4:junit4]   2> 174524 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83628
[junit4:junit4]   2> 175021 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83131
[junit4:junit4]   2> 175517 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82635
[junit4:junit4]   2> 176012 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82140
[junit4:junit4]   2> 176509 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81643
[junit4:junit4]   2> 177004 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81148
[junit4:junit4]   2> 177500 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80652
[junit4:junit4]   2> 177996 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80156
[junit4:junit4]   2> 178491 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79661
[junit4:junit4]   2> 178987 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79165
[junit4:junit4]   2> 179484 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78668
[junit4:junit4]   2> 179981 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78171
[junit4:junit4]   2> 180479 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77673
[junit4:junit4]   2> 180976 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77176
[junit4:junit4]   2> 181438 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76714
[junit4:junit4]   2> 181886 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76266
[junit4:junit4]   2> 182333 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75819
[junit4:junit4]   2> 182780 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75372
[junit4:junit4]   2> 183227 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74925
[junit4:junit4]   2> 183673 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74479
[junit4:junit4]   2> 184121 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74031
[junit4:junit4]   2> 184566 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73586
[junit4:junit4]   2> 185013 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73139
[junit4:junit4]   2> 185461 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72691
[junit4:junit4]   2> 185908 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72244
[junit4:junit4]   2> 186355 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71797
[junit4:junit4]   2> 186801 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71351
[junit4:junit4]   2> 187249 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70903
[junit4:junit4]   2> 187696 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70456
[junit4:junit4]   2> 188143 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70009
[junit4:junit4]   2> 188591 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69561
[junit4:junit4]   2> 189037 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69115
[junit4:junit4]   2> 189483 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68669
[junit4:junit4]   2> 189930 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68222
[junit4:junit4]   2> 190412 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67740
[junit4:junit4]   2> 190904 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67248
[junit4:junit4]   2> 191395 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66757
[junit4:junit4]   2> 191885 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66267
[junit4:junit4]   2> 192377 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65775
[junit4:junit4]   2> 192868 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65284
[junit4:junit4]   2> 193360 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64792
[junit4:junit4]   2> 193851 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64301
[junit4:junit4]   2> 194342 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63810
[junit4:junit4]   2> 194834 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63318
[junit4:junit4]   2> 195326 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62826
[junit4:junit4]   2> 195818 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62334
[junit4:junit4]   2> 196311 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61841
[junit4:junit4]   2> 196803 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61349
[junit4:junit4]   2> 197295 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60857
[junit4:junit4]   2> 197787 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60365
[junit4:junit4]   2> 198280 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59872
[junit4:junit4]   2> 198772 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59380
[junit4:junit4]   2> 199265 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58887
[junit4:junit4]   2> 199757 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58395
[junit4:junit4]   2> 200290 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57862
[junit4:junit4]   2> 200831 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57321
[junit4:junit4]   2> 201372 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56780
[junit4:junit4]   2> 201913 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56239
[junit4:junit4]   2> 202453 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55699
[junit4:junit4]   2> 202995 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55157
[junit4:junit4]   2> 203536 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54616
[junit4:junit4]   2> 204077 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54075
[junit4:junit4]   2> 204618 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53534
[junit4:junit4]   2> 205158 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52994
[junit4:junit4]   2> 205698 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52454
[junit4:junit4]   2> 206238 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51914
[junit4:junit4]   2> 206779 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51373
[junit4:junit4]   2> 207321 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50831
[junit4:junit4]   2> 207862 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50290
[junit4:junit4]   2> 208403 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49749
[junit4:junit4]   2> 208943 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49209
[junit4:junit4]   2> 209484 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48668
[junit4:junit4]   2> 210023 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48129
[junit4:junit4]   2> 210563 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47589
[junit4:junit4]   2> 211153 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46999
[junit4:junit4]   2> 211747 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46405
[junit4:junit4]   2> 212341 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45811
[junit4:junit4]   2> 212935 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45217
[junit4:junit4]   2> 213531 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44621
[junit4:junit4]   2> 214126 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44026
[junit4:junit4]   2> 214722 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43430
[junit4:junit4]   2> 215318 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42834
[junit4:junit4]   2> 215911 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42241
[junit4:junit4]   2> 216507 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41645
[junit4:junit4]   2> 217100 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41052
[junit4:junit4]   2> 217694 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40458
[junit4:junit4]   2> 218288 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39864
[junit4:junit4]   2> 218883 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39269
[junit4:junit4]   2> 219480 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38672
[junit4:junit4]   2> 220075 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38077
[junit4:junit4]   2> 220668 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37484
[junit4:junit4]   2> 221261 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36891
[junit4:junit4]   2> 221855 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36297
[junit4:junit4]   2> 222453 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35699
[junit4:junit4]   2> 222989 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35163
[junit4:junit4]   2> 223524 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34628
[junit4:junit4]   2> 224060 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34092
[junit4:junit4]   2> 224596 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33556
[junit4:junit4]   2> 225132 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33020
[junit4:junit4]   2> 225666 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32486
[junit4:junit4]   2> 226202 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31950
[junit4:junit4]   2> 226738 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31414
[junit4:junit4]   2> 227274 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30878
[junit4:junit4]   2> 227808 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30344
[junit4:junit4]   2> 228343 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29809
[junit4:junit4]   2> 228878 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29274
[junit4:junit4]   2> 229412 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28740
[junit4:junit4]   2> 229947 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28205
[junit4:junit4]   2> 230483 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27669
[junit4:junit4]   2> 231019 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27133
[junit4:junit4]   2> 231554 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26598
[junit4:junit4]   2> 232091 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26061
[junit4:junit4]   2> 232626 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25526
[junit4:junit4]   2> 233159 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24993
[junit4:junit4]   2> 233641 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24511
[junit4:junit4]   2> 234124 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24028
[junit4:junit4]   2> 234606 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23546
[junit4:junit4]   2> 235088 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23064
[junit4:junit4]   2> 235569 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22583
[junit4:junit4]   2> 236050 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22102
[junit4:junit4]   2> 236532 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21620
[junit4:junit4]   2> 237014 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21138
[junit4:junit4]   2> 237496 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20656
[junit4:junit4]   2> 237977 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20175
[junit4:junit4]   2> 238460 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19692
[junit4:junit4]   2> 238942 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19210
[junit4:junit4]   2> 239423 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18729
[junit4:junit4]   2> 239904 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18248
[junit4:junit4]   2> 240386 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17766
[junit4:junit4]   2> 240868 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17284
[junit4:junit4]   2> 241349 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16803
[junit4:junit4]   2> 241830 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16322
[junit4:junit4]   2> 242311 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15841
[junit4:junit4]   2> 242791 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15361
[junit4:junit4]   2> 243225 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14927
[junit4:junit4]   2> 243657 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14495
[junit4:junit4]   2> 244091 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14061
[junit4:junit4]   2> 244524 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13628
[junit4:junit4]   2> 244957 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13195
[junit4:junit4]   2> 245391 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12761
[junit4:junit4]   2> 245824 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12328
[junit4:junit4]   2> 246257 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11895
[junit4:junit4]   2> 246690 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11462
[junit4:junit4]   2> 247123 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11029
[junit4:junit4]   2> 247557 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10595
[junit4:junit4]   2> 247991 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10161
[junit4:junit4]   2> 248424 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9728
[junit4:junit4]   2> 248858 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9294
[junit4:junit4]   2> 249292 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8860
[junit4:junit4]   2> 249725 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8427
[junit4:junit4]   2> 250158 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7994
[junit4:junit4]   2> 250592 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7560
[junit4:junit4]   2> 251025 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7127
[junit4:junit4]   2> 251465 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6687
[junit4:junit4]   2> 251940 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6212
[junit4:junit4]   2> 252418 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5734
[junit4:junit4]   2> 252894 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5258
[junit4:junit4]   2> 253371 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4781
[junit4:junit4]   2> 253849 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4303
[junit4:junit4]   2> 254325 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3827
[junit4:junit4]   2> 254804 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3348
[junit4:junit4]   2> 255279 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2873
[junit4:junit4]   2> 255756 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2396
[junit4:junit4]   2> 256233 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1919
[junit4:junit4]   2> 256709 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1443
[junit4:junit4]   2> 257187 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=965
[junit4:junit4]   2> 257663 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=489
[junit4:junit4]   2> 258140 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12
[junit4:junit4]   2> 258627 T591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=-475
[junit4:junit4]   2> 258628 T591 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> 258630 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 258631 T591 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60271/solr/collection1/
[junit4:junit4]   2> 258641 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 258658 T591 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60271/solr START replicas=[http://127.0.0.1:60259/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 258659 T591 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60271/solr DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 258659 T591 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 258660 T591 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> 258662 T591 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60271/solr/collection1/
[junit4:junit4]   2> 258662 T591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 258678 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30006 type:create cxid:0x1b7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 258751 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 258769 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 258770 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 258770 T651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 258769 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 258778 T591 oasc.ZkController.register We are http://127.0.0.1:60271/solr/collection1/ and leader is http://127.0.0.1:60271/solr/collection1/
[junit4:junit4]   2> 258779 T591 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60271/solr
[junit4:junit4]   2> 258779 T591 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 258781 T591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 258789 T591 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 258790 T591 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 258792 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 258793 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 259130 T591 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 259135 T591 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:60278
[junit4:junit4]   2> 259136 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 259137 T591 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-1351367310006
[junit4:junit4]   2> 259137 T591 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-1351367310006\'
[junit4:junit4]   2> 259173 T591 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 259173 T591 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 259174 T591 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-1351367310006
[junit4:junit4]   2> 259174 T591 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-1351367310006\solr.xml
[junit4:junit4]   2> 259174 T591 oasc.CoreContainer.<init> New CoreContainer 14801571
[junit4:junit4]   2> 259175 T591 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-1351367310006\'
[junit4:junit4]   2> 259176 T591 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-1351367310006\'
[junit4:junit4]   2> 259197 T591 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 259215 T591 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60243/solr
[junit4:junit4]   2> 259216 T591 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60243/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@79ac99
[junit4:junit4]   2> 259217 T663 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:60243
[junit4:junit4]   2> 259217 T591 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 259219 T663 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:60243, initiating session
[junit4:junit4]   2> 259219 T593 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:60283
[junit4:junit4]   2> 259220 T593 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:60283
[junit4:junit4]   2> 259232 T595 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa3c0c7d30007 with negotiated timeout 5000 for client /127.0.0.1:60283
[junit4:junit4]   2> 259232 T663 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:60243, sessionid = 0x13aa3c0c7d30007, negotiated timeout = 5000
[junit4:junit4]   2> 259232 T664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79ac99 name:ZooKeeperConnection Watcher:127.0.0.1:60243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 259232 T591 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 259233 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30007 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 259236 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30007 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 259238 T591 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60278_solr
[junit4:junit4]   2> 259239 T596 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa3c0c7d30007 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60278_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60278_solr
[junit4:junit4]   2> 259240 T591 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60278_solr
[junit4:junit4]   2> 259244 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 259244 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 259244 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 259246 T651 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 259247 T651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259247 T616 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 259246 T627 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 259246 T591 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 259247 T591 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 259248 T591 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 259248 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 259248 T639 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 259249 T591 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 259249 T611 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 259250 T591 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 259250 T591 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 259251 T591 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 259251 T591 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 259251 T591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 259260 T612 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 259262 T612 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:60271_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60271/solr"}
[junit4:junit4]   2> 259265 T591 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 259271 T664 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259271 T611 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259271 T616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259273 T639 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259271 T651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 259276 T591 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-1351367310006\collection1
[junit4:junit4]   2> 259276 T591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 259278 T591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 259278 T591 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 259281 T591 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-1351367310006\collection1\'
[junit4:junit4]   2> 259283 T591 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-1351367310006/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 259284 T591 oasc.Sol

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

tedZkTest: 
[junit4:junit4]   2> 	   1) Thread[id=628, name=searcherExecutor-390-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> 1037776 T590 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4:junit4]   2> 	   1) Thread[id=628, name=searcherExecutor-390-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4]   2> 1041679 T590 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4:junit4]   2> 	   1) Thread[id=628, name=searcherExecutor-390-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=Lucene40, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ca, timezone=Europe/Tirane
[junit4:junit4]   2> NOTE: Windows 7 6.1 x86/Sun Microsystems Inc. 1.6.0_35 (32-bit)/cpus=2,threads=2,free=59728664,total=109854720
[junit4:junit4]   2> NOTE: All tests run in this JVM: [NumericFieldsTest, TestMultiCoreConfBootstrap, TestAnalyzedSuggestions, HighlighterTest, TestCodecSupport, SimplePostToolTest, TestExtendedDismaxParser, TestPropInjectDefaults, JSONWriterTest, TestPhraseSuggestions, TestCollationField, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, ScriptEngineTest, SolrRequestParserTest, TestSolrJ, TestCSVResponseWriter, ZkCLITest, TestRangeQuery, LegacyHTMLStripCharFilterTest, TestPHPSerializedResponseWriter, DocumentAnalysisRequestHandlerTest, TestStressReorder, LeaderElectionIntegrationTest, CircularListTest, TestElisionMultitermQuery, TestSolr4Spatial, RAMDirectoryFactoryTest, XmlUpdateRequestHandlerTest, SimpleFacetsTest, FieldMutatingUpdateProcessorTest, SuggesterWFSTTest, ConvertedLegacyTest, MoreLikeThisHandlerTest, ZkSolrClientTest, TestReplicationHandler, SolrInfoMBeanTest, TestCharFilters, BasicDistributedZkTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=3C2D05D42C2AAA16 -Dtests.slow=true -Dtests.locale=ca -Dtests.timezone=Europe/Tirane -Dtests.file.encoding=ISO-8859-1
[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([3C2D05D42C2AAA16]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:243)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
[junit4:junit4]    > 	at sun.reflect.GeneratedMethodAccessor24.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=628, name=searcherExecutor-390-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([3C2D05D42C2AAA16]:0)
[junit4:junit4]    > Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4:junit4]    >    1) Thread[id=628, name=searcherExecutor-390-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([3C2D05D42C2AAA16]:0)
[junit4:junit4] Completed in 1041.74s, 1 test, 2 failures, 2 errors <<< FAILURES!

[...truncated 583 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:1159: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:827: There were test failures: 232 suites, 961 tests, 3 suite-level errors, 1 failure, 661 ignored (2 assumptions)

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



Mime
View raw message