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-4.x-Windows (64bit/jdk1.6.0_35) - Build # 1343 - Failure!
Date Mon, 29 Oct 2012 00:15:24 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Windows/1343/
Java: 64bit/jdk1.6.0_35 -XX:+UseSerialGC

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

Error Message:
There are still nodes recoverying - waited for 15 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 15 seconds
	at __randomizedtesting.SeedInfo.seed([B0392E85CBD56EB2:31DFA09DBC8A0E8E]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:156)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:558)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1133)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:89)
	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.SyncSliceTest

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

Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=8 closes=7
	at __randomizedtesting.SeedInfo.seed([B0392E85CBD56EB2]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:242)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
	at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:662)


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

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.SyncSliceTest:     1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]         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.SyncSliceTest: 
   1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
        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([B0392E85CBD56EB2]:0)


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

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]         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=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
        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([B0392E85CBD56EB2]:0)




Build Log:
[...truncated 7766 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 3 T458 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-SyncSliceTest-1351469261134
[junit4:junit4]   2> 4 T458 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T459 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 8 T459 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 8 T459 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 77 T458 oasc.ZkTestServer.run start zk server on port:64512
[junit4:junit4]   2> 77 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4c3f0a0e
[junit4:junit4]   2> 78 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 78 T464 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 79 T464 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 79 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64515
[junit4:junit4]   2> 80 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64515
[junit4:junit4]   2> 80 T462 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 87 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530000 with negotiated timeout 10000 for client /127.0.0.1:64515
[junit4:junit4]   2> 87 T464 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530000, negotiated timeout = 10000
[junit4:junit4]   2> 88 T465 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c3f0a0e name:ZooKeeperConnection Watcher:127.0.0.1:64512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 88 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 89 T458 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 91 T463 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13aa9d861530000
[junit4:junit4]   2> 93 T458 oaz.ZooKeeper.close Session: 0x13aa9d861530000 closed
[junit4:junit4]   2> 93 T460 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:64515 which had sessionid 0x13aa9d861530000
[junit4:junit4]   2> 93 T465 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 93 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@103e0909
[junit4:junit4]   2> 96 T466 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 96 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 96 T466 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 97 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64518
[junit4:junit4]   2> 97 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64518
[junit4:junit4]   2> 98 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530001 with negotiated timeout 10000 for client /127.0.0.1:64518
[junit4:junit4]   2> 98 T466 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530001, negotiated timeout = 10000
[junit4:junit4]   2> 99 T467 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@103e0909 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 99 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 100 T458 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 103 T458 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 107 T458 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 109 T458 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 112 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 113 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 119 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 119 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 124 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 124 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 128 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 128 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 131 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 131 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 135 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 135 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 139 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 139 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 142 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 142 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 146 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 146 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 150 T458 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 150 T458 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 153 T463 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13aa9d861530001
[junit4:junit4]   2> 154 T458 oaz.ZooKeeper.close Session: 0x13aa9d861530001 closed
[junit4:junit4]   2> 154 T460 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:64518 which had sessionid 0x13aa9d861530001
[junit4:junit4]   2> 154 T467 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 156 T458 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 160 T458 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:64519
[junit4:junit4]   2> 161 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 161 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr
[junit4:junit4]   2> 161 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\'
[junit4:junit4]   2> 183 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 184 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 184 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr
[junit4:junit4]   2> 184 T458 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\solr.xml
[junit4:junit4]   2> 185 T458 oasc.CoreContainer.<init> New CoreContainer 1067975098
[junit4:junit4]   2> 186 T458 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\'
[junit4:junit4]   2> 186 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\'
[junit4:junit4]   2> 201 T458 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 213 T458 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:64512/solr
[junit4:junit4]   2> 213 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@17694e84
[junit4:junit4]   2> 215 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 217 T477 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 218 T477 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 219 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64524
[junit4:junit4]   2> 219 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64524
[junit4:junit4]   2> 225 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530002 with negotiated timeout 5000 for client /127.0.0.1:64524
[junit4:junit4]   2> 225 T477 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530002, negotiated timeout = 5000
[junit4:junit4]   2> 225 T478 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17694e84 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 226 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 228 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 230 T458 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 234 T458 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64519_solr
[junit4:junit4]   2> 234 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64519_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64519_solr
[junit4:junit4]   2> 236 T458 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64519_solr
[junit4:junit4]   2> 239 T458 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 239 T458 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 239 T458 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 240 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 240 T458 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 240 T458 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 240 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 240 T458 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 241 T458 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 241 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 248 T458 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 254 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 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> 255 T458 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 257 T458 oasc.Overseer.start Overseer (id=88569889498005506-127.0.0.1:64519_solr-n_0000000000) starting
[junit4:junit4]   2> 258 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 259 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 260 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 262 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 263 T480 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 264 T458 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 266 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 271 T458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1
[junit4:junit4]   2> 272 T479 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 272 T458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 273 T458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 273 T458 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 274 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\'
[junit4:junit4]   2> 276 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 276 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 313 T458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 356 T458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 357 T458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 362 T458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 864 T458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 871 T458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 874 T458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 889 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 894 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 902 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 903 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 905 T458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/control/data\
[junit4:junit4]   2> 905 T458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@395d601f
[junit4:junit4]   2> 925 T458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/control/data\index/
[junit4:junit4]   2> 926 T458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351469261133\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 927 T458 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.SyncSliceTest-1351469261133\control\data\index forceNew:false
[junit4:junit4]   2> 935 T458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1351469261133\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b72c45d; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 935 T458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 938 T458 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 939 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 939 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 940 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 940 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 941 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 941 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 941 T458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 941 T458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 941 T458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 942 T458 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 942 T458 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 942 T458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 943 T458 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 943 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 943 T458 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 943 T458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 943 T458 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 945 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 945 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 945 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 945 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 945 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 947 T458 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 947 T458 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 948 T458 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 954 T458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 960 T458 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 962 T458 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> 966 T458 oass.SolrIndexSearcher.<init> Opening Searcher@16f5e10a main
[junit4:junit4]   2> 967 T458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 968 T458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 969 T458 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 976 T458 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1018 T481 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16f5e10a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1020 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1020 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 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> 1025 T458 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1025 T458 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:64519/solr shardId:control_shard
[junit4:junit4]   2> 1025 T458 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1034 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 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> 1036 T458 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1037 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1355 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1357 T479 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:64519_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64519/solr"}
[junit4:junit4]   2> 1358 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 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> 1384 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 1400 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1400 T458 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1401 T458 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64519/solr/collection1/
[junit4:junit4]   2> 1402 T458 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1402 T458 oasc.SyncStrategy.syncToMe http://127.0.0.1:64519/solr/collection1/ has no replicas
[junit4:junit4]   2> 1402 T458 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64519/solr/collection1/
[junit4:junit4]   2> 1403 T458 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1411 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530002 type:create cxid:0x8b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1754 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1762 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 1778 T458 oasc.ZkController.register We are http://127.0.0.1:64519/solr/collection1/ and leader is http://127.0.0.1:64519/solr/collection1/
[junit4:junit4]   2> 1778 T458 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64519/solr
[junit4:junit4]   2> 1779 T458 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 1779 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1781 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1782 T458 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 1782 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1783 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2041 T458 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2044 T458 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:64525
[junit4:junit4]   2> 2046 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2046 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921
[junit4:junit4]   2> 2046 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\'
[junit4:junit4]   2> 2070 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2070 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2071 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921
[junit4:junit4]   2> 2071 T458 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\solr.xml
[junit4:junit4]   2> 2071 T458 oasc.CoreContainer.<init> New CoreContainer 267745359
[junit4:junit4]   2> 2072 T458 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\'
[junit4:junit4]   2> 2072 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\'
[junit4:junit4]   2> 2087 T458 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2102 T458 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:64512/solr
[junit4:junit4]   2> 2103 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@20700fb1
[junit4:junit4]   2> 2104 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2104 T491 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 2106 T491 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 2106 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64530
[junit4:junit4]   2> 2106 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64530
[junit4:junit4]   2> 2114 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530003 with negotiated timeout 5000 for client /127.0.0.1:64530
[junit4:junit4]   2> 2114 T491 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530003, negotiated timeout = 5000
[junit4:junit4]   2> 2114 T492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20700fb1 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2114 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2115 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2116 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2118 T458 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64525_solr
[junit4:junit4]   2> 2118 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64525_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64525_solr
[junit4:junit4]   2> 2119 T458 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64525_solr
[junit4:junit4]   2> 2122 T478 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2123 T458 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2123 T458 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2123 T458 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2123 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2124 T458 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2124 T458 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2125 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2125 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2125 T458 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2125 T479 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:64519_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64519/solr"}
[junit4:junit4]   2> 2126 T458 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2126 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2135 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2139 T492 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> 2139 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 2142 T458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\collection1
[junit4:junit4]   2> 2143 T458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2144 T458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2144 T458 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2146 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\collection1\'
[junit4:junit4]   2> 2147 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty1-1351469262921/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2148 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty1-1351469262921/collection1/lib/README' to classloader
[junit4:junit4]   2> 2186 T458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 2248 T458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2250 T458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2255 T458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2777 T458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2785 T458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2788 T458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2806 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2810 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2815 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2817 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2818 T458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351469262921\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty1\
[junit4:junit4]   2> 2818 T458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@395d601f
[junit4:junit4]   2> 2819 T458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty1\index/
[junit4:junit4]   2> 2821 T458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2821 T458 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty1\index forceNew:false
[junit4:junit4]   2> 2829 T458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@f1917cf; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2829 T458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 2830 T458 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2834 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2834 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2834 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2835 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2835 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2835 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2835 T458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2835 T458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2836 T458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2836 T458 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2837 T458 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2837 T458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2837 T458 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2837 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2837 T458 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2839 T458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2839 T458 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2839 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2839 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2841 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2842 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2842 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2843 T458 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2843 T458 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2844 T458 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2851 T458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2854 T458 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2855 T458 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> 2858 T458 oass.SolrIndexSearcher.<init> Opening Searcher@6ddf1547 main
[junit4:junit4]   2> 2860 T458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2861 T458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2861 T458 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2870 T458 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2917 T493 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ddf1547 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2919 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3223 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3224 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[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:64525_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64525/solr"}
[junit4:junit4]   2> 3224 T479 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 3229 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 51649 T458 oasc.SolrException.log SEVERE null:org.apache.solr.common.SolrException: Could not get shard_id for core: collection1
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.doGetShardIdProcess(ZkController.java:996)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.preRegister(ZkController.java:1054)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.register(CoreContainer.java:657)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:530)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:351)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer$Initializer.initialize(CoreContainer.java:303)
[junit4:junit4]   2> 		at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:107)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.FilterHolder.doStart(FilterHolder.java:114)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:59)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:754)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.updateMappings(ServletHandler.java:1227)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.setFilterMappings(ServletHandler.java:1263)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:965)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:923)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletContextHandler.addFilter(ServletContextHandler.java:333)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner$1.lifeCycleStarted(JettySolrRunner.java:173)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.setStarted(AbstractLifeCycle.java:169)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:60)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:225)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:205)
[junit4:junit4]   2> 		at org.apache.solr.BaseDistributedSearchTestCase.createJetty(BaseDistributedSearchTestCase.java:262)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createJettys(AbstractFullDistribZkTestBase.java:294)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:268)
[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> 51650 T458 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 51651 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 51651 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 52018 T458 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 52021 T458 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:64531
[junit4:junit4]   2> 52022 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 52022 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790
[junit4:junit4]   2> 52022 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\'
[junit4:junit4]   2> 52054 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 52054 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 52055 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790
[junit4:junit4]   2> 52055 T458 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\solr.xml
[junit4:junit4]   2> 52055 T458 oasc.CoreContainer.<init> New CoreContainer 1464500214
[junit4:junit4]   2> 52056 T458 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\'
[junit4:junit4]   2> 52060 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\'
[junit4:junit4]   2> 52081 T458 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 52097 T458 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:64512/solr
[junit4:junit4]   2> 52099 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@6eee1e2
[junit4:junit4]   2> 52100 T503 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 52100 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 52103 T503 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 52103 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64536
[junit4:junit4]   2> 52104 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64536
[junit4:junit4]   2> 52122 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530004 with negotiated timeout 5000 for client /127.0.0.1:64536
[junit4:junit4]   2> 52122 T503 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530004, negotiated timeout = 5000
[junit4:junit4]   2> 52123 T504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6eee1e2 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 52123 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 52124 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 52126 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 52128 T458 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64531_solr
[junit4:junit4]   2> 52128 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64531_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64531_solr
[junit4:junit4]   2> 52130 T458 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64531_solr
[junit4:junit4]   2> 52134 T492 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 52134 T478 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 52134 T458 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 52134 T458 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 52134 T458 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 52134 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 52135 T458 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 52135 T458 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 52137 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 52137 T458 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 52137 T458 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 52137 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 52147 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 52152 T458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\collection1
[junit4:junit4]   2> 52152 T458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 52154 T458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 52154 T458 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 52156 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\collection1\'
[junit4:junit4]   2> 52157 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty2-1351469312790/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 52158 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty2-1351469312790/collection1/lib/README' to classloader
[junit4:junit4]   2> 52213 T458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 52291 T458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 52293 T458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 52300 T458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 52991 T458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 53000 T458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 53003 T458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 53021 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 53026 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 53030 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 53033 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 53034 T458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351469312790\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty2\
[junit4:junit4]   2> 53034 T458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@395d601f
[junit4:junit4]   2> 53036 T458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty2\index/
[junit4:junit4]   2> 53037 T458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 53038 T458 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty2\index forceNew:false
[junit4:junit4]   2> 53048 T458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6a00409e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 53048 T458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 53050 T458 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 53052 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 53052 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 53053 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 53053 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 53054 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 53054 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 53055 T458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 53055 T458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 53056 T458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 53056 T458 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 53057 T458 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 53058 T458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 53058 T458 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 53058 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 53059 T458 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 53061 T458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 53062 T458 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53063 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53064 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53065 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53065 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53066 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53067 T458 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 53068 T458 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 53069 T458 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 53082 T458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 53088 T458 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 53089 T458 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> 53096 T458 oass.SolrIndexSearcher.<init> Opening Searcher@18879c56 main
[junit4:junit4]   2> 53098 T458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 53099 T458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 53099 T458 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 53111 T458 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 53170 T505 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18879c56 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 53174 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 53402 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 53403 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[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:64531_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64531/solr"}
[junit4:junit4]   2> 53415 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 53417 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 53696 T458 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 53696 T458 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:64531/solr shardId:shard1
[junit4:junit4]   2> 53697 T458 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 53710 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 53712 T458 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 53713 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 53717 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   2> 53945 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 53953 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 53954 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 54238 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179478
[junit4:junit4]   2> 54759 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178957
[junit4:junit4]   2> 55291 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178426
[junit4:junit4]   2> 55863 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177853
[junit4:junit4]   2> 56438 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177278
[junit4:junit4]   2> 57011 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176705
[junit4:junit4]   2> 57584 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176133
[junit4:junit4]   2> 58156 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175560
[junit4:junit4]   2> 58728 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174988
[junit4:junit4]   2> 59301 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174415
[junit4:junit4]   2> 59874 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173842
[junit4:junit4]   2> 60448 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173268
[junit4:junit4]   2> 61020 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172696
[junit4:junit4]   2> 61593 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172123
[junit4:junit4]   2> 62166 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171550
[junit4:junit4]   2> 62739 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170977
[junit4:junit4]   2> 63312 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170404
[junit4:junit4]   2> 63885 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169831
[junit4:junit4]   2> 64459 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169257
[junit4:junit4]   2> 65031 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168685
[junit4:junit4]   2> 65606 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168110
[junit4:junit4]   2> 66178 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167538
[junit4:junit4]   2> 66765 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166951
[junit4:junit4]   2> 67394 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166322
[junit4:junit4]   2> 68025 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165691
[junit4:junit4]   2> 68655 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165061
[junit4:junit4]   2> 69287 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164429
[junit4:junit4]   2> 69916 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163800
[junit4:junit4]   2> 70546 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163170
[junit4:junit4]   2> 71177 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162539
[junit4:junit4]   2> 71808 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161908
[junit4:junit4]   2> 72440 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161276
[junit4:junit4]   2> 73069 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160647
[junit4:junit4]   2> 73698 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160018
[junit4:junit4]   2> 74329 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159387
[junit4:junit4]   2> 74960 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158756
[junit4:junit4]   2> 75589 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158127
[junit4:junit4]   2> 76221 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157495
[junit4:junit4]   2> 76851 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156865
[junit4:junit4]   2> 77480 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156236
[junit4:junit4]   2> 78112 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155604
[junit4:junit4]   2> 78741 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154975
[junit4:junit4]   2> 79390 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154326
[junit4:junit4]   2> 80085 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153631
[junit4:junit4]   2> 80777 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152939
[junit4:junit4]   2> 81472 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152244
[junit4:junit4]   2> 82165 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151551
[junit4:junit4]   2> 82857 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150859
[junit4:junit4]   2> 83550 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150166
[junit4:junit4]   2> 84242 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149474
[junit4:junit4]   2> 84934 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148782
[junit4:junit4]   2> 85629 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148087
[junit4:junit4]   2> 86322 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147395
[junit4:junit4]   2> 87014 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146702
[junit4:junit4]   2> 87709 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146007
[junit4:junit4]   2> 88403 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145313
[junit4:junit4]   2> 89095 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144621
[junit4:junit4]   2> 89789 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143927
[junit4:junit4]   2> 90484 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143232
[junit4:junit4]   2> 91177 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142539
[junit4:junit4]   2> 91871 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141845
[junit4:junit4]   2> 92565 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141151
[junit4:junit4]   2> 93279 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140437
[junit4:junit4]   2> 94032 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139684
[junit4:junit4]   2> 94782 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138934
[junit4:junit4]   2> 95534 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138182
[junit4:junit4]   2> 96286 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137430
[junit4:junit4]   2> 97040 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136676
[junit4:junit4]   2> 97792 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135924
[junit4:junit4]   2> 98545 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135171
[junit4:junit4]   2> 99296 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134420
[junit4:junit4]   2> 100046 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133670
[junit4:junit4]   2> 100797 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132919
[junit4:junit4]   2> 101549 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132167
[junit4:junit4]   2> 102302 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131414
[junit4:junit4]   2> 103055 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130661
[junit4:junit4]   2> 103806 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129910
[junit4:junit4]   2> 104558 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129158
[junit4:junit4]   2> 105310 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128406
[junit4:junit4]   2> 106063 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127653
[junit4:junit4]   2> 106813 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126903
[junit4:junit4]   2> 107565 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126151
[junit4:junit4]   2> 108287 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125429
[junit4:junit4]   2> 108964 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124752
[junit4:junit4]   2> 109641 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124075
[junit4:junit4]   2> 110316 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123400
[junit4:junit4]   2> 110994 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122722
[junit4:junit4]   2> 111671 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122045
[junit4:junit4]   2> 112348 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121368
[junit4:junit4]   2> 113024 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120692
[junit4:junit4]   2> 113702 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120014
[junit4:junit4]   2> 114379 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119337
[junit4:junit4]   2> 115055 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118661
[junit4:junit4]   2> 115732 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117984
[junit4:junit4]   2> 116407 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117309
[junit4:junit4]   2> 117084 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116632
[junit4:junit4]   2> 117759 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115957
[junit4:junit4]   2> 118436 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115280
[junit4:junit4]   2> 119112 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114606
[junit4:junit4]   2> 119788 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113928
[junit4:junit4]   2> 120464 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113252
[junit4:junit4]   2> 121142 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112574
[junit4:junit4]   2> 121793 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111923
[junit4:junit4]   2> 122403 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111313
[junit4:junit4]   2> 123012 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110705
[junit4:junit4]   2> 123621 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110095
[junit4:junit4]   2> 124230 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109486
[junit4:junit4]   2> 124841 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108875
[junit4:junit4]   2> 125448 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108268
[junit4:junit4]   2> 126057 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107659
[junit4:junit4]   2> 126666 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107050
[junit4:junit4]   2> 127274 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106442
[junit4:junit4]   2> 127884 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105833
[junit4:junit4]   2> 128493 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105223
[junit4:junit4]   2> 129100 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104616
[junit4:junit4]   2> 129709 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104007
[junit4:junit4]   2> 130318 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103398
[junit4:junit4]   2> 130926 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102790
[junit4:junit4]   2> 131534 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102182
[junit4:junit4]   2> 132143 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101573
[junit4:junit4]   2> 132752 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100964
[junit4:junit4]   2> 133361 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100355
[junit4:junit4]   2> 133943 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99774
[junit4:junit4]   2> 134491 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99225
[junit4:junit4]   2> 135038 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98679
[junit4:junit4]   2> 135585 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98131
[junit4:junit4]   2> 136132 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97584
[junit4:junit4]   2> 136680 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97036
[junit4:junit4]   2> 137229 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96488
[junit4:junit4]   2> 137775 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95941
[junit4:junit4]   2> 138324 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95392
[junit4:junit4]   2> 138872 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94844
[junit4:junit4]   2> 139420 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94296
[junit4:junit4]   2> 139967 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93749
[junit4:junit4]   2> 140514 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93202
[junit4:junit4]   2> 141061 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92655
[junit4:junit4]   2> 141609 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92107
[junit4:junit4]   2> 142157 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91559
[junit4:junit4]   2> 142706 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91010
[junit4:junit4]   2> 143253 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90463
[junit4:junit4]   2> 143801 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89915
[junit4:junit4]   2> 144348 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89368
[junit4:junit4]   2> 144869 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88847
[junit4:junit4]   2> 145363 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88353
[junit4:junit4]   2> 145855 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87861
[junit4:junit4]   2> 146348 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87368
[junit4:junit4]   2> 146841 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86875
[junit4:junit4]   2> 147334 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86382
[junit4:junit4]   2> 147828 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85888
[junit4:junit4]   2> 148320 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85396
[junit4:junit4]   2> 148812 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84904
[junit4:junit4]   2> 149304 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84412
[junit4:junit4]   2> 149797 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83919
[junit4:junit4]   2> 150290 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83426
[junit4:junit4]   2> 150784 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82932
[junit4:junit4]   2> 151276 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82440
[junit4:junit4]   2> 151770 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81946
[junit4:junit4]   2> 152262 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81454
[junit4:junit4]   2> 152755 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80961
[junit4:junit4]   2> 153249 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80467
[junit4:junit4]   2> 153742 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79974
[junit4:junit4]   2> 154235 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79481
[junit4:junit4]   2> 154701 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79015
[junit4:junit4]   2> 155145 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78571
[junit4:junit4]   2> 155589 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78127
[junit4:junit4]   2> 156033 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77683
[junit4:junit4]   2> 156476 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77240
[junit4:junit4]   2> 156920 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76796
[junit4:junit4]   2> 157363 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76353
[junit4:junit4]   2> 157807 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75909
[junit4:junit4]   2> 158250 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75466
[junit4:junit4]   2> 158695 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75021
[junit4:junit4]   2> 159138 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74578
[junit4:junit4]   2> 159581 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74135
[junit4:junit4]   2> 160026 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73690
[junit4:junit4]   2> 160470 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73246
[junit4:junit4]   2> 160913 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72803
[junit4:junit4]   2> 161357 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72359
[junit4:junit4]   2> 161801 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71915
[junit4:junit4]   2> 162244 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71472
[junit4:junit4]   2> 162688 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71028
[junit4:junit4]   2> 163132 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70584
[junit4:junit4]   2> 163550 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70166
[junit4:junit4]   2> 163949 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69767
[junit4:junit4]   2> 164348 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69368
[junit4:junit4]   2> 164749 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68967
[junit4:junit4]   2> 165147 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68569
[junit4:junit4]   2> 165547 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68169
[junit4:junit4]   2> 165947 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67769
[junit4:junit4]   2> 166346 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67370
[junit4:junit4]   2> 166745 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66971
[junit4:junit4]   2> 167144 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66572
[junit4:junit4]   2> 167543 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66173
[junit4:junit4]   2> 167944 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65772
[junit4:junit4]   2> 168342 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65374
[junit4:junit4]   2> 168741 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64975
[junit4:junit4]   2> 169140 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64576
[junit4:junit4]   2> 169539 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64177
[junit4:junit4]   2> 169939 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63777
[junit4:junit4]   2> 170338 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63378
[junit4:junit4]   2> 170738 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62978
[junit4:junit4]   2> 171137 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62579
[junit4:junit4]   2> 171511 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62205
[junit4:junit4]   2> 171871 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61845
[junit4:junit4]   2> 172231 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61485
[junit4:junit4]   2> 172590 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61126
[junit4:junit4]   2> 172950 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60766
[junit4:junit4]   2> 173309 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60407
[junit4:junit4]   2> 173668 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60048
[junit4:junit4]   2> 174028 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59688
[junit4:junit4]   2> 174387 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59329
[junit4:junit4]   2> 174747 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58969
[junit4:junit4]   2> 175107 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58609
[junit4:junit4]   2> 175466 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58250
[junit4:junit4]   2> 175826 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57890
[junit4:junit4]   2> 176185 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57531
[junit4:junit4]   2> 176545 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57171
[junit4:junit4]   2> 176905 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56811
[junit4:junit4]   2> 177264 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56452
[junit4:junit4]   2> 177622 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56094
[junit4:junit4]   2> 177982 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55734
[junit4:junit4]   2> 178340 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55376
[junit4:junit4]   2> 178676 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55040
[junit4:junit4]   2> 178999 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54717
[junit4:junit4]   2> 179323 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54393
[junit4:junit4]   2> 179646 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54070
[junit4:junit4]   2> 179970 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53746
[junit4:junit4]   2> 180293 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53423
[junit4:junit4]   2> 180617 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53099
[junit4:junit4]   2> 180940 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52776
[junit4:junit4]   2> 181263 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52453
[junit4:junit4]   2> 181587 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52129
[junit4:junit4]   2> 181911 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51805
[junit4:junit4]   2> 182238 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51478
[junit4:junit4]   2> 182561 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51155
[junit4:junit4]   2> 182886 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50831
[junit4:junit4]   2> 183208 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50508
[junit4:junit4]   2> 183532 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50184
[junit4:junit4]   2> 183856 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49860
[junit4:junit4]   2> 184180 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49536
[junit4:junit4]   2> 184504 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49212
[junit4:junit4]   2> 184828 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48888
[junit4:junit4]   2> 185174 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48542
[junit4:junit4]   2> 185530 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48186
[junit4:junit4]   2> 185885 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47831
[junit4:junit4]   2> 186241 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47475
[junit4:junit4]   2> 186598 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47118
[junit4:junit4]   2> 186953 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46763
[junit4:junit4]   2> 187310 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46406
[junit4:junit4]   2> 187666 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46050
[junit4:junit4]   2> 188022 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45694
[junit4:junit4]   2> 188378 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45338
[junit4:junit4]   2> 188734 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44982
[junit4:junit4]   2> 189090 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44626
[junit4:junit4]   2> 189446 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44270
[junit4:junit4]   2> 189801 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43915
[junit4:junit4]   2> 190157 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43559
[junit4:junit4]   2> 190512 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43204
[junit4:junit4]   2> 190868 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42848
[junit4:junit4]   2> 191225 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42491
[junit4:junit4]   2> 191581 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42135
[junit4:junit4]   2> 191938 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41778
[junit4:junit4]   2> 192321 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41395
[junit4:junit4]   2> 192713 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41003
[junit4:junit4]   2> 193104 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40612
[junit4:junit4]   2> 193496 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40220
[junit4:junit4]   2> 193889 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39827
[junit4:junit4]   2> 194281 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39435
[junit4:junit4]   2> 194672 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39044
[junit4:junit4]   2> 195064 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38652
[junit4:junit4]   2> 195455 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38261
[junit4:junit4]   2> 195846 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37870
[junit4:junit4]   2> 196237 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37479
[junit4:junit4]   2> 196629 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37087
[junit4:junit4]   2> 197020 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36696
[junit4:junit4]   2> 197412 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36304
[junit4:junit4]   2> 197804 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35912
[junit4:junit4]   2> 198196 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35520
[junit4:junit4]   2> 198589 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35127
[junit4:junit4]   2> 198981 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34736
[junit4:junit4]   2> 199372 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34344
[junit4:junit4]   2> 199762 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33954
[junit4:junit4]   2> 200185 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33531
[junit4:junit4]   2> 200616 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33100
[junit4:junit4]   2> 201047 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32669
[junit4:junit4]   2> 201477 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32239
[junit4:junit4]   2> 201908 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31808
[junit4:junit4]   2> 202338 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31378
[junit4:junit4]   2> 202770 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30946
[junit4:junit4]   2> 203200 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30516
[junit4:junit4]   2> 203632 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30084
[junit4:junit4]   2> 204063 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29653
[junit4:junit4]   2> 204494 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29222
[junit4:junit4]   2> 204925 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28791
[junit4:junit4]   2> 205355 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28361
[junit4:junit4]   2> 205786 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27930
[junit4:junit4]   2> 206216 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27500
[junit4:junit4]   2> 206648 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27068
[junit4:junit4]   2> 207079 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26637
[junit4:junit4]   2> 207509 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26207
[junit4:junit4]   2> 207940 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25776
[junit4:junit4]   2> 208370 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25346
[junit4:junit4]   2> 208837 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24879
[junit4:junit4]   2> 209311 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24405
[junit4:junit4]   2> 209784 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23932
[junit4:junit4]   2> 210260 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23456
[junit4:junit4]   2> 210734 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22982
[junit4:junit4]   2> 211209 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22507
[junit4:junit4]   2> 211684 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22032
[junit4:junit4]   2> 212157 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21559
[junit4:junit4]   2> 212631 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21085
[junit4:junit4]   2> 213104 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20612
[junit4:junit4]   2> 213578 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20138
[junit4:junit4]   2> 214051 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19665
[junit4:junit4]   2> 214525 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19191
[junit4:junit4]   2> 214998 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18718
[junit4:junit4]   2> 215472 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18244
[junit4:junit4]   2> 215948 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17768
[junit4:junit4]   2> 216421 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17295
[junit4:junit4]   2> 216896 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16820
[junit4:junit4]   2> 217369 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16347
[junit4:junit4]   2> 217844 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15872
[junit4:junit4]   2> 218360 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15356
[junit4:junit4]   2> 218882 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14834
[junit4:junit4]   2> 219403 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14313
[junit4:junit4]   2> 219924 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13792
[junit4:junit4]   2> 220447 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13269
[junit4:junit4]   2> 220968 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12748
[junit4:junit4]   2> 221489 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12227
[junit4:junit4]   2> 222010 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11706
[junit4:junit4]   2> 222532 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11184
[junit4:junit4]   2> 223053 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10663
[junit4:junit4]   2> 223575 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10141
[junit4:junit4]   2> 224096 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9620
[junit4:junit4]   2> 224617 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9099
[junit4:junit4]   2> 225138 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8578
[junit4:junit4]   2> 225660 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8056
[junit4:junit4]   2> 226180 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7536
[junit4:junit4]   2> 226701 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7015
[junit4:junit4]   2> 227222 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6494
[junit4:junit4]   2> 227743 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5973
[junit4:junit4]   2> 228263 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5453
[junit4:junit4]   2> 228834 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4882
[junit4:junit4]   2> 229407 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4309
[junit4:junit4]   2> 229981 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3735
[junit4:junit4]   2> 230554 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3162
[junit4:junit4]   2> 231127 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2589
[junit4:junit4]   2> 231701 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2015
[junit4:junit4]   2> 232274 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1442
[junit4:junit4]   2> 232850 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=866
[junit4:junit4]   2> 233423 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=293
[junit4:junit4]   2> 233996 T458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=-280
[junit4:junit4]   2> 233996 T458 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> 233997 T458 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 233997 T458 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64531/solr/collection1/
[junit4:junit4]   2> 233997 T458 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:64531/solr START replicas=[http://127.0.0.1:64525/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 233998 T458 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:64531/solr DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 233999 T458 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 234000 T458 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> 234000 T458 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64531/solr/collection1/
[junit4:junit4]   2> 234002 T458 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 234020 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530004 type:create cxid:0x1ae zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 234095 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 234107 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 234107 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 234142 T458 oasc.ZkController.register We are http://127.0.0.1:64531/solr/collection1/ and leader is http://127.0.0.1:64531/solr/collection1/
[junit4:junit4]   2> 234142 T458 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64531/solr
[junit4:junit4]   2> 234143 T458 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 234144 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 234149 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 234150 T458 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 234150 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 234150 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 234606 T458 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 234609 T458 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:64538
[junit4:junit4]   2> 234610 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 234611 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291
[junit4:junit4]   2> 234613 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\'
[junit4:junit4]   2> 234667 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 234667 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 234667 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291
[junit4:junit4]   2> 234667 T458 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\solr.xml
[junit4:junit4]   2> 234667 T458 oasc.CoreContainer.<init> New CoreContainer 625530290
[junit4:junit4]   2> 234667 T458 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\'
[junit4:junit4]   2> 234667 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\'
[junit4:junit4]   2> 234686 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 234687 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[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:64531_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64531/solr"}
[junit4:junit4]   2> 234701 T458 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 234711 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 234712 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 234725 T458 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:64512/solr
[junit4:junit4]   2> 234725 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@42adef40
[junit4:junit4]   2> 234728 T516 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 234728 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 234731 T516 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 234731 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64543
[junit4:junit4]   2> 234732 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64543
[junit4:junit4]   2> 234734 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530005 with negotiated timeout 5000 for client /127.0.0.1:64543
[junit4:junit4]   2> 234734 T516 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530005, negotiated timeout = 5000
[junit4:junit4]   2> 234734 T517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42adef40 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 234735 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 234737 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 234739 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 234748 T458 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64538_solr
[junit4:junit4]   2> 234749 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64538_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64538_solr
[junit4:junit4]   2> 234756 T458 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64538_solr
[junit4:junit4]   2> 234760 T492 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 234760 T504 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 234761 T458 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 234761 T458 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 234762 T458 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 234763 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 234763 T478 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 234763 T458 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 234764 T458 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 234764 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 234766 T458 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 234766 T458 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 234767 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 234787 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 234797 T458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\collection1
[junit4:junit4]   2> 234797 T458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 234799 T458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 234800 T458 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 234802 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\collection1\'
[junit4:junit4]   2> 234807 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty3-1351469495291/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 234809 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty3-1351469495291/collection1/lib/README' to classloader
[junit4:junit4]   2> 234888 T458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 234981 T458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 234983 T458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 234992 T458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 235926 T458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 235939 T458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 235943 T458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 235963 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 235969 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 235973 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 235975 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 235979 T458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351469495291\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty3\
[junit4:junit4]   2> 235979 T458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@395d601f
[junit4:junit4]   2> 235980 T458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty3\index/
[junit4:junit4]   2> 235981 T458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 235981 T458 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty3\index forceNew:false
[junit4:junit4]   2> 235992 T458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c9c6e4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 235992 T458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 235994 T458 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 235997 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 235998 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 235998 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 235998 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 235999 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 235999 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 236000 T458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 236001 T458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 236001 T458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 236002 T458 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 236002 T458 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 236003 T458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 236003 T458 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 236004 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 236004 T458 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 236006 T458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 236006 T458 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236007 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236007 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236007 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236008 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236009 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236009 T458 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 236009 T458 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 236011 T458 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 236022 T458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 236030 T458 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 236032 T458 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> 236040 T458 oass.SolrIndexSearcher.<init> Opening Searcher@647bf4bc main
[junit4:junit4]   2> 236042 T458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 236044 T458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 236044 T458 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 236057 T458 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 236142 T518 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@647bf4bc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 236149 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 236449 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 236450 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[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:64538_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64538/solr"}
[junit4:junit4]   2> 236461 T517 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 236464 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 236464 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 236725 T458 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 236725 T458 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:64538/solr shardId:shard1
[junit4:junit4]   2> 236732 T458 oasc.ZkController.register We are http://127.0.0.1:64538/solr/collection1/ and leader is http://127.0.0.1:64531/solr/collection1/
[junit4:junit4]   2> 236732 T458 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64538/solr
[junit4:junit4]   2> 236733 T458 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 236733 T458 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C50 name=collection1 org.apache.solr.core.SolrCore@16442115 url=http://127.0.0.1:64538/solr/collection1 node=127.0.0.1:64538_solr
[junit4:junit4]   2> 236735 T519 C50 P64538 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 236736 T519 C50 P64538 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 236735 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 236736 T519 C50 P64538 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 236737 T458 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 236737 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 236738 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 236740 T519 C50 P64538 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:64531/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 236740 T519 C50 P64538 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:64538/solr START replicas=[http://127.0.0.1:64531/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 236740 T519 C50 P64538 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 236752 T519 C50 P64538 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 236753 T519 C50 P64538 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 236754 T519 C50 P64538 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C51 name=collection1 org.apache.solr.core.SolrCore@729c078 url=http://127.0.0.1:64531/solr/collection1 node=127.0.0.1:64531_solr
[junit4:junit4]   2> 236790 T499 C51 P64531 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=4 
[junit4:junit4]   2> 237053 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 237060 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:64538_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64538/solr"}
[junit4:junit4]   2> 237093 T517 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 237093 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 237093 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 237249 T458 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 237253 T458 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:64546
[junit4:junit4]   2> 237255 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 237256 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893
[junit4:junit4]   2> 237256 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\'
[junit4:junit4]   2> 237292 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 237292 T458 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 237294 T458 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893
[junit4:junit4]   2> 237294 T458 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\solr.xml
[junit4:junit4]   2> 237295 T458 oasc.CoreContainer.<init> New CoreContainer 1405101908
[junit4:junit4]   2> 237295 T458 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\'
[junit4:junit4]   2> 237296 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\'
[junit4:junit4]   2> 237330 T458 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 237357 T458 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:64512/solr
[junit4:junit4]   2> 237357 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3c2beb47
[junit4:junit4]   2> 237361 T530 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 237361 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 237364 T530 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 237364 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64551
[junit4:junit4]   2> 237365 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64551
[junit4:junit4]   2> 237371 T530 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530006, negotiated timeout = 5000
[junit4:junit4]   2> 237372 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530006 with negotiated timeout 5000 for client /127.0.0.1:64551
[junit4:junit4]   2> 237372 T531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c2beb47 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 237372 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 237374 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 237377 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 237382 T458 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64546_solr
[junit4:junit4]   2> 237383 T463 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13aa9d861530006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64546_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64546_solr
[junit4:junit4]   2> 237384 T458 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64546_solr
[junit4:junit4]   2> 237393 T492 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 237394 T478 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 237394 T504 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 237395 T517 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 237395 T458 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 237396 T458 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 237396 T458 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 237396 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 237397 T458 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 237397 T458 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 237397 T458 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 237399 T458 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 237399 T458 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 237400 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 237421 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 237441 T458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\collection1
[junit4:junit4]   2> 237442 T458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 237443 T458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 237444 T458 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 237449 T458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\collection1\'
[junit4:junit4]   2> 237451 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty4-1351469497893/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 237452 T458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty4-1351469497893/collection1/lib/README' to classloader
[junit4:junit4]   2> 237515 T458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 237630 T458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 237634 T458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 237648 T458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 238587 T458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 238598 T458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 238602 T458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 238629 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 238639 T458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 238645 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 238648 T458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 238650 T458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351469497893\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty4\
[junit4:junit4]   2> 238651 T458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@395d601f
[junit4:junit4]   2> 238653 T458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351469261133/jetty4\index/
[junit4:junit4]   2> 238655 T458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 238656 T458 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty4\index forceNew:false
[junit4:junit4]   2> 238698 T458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1351469261133\jetty4\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@681622f6; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 238699 T458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 238701 T458 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 238703 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 238704 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 238704 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 238706 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 238707 T458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 238707 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 238708 T458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 238708 T458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 238709 T458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 238710 T458 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 238711 T458 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 238711 T458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 238712 T458 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 238713 T458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 238713 T458 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 238715 T458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 238716 T458 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238716 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238717 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238718 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238718 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238719 T458 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238720 T458 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238720 T458 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 238721 T458 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 238731 T458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 238737 T458 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 238744 T458 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> 238750 T458 oass.SolrIndexSearcher.<init> Opening Searcher@46d24aa main
[junit4:junit4]   2> 238751 T458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 238753 T458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 238753 T458 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 238792 T458 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 238880 T532 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46d24aa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 238884 T458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 239407 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 239408 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[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:64546_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64546/solr"}
[junit4:junit4]   2> 239422 T517 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239424 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239424 T531 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239424 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239464 T458 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 239464 T458 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:64546/solr shardId:shard1
[junit4:junit4]   2> 239472 T458 oasc.ZkController.register We are http://127.0.0.1:64546/solr/collection1/ and leader is http://127.0.0.1:64531/solr/collection1/
[junit4:junit4]   2> 239472 T458 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64546/solr
[junit4:junit4]   2> 239472 T458 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 239473 T458 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C52 name=collection1 org.apache.solr.core.SolrCore@143403f2 url=http://127.0.0.1:64546/solr/collection1 node=127.0.0.1:64546_solr
[junit4:junit4]   2> 239476 T533 C52 P64546 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 239478 T533 C52 P64546 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 239478 T533 C52 P64546 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 239478 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 239479 T458 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 239479 T458 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 239480 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 239482 T533 C52 P64546 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:64531/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 239482 T533 C52 P64546 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:64546/solr START replicas=[http://127.0.0.1:64531/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 239483 T533 C52 P64546 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 239483 T533 C52 P64546 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 239484 T533 C52 P64546 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 239484 T533 C52 P64546 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 239494 T502 C51 P64531 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 239497 T458 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:64512/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@257380d3
[junit4:junit4]   2> 239500 T458 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 239500 T535 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:64512
[junit4:junit4]   2> 239502 T535 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:64512, initiating session
[junit4:junit4]   2> 239502 T460 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:64555
[junit4:junit4]   2> 239503 T460 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:64555
[junit4:junit4]   2> 239507 T462 oazs.NIOServerCnxn.finishSessionInit Established session 0x13aa9d861530007 with negotiated timeout 10000 for client /127.0.0.1:64555
[junit4:junit4]   2> 239507 T535 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:64512, sessionid = 0x13aa9d861530007, negotiated timeout = 10000
[junit4:junit4]   2> 239508 T536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@257380d3 name:ZooKeeperConnection Watcher:127.0.0.1:64512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 239508 T458 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 239509 T458 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 239512 T458 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 239512 T458 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 239522 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 239523 T458 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   2> 239524 T458 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   2> 239526 T458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 240035 T479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 240036 T479 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:64546_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:64546/solr"}
[junit4:junit4]   2> 240055 T536 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 240055 T517 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 240056 T478 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 240056 T504 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 240057 T531 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2>  C50_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:64538_solr, base_url=http://127.0.0.1:64538/solr}
[junit4:junit4]   2> 240272 T519 C50 P64538 oasc.Recovery

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

t org.apache.solr.cloud.SyncSliceTest: 
[junit4:junit4]   2> 	   1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
[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> 407593 T457 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4:junit4]   2> 	   1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
[junit4:junit4]   2> 411025 T457 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4:junit4]   2> 	   1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
[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=Lucene3x, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=pl_PL, timezone=America/Guayaquil
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Sun Microsystems Inc. 1.6.0_35 (64-bit)/cpus=2,threads=2,free=34294112,total=77996032
[junit4:junit4]   2> NOTE: All tests run in this JVM: [DisMaxRequestHandlerTest, SolrPluginUtilsTest, TestBM25SimilarityFactory, ZkCLITest, TestXIncludeConfig, TestBinaryResponseWriter, TestIndexSearcher, XmlUpdateRequestHandlerTest, DirectUpdateHandlerOptimizeTest, TestTrie, LegacyHTMLStripCharFilterTest, StatsComponentTest, FileBasedSpellCheckerTest, DocumentAnalysisRequestHandlerTest, BadIndexSchemaTest, TestElisionMultitermQuery, TestCoreContainer, PolyFieldTest, IndexSchemaRuntimeFieldTest, URLClassifyProcessorTest, IndexSchemaTest, UniqFieldsUpdateProcessorFactoryTest, HighlighterConfigTest, AlternateDirectoryTest, CacheHeaderTest, FieldMutatingUpdateProcessorTest, TestPerFieldSimilarity, ZkControllerTest, TestPhraseSuggestions, TestExtendedDismaxParser, TestQuerySenderNoQuery, SolrIndexConfigTest, TermsComponentTest, ResponseLogComponentTest, BasicDistributedZk2Test, TestUtils, CoreAdminHandlerTest, TestCollationField, NumericFieldsTest, AutoCommitTest, TestWriterPerf, SyncSliceTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.seed=B0392E85CBD56EB2 -Dtests.slow=true -Dtests.locale=pl_PL -Dtests.timezone=America/Guayaquil -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR   0.00s | SyncSliceTest (suite) <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=8 closes=7
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([B0392E85CBD56EB2]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:242)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
[junit4:junit4]    > 	at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:597)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]    > Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.SyncSliceTest: 
[junit4:junit4]    >    1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
[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([B0392E85CBD56EB2]:0)
[junit4:junit4]    > Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4:junit4]    >    1) Thread[id=493, name=searcherExecutor-384-thread-1, state=WAITING, group=TGRP-SyncSliceTest]
[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([B0392E85CBD56EB2]:0)
[junit4:junit4] Completed in 411.09s, 1 test, 2 failures, 2 errors <<< FAILURES!

[...truncated 580 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:335: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:178: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\module-build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1159: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:827: There were test failures: 233 suites, 965 tests, 3 suite-level errors, 1 failure, 700 ignored

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



Mime
View raw message