lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_09) - Build # 1411 - Failure!
Date Fri, 02 Nov 2012 14:20:14 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Windows/1411/
Java: 64bit/jdk1.7.0_09 -XX:+UseConcMarkSweepGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

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

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 180 seconds
	at __randomizedtesting.SeedInfo.seed([1591B044C1AA90F0:94773E5CB6F5F0CC]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:166)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:116)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:111)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:553)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:74)
	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)




Build Log:
[...truncated 8722 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 4 T1860 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1351864787209
[junit4:junit4]   2> 7 T1860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 12 T1861 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 13 T1861 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 15 T1861 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 144 T1860 oasc.ZkTestServer.run start zk server on port:57370
[junit4:junit4]   2> 144 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@46fc6e44
[junit4:junit4]   2> 148 T1866 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 149 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 152 T1866 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 153 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57373
[junit4:junit4]   2> 154 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57373
[junit4:junit4]   2> 156 T1864 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 193 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120000 with negotiated timeout 10000 for client /127.0.0.1:57373
[junit4:junit4]   2> 193 T1866 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120000, negotiated timeout = 10000
[junit4:junit4]   2> 194 T1867 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46fc6e44 name:ZooKeeperConnection Watcher:127.0.0.1:57370 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 194 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 195 T1860 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 233 T1865 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13ac16ba1120000
[junit4:junit4]   2> 259 T1860 oaz.ZooKeeper.close Session: 0x13ac16ba1120000 closed
[junit4:junit4]   2> 260 T1862 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:57373 which had sessionid 0x13ac16ba1120000
[junit4:junit4]   2> 259 T1867 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 261 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@37dbe32
[junit4:junit4]   2> 266 T1868 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 266 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 269 T1868 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 269 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57376
[junit4:junit4]   2> 270 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57376
[junit4:junit4]   2> 286 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120001 with negotiated timeout 10000 for client /127.0.0.1:57376
[junit4:junit4]   2> 286 T1868 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120001, negotiated timeout = 10000
[junit4:junit4]   2> 286 T1869 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37dbe32 name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 288 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 288 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 339 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 368 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 393 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 422 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 423 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 461 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 464 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 488 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 489 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 501 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 504 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 514 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 516 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 529 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 530 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 541 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 543 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 559 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 562 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 571 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 572 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 583 T1860 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 585 T1860 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 597 T1865 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13ac16ba1120001
[junit4:junit4]   2> 601 T1869 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 601 T1860 oaz.ZooKeeper.close Session: 0x13ac16ba1120001 closed
[junit4:junit4]   2> 602 T1862 oazs.NIOServerCnxn.doIO WARNING EndOfStreamException: Unable to read additional data from client sessionid 0x13ac16ba1120001, likely client has closed socket
[junit4:junit4]   2> 606 T1862 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:57376 which had sessionid 0x13ac16ba1120001
[junit4:junit4]   2> 990 T1860 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 1003 T1860 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:57377
[junit4:junit4]   2> 1004 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1006 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804
[junit4:junit4]   2> 1007 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\'
[junit4:junit4]   2> 1064 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1064 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1064 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804
[junit4:junit4]   2> 1065 T1860 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\solr.xml
[junit4:junit4]   2> 1065 T1860 oasc.CoreContainer.<init> New CoreContainer 76311180
[junit4:junit4]   2> 1066 T1860 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\'
[junit4:junit4]   2> 1066 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\'
[junit4:junit4]   2> 1105 T1860 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 1131 T1860 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:57370/solr
[junit4:junit4]   2> 1131 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@665a6b72
[junit4:junit4]   2> 1134 T1879 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 1134 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1138 T1879 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 1138 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57382
[junit4:junit4]   2> 1138 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57382
[junit4:junit4]   2> 1160 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120002 with negotiated timeout 5000 for client /127.0.0.1:57382
[junit4:junit4]   2> 1161 T1879 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120002, negotiated timeout = 5000
[junit4:junit4]   2> 1161 T1880 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@665a6b72 name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1163 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1194 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1197 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 1219 T1860 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57377_solr
[junit4:junit4]   2> 1221 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57377_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57377_solr
[junit4:junit4]   2> 1223 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57377_solr
[junit4:junit4]   2> 1265 T1860 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 1267 T1860 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1268 T1860 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 1268 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1269 T1860 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1269 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1269 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1271 T1860 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1271 T1860 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1271 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 1289 T1860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 1355 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 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> 1359 T1860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 1371 T1860 oasc.Overseer.start Overseer (id=88595810695118850-127.0.0.1:57377_solr-n_0000000000) starting
[junit4:junit4]   2> 1373 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1391 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1395 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1400 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1402 T1882 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4]   2> 1405 T1860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 1417 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 1425 T1881 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 1441 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\collection1
[junit4:junit4]   2> 1442 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 1445 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1445 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 1453 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\collection1\'
[junit4:junit4]   2> 1454 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1456 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804/collection1/lib/README' to classloader
[junit4:junit4]   2> 1536 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 1621 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1624 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1636 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2525 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2542 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2550 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2573 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2582 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2590 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2591 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2593 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1351864787804\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/control/data\
[junit4:junit4]   2> 2593 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58b315c1
[junit4:junit4]   2> 2594 T1860 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 2639 T1860 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data lockFactory=org.apache.lucene.store.NativeFSLockFactory@7bc0ef80 assuming 'simple'
[junit4:junit4]   2> 2640 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data forceNew:false
[junit4:junit4]   2> 2641 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data
[junit4:junit4]   2> 2643 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/control/data\index/
[junit4:junit4]   2> 2644 T1860 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2645 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data\index forceNew:false
[junit4:junit4]   2> 2695 T1860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data\index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2697 T1860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 2698 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data\index
[junit4:junit4]   2> 2698 T1860 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2702 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2705 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2705 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2706 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2707 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2707 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2710 T1860 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2710 T1860 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2711 T1860 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2711 T1860 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2712 T1860 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2714 T1860 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2715 T1860 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2715 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2715 T1860 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2718 T1860 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2718 T1860 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2719 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2720 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2722 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2723 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2724 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2726 T1860 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2727 T1860 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2728 T1860 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2740 T1860 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2748 T1860 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2751 T1860 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> 2759 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\control\data
[junit4:junit4]   2> 2761 T1860 oass.SolrIndexSearcher.<init> Opening Searcher@11cefbb2 main
[junit4:junit4]   2> 2764 T1860 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2765 T1860 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2765 T1860 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2794 T1860 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3010 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3047 T1883 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11cefbb2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3047 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 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> 3137 T1860 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 3138 T1860 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:57377/solr shardId:control_shard
[junit4:junit4]   2> 3138 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 3246 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 3271 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3271 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3274 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x68 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3274 T1881 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:57377_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57377/solr"}
[junit4:junit4]   2> 3275 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x69 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 3508 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 4029 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4030 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4032 T1860 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57377/solr/collection1/
[junit4:junit4]   2> 4032 T1860 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4032 T1860 oasc.SyncStrategy.syncToMe http://127.0.0.1:57377/solr/collection1/ has no replicas
[junit4:junit4]   2> 4033 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57377/solr/collection1/
[junit4:junit4]   2> 4033 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 4100 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120002 type:create cxid:0x89 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4244 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4301 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (1)
[junit4:junit4]   2> 4374 T1860 oasc.ZkController.register We are http://127.0.0.1:57377/solr/collection1/ and leader is http://127.0.0.1:57377/solr/collection1/
[junit4:junit4]   2> 4374 T1860 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57377/solr
[junit4:junit4]   2> 4376 T1860 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4376 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4380 T1860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4381 T1860 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 4381 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4381 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4393 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 4398 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@9e61610
[junit4:junit4]   2> 4401 T1884 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 4401 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4402 T1884 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 4403 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57385
[junit4:junit4]   2> 4403 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57385
[junit4:junit4]   2> 4409 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120003 with negotiated timeout 10000 for client /127.0.0.1:57385
[junit4:junit4]   2> 4409 T1884 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120003, negotiated timeout = 10000
[junit4:junit4]   2> 4410 T1885 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9e61610 name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4410 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4411 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4414 T1860 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4796 T1860 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4800 T1860 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:57386
[junit4:junit4]   2> 4801 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4803 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616
[junit4:junit4]   2> 4803 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\'
[junit4:junit4]   2> 4858 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4859 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4859 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616
[junit4:junit4]   2> 4861 T1860 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\solr.xml
[junit4:junit4]   2> 4861 T1860 oasc.CoreContainer.<init> New CoreContainer 479649282
[junit4:junit4]   2> 4861 T1860 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\'
[junit4:junit4]   2> 4861 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\'
[junit4:junit4]   2> 4895 T1860 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4915 T1860 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:57370/solr
[junit4:junit4]   2> 4916 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3448cebb
[junit4:junit4]   2> 4919 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4919 T1895 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 4921 T1895 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 4923 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57391
[junit4:junit4]   2> 4923 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57391
[junit4:junit4]   2> 4941 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120004 with negotiated timeout 5000 for client /127.0.0.1:57391
[junit4:junit4]   2> 4944 T1895 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120004, negotiated timeout = 5000
[junit4:junit4]   2> 4944 T1896 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3448cebb name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4944 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4944 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4958 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4971 T1860 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57386_solr
[junit4:junit4]   2> 4973 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57386_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57386_solr
[junit4:junit4]   2> 4991 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57386_solr
[junit4:junit4]   2> 5015 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5016 T1885 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5016 T1881 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:57377_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57377/solr"}
[junit4:junit4]   2> 5017 T1860 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5017 T1860 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5019 T1860 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5019 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5020 T1860 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5020 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5020 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5020 T1860 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5021 T1860 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5021 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5083 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5106 T1896 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> 5115 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\collection1
[junit4:junit4]   2> 5115 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5116 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 5123 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5123 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5148 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\collection1\'
[junit4:junit4]   2> 5149 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5151 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616/collection1/lib/README' to classloader
[junit4:junit4]   2> 5214 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5313 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5317 T1880 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5317 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 5318 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5331 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6127 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6188 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 6197 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6202 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6234 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6242 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6248 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6251 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6252 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1351864791616\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty1\
[junit4:junit4]   2> 6254 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58b315c1
[junit4:junit4]   2> 6255 T1860 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 6256 T1860 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@122e4849 assuming 'simple'
[junit4:junit4]   2> 6259 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1 forceNew:false
[junit4:junit4]   2> 6262 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1
[junit4:junit4]   2> 6263 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty1\index/
[junit4:junit4]   2> 6264 T1860 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6264 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1\index forceNew:false
[junit4:junit4]   2> 6295 T1860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1\index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6295 T1860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6296 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1\index
[junit4:junit4]   2> 6296 T1860 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6300 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6301 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6301 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6302 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6305 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6305 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6305 T1860 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6306 T1860 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6308 T1860 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6309 T1860 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6310 T1860 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6310 T1860 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6313 T1860 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6313 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6313 T1860 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6314 T1860 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6317 T1860 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6318 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6320 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6320 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6322 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6322 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6323 T1860 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6325 T1860 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6326 T1860 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6339 T1860 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6347 T1860 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6349 T1860 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> 6352 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1
[junit4:junit4]   2> 6356 T1860 oass.SolrIndexSearcher.<init> Opening Searcher@61848fc main
[junit4:junit4]   2> 6359 T1860 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6359 T1860 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6359 T1860 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6420 T1860 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6669 T1897 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61848fc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6675 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6909 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6910 T1881 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57386_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57386/solr"}
[junit4:junit4]   2> 6910 T1881 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6934 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 6934 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 76451 T1860 oasc.SolrException.log SEVERE null:org.apache.solr.common.SolrException: Could not get shard_id for core: collection1
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.doGetShardIdProcess(ZkController.java:998)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.preRegister(ZkController.java:1056)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.registerCore(CoreContainer.java:716)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.register(CoreContainer.java:696)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:565)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer.load(CoreContainer.java:375)
[junit4:junit4]   2> 		at org.apache.solr.core.CoreContainer$Initializer.initialize(CoreContainer.java:307)
[junit4:junit4]   2> 		at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:107)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.FilterHolder.doStart(FilterHolder.java:114)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:59)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:754)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.updateMappings(ServletHandler.java:1227)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.setFilterMappings(ServletHandler.java:1263)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:965)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:923)
[junit4:junit4]   2> 		at org.eclipse.jetty.servlet.ServletContextHandler.addFilter(ServletContextHandler.java:333)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner$1.lifeCycleStarted(JettySolrRunner.java:173)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.setStarted(AbstractLifeCycle.java:169)
[junit4:junit4]   2> 		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:60)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:225)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:205)
[junit4:junit4]   2> 		at org.apache.solr.BaseDistributedSearchTestCase.createJetty(BaseDistributedSearchTestCase.java:262)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createJettys(AbstractFullDistribZkTestBase.java:292)
[junit4:junit4]   2> 		at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:245)
[junit4:junit4]   2> 		at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:693)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: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> 76452 T1860 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@29feb929
[junit4:junit4]   2> 76460 T1860 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> 76460 T1860 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 76461 T1860 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 76461 T1860 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 76461 T1860 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 76461 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty1\index
[junit4:junit4]   2> 76461 T1860 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 76462 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 76462 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 76722 T1860 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 76724 T1860 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:57392
[junit4:junit4]   2> 76726 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 76726 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671
[junit4:junit4]   2> 76727 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\'
[junit4:junit4]   2> 76756 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 76757 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 76757 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671
[junit4:junit4]   2> 76757 T1860 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\solr.xml
[junit4:junit4]   2> 76758 T1860 oasc.CoreContainer.<init> New CoreContainer 24983286
[junit4:junit4]   2> 76758 T1860 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\'
[junit4:junit4]   2> 76758 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\'
[junit4:junit4]   2> 76782 T1860 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 76794 T1860 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:57370/solr
[junit4:junit4]   2> 76795 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3651062d
[junit4:junit4]   2> 76797 T1907 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 76797 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 76797 T1907 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 76799 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57397
[junit4:junit4]   2> 76799 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57397
[junit4:junit4]   2> 76816 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120005 with negotiated timeout 5000 for client /127.0.0.1:57397
[junit4:junit4]   2> 76816 T1907 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120005, negotiated timeout = 5000
[junit4:junit4]   2> 76816 T1908 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3651062d name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 76817 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 76818 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76819 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 76821 T1860 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57392_solr
[junit4:junit4]   2> 76822 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57392_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57392_solr
[junit4:junit4]   2> 76822 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57392_solr
[junit4:junit4]   2> 76825 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (2)
[junit4:junit4]   2> 76826 T1880 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 76826 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 76826 T1896 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 76826 T1860 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 76826 T1885 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 76826 T1860 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 76828 T1860 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 76828 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 76829 T1860 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 76829 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 76829 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 76829 T1860 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 76829 T1860 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 76830 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 76840 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 76846 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\collection1
[junit4:junit4]   2> 76847 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 76849 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 76849 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 76851 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\collection1\'
[junit4:junit4]   2> 76852 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 76852 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671/collection1/lib/README' to classloader
[junit4:junit4]   2> 76884 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 76939 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 76940 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 76945 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 77400 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 77413 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 77416 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 77432 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 77437 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 77443 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 77446 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 77447 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1351864863671\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty2\
[junit4:junit4]   2> 77448 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58b315c1
[junit4:junit4]   2> 77449 T1860 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 77450 T1860 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@287fb043 assuming 'simple'
[junit4:junit4]   2> 77451 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2 forceNew:false
[junit4:junit4]   2> 77453 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2
[junit4:junit4]   2> 77453 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty2\index/
[junit4:junit4]   2> 77455 T1860 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 77456 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2\index forceNew:false
[junit4:junit4]   2> 77465 T1860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2\index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 77465 T1860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 77466 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2\index
[junit4:junit4]   2> 77467 T1860 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 77468 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 77468 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 77469 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 77469 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 77470 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 77470 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 77470 T1860 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 77473 T1860 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 77474 T1860 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 77475 T1860 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 77477 T1860 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 77477 T1860 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 77478 T1860 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 77479 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 77479 T1860 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 77480 T1860 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 77481 T1860 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77482 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77483 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77484 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77484 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77484 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77485 T1860 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 77486 T1860 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 77487 T1860 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 77494 T1860 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 77498 T1860 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 77499 T1860 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> 77501 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty2
[junit4:junit4]   2> 77504 T1860 oass.SolrIndexSearcher.<init> Opening Searcher@2f1abc3e main
[junit4:junit4]   2> 77505 T1860 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 77506 T1860 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 77506 T1860 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 77515 T1860 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 77565 T1909 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f1abc3e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 77568 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 77610 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 77611 T1881 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57392_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57392/solr"}
[junit4:junit4]   2> 77615 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 77615 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 77615 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 77964 T1860 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 77965 T1860 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:57392/solr shardId:shard2
[junit4:junit4]   2> 77966 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 77977 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:delete cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 77979 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 77980 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 77984 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 77984 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 77984 T1860 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57392/solr/collection1/
[junit4:junit4]   2> 77985 T1860 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 77986 T1860 oasc.SyncStrategy.syncToMe http://127.0.0.1:57392/solr/collection1/ has no replicas
[junit4:junit4]   2> 77986 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57392/solr/collection1/
[junit4:junit4]   2> 77987 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 77996 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120005 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 78014 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 78027 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78027 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78027 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78041 T1860 oasc.ZkController.register We are http://127.0.0.1:57392/solr/collection1/ and leader is http://127.0.0.1:57392/solr/collection1/
[junit4:junit4]   2> 78042 T1860 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57392/solr
[junit4:junit4]   2> 78042 T1860 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 78043 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 78047 T1860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 78048 T1860 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 78049 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 78049 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 78361 T1860 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 78367 T1860 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:57398
[junit4:junit4]   2> 78368 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 78369 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261
[junit4:junit4]   2> 78370 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\'
[junit4:junit4]   2> 78405 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 78405 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 78406 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261
[junit4:junit4]   2> 78406 T1860 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\solr.xml
[junit4:junit4]   2> 78406 T1860 oasc.CoreContainer.<init> New CoreContainer 263046748
[junit4:junit4]   2> 78407 T1860 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\'
[junit4:junit4]   2> 78407 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\'
[junit4:junit4]   2> 78429 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 78430 T1881 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57392_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57392/solr"}
[junit4:junit4]   2> 78431 T1860 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 78446 T1860 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:57370/solr
[junit4:junit4]   2> 78447 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@22c9e06d
[junit4:junit4]   2> 78447 T1919 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 78447 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 78449 T1919 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 78450 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57403
[junit4:junit4]   2> 78450 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57403
[junit4:junit4]   2> 78454 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120006 with negotiated timeout 5000 for client /127.0.0.1:57403
[junit4:junit4]   2> 78454 T1919 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120006, negotiated timeout = 5000
[junit4:junit4]   2> 78454 T1920 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22c9e06d name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 78454 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 78455 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 78457 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78457 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78457 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78458 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 78463 T1860 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57398_solr
[junit4:junit4]   2> 78464 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57398_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57398_solr
[junit4:junit4]   2> 78464 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57398_solr
[junit4:junit4]   2> 78468 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (3)
[junit4:junit4]   2> 78469 T1896 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 78469 T1908 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 78469 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78469 T1880 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 78469 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 78469 T1860 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 78470 T1860 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 78471 T1860 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 78471 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 78471 T1885 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 78471 T1860 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 78471 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 78471 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 78473 T1860 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 78473 T1860 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 78473 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 78481 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 78487 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\collection1
[junit4:junit4]   2> 78487 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 78488 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 78488 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 78491 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\collection1\'
[junit4:junit4]   2> 78494 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 78494 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261/collection1/lib/README' to classloader
[junit4:junit4]   2> 78533 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 78590 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 78596 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 78600 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 79046 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 79055 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 79058 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 79070 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 79074 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 79078 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 79079 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 79080 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1351864865261\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty3\
[junit4:junit4]   2> 79080 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58b315c1
[junit4:junit4]   2> 79081 T1860 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 79082 T1860 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@19b33657 assuming 'simple'
[junit4:junit4]   2> 79082 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3 forceNew:false
[junit4:junit4]   2> 79083 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3
[junit4:junit4]   2> 79084 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty3\index/
[junit4:junit4]   2> 79085 T1860 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 79085 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3\index forceNew:false
[junit4:junit4]   2> 79098 T1860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3\index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 79098 T1860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 79099 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3\index
[junit4:junit4]   2> 79099 T1860 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 79102 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 79102 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 79102 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 79102 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 79103 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 79103 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 79104 T1860 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 79105 T1860 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 79106 T1860 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 79106 T1860 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 79108 T1860 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 79108 T1860 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 79108 T1860 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 79109 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 79109 T1860 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 79109 T1860 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 79109 T1860 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79111 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79112 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79113 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79115 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79115 T1860 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79116 T1860 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 79117 T1860 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 79119 T1860 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 79125 T1860 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 79129 T1860 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 79129 T1860 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> 79132 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty3
[junit4:junit4]   2> 79133 T1860 oass.SolrIndexSearcher.<init> Opening Searcher@629141ec main
[junit4:junit4]   2> 79135 T1860 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 79135 T1860 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 79136 T1860 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 79145 T1860 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 79207 T1921 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@629141ec main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 79212 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 79256 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 79257 T1881 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57398_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57398/solr"}
[junit4:junit4]   2> 79263 T1920 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79263 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79264 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79264 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79609 T1860 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 79610 T1860 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:57398/solr shardId:shard1
[junit4:junit4]   2> 79611 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 79619 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 79619 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 79620 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 79623 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4]   2> 79663 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 79669 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79669 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79669 T1920 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 79669 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 80018 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179605
[junit4:junit4]   2> 80413 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179210
[junit4:junit4]   2> 80808 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178815
[junit4:junit4]   2> 81203 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178420
[junit4:junit4]   2> 81600 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=178023
[junit4:junit4]   2> 81995 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177628
[junit4:junit4]   2> 82390 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=177233
[junit4:junit4]   2> 82785 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176838
[junit4:junit4]   2> 83180 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176443
[junit4:junit4]   2> 83575 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=176048
[junit4:junit4]   2> 83970 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175653
[junit4:junit4]   2> 84366 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=175257
[junit4:junit4]   2> 84756 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174867
[junit4:junit4]   2> 85112 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174511
[junit4:junit4]   2> 85467 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=174156
[junit4:junit4]   2> 85823 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173800
[junit4:junit4]   2> 86179 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173444
[junit4:junit4]   2> 86535 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=173088
[junit4:junit4]   2> 86891 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172732
[junit4:junit4]   2> 87246 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172377
[junit4:junit4]   2> 87602 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=172021
[junit4:junit4]   2> 87957 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171666
[junit4:junit4]   2> 88312 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=171311
[junit4:junit4]   2> 88668 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170955
[junit4:junit4]   2> 89024 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170599
[junit4:junit4]   2> 89380 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=170243
[junit4:junit4]   2> 89736 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169887
[junit4:junit4]   2> 90092 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169531
[junit4:junit4]   2> 90448 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=169175
[junit4:junit4]   2> 90803 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168820
[junit4:junit4]   2> 91159 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168464
[junit4:junit4]   2> 91514 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=168109
[junit4:junit4]   2> 91875 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167748
[junit4:junit4]   2> 92267 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=167356
[junit4:junit4]   2> 92659 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166964
[junit4:junit4]   2> 93051 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166572
[junit4:junit4]   2> 93442 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=166181
[junit4:junit4]   2> 93834 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165789
[junit4:junit4]   2> 94225 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165398
[junit4:junit4]   2> 94616 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=165007
[junit4:junit4]   2> 95008 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164615
[junit4:junit4]   2> 95399 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=164224
[junit4:junit4]   2> 95790 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163833
[junit4:junit4]   2> 96182 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163441
[junit4:junit4]   2> 96574 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=163049
[junit4:junit4]   2> 96965 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162658
[junit4:junit4]   2> 97356 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=162267
[junit4:junit4]   2> 97747 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161876
[junit4:junit4]   2> 98139 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161484
[junit4:junit4]   2> 98530 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=161093
[junit4:junit4]   2> 98921 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160702
[junit4:junit4]   2> 99312 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=160311
[junit4:junit4]   2> 99711 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159912
[junit4:junit4]   2> 100141 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159482
[junit4:junit4]   2> 100571 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=159052
[junit4:junit4]   2> 101002 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158621
[junit4:junit4]   2> 101432 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=158191
[junit4:junit4]   2> 101862 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157761
[junit4:junit4]   2> 102293 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=157330
[junit4:junit4]   2> 102724 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156899
[junit4:junit4]   2> 103155 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156468
[junit4:junit4]   2> 103584 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=156039
[junit4:junit4]   2> 104015 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155608
[junit4:junit4]   2> 104445 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=155178
[junit4:junit4]   2> 104876 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154747
[junit4:junit4]   2> 105306 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=154317
[junit4:junit4]   2> 105735 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153888
[junit4:junit4]   2> 106166 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153457
[junit4:junit4]   2> 106596 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=153027
[junit4:junit4]   2> 107027 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152596
[junit4:junit4]   2> 107456 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=152167
[junit4:junit4]   2> 107887 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151736
[junit4:junit4]   2> 108326 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=151297
[junit4:junit4]   2> 108800 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150823
[junit4:junit4]   2> 109273 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=150350
[junit4:junit4]   2> 109747 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149876
[junit4:junit4]   2> 110219 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=149404
[junit4:junit4]   2> 110693 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148930
[junit4:junit4]   2> 111166 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=148457
[junit4:junit4]   2> 111641 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147982
[junit4:junit4]   2> 112113 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147510
[junit4:junit4]   2> 112587 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=147036
[junit4:junit4]   2> 113060 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146563
[junit4:junit4]   2> 113532 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=146091
[junit4:junit4]   2> 114006 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145617
[junit4:junit4]   2> 114478 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=145145
[junit4:junit4]   2> 114952 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144671
[junit4:junit4]   2> 115425 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=144198
[junit4:junit4]   2> 115899 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143724
[junit4:junit4]   2> 116373 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=143250
[junit4:junit4]   2> 116848 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142775
[junit4:junit4]   2> 117321 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=142302
[junit4:junit4]   2> 117808 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141815
[junit4:junit4]   2> 118330 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=141293
[junit4:junit4]   2> 118852 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140771
[junit4:junit4]   2> 119372 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=140251
[junit4:junit4]   2> 119894 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139729
[junit4:junit4]   2> 120416 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=139208
[junit4:junit4]   2> 120936 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138687
[junit4:junit4]   2> 121456 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=138167
[junit4:junit4]   2> 121977 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137646
[junit4:junit4]   2> 122498 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=137125
[junit4:junit4]   2> 123019 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136604
[junit4:junit4]   2> 123540 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=136083
[junit4:junit4]   2> 124062 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135561
[junit4:junit4]   2> 124583 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=135040
[junit4:junit4]   2> 125105 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=134518
[junit4:junit4]   2> 125627 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133996
[junit4:junit4]   2> 126147 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=133476
[junit4:junit4]   2> 126669 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132954
[junit4:junit4]   2> 127190 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=132433
[junit4:junit4]   2> 127711 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131912
[junit4:junit4]   2> 128249 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=131374
[junit4:junit4]   2> 128823 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130800
[junit4:junit4]   2> 129397 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=130226
[junit4:junit4]   2> 129971 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129652
[junit4:junit4]   2> 130544 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=129079
[junit4:junit4]   2> 131119 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=128504
[junit4:junit4]   2> 131693 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127930
[junit4:junit4]   2> 132268 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=127355
[junit4:junit4]   2> 132841 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126782
[junit4:junit4]   2> 133416 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=126207
[junit4:junit4]   2> 133991 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125632
[junit4:junit4]   2> 134566 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=125057
[junit4:junit4]   2> 135138 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=124485
[junit4:junit4]   2> 135712 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123911
[junit4:junit4]   2> 136286 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=123337
[junit4:junit4]   2> 136859 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122764
[junit4:junit4]   2> 137434 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=122189
[junit4:junit4]   2> 138005 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121618
[junit4:junit4]   2> 138579 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=121044
[junit4:junit4]   2> 139152 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=120471
[junit4:junit4]   2> 139750 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119873
[junit4:junit4]   2> 140381 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=119242
[junit4:junit4]   2> 141011 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=118612
[junit4:junit4]   2> 141643 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117980
[junit4:junit4]   2> 142271 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=117352
[junit4:junit4]   2> 142902 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116721
[junit4:junit4]   2> 143532 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=116091
[junit4:junit4]   2> 144162 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=115461
[junit4:junit4]   2> 144793 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114830
[junit4:junit4]   2> 145425 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=114198
[junit4:junit4]   2> 146055 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=113568
[junit4:junit4]   2> 146685 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112938
[junit4:junit4]   2> 147315 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=112308
[junit4:junit4]   2> 147945 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111678
[junit4:junit4]   2> 148577 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=111046
[junit4:junit4]   2> 149208 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=110415
[junit4:junit4]   2> 149838 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109785
[junit4:junit4]   2> 150469 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=109154
[junit4:junit4]   2> 151099 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=108524
[junit4:junit4]   2> 151729 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107894
[junit4:junit4]   2> 152388 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=107235
[junit4:junit4]   2> 153081 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=106542
[junit4:junit4]   2> 153774 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105849
[junit4:junit4]   2> 154467 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=105156
[junit4:junit4]   2> 155162 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=104461
[junit4:junit4]   2> 155855 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103768
[junit4:junit4]   2> 156551 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=103072
[junit4:junit4]   2> 157245 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=102378
[junit4:junit4]   2> 157940 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=101683
[junit4:junit4]   2> 158633 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100990
[junit4:junit4]   2> 159326 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=100297
[junit4:junit4]   2> 160019 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=99604
[junit4:junit4]   2> 160712 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98911
[junit4:junit4]   2> 161406 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=98217
[junit4:junit4]   2> 162099 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=97524
[junit4:junit4]   2> 162792 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96831
[junit4:junit4]   2> 163484 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=96139
[junit4:junit4]   2> 164176 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=95447
[junit4:junit4]   2> 164867 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94756
[junit4:junit4]   2> 165561 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=94062
[junit4:junit4]   2> 166219 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=93404
[junit4:junit4]   2> 166842 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92781
[junit4:junit4]   2> 167465 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=92158
[junit4:junit4]   2> 168088 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=91535
[junit4:junit4]   2> 168712 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90911
[junit4:junit4]   2> 169336 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=90287
[junit4:junit4]   2> 169960 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89663
[junit4:junit4]   2> 170584 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=89039
[junit4:junit4]   2> 171206 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=88417
[junit4:junit4]   2> 171830 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87793
[junit4:junit4]   2> 172454 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=87169
[junit4:junit4]   2> 173078 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=86545
[junit4:junit4]   2> 173701 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85922
[junit4:junit4]   2> 174323 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=85300
[junit4:junit4]   2> 174948 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84675
[junit4:junit4]   2> 175571 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=84052
[junit4:junit4]   2> 176195 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=83428
[junit4:junit4]   2> 176820 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82803
[junit4:junit4]   2> 177444 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=82179
[junit4:junit4]   2> 178068 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=81555
[junit4:junit4]   2> 178659 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80964
[junit4:junit4]   2> 179220 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=80403
[junit4:junit4]   2> 179783 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79840
[junit4:junit4]   2> 180344 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=79279
[junit4:junit4]   2> 180906 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78717
[junit4:junit4]   2> 181467 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=78156
[junit4:junit4]   2> 182030 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77593
[junit4:junit4]   2> 182592 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=77031
[junit4:junit4]   2> 183153 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=76470
[junit4:junit4]   2> 183714 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75909
[junit4:junit4]   2> 184276 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=75347
[junit4:junit4]   2> 184836 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74787
[junit4:junit4]   2> 185397 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=74226
[junit4:junit4]   2> 185960 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73663
[junit4:junit4]   2> 186522 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=73101
[junit4:junit4]   2> 187083 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=72540
[junit4:junit4]   2> 187644 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71979
[junit4:junit4]   2> 188207 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=71416
[junit4:junit4]   2> 188769 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70854
[junit4:junit4]   2> 189330 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=70293
[junit4:junit4]   2> 189859 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69764
[junit4:junit4]   2> 190364 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=69259
[junit4:junit4]   2> 190870 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68753
[junit4:junit4]   2> 191375 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=68248
[junit4:junit4]   2> 191880 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67743
[junit4:junit4]   2> 192385 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=67238
[junit4:junit4]   2> 192890 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66733
[junit4:junit4]   2> 193396 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=66227
[junit4:junit4]   2> 193901 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65722
[junit4:junit4]   2> 194406 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=65217
[junit4:junit4]   2> 194911 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64712
[junit4:junit4]   2> 195417 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=64206
[junit4:junit4]   2> 195921 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63702
[junit4:junit4]   2> 196426 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=63197
[junit4:junit4]   2> 196931 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62692
[junit4:junit4]   2> 197436 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=62187
[junit4:junit4]   2> 197941 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61682
[junit4:junit4]   2> 198447 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=61176
[junit4:junit4]   2> 198951 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60672
[junit4:junit4]   2> 199456 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=60167
[junit4:junit4]   2> 199931 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59692
[junit4:junit4]   2> 200386 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=59237
[junit4:junit4]   2> 200840 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58783
[junit4:junit4]   2> 201294 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58329
[junit4:junit4]   2> 201748 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57875
[junit4:junit4]   2> 202204 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=57419
[junit4:junit4]   2> 202659 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56964
[junit4:junit4]   2> 203113 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56510
[junit4:junit4]   2> 203569 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=56054
[junit4:junit4]   2> 204024 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55599
[junit4:junit4]   2> 204480 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=55143
[junit4:junit4]   2> 204933 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54690
[junit4:junit4]   2> 205388 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=54235
[junit4:junit4]   2> 205843 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53780
[junit4:junit4]   2> 206297 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=53326
[junit4:junit4]   2> 206753 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52870
[junit4:junit4]   2> 207206 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=52417
[junit4:junit4]   2> 207660 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51963
[junit4:junit4]   2> 208114 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51509
[junit4:junit4]   2> 208569 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=51054
[junit4:junit4]   2> 208995 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50628
[junit4:junit4]   2> 209404 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=50219
[junit4:junit4]   2> 209813 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49810
[junit4:junit4]   2> 210222 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=49401
[junit4:junit4]   2> 210631 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48992
[junit4:junit4]   2> 211041 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48582
[junit4:junit4]   2> 211450 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=48173
[junit4:junit4]   2> 211859 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47764
[junit4:junit4]   2> 212269 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=47354
[junit4:junit4]   2> 212679 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46944
[junit4:junit4]   2> 213088 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46535
[junit4:junit4]   2> 213497 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=46126
[junit4:junit4]   2> 213906 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45717
[junit4:junit4]   2> 214315 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=45308
[junit4:junit4]   2> 214724 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44899
[junit4:junit4]   2> 215133 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44490
[junit4:junit4]   2> 215542 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=44081
[junit4:junit4]   2> 215952 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43671
[junit4:junit4]   2> 216362 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=43261
[junit4:junit4]   2> 216771 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42852
[junit4:junit4]   2> 217153 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42470
[junit4:junit4]   2> 217521 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=42102
[junit4:junit4]   2> 217890 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41733
[junit4:junit4]   2> 218258 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=41365
[junit4:junit4]   2> 218627 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40996
[junit4:junit4]   2> 218995 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40628
[junit4:junit4]   2> 219363 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=40260
[junit4:junit4]   2> 219732 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39891
[junit4:junit4]   2> 220101 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39522
[junit4:junit4]   2> 220469 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=39154
[junit4:junit4]   2> 220837 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38786
[junit4:junit4]   2> 221206 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38417
[junit4:junit4]   2> 221574 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=38049
[junit4:junit4]   2> 221943 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37680
[junit4:junit4]   2> 222312 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=37311
[junit4:junit4]   2> 222679 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36944
[junit4:junit4]   2> 223049 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36574
[junit4:junit4]   2> 223418 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=36205
[junit4:junit4]   2> 223785 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35838
[junit4:junit4]   2> 224154 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35469
[junit4:junit4]   2> 224548 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=35075
[junit4:junit4]   2> 224954 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34669
[junit4:junit4]   2> 225360 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=34263
[junit4:junit4]   2> 225764 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33859
[junit4:junit4]   2> 226168 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33455
[junit4:junit4]   2> 226573 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=33050
[junit4:junit4]   2> 226977 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32646
[junit4:junit4]   2> 227383 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=32240
[junit4:junit4]   2> 227787 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31836
[junit4:junit4]   2> 228192 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31431
[junit4:junit4]   2> 228597 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=31026
[junit4:junit4]   2> 229003 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30620
[junit4:junit4]   2> 229408 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=30215
[junit4:junit4]   2> 229813 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29810
[junit4:junit4]   2> 230218 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29405
[junit4:junit4]   2> 230623 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=29000
[junit4:junit4]   2> 231029 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28594
[junit4:junit4]   2> 231434 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=28189
[junit4:junit4]   2> 231838 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27785
[junit4:junit4]   2> 232244 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=27379
[junit4:junit4]   2> 232679 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26944
[junit4:junit4]   2> 233125 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26498
[junit4:junit4]   2> 233570 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=26053
[junit4:junit4]   2> 234015 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25608
[junit4:junit4]   2> 234461 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=25162
[junit4:junit4]   2> 234907 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24716
[junit4:junit4]   2> 235353 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=24270
[junit4:junit4]   2> 235798 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23825
[junit4:junit4]   2> 236242 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=23381
[junit4:junit4]   2> 236688 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22935
[junit4:junit4]   2> 237134 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22489
[junit4:junit4]   2> 237581 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=22042
[junit4:junit4]   2> 238026 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21597
[junit4:junit4]   2> 238472 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=21151
[junit4:junit4]   2> 238918 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20705
[junit4:junit4]   2> 239363 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=20260
[junit4:junit4]   2> 239809 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19814
[junit4:junit4]   2> 240255 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=19368
[junit4:junit4]   2> 240701 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18922
[junit4:junit4]   2> 241146 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=18477
[junit4:junit4]   2> 241627 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17996
[junit4:junit4]   2> 242118 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17505
[junit4:junit4]   2> 242609 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=17014
[junit4:junit4]   2> 243099 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16524
[junit4:junit4]   2> 243590 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=16033
[junit4:junit4]   2> 244081 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15542
[junit4:junit4]   2> 244571 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=15052
[junit4:junit4]   2> 245061 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14562
[junit4:junit4]   2> 245553 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=14070
[junit4:junit4]   2> 246044 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13579
[junit4:junit4]   2> 246533 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=13090
[junit4:junit4]   2> 247024 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12599
[junit4:junit4]   2> 247516 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=12107
[junit4:junit4]   2> 248005 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11618
[junit4:junit4]   2> 248494 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=11129
[junit4:junit4]   2> 248985 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10638
[junit4:junit4]   2> 249475 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=10148
[junit4:junit4]   2> 249965 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9658
[junit4:junit4]   2> 250456 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=9167
[junit4:junit4]   2> 250945 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8678
[junit4:junit4]   2> 251476 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=8147
[junit4:junit4]   2> 252015 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7608
[junit4:junit4]   2> 252555 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=7068
[junit4:junit4]   2> 253093 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=6530
[junit4:junit4]   2> 253632 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5991
[junit4:junit4]   2> 254172 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=5451
[junit4:junit4]   2> 254711 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4912
[junit4:junit4]   2> 255249 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=4374
[junit4:junit4]   2> 255788 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3835
[junit4:junit4]   2> 256327 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=3296
[junit4:junit4]   2> 256866 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2757
[junit4:junit4]   2> 257407 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=2216
[junit4:junit4]   2> 257946 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1677
[junit4:junit4]   2> 258487 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=1136
[junit4:junit4]   2> 259026 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=597
[junit4:junit4]   2> 259565 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=58
[junit4:junit4]   2> 260104 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=-481
[junit4:junit4]   2> 260104 T1860 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> 260105 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 260105 T1860 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57398/solr/collection1/
[junit4:junit4]   2> 260105 T1860 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:57398/solr START replicas=[http://127.0.0.1:57386/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 260107 T1860 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:57398/solr DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 260107 T1860 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 260110 T1860 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> 260111 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57398/solr/collection1/
[junit4:junit4]   2> 260112 T1860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 260119 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120006 type:create cxid:0x1bf zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 260388 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 260394 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260394 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260394 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260394 T1920 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260397 T1860 oasc.ZkController.register We are http://127.0.0.1:57398/solr/collection1/ and leader is http://127.0.0.1:57398/solr/collection1/
[junit4:junit4]   2> 260397 T1860 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57398/solr
[junit4:junit4]   2> 260397 T1860 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 260398 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 260401 T1860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 260402 T1860 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 260402 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 260403 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 260711 T1860 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 260716 T1860 oejs.AbstractConnector.doStart Started SelectChannelConnector@0.0.0.0:57405
[junit4:junit4]   2> 260717 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 260717 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614
[junit4:junit4]   2> 260718 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\'
[junit4:junit4]   2> 260748 T1860 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 260748 T1860 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 260749 T1860 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614
[junit4:junit4]   2> 260749 T1860 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\solr.xml
[junit4:junit4]   2> 260749 T1860 oasc.CoreContainer.<init> New CoreContainer 864267586
[junit4:junit4]   2> 260751 T1860 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\'
[junit4:junit4]   2> 260751 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\'
[junit4:junit4]   2> 260777 T1860 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 260792 T1860 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:57370/solr
[junit4:junit4]   2> 260793 T1860 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:57370/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@32e1bf21
[junit4:junit4]   2> 260794 T1932 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:57370
[junit4:junit4]   2> 260794 T1860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 260798 T1932 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:57370, initiating session
[junit4:junit4]   2> 260798 T1862 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /127.0.0.1:57410
[junit4:junit4]   2> 260798 T1862 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /127.0.0.1:57410
[junit4:junit4]   2> 260808 T1864 oazs.NIOServerCnxn.finishSessionInit Established session 0x13ac16ba1120007 with negotiated timeout 5000 for client /127.0.0.1:57410
[junit4:junit4]   2> 260808 T1932 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server 127.0.0.1/127.0.0.1:57370, sessionid = 0x13ac16ba1120007, negotiated timeout = 5000
[junit4:junit4]   2> 260808 T1933 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32e1bf21 name:ZooKeeperConnection Watcher:127.0.0.1:57370/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 260809 T1860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 260809 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120007 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 260811 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120007 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 260813 T1860 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57405_solr
[junit4:junit4]   2> 260814 T1865 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ac16ba1120007 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57405_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57405_solr
[junit4:junit4]   2> 260816 T1860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57405_solr
[junit4:junit4]   2> 260819 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260819 T1920 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (4)
[junit4:junit4]   2> 260820 T1896 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 260820 T1908 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 260820 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260820 T1880 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 260820 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260821 T1860 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 260823 T1885 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 260823 T1920 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 260823 T1860 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 260824 T1860 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 260824 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 260824 T1860 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 260825 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 260825 T1860 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 260825 T1860 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 260826 T1860 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 260826 T1860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 260838 T1860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 260845 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\collection1
[junit4:junit4]   2> 260845 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 260847 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 260847 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 260850 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\collection1\'
[junit4:junit4]   2> 260851 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 260852 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614/collection1/lib/README' to classloader
[junit4:junit4]   2> 260895 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 260948 T1881 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 260948 T1881 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57398_solr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57398/solr"}
[junit4:junit4]   2> 260957 T1933 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260959 T1885 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260959 T1920 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260960 T1908 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260960 T1880 oascc.ZkStateReader$2.process A cluster state change has occurred - updating... (5)
[junit4:junit4]   2> 260976 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 260980 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 260983 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 261564 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 261593 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 261599 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 261617 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 261622 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 261627 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 261629 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 261631 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1351865047614\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty4\
[junit4:junit4]   2> 261632 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58b315c1
[junit4:junit4]   2> 261632 T1860 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 261635 T1860 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f38735f assuming 'simple'
[junit4:junit4]   2> 261635 T1860 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty4 forceNew:false
[junit4:junit4]   2> 261636 T1860 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207\jetty4
[junit4:junit4]   2> 261637 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1351864787207/jetty4\inde

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

          "leader":"true"}}}}}
[junit4:junit4]   1>  /zookeeper (1)
[junit4:junit4]   1>  DATA:
[junit4:junit4]   1>      
[junit4:junit4]   1> 
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=1591B044C1AA90F0 -Dtests.slow=true -Dtests.locale=uk_UA -Dtests.timezone=America/Rosario -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE  459s | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 180 seconds
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([1591B044C1AA90F0:94773E5CB6F5F0CC]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:166)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:116)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:111)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:553)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:74)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:695)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.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> 459200 T1860 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Compressing(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=414, storedFieldsIndex=MEMORY_CHUNK)), sim=DefaultSimilarity, locale=uk_UA, timezone=America/Rosario
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=2,threads=1,free=140175144,total=277417984
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestPerFieldSimilarity, PrimitiveFieldTypeTest, ClusterStateTest, UUIDFieldTest, SimpleFacetsTest, DistributedQueryElevationComponentTest, StatelessScriptUpdateProcessorFactoryTest, TestPhraseSuggestions, TestStressRecovery, TestSolrJ, PathHierarchyTokenizerFactoryTest, TestFiltering, DirectUpdateHandlerTest, MultiTermTest, TestValueSourceCache, TestStressVersions, LegacyHTMLStripCharFilterTest, ResponseLogComponentTest, DefaultValueUpdateProcessorTest, TestDFRSimilarityFactory, LukeRequestHandlerTest, DocumentAnalysisRequestHandlerTest, DistanceFunctionTest, TestPropInjectDefaults, LeaderElectionIntegrationTest, SignatureUpdateProcessorFactoryTest, LoggingHandlerTest, CircularListTest, URLClassifyProcessorTest, TestReplicationHandler, SuggesterTest, TestDistributedGrouping, LeaderElectionTest, SolrRequestParserTest, TestArbitraryIndexDir, SolrCoreTest, TestUpdate, CSVRequestHandlerTest, SuggesterWFSTTest, TestCollationField, SampleTest, TestExtendedDismaxParser, TestQuerySenderNoQuery, SolrCoreCheckLockOnStartupTest, TestStressReorder, OverseerTest, TestReversedWildcardFilterFactory, TestDocSet, SolrIndexConfigTest, FieldMutatingUpdateProcessorTest, TimeZoneUtilsTest, IndexReaderFactoryTest, OpenExchangeRatesOrgProviderTest, SoftAutoCommitTest, NotRequiredUniqueKeyTest, MoreLikeThisHandlerTest, TestRTGBase, TestHashPartitioner, DistributedSpellCheckComponentTest, TestFastWriter, SyncSliceTest, UniqFieldsUpdateProcessorFactoryTest, TestIndexSearcher, BadComponentTest, DirectSolrConnectionTest, TestReload, ZkSolrClientTest, DateFieldTest, TestSolrXMLSerializer, ClusterStateUpdateTest, IndexSchemaTest, SystemInfoHandlerTest, TestTrie, TestSolrCoreProperties, DirectSolrSpellCheckerTest, DirectUpdateHandlerOptimizeTest, SpellingQueryConverterTest, TestStressLucene, TestBadConfig, TestUtils, TestSolrDeletionPolicy1, PluginInfoTest, BasicDistributedZk2Test]
[junit4:junit4] Completed in 459.23s, 1 test, 1 failure <<< FAILURES!

[...truncated 457 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:335: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:178: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\module-build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1163: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:827: There were test failures: 233 suites, 965 tests, 1 failure, 12 ignored (7 assumptions)

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



Mime
View raw message