You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@sd-datasolutions.de> on 2012/11/02 21:43:54 UTC

[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_09) - Build # 1409 - Still Failing!

Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Windows/1409/
Java: 64bit/jdk1.7.0_09 -XX:+UseSerialGC

All tests passed

Build Log:
[...truncated 24386 lines...]
-documentation-lint:
     [echo] checking for broken html...
    [jtidy] Checking for broken html (such as invalid tags)...
   [delete] Deleting directory C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\build\jtidy_tmp
     [echo] Checking for broken links...
     [exec] 
     [exec] Crawl/parse...
     [exec] 
     [exec] Verify...
     [echo] Checking for missing docs...
     [exec] 
     [exec] build/docs/memory\org\apache\lucene\index\memory/MemoryIndex.html
     [exec]   missing Methods: addField(java.lang.String, org.apache.lucene.analysis.TokenStream, float, int)
     [exec] 
     [exec] Missing javadocs were found!

BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:60: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\build.xml:266: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1943: exec returned: 1

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



[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_09) - Build # 1410 - Still Failing!

Posted by Policeman Jenkins Server <je...@sd-datasolutions.de>.
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Windows/1410/
Java: 64bit/jdk1.7.0_09 -XX:+UseSerialGC

2 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([EF4A09EC7E043059:6EAC87F4095B5065]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:165)
	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:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java: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:722)


REGRESSION:  org.apache.solr.handler.TestReplicationHandler.test

Error Message:
Backup success not detected:<?xml version="1.0" encoding="UTF-8"?> <response> <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><lst name="details"><str name="indexSize">22.34 KB</str><str name="indexPath">C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1351894690248\master\collection1\data\index</str><arr name="commits"><lst><long name="indexVersion">1351894757995</long><long name="generation">19</long><arr name="filelist"><str>_b.si</str><str>_b_nrm.cfe</str><str>_b_Lucene40_0.tip</str><str>_b.fnm</str><str>_b.fdt</str><str>_b_Lucene40_0.tim</str><str>_b_nrm.cfs</str><str>segments_j</str><str>_b.fdx</str><str>_b_Lucene40_0.frq</str></arr></lst></arr><str name="isMaster">true</str><str name="isSlave">false</str><long name="indexVersion">1351894757995</long><long name="generation">19</long><lst name="master"><str name="confFiles">schema-replication2.xml:schema.xml</str><arr name="replicateAfter"><str>commit</str></arr><str name="replicationEnabled">true</str><long name="replicatableGeneration">19</long></lst><lst name="backup"><str name="startTime">Fri Nov 02 17:19:18 EST 2012</str><int name="fileCount">10</int><str name="status">success</str><str name="snapshotCompletedAt">Fri Nov 02 17:19:18 EST 2012</str></lst></lst><str name="WARNING">This response format is experimental.  It is likely to change in the future.</str> </response> 

Stack Trace:
java.lang.AssertionError: Backup success not detected:<?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><lst name="details"><str name="indexSize">22.34 KB</str><str name="indexPath">C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1351894690248\master\collection1\data\index</str><arr name="commits"><lst><long name="indexVersion">1351894757995</long><long name="generation">19</long><arr name="filelist"><str>_b.si</str><str>_b_nrm.cfe</str><str>_b_Lucene40_0.tip</str><str>_b.fnm</str><str>_b.fdt</str><str>_b_Lucene40_0.tim</str><str>_b_nrm.cfs</str><str>segments_j</str><str>_b.fdx</str><str>_b_Lucene40_0.frq</str></arr></lst></arr><str name="isMaster">true</str><str name="isSlave">false</str><long name="indexVersion">1351894757995</long><long name="generation">19</long><lst name="master"><str name="confFiles">schema-replication2.xml:schema.xml</str><arr name="replicateAfter"><str>commit</str></arr><str name="replicationEnabled">true</str><long name="replicatableGeneration">19</long></lst><lst name="backup"><str name="startTime">Fri Nov 02 17:19:18 EST 2012</str><int name="fileCount">10</int><str name="status">success</str><str name="snapshotCompletedAt">Fri Nov 02 17:19:18 EST 2012</str></lst></lst><str name="WARNING">This response format is experimental.  It is likely to change in the future.</str>
</response>

	at __randomizedtesting.SeedInfo.seed([EF4A09EC7E043059:671E3636D0F85DA1]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.handler.TestReplicationHandler.doTestBackup(TestReplicationHandler.java:915)
	at org.apache.solr.handler.TestReplicationHandler.test(TestReplicationHandler.java:256)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java: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:722)




Build Log:
[...truncated 8676 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 2 T1933 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-1351894120259
[junit4:junit4]   2> 4 T1933 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 9 T1934 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 10 T1934 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 12 T1934 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 128 T1933 oasc.ZkTestServer.run start zk server on port:62615
[junit4:junit4]   2> 128 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f7e97a5
[junit4:junit4]   2> 131 T1939 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 131 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 133 T1939 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 133 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62618
[junit4:junit4]   2> 134 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62618
[junit4:junit4]   2> 134 T1937 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 141 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0000 with negotiated timeout 10000 for client /127.0.0.1:62618
[junit4:junit4]   2> 141 T1939 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0000, negotiated timeout = 10000
[junit4:junit4]   2> 141 T1940 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f7e97a5 name:ZooKeeperConnection Watcher:127.0.0.1:62615 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 141 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 141 T1933 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 147 T1938 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13ac32b374d0000
[junit4:junit4]   2> 149 T1933 oaz.ZooKeeper.close Session: 0x13ac32b374d0000 closed
[junit4:junit4]   2> 149 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6760753
[junit4:junit4]   2> 149 T1935 oazs.NIOServerCnxn.doIO WARNING EndOfStreamException: Unable to read additional data from client sessionid 0x13ac32b374d0000, likely client has closed socket
[junit4:junit4]   2> 149 T1940 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 150 T1935 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:62618 which had sessionid 0x13ac32b374d0000
[junit4:junit4]   2> 152 T1941 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 153 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 153 T1941 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 155 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62621
[junit4:junit4]   2> 155 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62621
[junit4:junit4]   2> 157 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0001 with negotiated timeout 10000 for client /127.0.0.1:62621
[junit4:junit4]   2> 157 T1941 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0001, negotiated timeout = 10000
[junit4:junit4]   2> 157 T1942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6760753 name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 159 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 159 T1933 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 163 T1933 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 168 T1933 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 172 T1933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 175 T1933 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> 184 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 192 T1933 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> 192 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 197 T1933 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> 198 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 206 T1933 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> 206 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 212 T1933 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> 213 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 218 T1933 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> 219 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 249 T1933 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> 250 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 254 T1933 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> 254 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 257 T1933 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> 258 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 262 T1933 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> 262 T1933 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 268 T1938 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13ac32b374d0001
[junit4:junit4]   2> 270 T1935 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:62621 which had sessionid 0x13ac32b374d0001
[junit4:junit4]   2> 271 T1933 oaz.ZooKeeper.close Session: 0x13ac32b374d0001 closed
[junit4:junit4]   2> 274 T1933 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 274 T1942 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 279 T1933 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:62622
[junit4:junit4]   2> 279 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 279 T1933 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> 280 T1933 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> 316 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 316 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 316 T1933 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> 318 T1933 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> 318 T1933 oasc.CoreContainer.<init> New CoreContainer 2073368292
[junit4:junit4]   2> 319 T1933 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> 319 T1933 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> 356 T1933 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 375 T1933 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:62615/solr
[junit4:junit4]   2> 375 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@120f0908
[junit4:junit4]   2> 377 T1952 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 378 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 379 T1952 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 379 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62627
[junit4:junit4]   2> 379 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62627
[junit4:junit4]   2> 382 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0002 with negotiated timeout 5000 for client /127.0.0.1:62627
[junit4:junit4]   2> 382 T1952 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0002, negotiated timeout = 5000
[junit4:junit4]   2> 382 T1953 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@120f0908 name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 383 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 385 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 386 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 390 T1933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62622_solr
[junit4:junit4]   2> 390 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:62622_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:62622_solr
[junit4:junit4]   2> 391 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62622_solr
[junit4:junit4]   2> 396 T1933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 396 T1933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 396 T1933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 396 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 397 T1933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 397 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 397 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 397 T1933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 397 T1933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 398 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 405 T1933 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 414 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 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> 415 T1933 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 419 T1933 oasc.Overseer.start Overseer (id=88597733065949186-127.0.0.1:62622_solr-n_0000000000) starting
[junit4:junit4]   2> 419 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 421 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 422 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 424 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 426 T1955 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4]   2> 427 T1933 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 430 T1933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 433 T1954 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 439 T1933 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> 439 T1933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 440 T1933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 440 T1933 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 441 T1933 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> 443 T1933 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> 443 T1933 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> 490 T1933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 564 T1933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 566 T1933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 572 T1933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1246 T1933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1254 T1933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1257 T1933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1274 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1280 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1286 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1288 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1291 T1933 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-1351894120258/control/data\
[junit4:junit4]   2> 1292 T1933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c6547f6
[junit4:junit4]   2> 1293 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/control/data\index/
[junit4:junit4]   2> 1294 T1933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351894120258\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1295 T1933 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-1351894120258\control\data\index forceNew:false
[junit4:junit4]   2> 1308 T1933 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-1351894120258\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e8651f8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1308 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1311 T1933 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1313 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1313 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1314 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1314 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1316 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1316 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1317 T1933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1317 T1933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1318 T1933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1318 T1933 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1319 T1933 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1319 T1933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1320 T1933 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1320 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1320 T1933 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1321 T1933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1321 T1933 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1323 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1323 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1324 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1324 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1325 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1325 T1933 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1326 T1933 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1326 T1933 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1338 T1933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1345 T1933 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1346 T1933 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> 1353 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@c29264d main
[junit4:junit4]   2> 1356 T1933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1356 T1933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1357 T1933 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1370 T1933 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1437 T1956 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c29264d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1440 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1441 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x53 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1447 T1933 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1447 T1933 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:62622/solr shardId:control_shard
[junit4:junit4]   2> 1448 T1933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1460 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:delete cxid:0x62 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> 1463 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1463 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1655 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1655 T1954 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:62622_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62622/solr"}
[junit4:junit4]   2> 1656 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1671 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 2076 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2077 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2077 T1933 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:62622/solr/collection1/
[junit4:junit4]   2> 2078 T1933 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2078 T1933 oasc.SyncStrategy.syncToMe http://127.0.0.1:62622/solr/collection1/ has no replicas
[junit4:junit4]   2> 2080 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:62622/solr/collection1/
[junit4:junit4]   2> 2080 T1933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2089 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2288 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2298 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 2341 T1933 oasc.ZkController.register We are http://127.0.0.1:62622/solr/collection1/ and leader is http://127.0.0.1:62622/solr/collection1/
[junit4:junit4]   2> 2341 T1933 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:62622/solr
[junit4:junit4]   2> 2342 T1933 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2342 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2349 T1933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2350 T1933 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 2350 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2350 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2688 T1933 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2704 T1933 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:62628
[junit4:junit4]   2> 2705 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2705 T1933 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-1351894122612
[junit4:junit4]   2> 2706 T1933 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-1351894122612\'
[junit4:junit4]   2> 2744 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2744 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2745 T1933 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-1351894122612
[junit4:junit4]   2> 2745 T1933 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-1351894122612\solr.xml
[junit4:junit4]   2> 2745 T1933 oasc.CoreContainer.<init> New CoreContainer 183606507
[junit4:junit4]   2> 2746 T1933 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-1351894122612\'
[junit4:junit4]   2> 2746 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351894122612\'
[junit4:junit4]   2> 2769 T1933 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2783 T1933 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:62615/solr
[junit4:junit4]   2> 2783 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@20b405ff
[junit4:junit4]   2> 2784 T1966 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 2786 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2787 T1966 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 2788 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62633
[junit4:junit4]   2> 2788 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62633
[junit4:junit4]   2> 2813 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0003 with negotiated timeout 5000 for client /127.0.0.1:62633
[junit4:junit4]   2> 2813 T1966 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0003, negotiated timeout = 5000
[junit4:junit4]   2> 2813 T1967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20b405ff name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2813 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2814 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2844 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2881 T1933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62628_solr
[junit4:junit4]   2> 2882 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:62628_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:62628_solr
[junit4:junit4]   2> 2904 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62628_solr
[junit4:junit4]   2> 2916 T1953 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2917 T1933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2917 T1933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2918 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2918 T1933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2918 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2920 T1954 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:62622_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62622/solr"}
[junit4:junit4]   2> 2918 T1933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2920 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2920 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2921 T1933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2922 T1933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2922 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2945 T1933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2947 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 2947 T1967 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> 2956 T1933 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-1351894122612\collection1
[junit4:junit4]   2> 2958 T1933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2959 T1933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2959 T1933 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2961 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty1-1351894122612\collection1\'
[junit4:junit4]   2> 2962 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty1-1351894122612/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2965 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty1-1351894122612/collection1/lib/README' to classloader
[junit4:junit4]   2> 3004 T1933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 3092 T1933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3094 T1933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3099 T1933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3818 T1933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3831 T1933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3836 T1933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3852 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3857 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3862 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3864 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3865 T1933 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-1351894122612\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty1\
[junit4:junit4]   2> 3865 T1933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c6547f6
[junit4:junit4]   2> 3868 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty1\index/
[junit4:junit4]   2> 3870 T1933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351894120258\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3871 T1933 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-1351894120258\jetty1\index forceNew:false
[junit4:junit4]   2> 3884 T1933 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-1351894120258\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@56e6e469; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3884 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3888 T1933 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3890 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3890 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3891 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3891 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3893 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3893 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3893 T1933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3894 T1933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3895 T1933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3895 T1933 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3896 T1933 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3896 T1933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3897 T1933 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3899 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3899 T1933 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3900 T1933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3900 T1933 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3900 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3901 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3902 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3902 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3903 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3903 T1933 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3904 T1933 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3904 T1933 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3916 T1933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3923 T1933 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3925 T1933 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> 3931 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@986f596 main
[junit4:junit4]   2> 3935 T1933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3935 T1933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3936 T1933 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3957 T1933 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4020 T1968 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@986f596 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4024 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4175 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4176 T1954 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:62628_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62628/solr"}
[junit4:junit4]   2> 4176 T1954 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 4184 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 55831 T1933 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:661)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:531)
[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:57)
[junit4:junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:601)
[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:722)
[junit4:junit4]   2> 	
[junit4:junit4]   2> 55831 T1933 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5968eea4
[junit4:junit4]   2> 55831 T1933 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 55831 T1933 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 55831 T1933 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 55831 T1933 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 55831 T1933 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 55831 T1933 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 55831 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 55831 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 56032 T1933 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 56032 T1933 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:62634
[junit4:junit4]   2> 56032 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 56032 T1933 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-1351894176097
[junit4:junit4]   2> 56032 T1933 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-1351894176097\'
[junit4:junit4]   2> 56052 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 56052 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 56052 T1933 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-1351894176097
[junit4:junit4]   2> 56052 T1933 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-1351894176097\solr.xml
[junit4:junit4]   2> 56052 T1933 oasc.CoreContainer.<init> New CoreContainer 1770856829
[junit4:junit4]   2> 56052 T1933 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-1351894176097\'
[junit4:junit4]   2> 56052 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351894176097\'
[junit4:junit4]   2> 56073 T1933 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 56083 T1933 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:62615/solr
[junit4:junit4]   2> 56083 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@58583dcf
[junit4:junit4]   2> 56083 T1978 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 56083 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 56083 T1978 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 56093 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62639
[junit4:junit4]   2> 56093 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62639
[junit4:junit4]   2> 56093 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0004 with negotiated timeout 5000 for client /127.0.0.1:62639
[junit4:junit4]   2> 56093 T1978 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0004, negotiated timeout = 5000
[junit4:junit4]   2> 56093 T1979 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58583dcf name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 56093 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 56093 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 56093 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 56103 T1933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62634_solr
[junit4:junit4]   2> 56103 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:62634_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:62634_solr
[junit4:junit4]   2> 56103 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62634_solr
[junit4:junit4]   2> 56103 T1953 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 56103 T1967 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 56103 T1933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 56103 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 56113 T1933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 56123 T1933 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-1351894176097\collection1
[junit4:junit4]   2> 56123 T1933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 56123 T1933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 56123 T1933 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 56123 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty2-1351894176097\collection1\'
[junit4:junit4]   2> 56123 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty2-1351894176097/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 56123 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty2-1351894176097/collection1/lib/README' to classloader
[junit4:junit4]   2> 56153 T1933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 56194 T1933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 56194 T1933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 56194 T1933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 56544 T1933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 56555 T1933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 56555 T1933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 56566 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 56566 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 56577 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 56577 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 56577 T1933 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-1351894176097\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty2\
[junit4:junit4]   2> 56577 T1933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c6547f6
[junit4:junit4]   2> 56577 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty2\index/
[junit4:junit4]   2> 56577 T1933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351894120258\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 56577 T1933 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-1351894120258\jetty2\index forceNew:false
[junit4:junit4]   2> 56588 T1933 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-1351894120258\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@11348f22; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 56588 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 56588 T1933 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 56588 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 56588 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 56588 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 56588 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 56588 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 56588 T1933 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 56599 T1933 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 56599 T1933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 56610 T1933 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 56610 T1933 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> 56610 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@14896b1c main
[junit4:junit4]   2> 56610 T1933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 56610 T1933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 56610 T1933 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 56622 T1933 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 56655 T1980 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14896b1c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 56655 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 56699 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 56699 T1954 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:62634_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62634/solr"}
[junit4:junit4]   2> 56699 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 56699 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 57010 T1933 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 57010 T1933 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:62634/solr shardId:shard1
[junit4:junit4]   2> 57010 T1933 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 57021 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 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> 57021 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 57021 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 57032 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4]   2> 57054 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 57054 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 57054 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 57387 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179645
[junit4:junit4]   2> 57742 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179290
[junit4:junit4]   2> 58098 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178934
[junit4:junit4]   2> 58453 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178579
[junit4:junit4]   2> 58808 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178224
[junit4:junit4]   2> 59163 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177869
[junit4:junit4]   2> 59518 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177514
[junit4:junit4]   2> 59873 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177159
[junit4:junit4]   2> 60228 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176804
[junit4:junit4]   2> 60584 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176448
[junit4:junit4]   2> 60939 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176093
[junit4:junit4]   2> 61294 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175738
[junit4:junit4]   2> 61649 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175383
[junit4:junit4]   2> 62004 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175028
[junit4:junit4]   2> 62359 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174673
[junit4:junit4]   2> 62714 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174318
[junit4:junit4]   2> 63070 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173962
[junit4:junit4]   2> 63425 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173607
[junit4:junit4]   2> 63801 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173231
[junit4:junit4]   2> 64192 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172840
[junit4:junit4]   2> 64582 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172450
[junit4:junit4]   2> 64973 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172059
[junit4:junit4]   2> 65364 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171668
[junit4:junit4]   2> 65754 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171278
[junit4:junit4]   2> 66145 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170887
[junit4:junit4]   2> 66536 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170496
[junit4:junit4]   2> 66926 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170106
[junit4:junit4]   2> 67317 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169715
[junit4:junit4]   2> 67708 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169324
[junit4:junit4]   2> 68098 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168934
[junit4:junit4]   2> 68489 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168543
[junit4:junit4]   2> 68880 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168152
[junit4:junit4]   2> 69270 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167762
[junit4:junit4]   2> 69661 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167371
[junit4:junit4]   2> 70052 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166980
[junit4:junit4]   2> 70442 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166590
[junit4:junit4]   2> 70833 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166199
[junit4:junit4]   2> 71224 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165808
[junit4:junit4]   2> 71637 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165395
[junit4:junit4]   2> 72067 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164965
[junit4:junit4]   2> 72497 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164535
[junit4:junit4]   2> 72927 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164105
[junit4:junit4]   2> 73356 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163676
[junit4:junit4]   2> 73786 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163246
[junit4:junit4]   2> 74216 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162816
[junit4:junit4]   2> 74645 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162387
[junit4:junit4]   2> 75075 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161957
[junit4:junit4]   2> 75505 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161527
[junit4:junit4]   2> 75935 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161097
[junit4:junit4]   2> 76364 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160668
[junit4:junit4]   2> 76794 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160238
[junit4:junit4]   2> 77224 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159808
[junit4:junit4]   2> 77654 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159378
[junit4:junit4]   2> 78083 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158949
[junit4:junit4]   2> 78513 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158519
[junit4:junit4]   2> 78943 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158089
[junit4:junit4]   2> 79372 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157660
[junit4:junit4]   2> 79802 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157230
[junit4:junit4]   2> 80257 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156775
[junit4:junit4]   2> 80730 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156302
[junit4:junit4]   2> 81203 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155829
[junit4:junit4]   2> 81675 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155357
[junit4:junit4]   2> 82148 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154884
[junit4:junit4]   2> 82621 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154411
[junit4:junit4]   2> 83094 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153938
[junit4:junit4]   2> 83566 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153466
[junit4:junit4]   2> 84039 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152993
[junit4:junit4]   2> 84512 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152520
[junit4:junit4]   2> 84984 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152048
[junit4:junit4]   2> 85457 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151575
[junit4:junit4]   2> 85930 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151102
[junit4:junit4]   2> 86402 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150630
[junit4:junit4]   2> 86875 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150157
[junit4:junit4]   2> 87348 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149684
[junit4:junit4]   2> 87821 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149211
[junit4:junit4]   2> 88293 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148739
[junit4:junit4]   2> 88766 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148266
[junit4:junit4]   2> 89239 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147793
[junit4:junit4]   2> 89739 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147293
[junit4:junit4]   2> 90259 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146773
[junit4:junit4]   2> 90779 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146253
[junit4:junit4]   2> 91299 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145733
[junit4:junit4]   2> 91819 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145213
[junit4:junit4]   2> 92339 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144693
[junit4:junit4]   2> 92859 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144173
[junit4:junit4]   2> 93379 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143653
[junit4:junit4]   2> 93899 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143133
[junit4:junit4]   2> 94419 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142613
[junit4:junit4]   2> 94939 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142093
[junit4:junit4]   2> 95459 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141573
[junit4:junit4]   2> 95979 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141053
[junit4:junit4]   2> 96499 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140533
[junit4:junit4]   2> 97019 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140013
[junit4:junit4]   2> 97539 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139493
[junit4:junit4]   2> 98059 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138973
[junit4:junit4]   2> 98579 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138453
[junit4:junit4]   2> 99099 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137933
[junit4:junit4]   2> 99619 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137413
[junit4:junit4]   2> 100169 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136863
[junit4:junit4]   2> 100741 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136291
[junit4:junit4]   2> 101313 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135719
[junit4:junit4]   2> 101885 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135147
[junit4:junit4]   2> 102457 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134575
[junit4:junit4]   2> 103029 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134003
[junit4:junit4]   2> 103601 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133431
[junit4:junit4]   2> 104173 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132859
[junit4:junit4]   2> 104745 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132287
[junit4:junit4]   2> 105317 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131715
[junit4:junit4]   2> 105889 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131143
[junit4:junit4]   2> 106461 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130571
[junit4:junit4]   2> 107033 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129999
[junit4:junit4]   2> 107605 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129427
[junit4:junit4]   2> 108177 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128855
[junit4:junit4]   2> 108749 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128283
[junit4:junit4]   2> 109321 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127711
[junit4:junit4]   2> 109893 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127139
[junit4:junit4]   2> 110465 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126567
[junit4:junit4]   2> 111037 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125995
[junit4:junit4]   2> 111643 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125389
[junit4:junit4]   2> 112272 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124760
[junit4:junit4]   2> 112901 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124131
[junit4:junit4]   2> 113530 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123502
[junit4:junit4]   2> 114159 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122873
[junit4:junit4]   2> 114788 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122244
[junit4:junit4]   2> 115417 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121615
[junit4:junit4]   2> 116047 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120985
[junit4:junit4]   2> 116676 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120356
[junit4:junit4]   2> 117305 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119727
[junit4:junit4]   2> 117934 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119098
[junit4:junit4]   2> 118563 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118469
[junit4:junit4]   2> 119192 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117840
[junit4:junit4]   2> 119821 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117211
[junit4:junit4]   2> 120451 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116581
[junit4:junit4]   2> 121080 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115952
[junit4:junit4]   2> 121709 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115323
[junit4:junit4]   2> 122338 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114694
[junit4:junit4]   2> 122967 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114065
[junit4:junit4]   2> 123596 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113436
[junit4:junit4]   2> 124263 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112769
[junit4:junit4]   2> 124955 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112077
[junit4:junit4]   2> 125647 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111385
[junit4:junit4]   2> 126339 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110693
[junit4:junit4]   2> 127031 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110001
[junit4:junit4]   2> 127723 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109309
[junit4:junit4]   2> 128415 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108617
[junit4:junit4]   2> 129107 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107925
[junit4:junit4]   2> 129799 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107233
[junit4:junit4]   2> 130491 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106541
[junit4:junit4]   2> 131183 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105849
[junit4:junit4]   2> 131876 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105156
[junit4:junit4]   2> 132568 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104464
[junit4:junit4]   2> 133260 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103772
[junit4:junit4]   2> 133952 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103080
[junit4:junit4]   2> 134644 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102388
[junit4:junit4]   2> 135336 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101696
[junit4:junit4]   2> 136028 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101004
[junit4:junit4]   2> 136720 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100312
[junit4:junit4]   2> 137412 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99620
[junit4:junit4]   2> 138138 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98894
[junit4:junit4]   2> 138888 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98144
[junit4:junit4]   2> 139638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97394
[junit4:junit4]   2> 140388 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96644
[junit4:junit4]   2> 141138 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95894
[junit4:junit4]   2> 141888 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95144
[junit4:junit4]   2> 142638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94394
[junit4:junit4]   2> 143388 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93644
[junit4:junit4]   2> 144138 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92894
[junit4:junit4]   2> 144888 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92144
[junit4:junit4]   2> 145638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91394
[junit4:junit4]   2> 146388 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90644
[junit4:junit4]   2> 147138 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89894
[junit4:junit4]   2> 147888 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89144
[junit4:junit4]   2> 148638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88394
[junit4:junit4]   2> 149388 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87644
[junit4:junit4]   2> 150138 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86894
[junit4:junit4]   2> 150888 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86144
[junit4:junit4]   2> 151638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85394
[junit4:junit4]   2> 152388 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84644
[junit4:junit4]   2> 153094 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83938
[junit4:junit4]   2> 153769 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83263
[junit4:junit4]   2> 154444 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82588
[junit4:junit4]   2> 155119 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81913
[junit4:junit4]   2> 155794 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81238
[junit4:junit4]   2> 156469 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80563
[junit4:junit4]   2> 157144 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79888
[junit4:junit4]   2> 157819 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79213
[junit4:junit4]   2> 158494 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78538
[junit4:junit4]   2> 159169 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77863
[junit4:junit4]   2> 159844 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77188
[junit4:junit4]   2> 160519 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76513
[junit4:junit4]   2> 161194 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75838
[junit4:junit4]   2> 161869 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75163
[junit4:junit4]   2> 162544 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74488
[junit4:junit4]   2> 163219 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73813
[junit4:junit4]   2> 163894 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73138
[junit4:junit4]   2> 164569 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72463
[junit4:junit4]   2> 165244 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71788
[junit4:junit4]   2> 165919 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71113
[junit4:junit4]   2> 166554 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70478
[junit4:junit4]   2> 167161 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69871
[junit4:junit4]   2> 167769 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69263
[junit4:junit4]   2> 168376 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68656
[junit4:junit4]   2> 168984 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68048
[junit4:junit4]   2> 169591 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67441
[junit4:junit4]   2> 170199 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66833
[junit4:junit4]   2> 170806 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66226
[junit4:junit4]   2> 171414 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65618
[junit4:junit4]   2> 172021 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65011
[junit4:junit4]   2> 172629 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64403
[junit4:junit4]   2> 173236 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63796
[junit4:junit4]   2> 173844 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63188
[junit4:junit4]   2> 174451 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62581
[junit4:junit4]   2> 175059 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61973
[junit4:junit4]   2> 175666 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61366
[junit4:junit4]   2> 176274 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60758
[junit4:junit4]   2> 176881 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60151
[junit4:junit4]   2> 177489 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59543
[junit4:junit4]   2> 178096 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58936
[junit4:junit4]   2> 178668 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58364
[junit4:junit4]   2> 179215 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57817
[junit4:junit4]   2> 179761 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57271
[junit4:junit4]   2> 180308 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56724
[junit4:junit4]   2> 180855 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56177
[junit4:junit4]   2> 181402 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55630
[junit4:junit4]   2> 181948 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55084
[junit4:junit4]   2> 182495 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54537
[junit4:junit4]   2> 183042 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53990
[junit4:junit4]   2> 183589 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53443
[junit4:junit4]   2> 184135 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52897
[junit4:junit4]   2> 184682 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52350
[junit4:junit4]   2> 185229 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51803
[junit4:junit4]   2> 185776 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51256
[junit4:junit4]   2> 186322 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50710
[junit4:junit4]   2> 186869 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50163
[junit4:junit4]   2> 187416 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49616
[junit4:junit4]   2> 187963 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49069
[junit4:junit4]   2> 188509 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48523
[junit4:junit4]   2> 189056 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47976
[junit4:junit4]   2> 189571 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47461
[junit4:junit4]   2> 190063 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46969
[junit4:junit4]   2> 190555 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46477
[junit4:junit4]   2> 191047 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45985
[junit4:junit4]   2> 191539 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45493
[junit4:junit4]   2> 192031 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45001
[junit4:junit4]   2> 192523 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44509
[junit4:junit4]   2> 193015 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44017
[junit4:junit4]   2> 193507 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43525
[junit4:junit4]   2> 193999 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43033
[junit4:junit4]   2> 194491 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42541
[junit4:junit4]   2> 194983 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42049
[junit4:junit4]   2> 195476 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41556
[junit4:junit4]   2> 195968 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41064
[junit4:junit4]   2> 196460 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40572
[junit4:junit4]   2> 196952 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40080
[junit4:junit4]   2> 197444 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39588
[junit4:junit4]   2> 197936 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39096
[junit4:junit4]   2> 198428 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38604
[junit4:junit4]   2> 198920 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38112
[junit4:junit4]   2> 199383 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37649
[junit4:junit4]   2> 199826 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37206
[junit4:junit4]   2> 200269 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36763
[junit4:junit4]   2> 200712 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36320
[junit4:junit4]   2> 201154 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35878
[junit4:junit4]   2> 201597 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35435
[junit4:junit4]   2> 202040 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34992
[junit4:junit4]   2> 202483 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34549
[junit4:junit4]   2> 202926 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34106
[junit4:junit4]   2> 203369 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33663
[junit4:junit4]   2> 203812 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33220
[junit4:junit4]   2> 204255 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32777
[junit4:junit4]   2> 204697 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32335
[junit4:junit4]   2> 205140 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31892
[junit4:junit4]   2> 205583 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31449
[junit4:junit4]   2> 206026 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31006
[junit4:junit4]   2> 206469 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30563
[junit4:junit4]   2> 206912 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30120
[junit4:junit4]   2> 207355 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29677
[junit4:junit4]   2> 207798 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29234
[junit4:junit4]   2> 208214 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28818
[junit4:junit4]   2> 208613 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28419
[junit4:junit4]   2> 209011 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28021
[junit4:junit4]   2> 209410 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27622
[junit4:junit4]   2> 209808 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27224
[junit4:junit4]   2> 210207 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26825
[junit4:junit4]   2> 210606 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26426
[junit4:junit4]   2> 211004 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26028
[junit4:junit4]   2> 211403 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25629
[junit4:junit4]   2> 211801 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25231
[junit4:junit4]   2> 212200 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24832
[junit4:junit4]   2> 212599 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24433
[junit4:junit4]   2> 212997 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24035
[junit4:junit4]   2> 213396 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23636
[junit4:junit4]   2> 213794 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23238
[junit4:junit4]   2> 214193 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22839
[junit4:junit4]   2> 214592 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22440
[junit4:junit4]   2> 214990 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22042
[junit4:junit4]   2> 215389 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21643
[junit4:junit4]   2> 215787 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21245
[junit4:junit4]   2> 216162 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20870
[junit4:junit4]   2> 216521 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20511
[junit4:junit4]   2> 216880 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20152
[junit4:junit4]   2> 217238 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19794
[junit4:junit4]   2> 217597 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19435
[junit4:junit4]   2> 217956 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19076
[junit4:junit4]   2> 218315 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18717
[junit4:junit4]   2> 218673 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18359
[junit4:junit4]   2> 219032 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18000
[junit4:junit4]   2> 219391 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17641
[junit4:junit4]   2> 219750 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17282
[junit4:junit4]   2> 220108 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16924
[junit4:junit4]   2> 220467 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16565
[junit4:junit4]   2> 220826 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16206
[junit4:junit4]   2> 221184 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15848
[junit4:junit4]   2> 221543 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15489
[junit4:junit4]   2> 221902 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15130
[junit4:junit4]   2> 222261 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14771
[junit4:junit4]   2> 222619 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14413
[junit4:junit4]   2> 222978 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14054
[junit4:junit4]   2> 223316 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13716
[junit4:junit4]   2> 223638 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13394
[junit4:junit4]   2> 223961 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13071
[junit4:junit4]   2> 224284 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12748
[junit4:junit4]   2> 224607 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12425
[junit4:junit4]   2> 224930 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12102
[junit4:junit4]   2> 225253 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11779
[junit4:junit4]   2> 225576 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11456
[junit4:junit4]   2> 225898 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11134
[junit4:junit4]   2> 226221 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10811
[junit4:junit4]   2> 226544 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10488
[junit4:junit4]   2> 226867 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10165
[junit4:junit4]   2> 227190 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9842
[junit4:junit4]   2> 227513 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9519
[junit4:junit4]   2> 227836 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9196
[junit4:junit4]   2> 228158 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8874
[junit4:junit4]   2> 228481 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8551
[junit4:junit4]   2> 228804 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8228
[junit4:junit4]   2> 229127 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7905
[junit4:junit4]   2> 229450 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7582
[junit4:junit4]   2> 229754 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7278
[junit4:junit4]   2> 230044 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6988
[junit4:junit4]   2> 230335 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6697
[junit4:junit4]   2> 230625 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6407
[junit4:junit4]   2> 230916 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6116
[junit4:junit4]   2> 231207 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5825
[junit4:junit4]   2> 231497 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5535
[junit4:junit4]   2> 231788 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5244
[junit4:junit4]   2> 232078 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4954
[junit4:junit4]   2> 232369 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4663
[junit4:junit4]   2> 232659 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4373
[junit4:junit4]   2> 232950 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4082
[junit4:junit4]   2> 233241 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3791
[junit4:junit4]   2> 233531 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3501
[junit4:junit4]   2> 233822 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3210
[junit4:junit4]   2> 234112 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2920
[junit4:junit4]   2> 234403 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2629
[junit4:junit4]   2> 234693 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2339
[junit4:junit4]   2> 234984 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2048
[junit4:junit4]   2> 235275 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1757
[junit4:junit4]   2> 235582 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1450
[junit4:junit4]   2> 235902 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1130
[junit4:junit4]   2> 236222 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=810
[junit4:junit4]   2> 236541 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=491
[junit4:junit4]   2> 236861 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171
[junit4:junit4]   2> 237181 T1933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=-149
[junit4:junit4]   2> 237181 T1933 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> 237181 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 237181 T1933 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:62634/solr/collection1/
[junit4:junit4]   2> 237181 T1933 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:62634/solr START replicas=[http://127.0.0.1:62628/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 237181 T1933 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:62634/solr DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 237181 T1933 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 237181 T1933 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> 237181 T1933 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:62634/solr/collection1/
[junit4:junit4]   2> 237181 T1933 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 237191 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0004 type:create cxid:0x1ba zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 237201 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 237201 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 237201 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 237230 T1933 oasc.ZkController.register We are http://127.0.0.1:62634/solr/collection1/ and leader is http://127.0.0.1:62634/solr/collection1/
[junit4:junit4]   2> 237230 T1933 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:62634/solr
[junit4:junit4]   2> 237230 T1933 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 237230 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 237230 T1933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 237230 T1933 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 237230 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 237230 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 237470 T1933 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 237480 T1933 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:62641
[junit4:junit4]   2> 237480 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 237480 T1933 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-1351894357496
[junit4:junit4]   2> 237480 T1933 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-1351894357496\'
[junit4:junit4]   2> 237490 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 237500 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 237500 T1933 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-1351894357496
[junit4:junit4]   2> 237500 T1933 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-1351894357496\solr.xml
[junit4:junit4]   2> 237500 T1933 oasc.CoreContainer.<init> New CoreContainer 1624340912
[junit4:junit4]   2> 237500 T1933 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-1351894357496\'
[junit4:junit4]   2> 237500 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351894357496\'
[junit4:junit4]   2> 237510 T1933 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 237520 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 237520 T1954 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:62634_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62634/solr"}
[junit4:junit4]   2> 237530 T1933 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:62615/solr
[junit4:junit4]   2> 237530 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@4f64e07a
[junit4:junit4]   2> 237530 T1991 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 237530 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 237530 T1991 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 237530 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62646
[junit4:junit4]   2> 237530 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62646
[junit4:junit4]   2> 237530 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0005 with negotiated timeout 5000 for client /127.0.0.1:62646
[junit4:junit4]   2> 237530 T1991 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0005, negotiated timeout = 5000
[junit4:junit4]   2> 237530 T1992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f64e07a name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 237540 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 237540 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 237540 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 237540 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 237540 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 237540 T1933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62641_solr
[junit4:junit4]   2> 237540 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:62641_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:62641_solr
[junit4:junit4]   2> 237540 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62641_solr
[junit4:junit4]   2> 237540 T1979 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 237540 T1967 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 237540 T1953 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 237540 T1933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 237540 T1933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 237540 T1933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 237540 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 237540 T1933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 237550 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 237550 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 237550 T1933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 237550 T1933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 237550 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 237560 T1933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 237560 T1933 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-1351894357496\collection1
[junit4:junit4]   2> 237560 T1933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 237560 T1933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 237560 T1933 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 237570 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty3-1351894357496\collection1\'
[junit4:junit4]   2> 237570 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty3-1351894357496/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 237570 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty3-1351894357496/collection1/lib/README' to classloader
[junit4:junit4]   2> 237610 T1933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 237650 T1933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 237660 T1933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 237670 T1933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 238189 T1933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 238199 T1933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 238199 T1933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 238209 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 238219 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 238229 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 238229 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 238229 T1933 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-1351894357496\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty3\
[junit4:junit4]   2> 238229 T1933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c6547f6
[junit4:junit4]   2> 238229 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty3\index/
[junit4:junit4]   2> 238229 T1933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351894120258\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 238239 T1933 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-1351894120258\jetty3\index forceNew:false
[junit4:junit4]   2> 238239 T1933 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-1351894120258\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@501ec7c9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 238239 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 238249 T1933 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 238249 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 238249 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 238249 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 238249 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 238249 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 238249 T1933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 238259 T1933 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 238269 T1933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 238269 T1933 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 238269 T1933 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> 238279 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@2dc901cc main
[junit4:junit4]   2> 238279 T1933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 238279 T1933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 238279 T1933 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 238289 T1933 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 238339 T1993 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2dc901cc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 238339 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 238499 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 238499 T1954 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:62641_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62641/solr"}
[junit4:junit4]   2> 238499 T1992 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238499 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238499 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238679 T1933 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 238679 T1933 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:62641/solr shardId:shard1
[junit4:junit4]   2> 238679 T1933 oasc.ZkController.register We are http://127.0.0.1:62641/solr/collection1/ and leader is http://127.0.0.1:62634/solr/collection1/
[junit4:junit4]   2> 238679 T1933 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:62641/solr
[junit4:junit4]   2> 238679 T1933 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 238679 T1933 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C119 name=collection1 org.apache.solr.core.SolrCore@39e0d8f4 url=http://127.0.0.1:62641/solr/collection1 node=127.0.0.1:62641_solr
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 238679 T1933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:62634/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:62641/solr START replicas=[http://127.0.0.1:62634/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 238679 T1933 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 238679 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 238679 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 238679 T1994 C119 P62641 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 238689 T1994 C119 P62641 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 238689 T1994 C119 P62641 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 238689 T1994 C119 P62641 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C120 name=collection1 org.apache.solr.core.SolrCore@52260793 url=http://127.0.0.1:62634/solr/collection1 node=127.0.0.1:62634_solr
[junit4:junit4]   2> 238689 T1975 C120 P62634 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 238819 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 238819 T1954 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:62641_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62641/solr"}
[junit4:junit4]   2> 238829 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238829 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238829 T1992 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 238879 T1933 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 238879 T1933 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:62649
[junit4:junit4]   2> 238879 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 238879 T1933 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-1351894358955
[junit4:junit4]   2> 238879 T1933 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-1351894358955\'
[junit4:junit4]   2> 238899 T1933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 238899 T1933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 238899 T1933 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-1351894358955
[junit4:junit4]   2> 238899 T1933 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-1351894358955\solr.xml
[junit4:junit4]   2> 238899 T1933 oasc.CoreContainer.<init> New CoreContainer 837355151
[junit4:junit4]   2> 238899 T1933 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-1351894358955\'
[junit4:junit4]   2> 238899 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351894358955\'
[junit4:junit4]   2> 238919 T1933 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 238919 T1933 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:62615/solr
[junit4:junit4]   2> 238919 T1933 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:62615/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@2ffc88da
[junit4:junit4]   2> 238929 T2005 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:62615
[junit4:junit4]   2> 238929 T1933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 238929 T2005 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:62615, initiating session
[junit4:junit4]   2> 238929 T1935 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:62654
[junit4:junit4]   2> 238929 T1935 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:62654
[junit4:junit4]   2> 238929 T1937 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac32b374d0006 with negotiated timeout 5000 for client /127.0.0.1:62654
[junit4:junit4]   2> 238929 T2005 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:62615, sessionid = 0x13ac32b374d0006, negotiated timeout = 5000
[junit4:junit4]   2> 238929 T2006 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ffc88da name:ZooKeeperConnection Watcher:127.0.0.1:62615/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 238929 T1933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 238929 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 238929 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 238929 T1933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62649_solr
[junit4:junit4]   2> 238929 T1938 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac32b374d0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:62649_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:62649_solr
[junit4:junit4]   2> 238929 T1933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62649_solr
[junit4:junit4]   2> 238939 T1992 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 238939 T1979 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 238939 T1967 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 238939 T1953 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 238939 T1933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 238939 T1933 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 238949 T1933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 238949 T1933 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-1351894358955\collection1
[junit4:junit4]   2> 238949 T1933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 238959 T1933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 238959 T1933 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 238959 T1933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-jetty4-1351894358955\collection1\'
[junit4:junit4]   2> 238959 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty4-1351894358955/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 238959 T1933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solrtest-jetty4-1351894358955/collection1/lib/README' to classloader
[junit4:junit4]   2> 238988 T1933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 239028 T1933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 239038 T1933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 239038 T1933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 239508 T1933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 239518 T1933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 239518 T1933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 239528 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 239538 T1933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 239538 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 239538 T1933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 239538 T1933 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-1351894358955\collection1\, dataDir=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty4\
[junit4:junit4]   2> 239538 T1933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7c6547f6
[junit4:junit4]   2> 239538 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.SyncSliceTest-1351894120258/jetty4\index/
[junit4:junit4]   2> 239548 T1933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.SyncSliceTest-1351894120258\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 239548 T1933 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-1351894120258\jetty4\index forceNew:false
[junit4:junit4]   2> 239558 T1933 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-1351894120258\jetty4\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5bb0bae0; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 239558 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 239558 T1933 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 239558 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 239558 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 239558 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 239558 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 239558 T1933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 239558 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 239558 T1933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 239558 T1933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 239558 T1933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 239558 T1933 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239568 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 239578 T1933 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 239588 T1933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 239588 T1933 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 239588 T1933 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> 239598 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@57d7a663 main
[junit4:junit4]   2> 239598 T1933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 239598 T1933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 239598 T1933 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 239608 T1933 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 239658 T2007 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@57d7a663 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 239668 T1933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 239788 T1954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 239788 T1954 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:62649_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:62649/solr"}
[junit4:junit4]   2> 239788 T1979 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239788 T2006 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239788 T1953 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239788 T1992 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 239987 T1933 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 239987 T1933 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:62649/solr shardId:shard1
[junit4:junit4]   2> 239987 T1933 oasc.ZkController.register We are http://127.0.0.1:62649/solr/collection1/ and leader is http://127.0.0.1:62634/solr/collection1/
[junit4:junit4]   2> 239987 T1933 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:62649/solr
[junit4:junit4]   2> 239987 T1933 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 239987 T1933 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C121 name=collection1 org.apache.solr.core.SolrCore@68964a8a url=http://127.0.0.1:62649/solr/collection1 node=127.0.0.1:62649_solr
[junit4:junit4]   2> 239987 T2008 C121 P62649 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 239987 T2008 C121 P62649 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 239987 T2008 C121 P62649 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 239987 T1933

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

g.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[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 com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[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:722)
[junit4:junit4]   2> 71331 T2772 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1903200587
[junit4:junit4]   2> 71331 T2772 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@224d1357
[junit4:junit4]   2> 71331 T2772 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=493,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 71331 T2772 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 71331 T2772 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 71331 T2772 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 71331 T2772 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 71331 T2772 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 71405 T2772 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=14764458
[junit4:junit4]   2> 71405 T2772 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3aee8b9c
[junit4:junit4]   2> 71405 T2772 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 71405 T2772 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 71405 T2772 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 71405 T2772 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 71405 T2772 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 71405 T2772 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 71405 T2975 oash.SnapPuller.fetchLatestIndex SEVERE Master at: http://127.0.0.1:63329/solr is not available. Index fetch failed. Exception: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:63329/solr
[junit4:junit4]   2> 71556 T2772 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=ar_YE, timezone=America/Jamaica
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=2,threads=1,free=84392432,total=192724992
[junit4:junit4]   2> NOTE: All tests run in this JVM: [DistanceFunctionTest, TestBadConfig, PathHierarchyTokenizerFactoryTest, SortByFunctionTest, TestGroupingSearch, TestStressRecovery, SoftAutoCommitTest, DisMaxRequestHandlerTest, DateFieldTest, PingRequestHandlerTest, BasicFunctionalityTest, SpellCheckCollatorTest, UniqFieldsUpdateProcessorFactoryTest, SolrRequestParserTest, SpellPossibilityIteratorTest, TestFastWriter, TestFunctionQuery, SpellCheckComponentTest, TestElisionMultitermQuery, ZkControllerTest, RequestHandlersTest, TestHashPartitioner, TermVectorComponentTest, LeaderElectionIntegrationTest, TestStressVersions, SolrCoreCheckLockOnStartupTest, TestRangeQuery, TestCSVResponseWriter, ShowFileRequestHandlerTest, TestStressLucene, OverseerTest, BadComponentTest, UpdateRequestProcessorFactoryTest, TestRTGBase, IndexSchemaRuntimeFieldTest, TestSuggestSpellingConverter, DocumentAnalysisRequestHandlerTest, SolrCoreTest, XmlUpdateRequestHandlerTest, StatelessScriptUpdateProcessorFactoryTest, FieldAnalysisRequestHandlerTest, TestTrie, TestWriterPerf, ScriptEngineTest, TestDFRSimilarityFactory, TestSearchPerf, NumericFieldsTest, TestIndexSearcher, TestDocSet, TestDistributedSearch, TestQuerySenderListener, DistributedSpellCheckComponentTest, QueryEqualityTest, TestArbitraryIndexDir, TestCollationKeyRangeQueries, TestLMDirichletSimilarityFactory, CoreContainerCoreInitFailuresTest, ZkSolrClientTest, TestExtendedDismaxParser, LoggingHandlerTest, HighlighterTest, CSVRequestHandlerTest, TestLFUCache, ConvertedLegacyTest, TestMultiCoreConfBootstrap, TestPHPSerializedResponseWriter, LeaderElectionTest, TestSolrDeletionPolicy1, TestFoldingMultitermQuery, TestFaceting, DistributedQueryElevationComponentTest, DocumentBuilderTest, TestBinaryField, TestValueSourceCache, DistributedTermsComponentTest, DirectSolrSpellCheckerTest, CircularListTest, UUIDFieldTest, MBeansHandlerTest, ClusterStateTest, PluginInfoTest, NotRequiredUniqueKeyTest, OpenExchangeRatesOrgProviderTest, TestCollationField, TestDistributedGrouping, TestSolrQueryParser, UpdateParamsTest, TestPseudoReturnFields, LegacyHTMLStripCharFilterTest, BasicDistributedZk2Test, TestReload, TestUpdate, DateMathParserTest, ZkCLITest, TestConfig, ResponseLogComponentTest, TestQuerySenderNoQuery, MultiTermTest, TestPerFieldSimilarity, FieldMutatingUpdateProcessorTest, SolrPluginUtilsTest, TestOmitPositions, IndexSchemaTest, SignatureUpdateProcessorFactoryTest, SyncSliceTest, TermVectorComponentDistributedTest, FileUtilsTest, TestSystemIdResolver, TestSurroundQueryParser, NoCacheHeaderTest, SolrInfoMBeanTest, PreAnalyzedFieldTest, BasicDistributedZkTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4:junit4] Completed in 71.56s, 1 test, 1 failure <<< FAILURES!

[...truncated 348 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:1163: 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, 2 failures, 12 ignored (7 assumptions)

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